1 /* Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.
2
3 This program is free software; you can redistribute it and/or modify
4 it under the terms of the GNU General Public License as published by
5 the Free Software Foundation; version 2 of the License.
6
7 This program is distributed in the hope that it will be useful,
8 but WITHOUT ANY WARRANTY; without even the implied warranty of
9 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
10 GNU General Public License for more details.
11
12 You should have received a copy of the GNU General Public License
13 along with this program; if not, write to the Free Software
14 Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA */
15
16
17 /**
18 @file
19
20 @brief
21 logging of commands
22
23 @todo
24 Abort logging when we get an error in reading or writing log files
25 */
26
27 #include "my_global.h" /* NO_EMBEDDED_ACCESS_CHECKS */
28 #include "sql_priv.h"
29 #include "log.h"
30 #include "sql_base.h" // open_log_table
31 #include "sql_repl.h"
32 #include "sql_delete.h" // mysql_truncate
33 #include "sql_parse.h" // command_name
34 #include "sql_time.h" // calc_time_from_sec, my_time_compare
35 #include "tztime.h" // my_tz_OFFSET0, struct Time_zone
36 #include "sql_acl.h" // SUPER_ACL
37 #include "log_event.h" // Query_log_event
38 #include "rpl_filter.h"
39 #include "rpl_rli.h"
40 #include "sql_audit.h"
41
42 #include "sql_show.h"
43 #include <my_dir.h>
44 #include <stdarg.h>
45 #include <m_ctype.h> // For test_if_number
46
47 #ifdef _WIN32
48 #include "message.h"
49 #endif
50
51 #include "sql_plugin.h"
52 #include "rpl_handler.h"
53 #include "debug_sync.h"
54 /* max size of the log message */
55 #define MAX_LOG_BUFFER_SIZE 1024
56 #define MAX_TIME_SIZE 32
57 #define MY_OFF_T_UNDEF (~(my_off_t)0UL)
58
59 #define FLAGSTR(V,F) ((V)&(F)?#F" ":"")
60
61 LOGGER logger;
62
63 MYSQL_BIN_LOG mysql_bin_log(&sync_binlog_period);
64
65 static bool test_if_number(const char *str,
66 ulong *res, bool allow_wildcards);
67 static int binlog_init(void *p);
68 static int binlog_close_connection(handlerton *hton, THD *thd);
69 static int binlog_savepoint_set(handlerton *hton, THD *thd, void *sv);
70 static int binlog_savepoint_rollback(handlerton *hton, THD *thd, void *sv);
71 static int binlog_commit(handlerton *hton, THD *thd, bool all);
72 static int binlog_rollback(handlerton *hton, THD *thd, bool all);
73 static int binlog_prepare(handlerton *hton, THD *thd, bool all);
74
75 /**
76 purge logs, master and slave sides both, related error code
77 convertor.
78 Called from @c purge_error_message(), @c MYSQL_BIN_LOG::reset_logs()
79
80 @param res an internal to purging routines error code
81
82 @return the user level error code ER_*
83 */
purge_log_get_error_code(int res)84 uint purge_log_get_error_code(int res)
85 {
86 uint errcode= 0;
87
88 switch (res) {
89 case 0: break;
90 case LOG_INFO_EOF: errcode= ER_UNKNOWN_TARGET_BINLOG; break;
91 case LOG_INFO_IO: errcode= ER_IO_ERR_LOG_INDEX_READ; break;
92 case LOG_INFO_INVALID:errcode= ER_BINLOG_PURGE_PROHIBITED; break;
93 case LOG_INFO_SEEK: errcode= ER_FSEEK_FAIL; break;
94 case LOG_INFO_MEM: errcode= ER_OUT_OF_RESOURCES; break;
95 case LOG_INFO_FATAL: errcode= ER_BINLOG_PURGE_FATAL_ERR; break;
96 case LOG_INFO_IN_USE: errcode= ER_LOG_IN_USE; break;
97 case LOG_INFO_EMFILE: errcode= ER_BINLOG_PURGE_EMFILE; break;
98 default: errcode= ER_LOG_PURGE_UNKNOWN_ERR; break;
99 }
100
101 return errcode;
102 }
103
104 /**
105 Silence all errors and warnings reported when performing a write
106 to a log table.
107 Errors and warnings are not reported to the client or SQL exception
108 handlers, so that the presence of logging does not interfere and affect
109 the logic of an application.
110 */
111 class Silence_log_table_errors : public Internal_error_handler
112 {
113 char m_message[MYSQL_ERRMSG_SIZE];
114 public:
Silence_log_table_errors()115 Silence_log_table_errors()
116 {
117 m_message[0]= '\0';
118 }
119
~Silence_log_table_errors()120 virtual ~Silence_log_table_errors() {}
121
122 virtual bool handle_condition(THD *thd,
123 uint sql_errno,
124 const char* sql_state,
125 MYSQL_ERROR::enum_warning_level level,
126 const char* msg,
127 MYSQL_ERROR ** cond_hdl);
message() const128 const char *message() const { return m_message; }
129 };
130
131 bool
handle_condition(THD *,uint,const char *,MYSQL_ERROR::enum_warning_level,const char * msg,MYSQL_ERROR ** cond_hdl)132 Silence_log_table_errors::handle_condition(THD *,
133 uint,
134 const char*,
135 MYSQL_ERROR::enum_warning_level,
136 const char* msg,
137 MYSQL_ERROR ** cond_hdl)
138 {
139 *cond_hdl= NULL;
140 strmake(m_message, msg, sizeof(m_message)-1);
141 return TRUE;
142 }
143
144 sql_print_message_func sql_print_message_handlers[3] =
145 {
146 sql_print_information,
147 sql_print_warning,
148 sql_print_error
149 };
150
151 /**
152 Create the name of the log specified.
153
154 This method forms a new path + file name for the
155 log specified in @c name.
156
157 @param[IN] buff Location for building new string.
158 @param[IN] name Name of the log file.
159 @param[IN] log_ext The extension for the log (e.g. .log).
160
161 @returns Pointer to new string containing the name.
162 */
make_log_name(char * buff,const char * name,const char * log_ext)163 char *make_log_name(char *buff, const char *name, const char* log_ext)
164 {
165 strmake(buff, name, FN_REFLEN-5);
166 return fn_format(buff, buff, mysql_real_data_home, log_ext,
167 MYF(MY_UNPACK_FILENAME|MY_REPLACE_EXT));
168 }
169
170 /*
171 Helper class to hold a mutex for the duration of the
172 block.
173
174 Eliminates the need for explicit unlocking of mutexes on, e.g.,
175 error returns. On passing a null pointer, the sentry will not do
176 anything.
177 */
178 class Mutex_sentry
179 {
180 public:
Mutex_sentry(mysql_mutex_t * mutex)181 Mutex_sentry(mysql_mutex_t *mutex)
182 : m_mutex(mutex)
183 {
184 if (m_mutex)
185 mysql_mutex_lock(mutex);
186 }
187
~Mutex_sentry()188 ~Mutex_sentry()
189 {
190 if (m_mutex)
191 mysql_mutex_unlock(m_mutex);
192 #ifndef DBUG_OFF
193 m_mutex= 0;
194 #endif
195 }
196
197 private:
198 mysql_mutex_t *m_mutex;
199
200 // It's not allowed to copy this object in any way
201 Mutex_sentry(Mutex_sentry const&);
202 void operator=(Mutex_sentry const&);
203 };
204
205 /*
206 Helper classes to store non-transactional and transactional data
207 before copying it to the binary log.
208 */
209 class binlog_cache_data
210 {
211 public:
binlog_cache_data()212 binlog_cache_data(): m_pending(0), before_stmt_pos(MY_OFF_T_UNDEF),
213 incident(FALSE), changes_to_non_trans_temp_table_flag(FALSE),
214 saved_max_binlog_cache_size(0), ptr_binlog_cache_use(0),
215 ptr_binlog_cache_disk_use(0)
216 { }
217
~binlog_cache_data()218 ~binlog_cache_data()
219 {
220 DBUG_ASSERT(empty());
221 close_cached_file(&cache_log);
222 }
223
empty() const224 bool empty() const
225 {
226 return pending() == NULL && my_b_tell(&cache_log) == 0;
227 }
228
pending() const229 Rows_log_event *pending() const
230 {
231 return m_pending;
232 }
233
set_pending(Rows_log_event * const pending)234 void set_pending(Rows_log_event *const pending)
235 {
236 m_pending= pending;
237 }
238
set_incident(void)239 void set_incident(void)
240 {
241 incident= TRUE;
242 }
243
has_incident(void)244 bool has_incident(void)
245 {
246 return(incident);
247 }
248
set_changes_to_non_trans_temp_table()249 void set_changes_to_non_trans_temp_table()
250 {
251 changes_to_non_trans_temp_table_flag= TRUE;
252 }
253
changes_to_non_trans_temp_table()254 bool changes_to_non_trans_temp_table()
255 {
256 return (changes_to_non_trans_temp_table_flag);
257 }
258
reset()259 void reset()
260 {
261 compute_statistics();
262 truncate(0);
263 changes_to_non_trans_temp_table_flag= FALSE;
264 incident= FALSE;
265 before_stmt_pos= MY_OFF_T_UNDEF;
266 /*
267 The truncate function calls reinit_io_cache that calls my_b_flush_io_cache
268 which may increase disk_writes. This breaks the disk_writes use by the
269 binary log which aims to compute the ratio between in-memory cache usage
270 and disk cache usage. To avoid this undesirable behavior, we reset the
271 variable after truncating the cache.
272 */
273 cache_log.disk_writes= 0;
274 DBUG_ASSERT(empty());
275 }
276
get_byte_position() const277 my_off_t get_byte_position() const
278 {
279 return my_b_tell(&cache_log);
280 }
281
get_prev_position()282 my_off_t get_prev_position()
283 {
284 return(before_stmt_pos);
285 }
286
set_prev_position(my_off_t pos)287 void set_prev_position(my_off_t pos)
288 {
289 before_stmt_pos= pos;
290 }
291
restore_prev_position()292 void restore_prev_position()
293 {
294 truncate(before_stmt_pos);
295 }
296
restore_savepoint(my_off_t pos)297 void restore_savepoint(my_off_t pos)
298 {
299 truncate(pos);
300 if (pos < before_stmt_pos)
301 before_stmt_pos= MY_OFF_T_UNDEF;
302 }
303
set_binlog_cache_info(my_off_t param_max_binlog_cache_size,ulong * param_ptr_binlog_cache_use,ulong * param_ptr_binlog_cache_disk_use)304 void set_binlog_cache_info(my_off_t param_max_binlog_cache_size,
305 ulong *param_ptr_binlog_cache_use,
306 ulong *param_ptr_binlog_cache_disk_use)
307 {
308 /*
309 The assertions guarantee that the set_binlog_cache_info is
310 called just once and information passed as parameters are
311 never zero.
312
313 This is done while calling the constructor binlog_cache_mngr.
314 We cannot set informaton in the constructor binlog_cache_data
315 because the space for binlog_cache_mngr is allocated through
316 a placement new.
317
318 In the future, we can refactor this and change it to avoid
319 the set_binlog_info.
320 */
321 DBUG_ASSERT(saved_max_binlog_cache_size == 0 &&
322 param_max_binlog_cache_size != 0 &&
323 ptr_binlog_cache_use == 0 &&
324 param_ptr_binlog_cache_use != 0 &&
325 ptr_binlog_cache_disk_use == 0 &&
326 param_ptr_binlog_cache_disk_use != 0);
327
328 saved_max_binlog_cache_size= param_max_binlog_cache_size;
329 ptr_binlog_cache_use= param_ptr_binlog_cache_use;
330 ptr_binlog_cache_disk_use= param_ptr_binlog_cache_disk_use;
331 cache_log.end_of_file= saved_max_binlog_cache_size;
332 }
333
334 /*
335 Cache to store data before copying it to the binary log.
336 */
337 IO_CACHE cache_log;
338
339 private:
340 /*
341 Pending binrows event. This event is the event where the rows are currently
342 written.
343 */
344 Rows_log_event *m_pending;
345
346 /*
347 Binlog position before the start of the current statement.
348 */
349 my_off_t before_stmt_pos;
350
351 /*
352 This indicates that some events did not get into the cache and most likely
353 it is corrupted.
354 */
355 bool incident;
356
357 /*
358 This flag indicates if the cache has changes to temporary tables.
359 @TODO This a temporary fix and should be removed after BUG#54562.
360 */
361 bool changes_to_non_trans_temp_table_flag;
362
363 /**
364 This function computes binlog cache and disk usage.
365 */
compute_statistics()366 void compute_statistics()
367 {
368 if (!empty())
369 {
370 statistic_increment(*ptr_binlog_cache_use, &LOCK_status);
371 if (cache_log.disk_writes != 0)
372 statistic_increment(*ptr_binlog_cache_disk_use, &LOCK_status);
373 }
374 }
375
376 /*
377 Stores the values of maximum size of the cache allowed when this cache
378 is configured. This corresponds to either
379 . max_binlog_cache_size or max_binlog_stmt_cache_size.
380 */
381 my_off_t saved_max_binlog_cache_size;
382
383 /*
384 Stores a pointer to the status variable that keeps track of the in-memory
385 cache usage. This corresponds to either
386 . binlog_cache_use or binlog_stmt_cache_use.
387 */
388 ulong *ptr_binlog_cache_use;
389
390 /*
391 Stores a pointer to the status variable that keeps track of the disk
392 cache usage. This corresponds to either
393 . binlog_cache_disk_use or binlog_stmt_cache_disk_use.
394 */
395 ulong *ptr_binlog_cache_disk_use;
396
397 /*
398 It truncates the cache to a certain position. This includes deleting the
399 pending event.
400 */
truncate(my_off_t pos)401 void truncate(my_off_t pos)
402 {
403 DBUG_PRINT("info", ("truncating to position %lu", (ulong) pos));
404 if (pending())
405 {
406 delete pending();
407 set_pending(0);
408 }
409 reinit_io_cache(&cache_log, WRITE_CACHE, pos, 0, 0);
410 cache_log.end_of_file= saved_max_binlog_cache_size;
411 }
412
413 binlog_cache_data& operator=(const binlog_cache_data& info);
414 binlog_cache_data(const binlog_cache_data& info);
415 };
416
417 class binlog_cache_mngr {
418 public:
binlog_cache_mngr(my_off_t param_max_binlog_stmt_cache_size,my_off_t param_max_binlog_cache_size,ulong * param_ptr_binlog_stmt_cache_use,ulong * param_ptr_binlog_stmt_cache_disk_use,ulong * param_ptr_binlog_cache_use,ulong * param_ptr_binlog_cache_disk_use)419 binlog_cache_mngr(my_off_t param_max_binlog_stmt_cache_size,
420 my_off_t param_max_binlog_cache_size,
421 ulong *param_ptr_binlog_stmt_cache_use,
422 ulong *param_ptr_binlog_stmt_cache_disk_use,
423 ulong *param_ptr_binlog_cache_use,
424 ulong *param_ptr_binlog_cache_disk_use)
425 {
426 stmt_cache.set_binlog_cache_info(param_max_binlog_stmt_cache_size,
427 param_ptr_binlog_stmt_cache_use,
428 param_ptr_binlog_stmt_cache_disk_use);
429 trx_cache.set_binlog_cache_info(param_max_binlog_cache_size,
430 param_ptr_binlog_cache_use,
431 param_ptr_binlog_cache_disk_use);
432 }
433
reset_cache(binlog_cache_data * cache_data)434 void reset_cache(binlog_cache_data* cache_data)
435 {
436 cache_data->reset();
437 }
438
get_binlog_cache_data(bool is_transactional)439 binlog_cache_data* get_binlog_cache_data(bool is_transactional)
440 {
441 return (is_transactional ? &trx_cache : &stmt_cache);
442 }
443
get_binlog_cache_log(bool is_transactional)444 IO_CACHE* get_binlog_cache_log(bool is_transactional)
445 {
446 return (is_transactional ? &trx_cache.cache_log : &stmt_cache.cache_log);
447 }
448
449 binlog_cache_data stmt_cache;
450
451 binlog_cache_data trx_cache;
452
453 private:
454
455 binlog_cache_mngr& operator=(const binlog_cache_mngr& info);
456 binlog_cache_mngr(const binlog_cache_mngr& info);
457 };
458
459 handlerton *binlog_hton;
460
is_log_table_enabled(uint log_table_type)461 bool LOGGER::is_log_table_enabled(uint log_table_type)
462 {
463 switch (log_table_type) {
464 case QUERY_LOG_SLOW:
465 return (table_log_handler != NULL) && opt_slow_log;
466 case QUERY_LOG_GENERAL:
467 return (table_log_handler != NULL) && opt_log ;
468 default:
469 DBUG_ASSERT(0);
470 return FALSE; /* make compiler happy */
471 }
472 }
473
474
475 /* Check if a given table is opened log table */
check_if_log_table(size_t db_len,const char * db,size_t table_name_len,const char * table_name,bool check_if_opened)476 int check_if_log_table(size_t db_len, const char *db, size_t table_name_len,
477 const char *table_name, bool check_if_opened)
478 {
479 if (db_len == 5 &&
480 !(lower_case_table_names ?
481 my_strcasecmp(system_charset_info, db, "mysql") :
482 strcmp(db, "mysql")))
483 {
484 if (table_name_len == 11 && !(lower_case_table_names ?
485 my_strcasecmp(system_charset_info,
486 table_name, "general_log") :
487 strcmp(table_name, "general_log")))
488 {
489 if (!check_if_opened || logger.is_log_table_enabled(QUERY_LOG_GENERAL))
490 return QUERY_LOG_GENERAL;
491 return 0;
492 }
493
494 if (table_name_len == 8 && !(lower_case_table_names ?
495 my_strcasecmp(system_charset_info, table_name, "slow_log") :
496 strcmp(table_name, "slow_log")))
497 {
498 if (!check_if_opened || logger.is_log_table_enabled(QUERY_LOG_SLOW))
499 return QUERY_LOG_SLOW;
500 return 0;
501 }
502 }
503 return 0;
504 }
505
506
Log_to_csv_event_handler()507 Log_to_csv_event_handler::Log_to_csv_event_handler()
508 {
509 }
510
511
~Log_to_csv_event_handler()512 Log_to_csv_event_handler::~Log_to_csv_event_handler()
513 {
514 }
515
516
cleanup()517 void Log_to_csv_event_handler::cleanup()
518 {
519 logger.is_log_tables_initialized= FALSE;
520 }
521
522 /* log event handlers */
523
524 /**
525 Log command to the general log table
526
527 Log given command to the general log table.
528
529 @param event_time command start timestamp
530 @param user_host the pointer to the string with user@host info
531 @param user_host_len length of the user_host string. this is computed
532 once and passed to all general log event handlers
533 @param thread_id Id of the thread, issued a query
534 @param command_type the type of the command being logged
535 @param command_type_len the length of the string above
536 @param sql_text the very text of the query being executed
537 @param sql_text_len the length of sql_text string
538
539
540 @return This function attempts to never call my_error(). This is
541 necessary, because general logging happens already after a statement
542 status has been sent to the client, so the client can not see the
543 error anyway. Besides, the error is not related to the statement
544 being executed and is internal, and thus should be handled
545 internally (@todo: how?).
546 If a write to the table has failed, the function attempts to
547 write to a short error message to the file. The failure is also
548 indicated in the return value.
549
550 @retval FALSE OK
551 @retval TRUE error occured
552 */
553
554 bool Log_to_csv_event_handler::
log_general(THD * thd,time_t event_time,const char * user_host,uint user_host_len,int thread_id,const char * command_type,uint command_type_len,const char * sql_text,uint sql_text_len,CHARSET_INFO * client_cs)555 log_general(THD *thd, time_t event_time, const char *user_host,
556 uint user_host_len, int thread_id,
557 const char *command_type, uint command_type_len,
558 const char *sql_text, uint sql_text_len,
559 CHARSET_INFO *client_cs)
560 {
561 TABLE_LIST table_list;
562 TABLE *table;
563 bool result= TRUE;
564 bool need_close= FALSE;
565 bool need_pop= FALSE;
566 bool need_rnd_end= FALSE;
567 uint field_index;
568 Silence_log_table_errors error_handler;
569 Open_tables_backup open_tables_backup;
570 ulonglong save_thd_options;
571 bool save_time_zone_used;
572
573 /*
574 CSV uses TIME_to_timestamp() internally if table needs to be repaired
575 which will set thd->time_zone_used
576 */
577 save_time_zone_used= thd->time_zone_used;
578
579 save_thd_options= thd->variables.option_bits;
580 thd->variables.option_bits&= ~OPTION_BIN_LOG;
581
582 table_list.init_one_table(MYSQL_SCHEMA_NAME.str, MYSQL_SCHEMA_NAME.length,
583 GENERAL_LOG_NAME.str, GENERAL_LOG_NAME.length,
584 GENERAL_LOG_NAME.str,
585 TL_WRITE_CONCURRENT_INSERT);
586
587 /*
588 1) open_log_table generates an error of the
589 table can not be opened or is corrupted.
590 2) "INSERT INTO general_log" can generate warning sometimes.
591
592 Suppress these warnings and errors, they can't be dealt with
593 properly anyway.
594
595 QQ: this problem needs to be studied in more detail.
596 Comment this 2 lines and run "cast.test" to see what's happening.
597 */
598 thd->push_internal_handler(& error_handler);
599 need_pop= TRUE;
600
601 if (!(table= open_log_table(thd, &table_list, &open_tables_backup)))
602 goto err;
603
604 need_close= TRUE;
605
606 if (table->file->extra(HA_EXTRA_MARK_AS_LOG_TABLE) ||
607 table->file->ha_rnd_init(0))
608 goto err;
609
610 need_rnd_end= TRUE;
611
612 /* Honor next number columns if present */
613 table->next_number_field= table->found_next_number_field;
614
615 /*
616 NOTE: we do not call restore_record() here, as all fields are
617 filled by the Logger (=> no need to load default ones).
618 */
619
620 /*
621 We do not set a value for table->field[0], as it will use
622 default value (which is CURRENT_TIMESTAMP).
623 */
624
625 /* check that all columns exist */
626 if (table->s->fields < 6)
627 goto err;
628
629 DBUG_ASSERT(table->field[0]->type() == MYSQL_TYPE_TIMESTAMP);
630
631 ((Field_timestamp*) table->field[0])->store_timestamp((my_time_t)
632 event_time);
633
634 /* do a write */
635 if (table->field[1]->store(user_host, user_host_len, client_cs) ||
636 table->field[2]->store((longlong) thread_id, TRUE) ||
637 table->field[3]->store((longlong) server_id, TRUE) ||
638 table->field[4]->store(command_type, command_type_len, client_cs))
639 goto err;
640
641 /*
642 A positive return value in store() means truncation.
643 Still logging a message in the log in this case.
644 */
645 table->field[5]->flags|= FIELDFLAG_HEX_ESCAPE;
646 if (table->field[5]->store(sql_text, sql_text_len, client_cs) < 0)
647 goto err;
648
649 /* mark all fields as not null */
650 table->field[1]->set_notnull();
651 table->field[2]->set_notnull();
652 table->field[3]->set_notnull();
653 table->field[4]->set_notnull();
654 table->field[5]->set_notnull();
655
656 /* Set any extra columns to their default values */
657 for (field_index= 6 ; field_index < table->s->fields ; field_index++)
658 {
659 table->field[field_index]->set_default();
660 }
661
662 /* log table entries are not replicated */
663 if (table->file->ha_write_row(table->record[0]))
664 goto err;
665
666 result= FALSE;
667
668 err:
669 if (result && !thd->killed)
670 sql_print_error("Failed to write to mysql.general_log: %s",
671 error_handler.message());
672
673 if (need_rnd_end)
674 {
675 table->file->ha_rnd_end();
676 table->file->ha_release_auto_increment();
677 }
678 if (need_pop)
679 thd->pop_internal_handler();
680 if (need_close)
681 close_log_table(thd, &open_tables_backup);
682
683 thd->variables.option_bits= save_thd_options;
684 thd->time_zone_used= save_time_zone_used;
685 return result;
686 }
687
688
689 /*
690 Log a query to the slow log table
691
692 SYNOPSIS
693 log_slow()
694 thd THD of the query
695 current_time current timestamp
696 query_start_arg command start timestamp
697 user_host the pointer to the string with user@host info
698 user_host_len length of the user_host string. this is computed once
699 and passed to all general log event handlers
700 query_time Amount of time the query took to execute (in microseconds)
701 lock_time Amount of time the query was locked (in microseconds)
702 is_command The flag, which determines, whether the sql_text is a
703 query or an administrator command (these are treated
704 differently by the old logging routines)
705 sql_text the very text of the query or administrator command
706 processed
707 sql_text_len the length of sql_text string
708
709 DESCRIPTION
710
711 Log a query to the slow log table
712
713 RETURN
714 FALSE - OK
715 TRUE - error occured
716 */
717
718 bool Log_to_csv_event_handler::
log_slow(THD * thd,time_t current_time,time_t query_start_arg,const char * user_host,uint user_host_len,ulonglong query_utime,ulonglong lock_utime,bool is_command,const char * sql_text,uint sql_text_len)719 log_slow(THD *thd, time_t current_time, time_t query_start_arg,
720 const char *user_host, uint user_host_len,
721 ulonglong query_utime, ulonglong lock_utime, bool is_command,
722 const char *sql_text, uint sql_text_len)
723 {
724 TABLE_LIST table_list;
725 TABLE *table;
726 bool result= TRUE;
727 bool need_close= FALSE;
728 bool need_rnd_end= FALSE;
729 Silence_log_table_errors error_handler;
730 Open_tables_backup open_tables_backup;
731 CHARSET_INFO *client_cs= thd->variables.character_set_client;
732 bool save_time_zone_used;
733 DBUG_ENTER("Log_to_csv_event_handler::log_slow");
734
735 thd->push_internal_handler(& error_handler);
736 /*
737 CSV uses TIME_to_timestamp() internally if table needs to be repaired
738 which will set thd->time_zone_used
739 */
740 save_time_zone_used= thd->time_zone_used;
741
742 table_list.init_one_table(MYSQL_SCHEMA_NAME.str, MYSQL_SCHEMA_NAME.length,
743 SLOW_LOG_NAME.str, SLOW_LOG_NAME.length,
744 SLOW_LOG_NAME.str,
745 TL_WRITE_CONCURRENT_INSERT);
746
747 if (!(table= open_log_table(thd, &table_list, &open_tables_backup)))
748 goto err;
749
750 need_close= TRUE;
751
752 if (table->file->extra(HA_EXTRA_MARK_AS_LOG_TABLE) ||
753 table->file->ha_rnd_init(0))
754 goto err;
755
756 need_rnd_end= TRUE;
757
758 /* Honor next number columns if present */
759 table->next_number_field= table->found_next_number_field;
760
761 restore_record(table, s->default_values); // Get empty record
762
763 /* check that all columns exist */
764 if (table->s->fields < 11)
765 goto err;
766
767 /* store the time and user values */
768 DBUG_ASSERT(table->field[0]->type() == MYSQL_TYPE_TIMESTAMP);
769 ((Field_timestamp*) table->field[0])->store_timestamp((my_time_t)
770 current_time);
771 if (table->field[1]->store(user_host, user_host_len, client_cs))
772 goto err;
773
774 if (query_start_arg)
775 {
776 longlong query_time= (longlong) (query_utime/1000000);
777 longlong lock_time= (longlong) (lock_utime/1000000);
778 /*
779 A TIME field can not hold the full longlong range; query_time or
780 lock_time may be truncated without warning here, if greater than
781 839 hours (~35 days)
782 */
783 MYSQL_TIME t;
784 t.neg= 0;
785
786 /* fill in query_time field */
787 calc_time_from_sec(&t, (long) min(query_time, (longlong) TIME_MAX_VALUE_SECONDS), 0);
788 if (table->field[2]->store_time(&t, MYSQL_TIMESTAMP_TIME))
789 goto err;
790 /* lock_time */
791 calc_time_from_sec(&t, (long) min(lock_time, (longlong) TIME_MAX_VALUE_SECONDS), 0);
792 if (table->field[3]->store_time(&t, MYSQL_TIMESTAMP_TIME))
793 goto err;
794 /* rows_sent */
795 if (table->field[4]->store((longlong) thd->sent_row_count, TRUE))
796 goto err;
797 /* rows_examined */
798 if (table->field[5]->store((longlong) thd->examined_row_count, TRUE))
799 goto err;
800 }
801 else
802 {
803 table->field[2]->set_null();
804 table->field[3]->set_null();
805 table->field[4]->set_null();
806 table->field[5]->set_null();
807 }
808 /* fill database field */
809 if (thd->db)
810 {
811 if (table->field[6]->store(thd->db, thd->db_length, client_cs))
812 goto err;
813 table->field[6]->set_notnull();
814 }
815
816 if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt)
817 {
818 if (table->
819 field[7]->store((longlong)
820 thd->first_successful_insert_id_in_prev_stmt_for_binlog,
821 TRUE))
822 goto err;
823 table->field[7]->set_notnull();
824 }
825
826 /*
827 Set value if we do an insert on autoincrement column. Note that for
828 some engines (those for which get_auto_increment() does not leave a
829 table lock until the statement ends), this is just the first value and
830 the next ones used may not be contiguous to it.
831 */
832 if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0)
833 {
834 if (table->
835 field[8]->store((longlong)
836 thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum(), TRUE))
837 goto err;
838 table->field[8]->set_notnull();
839 }
840
841 if (table->field[9]->store((longlong) server_id, TRUE))
842 goto err;
843 table->field[9]->set_notnull();
844
845 /*
846 Column sql_text.
847 A positive return value in store() means truncation.
848 Still logging a message in the log in this case.
849 */
850 if (table->field[10]->store(sql_text, sql_text_len, client_cs) < 0)
851 goto err;
852
853 /* log table entries are not replicated */
854 if (table->file->ha_write_row(table->record[0]))
855 goto err;
856
857 result= FALSE;
858
859 err:
860 thd->pop_internal_handler();
861
862 if (result && !thd->killed)
863 sql_print_error("Failed to write to mysql.slow_log: %s",
864 error_handler.message());
865
866 if (need_rnd_end)
867 {
868 table->file->ha_rnd_end();
869 table->file->ha_release_auto_increment();
870 }
871 if (need_close)
872 close_log_table(thd, &open_tables_backup);
873 thd->time_zone_used= save_time_zone_used;
874 DBUG_RETURN(result);
875 }
876
877 int Log_to_csv_event_handler::
activate_log(THD * thd,uint log_table_type)878 activate_log(THD *thd, uint log_table_type)
879 {
880 TABLE_LIST table_list;
881 TABLE *table;
882 LEX_STRING *UNINIT_VAR(log_name);
883 int result;
884 Open_tables_backup open_tables_backup;
885
886 DBUG_ENTER("Log_to_csv_event_handler::activate_log");
887
888 if (log_table_type == QUERY_LOG_GENERAL)
889 {
890 log_name= &GENERAL_LOG_NAME;
891 }
892 else
893 {
894 DBUG_ASSERT(log_table_type == QUERY_LOG_SLOW);
895
896 log_name= &SLOW_LOG_NAME;
897 }
898 table_list.init_one_table(MYSQL_SCHEMA_NAME.str, MYSQL_SCHEMA_NAME.length,
899 log_name->str, log_name->length, log_name->str,
900 TL_WRITE_CONCURRENT_INSERT);
901
902 table= open_log_table(thd, &table_list, &open_tables_backup);
903 if (table)
904 {
905 result= 0;
906 close_log_table(thd, &open_tables_backup);
907 }
908 else
909 result= 1;
910
911 DBUG_RETURN(result);
912 }
913
914 bool Log_to_csv_event_handler::
log_error(enum loglevel level,const char * format,va_list args)915 log_error(enum loglevel level, const char *format, va_list args)
916 {
917 /* No log table is implemented */
918 DBUG_ASSERT(0);
919 return FALSE;
920 }
921
922 bool Log_to_file_event_handler::
log_error(enum loglevel level,const char * format,va_list args)923 log_error(enum loglevel level, const char *format,
924 va_list args)
925 {
926 return vprint_msg_to_log(level, format, args);
927 }
928
init_pthread_objects()929 void Log_to_file_event_handler::init_pthread_objects()
930 {
931 mysql_log.init_pthread_objects();
932 mysql_slow_log.init_pthread_objects();
933 }
934
935
936 /** Wrapper around MYSQL_LOG::write() for slow log. */
937
938 bool Log_to_file_event_handler::
log_slow(THD * thd,time_t current_time,time_t query_start_arg,const char * user_host,uint user_host_len,ulonglong query_utime,ulonglong lock_utime,bool is_command,const char * sql_text,uint sql_text_len)939 log_slow(THD *thd, time_t current_time, time_t query_start_arg,
940 const char *user_host, uint user_host_len,
941 ulonglong query_utime, ulonglong lock_utime, bool is_command,
942 const char *sql_text, uint sql_text_len)
943 {
944 Silence_log_table_errors error_handler;
945 thd->push_internal_handler(&error_handler);
946 bool retval= mysql_slow_log.write(thd, current_time, query_start_arg,
947 user_host, user_host_len,
948 query_utime, lock_utime, is_command,
949 sql_text, sql_text_len);
950 thd->pop_internal_handler();
951 return retval;
952 }
953
954
955 /**
956 Wrapper around MYSQL_LOG::write() for general log. We need it since we
957 want all log event handlers to have the same signature.
958 */
959
960 bool Log_to_file_event_handler::
log_general(THD * thd,time_t event_time,const char * user_host,uint user_host_len,int thread_id,const char * command_type,uint command_type_len,const char * sql_text,uint sql_text_len,CHARSET_INFO * client_cs)961 log_general(THD *thd, time_t event_time, const char *user_host,
962 uint user_host_len, int thread_id,
963 const char *command_type, uint command_type_len,
964 const char *sql_text, uint sql_text_len,
965 CHARSET_INFO *client_cs)
966 {
967 Silence_log_table_errors error_handler;
968 thd->push_internal_handler(&error_handler);
969 bool retval= mysql_log.write(event_time, user_host, user_host_len,
970 thread_id, command_type, command_type_len,
971 sql_text, sql_text_len);
972 thd->pop_internal_handler();
973 return retval;
974 }
975
976
init()977 bool Log_to_file_event_handler::init()
978 {
979 if (!is_initialized)
980 {
981 if (opt_slow_log)
982 mysql_slow_log.open_slow_log(opt_slow_logname);
983
984 if (opt_log)
985 mysql_log.open_query_log(opt_logname);
986
987 is_initialized= TRUE;
988 }
989
990 return FALSE;
991 }
992
993
cleanup()994 void Log_to_file_event_handler::cleanup()
995 {
996 mysql_log.cleanup();
997 mysql_slow_log.cleanup();
998 }
999
flush()1000 void Log_to_file_event_handler::flush()
1001 {
1002 /* reopen log files */
1003 if (opt_log)
1004 mysql_log.reopen_file();
1005 if (opt_slow_log)
1006 mysql_slow_log.reopen_file();
1007 }
1008
1009 /*
1010 Log error with all enabled log event handlers
1011
1012 SYNOPSIS
1013 error_log_print()
1014
1015 level The level of the error significance: NOTE,
1016 WARNING or ERROR.
1017 format format string for the error message
1018 args list of arguments for the format string
1019
1020 RETURN
1021 FALSE - OK
1022 TRUE - error occured
1023 */
1024
error_log_print(enum loglevel level,const char * format,va_list args)1025 bool LOGGER::error_log_print(enum loglevel level, const char *format,
1026 va_list args)
1027 {
1028 bool error= FALSE;
1029 Log_event_handler **current_handler;
1030
1031 /* currently we don't need locking here as there is no error_log table */
1032 for (current_handler= error_log_handler_list ; *current_handler ;)
1033 error= (*current_handler++)->log_error(level, format, args) || error;
1034
1035 return error;
1036 }
1037
1038
cleanup_base()1039 void LOGGER::cleanup_base()
1040 {
1041 DBUG_ASSERT(inited == 1);
1042 mysql_rwlock_destroy(&LOCK_logger);
1043 if (table_log_handler)
1044 {
1045 table_log_handler->cleanup();
1046 delete table_log_handler;
1047 table_log_handler= NULL;
1048 }
1049 if (file_log_handler)
1050 file_log_handler->cleanup();
1051 }
1052
1053
cleanup_end()1054 void LOGGER::cleanup_end()
1055 {
1056 DBUG_ASSERT(inited == 1);
1057 if (file_log_handler)
1058 {
1059 delete file_log_handler;
1060 file_log_handler=NULL;
1061 }
1062 inited= 0;
1063 }
1064
1065
1066 /**
1067 Perform basic log initialization: create file-based log handler and
1068 init error log.
1069 */
init_base()1070 void LOGGER::init_base()
1071 {
1072 DBUG_ASSERT(inited == 0);
1073 inited= 1;
1074
1075 /*
1076 Here we create file log handler. We don't do it for the table log handler
1077 here as it cannot be created so early. The reason is THD initialization,
1078 which depends on the system variables (parsed later).
1079 */
1080 if (!file_log_handler)
1081 file_log_handler= new Log_to_file_event_handler;
1082
1083 /* by default we use traditional error log */
1084 init_error_log(LOG_FILE);
1085
1086 file_log_handler->init_pthread_objects();
1087 mysql_rwlock_init(key_rwlock_LOCK_logger, &LOCK_logger);
1088 }
1089
1090
init_log_tables()1091 void LOGGER::init_log_tables()
1092 {
1093 if (!table_log_handler)
1094 table_log_handler= new Log_to_csv_event_handler;
1095
1096 if (!is_log_tables_initialized &&
1097 !table_log_handler->init() && !file_log_handler->init())
1098 is_log_tables_initialized= TRUE;
1099 }
1100
1101
flush_logs(THD * thd)1102 bool LOGGER::flush_logs(THD *thd)
1103 {
1104 int rc= 0;
1105
1106 /*
1107 Now we lock logger, as nobody should be able to use logging routines while
1108 log tables are closed
1109 */
1110 logger.lock_exclusive();
1111
1112 /* reopen log files */
1113 file_log_handler->flush();
1114
1115 /* end of log flush */
1116 logger.unlock();
1117 return rc;
1118 }
1119
1120
1121 /**
1122 Close and reopen the slow log (with locks).
1123
1124 @returns FALSE.
1125 */
flush_slow_log()1126 bool LOGGER::flush_slow_log()
1127 {
1128 /*
1129 Now we lock logger, as nobody should be able to use logging routines while
1130 log tables are closed
1131 */
1132 logger.lock_exclusive();
1133
1134 /* Reopen slow log file */
1135 if (opt_slow_log)
1136 file_log_handler->get_mysql_slow_log()->reopen_file();
1137
1138 /* End of log flush */
1139 logger.unlock();
1140
1141 return 0;
1142 }
1143
1144
1145 /**
1146 Close and reopen the general log (with locks).
1147
1148 @returns FALSE.
1149 */
flush_general_log()1150 bool LOGGER::flush_general_log()
1151 {
1152 /*
1153 Now we lock logger, as nobody should be able to use logging routines while
1154 log tables are closed
1155 */
1156 logger.lock_exclusive();
1157
1158 /* Reopen general log file */
1159 if (opt_log)
1160 file_log_handler->get_mysql_log()->reopen_file();
1161
1162 /* End of log flush */
1163 logger.unlock();
1164
1165 return 0;
1166 }
1167
1168
1169 /*
1170 Log slow query with all enabled log event handlers
1171
1172 SYNOPSIS
1173 slow_log_print()
1174
1175 thd THD of the query being logged
1176 query The query being logged
1177 query_length The length of the query string
1178 current_utime Current time in microseconds (from undefined start)
1179
1180 RETURN
1181 FALSE OK
1182 TRUE error occured
1183 */
1184
slow_log_print(THD * thd,const char * query,uint query_length,ulonglong current_utime)1185 bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length,
1186 ulonglong current_utime)
1187
1188 {
1189 bool error= FALSE;
1190 Log_event_handler **current_handler;
1191 bool is_command= FALSE;
1192 char user_host_buff[MAX_USER_HOST_SIZE + 1];
1193 Security_context *sctx= thd->security_ctx;
1194 uint user_host_len= 0;
1195 ulonglong query_utime, lock_utime;
1196
1197 DBUG_ASSERT(thd->enable_slow_log);
1198 /*
1199 Print the message to the buffer if we have slow log enabled
1200 */
1201
1202 if (*slow_log_handler_list)
1203 {
1204 time_t current_time;
1205
1206 /* do not log slow queries from replication threads */
1207 if (thd->slave_thread && !opt_log_slow_slave_statements)
1208 return 0;
1209
1210 lock_shared();
1211 if (!opt_slow_log)
1212 {
1213 unlock();
1214 return 0;
1215 }
1216
1217 /* fill in user_host value: the format is "%s[%s] @ %s [%s]" */
1218 user_host_len= (strxnmov(user_host_buff, MAX_USER_HOST_SIZE,
1219 sctx->priv_user ? sctx->priv_user : "", "[",
1220 sctx->user ? sctx->user : "", "] @ ",
1221 sctx->get_host()->length() ?
1222 sctx->get_host()->ptr() : "", " [",
1223 sctx->get_ip()->length() ? sctx->get_ip()->ptr() :
1224 "", "]", NullS) - user_host_buff);
1225
1226
1227 current_time= my_time_possible_from_micro(current_utime);
1228 if (thd->start_utime)
1229 {
1230 query_utime= (current_utime - thd->start_utime);
1231 lock_utime= (thd->utime_after_lock - thd->start_utime);
1232 }
1233 else
1234 {
1235 query_utime= lock_utime= 0;
1236 }
1237
1238 if (!query)
1239 {
1240 is_command= TRUE;
1241 query= command_name[thd->command].str;
1242 query_length= command_name[thd->command].length;
1243 }
1244
1245 for (current_handler= slow_log_handler_list; *current_handler ;)
1246 error= (*current_handler++)->log_slow(thd, current_time, thd->start_time,
1247 user_host_buff, user_host_len,
1248 query_utime, lock_utime, is_command,
1249 query, query_length) || error;
1250
1251 unlock();
1252 }
1253 return error;
1254 }
1255
general_log_write(THD * thd,enum enum_server_command command,const char * query,uint query_length)1256 bool LOGGER::general_log_write(THD *thd, enum enum_server_command command,
1257 const char *query, uint query_length)
1258 {
1259 bool error= FALSE;
1260 Log_event_handler **current_handler= general_log_handler_list;
1261 char user_host_buff[MAX_USER_HOST_SIZE + 1];
1262 uint user_host_len= 0;
1263 time_t current_time;
1264
1265 DBUG_ASSERT(thd);
1266
1267 lock_shared();
1268 if (!opt_log)
1269 {
1270 unlock();
1271 return 0;
1272 }
1273 user_host_len= make_user_name(thd, user_host_buff);
1274
1275 current_time= my_time(0);
1276
1277 mysql_audit_general_log(thd, current_time,
1278 user_host_buff, user_host_len,
1279 command_name[(uint) command].str,
1280 command_name[(uint) command].length,
1281 query, query_length);
1282
1283 while (*current_handler)
1284 error|= (*current_handler++)->
1285 log_general(thd, current_time, user_host_buff,
1286 user_host_len, thd->thread_id,
1287 command_name[(uint) command].str,
1288 command_name[(uint) command].length,
1289 query, query_length,
1290 thd->variables.character_set_client) || error;
1291 unlock();
1292
1293 return error;
1294 }
1295
general_log_print(THD * thd,enum enum_server_command command,const char * format,va_list args)1296 bool LOGGER::general_log_print(THD *thd, enum enum_server_command command,
1297 const char *format, va_list args)
1298 {
1299 uint message_buff_len= 0;
1300 char message_buff[MAX_LOG_BUFFER_SIZE];
1301
1302 /* prepare message */
1303 if (format)
1304 message_buff_len= my_vsnprintf(message_buff, sizeof(message_buff),
1305 format, args);
1306 else
1307 message_buff[0]= '\0';
1308
1309 return general_log_write(thd, command, message_buff, message_buff_len);
1310 }
1311
init_error_log(uint error_log_printer)1312 void LOGGER::init_error_log(uint error_log_printer)
1313 {
1314 if (error_log_printer & LOG_NONE)
1315 {
1316 error_log_handler_list[0]= 0;
1317 return;
1318 }
1319
1320 switch (error_log_printer) {
1321 case LOG_FILE:
1322 error_log_handler_list[0]= file_log_handler;
1323 error_log_handler_list[1]= 0;
1324 break;
1325 /* these two are disabled for now */
1326 case LOG_TABLE:
1327 DBUG_ASSERT(0);
1328 break;
1329 case LOG_TABLE|LOG_FILE:
1330 DBUG_ASSERT(0);
1331 break;
1332 }
1333 }
1334
init_slow_log(uint slow_log_printer)1335 void LOGGER::init_slow_log(uint slow_log_printer)
1336 {
1337 if (slow_log_printer & LOG_NONE)
1338 {
1339 slow_log_handler_list[0]= 0;
1340 return;
1341 }
1342
1343 switch (slow_log_printer) {
1344 case LOG_FILE:
1345 slow_log_handler_list[0]= file_log_handler;
1346 slow_log_handler_list[1]= 0;
1347 break;
1348 case LOG_TABLE:
1349 slow_log_handler_list[0]= table_log_handler;
1350 slow_log_handler_list[1]= 0;
1351 break;
1352 case LOG_TABLE|LOG_FILE:
1353 slow_log_handler_list[0]= file_log_handler;
1354 slow_log_handler_list[1]= table_log_handler;
1355 slow_log_handler_list[2]= 0;
1356 break;
1357 }
1358 }
1359
init_general_log(uint general_log_printer)1360 void LOGGER::init_general_log(uint general_log_printer)
1361 {
1362 if (general_log_printer & LOG_NONE)
1363 {
1364 general_log_handler_list[0]= 0;
1365 return;
1366 }
1367
1368 switch (general_log_printer) {
1369 case LOG_FILE:
1370 general_log_handler_list[0]= file_log_handler;
1371 general_log_handler_list[1]= 0;
1372 break;
1373 case LOG_TABLE:
1374 general_log_handler_list[0]= table_log_handler;
1375 general_log_handler_list[1]= 0;
1376 break;
1377 case LOG_TABLE|LOG_FILE:
1378 general_log_handler_list[0]= file_log_handler;
1379 general_log_handler_list[1]= table_log_handler;
1380 general_log_handler_list[2]= 0;
1381 break;
1382 }
1383 }
1384
1385
activate_log_handler(THD * thd,uint log_type)1386 bool LOGGER::activate_log_handler(THD* thd, uint log_type)
1387 {
1388 MYSQL_QUERY_LOG *file_log;
1389 bool res= FALSE;
1390 lock_exclusive();
1391 switch (log_type) {
1392 case QUERY_LOG_SLOW:
1393 if (!opt_slow_log)
1394 {
1395 file_log= file_log_handler->get_mysql_slow_log();
1396
1397 file_log->open_slow_log(opt_slow_logname);
1398 if (table_log_handler->activate_log(thd, QUERY_LOG_SLOW))
1399 {
1400 /* Error printed by open table in activate_log() */
1401 res= TRUE;
1402 file_log->close(0);
1403 }
1404 else
1405 {
1406 init_slow_log(log_output_options);
1407 opt_slow_log= TRUE;
1408 }
1409 }
1410 break;
1411 case QUERY_LOG_GENERAL:
1412 if (!opt_log)
1413 {
1414 file_log= file_log_handler->get_mysql_log();
1415
1416 file_log->open_query_log(opt_logname);
1417 if (table_log_handler->activate_log(thd, QUERY_LOG_GENERAL))
1418 {
1419 /* Error printed by open table in activate_log() */
1420 res= TRUE;
1421 file_log->close(0);
1422 }
1423 else
1424 {
1425 init_general_log(log_output_options);
1426 opt_log= TRUE;
1427 }
1428 }
1429 break;
1430 default:
1431 DBUG_ASSERT(0);
1432 }
1433 unlock();
1434 return res;
1435 }
1436
1437
deactivate_log_handler(THD * thd,uint log_type)1438 void LOGGER::deactivate_log_handler(THD *thd, uint log_type)
1439 {
1440 my_bool *tmp_opt= 0;
1441 MYSQL_LOG *file_log;
1442
1443 switch (log_type) {
1444 case QUERY_LOG_SLOW:
1445 tmp_opt= &opt_slow_log;
1446 file_log= file_log_handler->get_mysql_slow_log();
1447 break;
1448 case QUERY_LOG_GENERAL:
1449 tmp_opt= &opt_log;
1450 file_log= file_log_handler->get_mysql_log();
1451 break;
1452 default:
1453 MY_ASSERT_UNREACHABLE();
1454 }
1455
1456 if (!(*tmp_opt))
1457 return;
1458
1459 lock_exclusive();
1460 file_log->close(0);
1461 *tmp_opt= FALSE;
1462 unlock();
1463 }
1464
1465
1466 /* the parameters are unused for the log tables */
init()1467 bool Log_to_csv_event_handler::init()
1468 {
1469 return 0;
1470 }
1471
set_handlers(uint error_log_printer,uint slow_log_printer,uint general_log_printer)1472 int LOGGER::set_handlers(uint error_log_printer,
1473 uint slow_log_printer,
1474 uint general_log_printer)
1475 {
1476 /* error log table is not supported yet */
1477 DBUG_ASSERT(error_log_printer < LOG_TABLE);
1478
1479 lock_exclusive();
1480
1481 if ((slow_log_printer & LOG_TABLE || general_log_printer & LOG_TABLE) &&
1482 !is_log_tables_initialized)
1483 {
1484 slow_log_printer= (slow_log_printer & ~LOG_TABLE) | LOG_FILE;
1485 general_log_printer= (general_log_printer & ~LOG_TABLE) | LOG_FILE;
1486
1487 sql_print_error("Failed to initialize log tables. "
1488 "Falling back to the old-fashioned logs");
1489 }
1490
1491 init_error_log(error_log_printer);
1492 init_slow_log(slow_log_printer);
1493 init_general_log(general_log_printer);
1494
1495 unlock();
1496
1497 return 0;
1498 }
1499
1500 /*
1501 Save position of binary log transaction cache.
1502
1503 SYNPOSIS
1504 binlog_trans_log_savepos()
1505
1506 thd The thread to take the binlog data from
1507 pos Pointer to variable where the position will be stored
1508
1509 DESCRIPTION
1510
1511 Save the current position in the binary log transaction cache into
1512 the variable pointed to by 'pos'
1513 */
1514
1515 static void
binlog_trans_log_savepos(THD * thd,my_off_t * pos)1516 binlog_trans_log_savepos(THD *thd, my_off_t *pos)
1517 {
1518 DBUG_ENTER("binlog_trans_log_savepos");
1519 DBUG_ASSERT(pos != NULL);
1520 if (thd_get_ha_data(thd, binlog_hton) == NULL)
1521 thd->binlog_setup_trx_data();
1522 binlog_cache_mngr *const cache_mngr=
1523 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1524 DBUG_ASSERT(mysql_bin_log.is_open());
1525 *pos= cache_mngr->trx_cache.get_byte_position();
1526 DBUG_PRINT("return", ("*pos: %lu", (ulong) *pos));
1527 DBUG_VOID_RETURN;
1528 }
1529
1530
1531 /*
1532 Truncate the binary log transaction cache.
1533
1534 SYNPOSIS
1535 binlog_trans_log_truncate()
1536
1537 thd The thread to take the binlog data from
1538 pos Position to truncate to
1539
1540 DESCRIPTION
1541
1542 Truncate the binary log to the given position. Will not change
1543 anything else.
1544
1545 */
1546 static void
binlog_trans_log_truncate(THD * thd,my_off_t pos)1547 binlog_trans_log_truncate(THD *thd, my_off_t pos)
1548 {
1549 DBUG_ENTER("binlog_trans_log_truncate");
1550 DBUG_PRINT("enter", ("pos: %lu", (ulong) pos));
1551
1552 DBUG_ASSERT(thd_get_ha_data(thd, binlog_hton) != NULL);
1553 /* Only true if binlog_trans_log_savepos() wasn't called before */
1554 DBUG_ASSERT(pos != ~(my_off_t) 0);
1555
1556 binlog_cache_mngr *const cache_mngr=
1557 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1558 cache_mngr->trx_cache.restore_savepoint(pos);
1559 DBUG_VOID_RETURN;
1560 }
1561
1562
1563 /*
1564 this function is mostly a placeholder.
1565 conceptually, binlog initialization (now mostly done in MYSQL_BIN_LOG::open)
1566 should be moved here.
1567 */
1568
binlog_init(void * p)1569 int binlog_init(void *p)
1570 {
1571 binlog_hton= (handlerton *)p;
1572 binlog_hton->state=opt_bin_log ? SHOW_OPTION_YES : SHOW_OPTION_NO;
1573 binlog_hton->db_type=DB_TYPE_BINLOG;
1574 binlog_hton->savepoint_offset= sizeof(my_off_t);
1575 binlog_hton->close_connection= binlog_close_connection;
1576 binlog_hton->savepoint_set= binlog_savepoint_set;
1577 binlog_hton->savepoint_rollback= binlog_savepoint_rollback;
1578 binlog_hton->commit= binlog_commit;
1579 binlog_hton->rollback= binlog_rollback;
1580 binlog_hton->prepare= binlog_prepare;
1581 binlog_hton->flags= HTON_NOT_USER_SELECTABLE | HTON_HIDDEN;
1582 return 0;
1583 }
1584
binlog_close_connection(handlerton * hton,THD * thd)1585 static int binlog_close_connection(handlerton *hton, THD *thd)
1586 {
1587 binlog_cache_mngr *const cache_mngr=
1588 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1589 DBUG_ASSERT(cache_mngr->trx_cache.empty() && cache_mngr->stmt_cache.empty());
1590 thd_set_ha_data(thd, binlog_hton, NULL);
1591 cache_mngr->~binlog_cache_mngr();
1592 my_free(cache_mngr);
1593 return 0;
1594 }
1595
1596 /**
1597 This function flushes a cache upon commit/rollback.
1598
1599 @param thd The thread whose transaction should be flushed
1600 @param cache_data Pointer to the cache
1601 @param end_ev The end event either commit/rollback
1602 @param is_transactional The type of the cache: transactional or
1603 non-transactional
1604
1605 @return
1606 nonzero if an error pops up when flushing the cache.
1607 */
1608 static inline int
binlog_flush_cache(THD * thd,binlog_cache_data * cache_data,Log_event * end_evt,bool is_transactional)1609 binlog_flush_cache(THD *thd, binlog_cache_data* cache_data, Log_event *end_evt,
1610 bool is_transactional)
1611 {
1612 DBUG_ENTER("binlog_flush_cache");
1613 int error= 0;
1614
1615 if (!cache_data->empty())
1616 {
1617 if (thd->binlog_flush_pending_rows_event(TRUE, is_transactional))
1618 DBUG_RETURN(1);
1619 /*
1620 Doing a commit or a rollback including non-transactional tables,
1621 i.e., ending a transaction where we might write the transaction
1622 cache to the binary log.
1623
1624 We can always end the statement when ending a transaction since
1625 transactions are not allowed inside stored functions. If they
1626 were, we would have to ensure that we're not ending a statement
1627 inside a stored function.
1628 */
1629 error= mysql_bin_log.write(thd, &cache_data->cache_log, end_evt,
1630 cache_data->has_incident());
1631 }
1632 cache_data->reset();
1633
1634 DBUG_ASSERT(cache_data->empty());
1635 DBUG_RETURN(error);
1636 }
1637
1638 /**
1639 This function flushes the stmt-cache upon commit.
1640
1641 @param thd The thread whose transaction should be flushed
1642 @param cache_mngr Pointer to the cache manager
1643
1644 @return
1645 nonzero if an error pops up when flushing the cache.
1646 */
1647 static inline int
binlog_commit_flush_stmt_cache(THD * thd,binlog_cache_mngr * cache_mngr)1648 binlog_commit_flush_stmt_cache(THD *thd,
1649 binlog_cache_mngr *cache_mngr)
1650 {
1651 Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"),
1652 FALSE, FALSE, TRUE, 0);
1653 return (binlog_flush_cache(thd, &cache_mngr->stmt_cache, &end_evt,
1654 FALSE));
1655 }
1656
1657 /**
1658 This function flushes the trx-cache upon commit.
1659
1660 @param thd The thread whose transaction should be flushed
1661 @param cache_mngr Pointer to the cache manager
1662
1663 @return
1664 nonzero if an error pops up when flushing the cache.
1665 */
1666 static inline int
binlog_commit_flush_trx_cache(THD * thd,binlog_cache_mngr * cache_mngr)1667 binlog_commit_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr)
1668 {
1669 Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"),
1670 TRUE, FALSE, TRUE, 0);
1671 return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt,
1672 TRUE));
1673 }
1674
1675 /**
1676 This function flushes the trx-cache upon rollback.
1677
1678 @param thd The thread whose transaction should be flushed
1679 @param cache_mngr Pointer to the cache manager
1680
1681 @return
1682 nonzero if an error pops up when flushing the cache.
1683 */
1684 static inline int
binlog_rollback_flush_trx_cache(THD * thd,binlog_cache_mngr * cache_mngr)1685 binlog_rollback_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr)
1686 {
1687 Query_log_event end_evt(thd, STRING_WITH_LEN("ROLLBACK"),
1688 TRUE, FALSE, TRUE, 0);
1689 return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt,
1690 TRUE));
1691 }
1692
1693 /**
1694 This function flushes the trx-cache upon commit.
1695
1696 @param thd The thread whose transaction should be flushed
1697 @param cache_mngr Pointer to the cache manager
1698 @param xid Transaction Id
1699
1700 @return
1701 nonzero if an error pops up when flushing the cache.
1702 */
1703 static inline int
binlog_commit_flush_trx_cache(THD * thd,binlog_cache_mngr * cache_mngr,my_xid xid)1704 binlog_commit_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr,
1705 my_xid xid)
1706 {
1707 Xid_log_event end_evt(thd, xid);
1708 return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt,
1709 TRUE));
1710 }
1711
1712 /**
1713 This function truncates the transactional cache upon committing or rolling
1714 back either a transaction or a statement.
1715
1716 @param thd The thread whose transaction should be flushed
1717 @param cache_mngr Pointer to the cache data to be flushed
1718 @param all @c true means truncate the transaction, otherwise the
1719 statement must be truncated.
1720
1721 @return
1722 nonzero if an error pops up when truncating the transactional cache.
1723 */
1724 static int
binlog_truncate_trx_cache(THD * thd,binlog_cache_mngr * cache_mngr,bool all)1725 binlog_truncate_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr, bool all)
1726 {
1727 DBUG_ENTER("binlog_truncate_trx_cache");
1728 int error=0;
1729 /*
1730 This function handles transactional changes and as such this flag
1731 equals to true.
1732 */
1733 bool const is_transactional= TRUE;
1734
1735 DBUG_PRINT("info", ("thd->options={ %s %s}, transaction: %s",
1736 FLAGSTR(thd->variables.option_bits, OPTION_NOT_AUTOCOMMIT),
1737 FLAGSTR(thd->variables.option_bits, OPTION_BEGIN),
1738 all ? "all" : "stmt"));
1739
1740 thd->binlog_remove_pending_rows_event(TRUE, is_transactional);
1741 /*
1742 If rolling back an entire transaction or a single statement not
1743 inside a transaction, we reset the transaction cache.
1744 */
1745 if (ending_trans(thd, all))
1746 {
1747 if (cache_mngr->trx_cache.has_incident())
1748 error= mysql_bin_log.write_incident(thd, TRUE);
1749
1750 thd->clear_binlog_table_maps();
1751
1752 cache_mngr->reset_cache(&cache_mngr->trx_cache);
1753 }
1754 /*
1755 If rolling back a statement in a transaction, we truncate the
1756 transaction cache to remove the statement.
1757 */
1758 else
1759 cache_mngr->trx_cache.restore_prev_position();
1760
1761 DBUG_ASSERT(thd->binlog_get_pending_rows_event(is_transactional) == NULL);
1762 DBUG_RETURN(error);
1763 }
1764
binlog_prepare(handlerton * hton,THD * thd,bool all)1765 static int binlog_prepare(handlerton *hton, THD *thd, bool all)
1766 {
1767 /*
1768 do nothing.
1769 just pretend we can do 2pc, so that MySQL won't
1770 switch to 1pc.
1771 real work will be done in MYSQL_BIN_LOG::log_xid()
1772 */
1773 return 0;
1774 }
1775
1776 /**
1777 This function is called once after each statement.
1778
1779 It has the responsibility to flush the caches to the binary log on commits.
1780
1781 @param hton The binlog handlerton.
1782 @param thd The client thread that executes the transaction.
1783 @param all This is @c true if this is a real transaction commit, and
1784 @false otherwise.
1785
1786 @see handlerton::commit
1787 */
binlog_commit(handlerton * hton,THD * thd,bool all)1788 static int binlog_commit(handlerton *hton, THD *thd, bool all)
1789 {
1790 int error= 0;
1791 DBUG_ENTER("binlog_commit");
1792 binlog_cache_mngr *const cache_mngr=
1793 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1794
1795 DBUG_PRINT("debug",
1796 ("all: %d, in_transaction: %s, all.modified_non_trans_table: %s, stmt.modified_non_trans_table: %s",
1797 all,
1798 YESNO(thd->in_multi_stmt_transaction_mode()),
1799 YESNO(thd->transaction.all.modified_non_trans_table),
1800 YESNO(thd->transaction.stmt.modified_non_trans_table)));
1801
1802 if (!cache_mngr->stmt_cache.empty())
1803 {
1804 error= binlog_commit_flush_stmt_cache(thd, cache_mngr);
1805 }
1806
1807 if (cache_mngr->trx_cache.empty())
1808 {
1809 /*
1810 we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid()
1811 */
1812 cache_mngr->reset_cache(&cache_mngr->trx_cache);
1813 DBUG_RETURN(error);
1814 }
1815
1816 /*
1817 We commit the transaction if:
1818 - We are not in a transaction and committing a statement, or
1819 - We are in a transaction and a full transaction is committed.
1820 Otherwise, we accumulate the changes.
1821 */
1822 if (!error && ending_trans(thd, all))
1823 error= binlog_commit_flush_trx_cache(thd, cache_mngr);
1824
1825 /*
1826 This is part of the stmt rollback.
1827 */
1828 if (!all)
1829 cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF);
1830
1831 DBUG_RETURN(error);
1832 }
1833
1834 /**
1835 This function is called when a transaction or a statement is rolled back.
1836
1837 @param hton The binlog handlerton.
1838 @param thd The client thread that executes the transaction.
1839 @param all This is @c true if this is a real transaction rollback, and
1840 @false otherwise.
1841
1842 @see handlerton::rollback
1843 */
binlog_rollback(handlerton * hton,THD * thd,bool all)1844 static int binlog_rollback(handlerton *hton, THD *thd, bool all)
1845 {
1846 DBUG_ENTER("binlog_rollback");
1847 int error= 0;
1848 binlog_cache_mngr *const cache_mngr=
1849 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1850
1851 DBUG_PRINT("debug", ("all: %s, all.modified_non_trans_table: %s, stmt.modified_non_trans_table: %s",
1852 YESNO(all),
1853 YESNO(thd->transaction.all.modified_non_trans_table),
1854 YESNO(thd->transaction.stmt.modified_non_trans_table)));
1855
1856 /*
1857 If an incident event is set we do not flush the content of the statement
1858 cache because it may be corrupted.
1859 */
1860 if (cache_mngr->stmt_cache.has_incident())
1861 {
1862 error= mysql_bin_log.write_incident(thd, TRUE);
1863 cache_mngr->reset_cache(&cache_mngr->stmt_cache);
1864 }
1865 else if (!cache_mngr->stmt_cache.empty())
1866 {
1867 error= binlog_commit_flush_stmt_cache(thd, cache_mngr);
1868 }
1869
1870 if (cache_mngr->trx_cache.empty())
1871 {
1872 /*
1873 we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid()
1874 */
1875 cache_mngr->reset_cache(&cache_mngr->trx_cache);
1876 DBUG_RETURN(error);
1877 }
1878
1879 if (mysql_bin_log.check_write_error(thd))
1880 {
1881 /*
1882 "all == true" means that a "rollback statement" triggered the error and
1883 this function was called. However, this must not happen as a rollback
1884 is written directly to the binary log. And in auto-commit mode, a single
1885 statement that is rolled back has the flag all == false.
1886 */
1887 DBUG_ASSERT(!all);
1888 /*
1889 We reach this point if the effect of a statement did not properly get into
1890 a cache and need to be rolled back.
1891 */
1892 error |= binlog_truncate_trx_cache(thd, cache_mngr, all);
1893 }
1894 else if (!error)
1895 {
1896 /*
1897 We flush the cache wrapped in a beging/rollback if:
1898 . aborting a single or multi-statement transaction and;
1899 . the OPTION_KEEP_LOG is active or;
1900 . the format is STMT and a non-trans table was updated or;
1901 . the format is MIXED and a temporary non-trans table was
1902 updated or;
1903 . the format is MIXED, non-trans table was updated and
1904 aborting a single statement transaction;
1905 */
1906 if (ending_trans(thd, all) &&
1907 ((thd->variables.option_bits & OPTION_KEEP_LOG) ||
1908 (trans_has_updated_non_trans_table(thd) &&
1909 thd->variables.binlog_format == BINLOG_FORMAT_STMT) ||
1910 (cache_mngr->trx_cache.changes_to_non_trans_temp_table() &&
1911 thd->variables.binlog_format == BINLOG_FORMAT_MIXED) ||
1912 (trans_has_updated_non_trans_table(thd) &&
1913 ending_single_stmt_trans(thd,all) &&
1914 thd->variables.binlog_format == BINLOG_FORMAT_MIXED)))
1915 error= binlog_rollback_flush_trx_cache(thd, cache_mngr);
1916 /*
1917 Truncate the cache if:
1918 . aborting a single or multi-statement transaction or;
1919 . the OPTION_KEEP_LOG is not active and;
1920 . the format is not STMT or no non-trans table was
1921 updated and;
1922 . the format is not MIXED or no temporary non-trans table
1923 was updated.
1924 */
1925 else if (ending_trans(thd, all) ||
1926 (!(thd->variables.option_bits & OPTION_KEEP_LOG) &&
1927 (!stmt_has_updated_non_trans_table(thd) ||
1928 thd->variables.binlog_format != BINLOG_FORMAT_STMT) &&
1929 (!cache_mngr->trx_cache.changes_to_non_trans_temp_table() ||
1930 thd->variables.binlog_format != BINLOG_FORMAT_MIXED)))
1931 error= binlog_truncate_trx_cache(thd, cache_mngr, all);
1932 }
1933
1934 /*
1935 This is part of the stmt rollback.
1936 */
1937 if (!all)
1938 cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF);
1939
1940 DBUG_RETURN(error);
1941 }
1942
set_write_error(THD * thd,bool is_transactional)1943 void MYSQL_BIN_LOG::set_write_error(THD *thd, bool is_transactional)
1944 {
1945 DBUG_ENTER("MYSQL_BIN_LOG::set_write_error");
1946
1947 write_error= 1;
1948
1949 if (check_write_error(thd))
1950 DBUG_VOID_RETURN;
1951
1952 if (my_errno == EFBIG)
1953 {
1954 if (is_transactional)
1955 {
1956 my_message(ER_TRANS_CACHE_FULL, ER(ER_TRANS_CACHE_FULL), MYF(MY_WME));
1957 }
1958 else
1959 {
1960 my_message(ER_STMT_CACHE_FULL, ER(ER_STMT_CACHE_FULL), MYF(MY_WME));
1961 }
1962 }
1963 else
1964 {
1965 my_error(ER_ERROR_ON_WRITE, MYF(MY_WME), name, errno);
1966 }
1967
1968 DBUG_VOID_RETURN;
1969 }
1970
check_write_error(THD * thd)1971 bool MYSQL_BIN_LOG::check_write_error(THD *thd)
1972 {
1973 DBUG_ENTER("MYSQL_BIN_LOG::check_write_error");
1974
1975 bool checked= FALSE;
1976
1977 if (!thd->is_error())
1978 DBUG_RETURN(checked);
1979
1980 switch (thd->stmt_da->sql_errno())
1981 {
1982 case ER_TRANS_CACHE_FULL:
1983 case ER_STMT_CACHE_FULL:
1984 case ER_ERROR_ON_WRITE:
1985 case ER_BINLOG_LOGGING_IMPOSSIBLE:
1986 checked= TRUE;
1987 break;
1988 }
1989
1990 DBUG_RETURN(checked);
1991 }
1992
1993 /**
1994 @note
1995 How do we handle this (unlikely but legal) case:
1996 @verbatim
1997 [transaction] + [update to non-trans table] + [rollback to savepoint] ?
1998 @endverbatim
1999 The problem occurs when a savepoint is before the update to the
2000 non-transactional table. Then when there's a rollback to the savepoint, if we
2001 simply truncate the binlog cache, we lose the part of the binlog cache where
2002 the update is. If we want to not lose it, we need to write the SAVEPOINT
2003 command and the ROLLBACK TO SAVEPOINT command to the binlog cache. The latter
2004 is easy: it's just write at the end of the binlog cache, but the former
2005 should be *inserted* to the place where the user called SAVEPOINT. The
2006 solution is that when the user calls SAVEPOINT, we write it to the binlog
2007 cache (so no need to later insert it). As transactions are never intermixed
2008 in the binary log (i.e. they are serialized), we won't have conflicts with
2009 savepoint names when using mysqlbinlog or in the slave SQL thread.
2010 Then when ROLLBACK TO SAVEPOINT is called, if we updated some
2011 non-transactional table, we don't truncate the binlog cache but instead write
2012 ROLLBACK TO SAVEPOINT to it; otherwise we truncate the binlog cache (which
2013 will chop the SAVEPOINT command from the binlog cache, which is good as in
2014 that case there is no need to have it in the binlog).
2015 */
2016
binlog_savepoint_set(handlerton * hton,THD * thd,void * sv)2017 static int binlog_savepoint_set(handlerton *hton, THD *thd, void *sv)
2018 {
2019 DBUG_ENTER("binlog_savepoint_set");
2020
2021 binlog_trans_log_savepos(thd, (my_off_t*) sv);
2022
2023 // buffer to store quoted identifier
2024 char* buffer= (char *)my_malloc(sizeof("SAVEPOINT ")+ 1 + NAME_LEN * 2 + 2,
2025 MYF(0));
2026 String log_query(buffer, sizeof(buffer), system_charset_info);
2027 log_query.length(0);
2028
2029 /* Write it to the binary log */
2030
2031 if (log_query.append(STRING_WITH_LEN("SAVEPOINT ")))
2032 DBUG_RETURN(1);
2033 else
2034 append_identifier(thd, &log_query, thd->lex->ident.str,
2035 thd->lex->ident.length);
2036 int errcode= query_error_code(thd, thd->killed == THD::NOT_KILLED);
2037 Query_log_event qinfo(thd, log_query.c_ptr_safe(), log_query.length(),
2038 TRUE, FALSE, TRUE, errcode);
2039 my_free(buffer);
2040 DBUG_RETURN(mysql_bin_log.write(&qinfo));
2041 }
2042
binlog_savepoint_rollback(handlerton * hton,THD * thd,void * sv)2043 static int binlog_savepoint_rollback(handlerton *hton, THD *thd, void *sv)
2044 {
2045 DBUG_ENTER("binlog_savepoint_rollback");
2046
2047 /*
2048 Write ROLLBACK TO SAVEPOINT to the binlog cache if we have updated some
2049 non-transactional table. Otherwise, truncate the binlog cache starting
2050 from the SAVEPOINT command.
2051 */
2052 if (unlikely(trans_has_updated_non_trans_table(thd) ||
2053 (thd->variables.option_bits & OPTION_KEEP_LOG)))
2054 {
2055 // buffer to store rollback query with quoted identifier
2056 char* buffer= (char *)my_malloc(12 + 1 + NAME_LEN * 2 + 2, MYF(0));
2057 String log_query(buffer, sizeof(buffer), system_charset_info);
2058 log_query.length(0);
2059
2060 if (log_query.append(STRING_WITH_LEN("ROLLBACK TO ")))
2061 DBUG_RETURN(1);
2062 else
2063 append_identifier(thd, &log_query, thd->lex->ident.str,
2064 thd->lex->ident.length);
2065 int errcode= query_error_code(thd, thd->killed == THD::NOT_KILLED);
2066 Query_log_event qinfo(thd, log_query.c_ptr_safe(), log_query.length(),
2067 TRUE, FALSE, TRUE, errcode);
2068 my_free(buffer);
2069 DBUG_RETURN(mysql_bin_log.write(&qinfo));
2070 }
2071 binlog_trans_log_truncate(thd, *(my_off_t*)sv);
2072 DBUG_RETURN(0);
2073 }
2074
2075
check_binlog_magic(IO_CACHE * log,const char ** errmsg)2076 int check_binlog_magic(IO_CACHE* log, const char** errmsg)
2077 {
2078 char magic[4];
2079 DBUG_ASSERT(my_b_tell(log) == 0);
2080
2081 if (my_b_read(log, (uchar*) magic, sizeof(magic)))
2082 {
2083 *errmsg = "I/O error reading the header from the binary log";
2084 sql_print_error("%s, errno=%d, io cache code=%d", *errmsg, my_errno,
2085 log->error);
2086 return 1;
2087 }
2088 if (memcmp(magic, BINLOG_MAGIC, sizeof(magic)))
2089 {
2090 *errmsg = "Binlog has bad magic number; It's not a binary log file that can be used by this version of MySQL";
2091 return 1;
2092 }
2093 return 0;
2094 }
2095
2096
open_binlog(IO_CACHE * log,const char * log_file_name,const char ** errmsg)2097 File open_binlog(IO_CACHE *log, const char *log_file_name, const char **errmsg)
2098 {
2099 File file;
2100 DBUG_ENTER("open_binlog");
2101
2102 if ((file= mysql_file_open(key_file_binlog,
2103 log_file_name, O_RDONLY | O_BINARY | O_SHARE,
2104 MYF(MY_WME))) < 0)
2105 {
2106 sql_print_error("Failed to open log (file '%s', errno %d)",
2107 log_file_name, my_errno);
2108 *errmsg = "Could not open log file";
2109 goto err;
2110 }
2111 if (init_io_cache(log, file, IO_SIZE*2, READ_CACHE, 0, 0,
2112 MYF(MY_WME|MY_DONT_CHECK_FILESIZE)))
2113 {
2114 sql_print_error("Failed to create a cache on log (file '%s')",
2115 log_file_name);
2116 *errmsg = "Could not open log file";
2117 goto err;
2118 }
2119 if (check_binlog_magic(log,errmsg))
2120 goto err;
2121 DBUG_RETURN(file);
2122
2123 err:
2124 if (file >= 0)
2125 {
2126 mysql_file_close(file, MYF(0));
2127 end_io_cache(log);
2128 }
2129 DBUG_RETURN(-1);
2130 }
2131
2132 #ifdef _WIN32
2133 static int eventSource = 0;
2134
setup_windows_event_source()2135 static void setup_windows_event_source()
2136 {
2137 HKEY hRegKey= NULL;
2138 DWORD dwError= 0;
2139 TCHAR szPath[MAX_PATH];
2140 DWORD dwTypes;
2141
2142 if (eventSource) // Ensure that we are only called once
2143 return;
2144 eventSource= 1;
2145
2146 // Create the event source registry key
2147 dwError= RegCreateKey(HKEY_LOCAL_MACHINE,
2148 "SYSTEM\\CurrentControlSet\\Services\\EventLog\\Application\\MySQL",
2149 &hRegKey);
2150
2151 /* Name of the PE module that contains the message resource */
2152 GetModuleFileName(NULL, szPath, MAX_PATH);
2153
2154 /* Register EventMessageFile */
2155 dwError = RegSetValueEx(hRegKey, "EventMessageFile", 0, REG_EXPAND_SZ,
2156 (PBYTE) szPath, (DWORD) (strlen(szPath) + 1));
2157
2158 /* Register supported event types */
2159 dwTypes= (EVENTLOG_ERROR_TYPE | EVENTLOG_WARNING_TYPE |
2160 EVENTLOG_INFORMATION_TYPE);
2161 dwError= RegSetValueEx(hRegKey, "TypesSupported", 0, REG_DWORD,
2162 (LPBYTE) &dwTypes, sizeof dwTypes);
2163
2164 RegCloseKey(hRegKey);
2165 }
2166
2167 #endif /* _WIN32 */
2168
2169
2170 /**
2171 Find a unique filename for 'filename.#'.
2172
2173 Set '#' to the number next to the maximum found in the most
2174 recent log file extension.
2175
2176 This function will return nonzero if: (i) the generated name
2177 exceeds FN_REFLEN; (ii) if the number of extensions is exhausted;
2178 or (iii) some other error happened while examining the filesystem.
2179
2180 @return
2181 nonzero if not possible to get unique filename.
2182 */
2183
find_uniq_filename(char * name)2184 static int find_uniq_filename(char *name)
2185 {
2186 uint i;
2187 char buff[FN_REFLEN], ext_buf[FN_REFLEN];
2188 struct st_my_dir *dir_info;
2189 reg1 struct fileinfo *file_info;
2190 ulong max_found= 0, next= 0, number= 0;
2191 size_t buf_length, length;
2192 char *start, *end;
2193 int error= 0;
2194 DBUG_ENTER("find_uniq_filename");
2195
2196 length= dirname_part(buff, name, &buf_length);
2197 start= name + length;
2198 end= strend(start);
2199
2200 *end='.';
2201 length= (size_t) (end - start + 1);
2202
2203 if ((DBUG_EVALUATE_IF("error_unique_log_filename", 1,
2204 !(dir_info= my_dir(buff,MYF(MY_DONT_SORT))))))
2205 { // This shouldn't happen
2206 strmov(end,".1"); // use name+1
2207 DBUG_RETURN(1);
2208 }
2209 file_info= dir_info->dir_entry;
2210 for (i= dir_info->number_off_files ; i-- ; file_info++)
2211 {
2212 if (strncmp(file_info->name, start, length) == 0 &&
2213 test_if_number(file_info->name+length, &number,0))
2214 {
2215 set_if_bigger(max_found,(ulong) number);
2216 }
2217 }
2218 my_dirend(dir_info);
2219
2220 /* check if reached the maximum possible extension number */
2221 if ((max_found == MAX_LOG_UNIQUE_FN_EXT))
2222 {
2223 sql_print_error("Log filename extension number exhausted: %06lu. \
2224 Please fix this by archiving old logs and \
2225 updating the index files.", max_found);
2226 error= 1;
2227 goto end;
2228 }
2229
2230 next= max_found + 1;
2231 if (sprintf(ext_buf, "%06lu", next)<0)
2232 {
2233 error= 1;
2234 goto end;
2235 }
2236 *end++='.';
2237
2238 /*
2239 Check if the generated extension size + the file name exceeds the
2240 buffer size used. If one did not check this, then the filename might be
2241 truncated, resulting in error.
2242 */
2243 if (((strlen(ext_buf) + (end - name)) >= FN_REFLEN))
2244 {
2245 sql_print_error("Log filename too large: %s%s (%zu). \
2246 Please fix this by archiving old logs and updating the \
2247 index files.", name, ext_buf, (strlen(ext_buf) + (end - name)));
2248 error= 1;
2249 goto end;
2250 }
2251
2252 if (sprintf(end, "%06lu", next)<0)
2253 {
2254 error= 1;
2255 goto end;
2256 }
2257
2258 /* print warning if reaching the end of available extensions. */
2259 if ((next > (MAX_LOG_UNIQUE_FN_EXT - LOG_WARN_UNIQUE_FN_EXT_LEFT)))
2260 sql_print_warning("Next log extension: %lu. \
2261 Remaining log filename extensions: %lu. \
2262 Please consider archiving some logs.", next, (MAX_LOG_UNIQUE_FN_EXT - next));
2263
2264 end:
2265 DBUG_RETURN(error);
2266 }
2267
2268
init(enum_log_type log_type_arg,enum cache_type io_cache_type_arg)2269 void MYSQL_LOG::init(enum_log_type log_type_arg,
2270 enum cache_type io_cache_type_arg)
2271 {
2272 DBUG_ENTER("MYSQL_LOG::init");
2273 log_type= log_type_arg;
2274 io_cache_type= io_cache_type_arg;
2275 DBUG_PRINT("info",("log_type: %d", log_type));
2276 DBUG_VOID_RETURN;
2277 }
2278
2279
init_and_set_log_file_name(const char * log_name,const char * new_name,enum_log_type log_type_arg,enum cache_type io_cache_type_arg)2280 bool MYSQL_LOG::init_and_set_log_file_name(const char *log_name,
2281 const char *new_name,
2282 enum_log_type log_type_arg,
2283 enum cache_type io_cache_type_arg)
2284 {
2285 init(log_type_arg, io_cache_type_arg);
2286
2287 if (new_name && !strmov(log_file_name, new_name))
2288 return TRUE;
2289 else if (!new_name && generate_new_name(log_file_name, log_name))
2290 return TRUE;
2291
2292 return FALSE;
2293 }
2294
2295
is_valid_log_name(const char * name,size_t len)2296 bool is_valid_log_name(const char *name, size_t len)
2297 {
2298 if (len > 3)
2299 {
2300 const char *tail= name + len - 4;
2301 if (my_strcasecmp(system_charset_info, tail, ".ini") == 0 ||
2302 my_strcasecmp(system_charset_info, tail, ".cnf") == 0)
2303 {
2304 return false;
2305 }
2306 }
2307 return true;
2308 }
2309
2310
2311 /**
2312 Get the real log file name, and possibly reopen file.
2313
2314 Use realpath() to get the path with symbolic links
2315 expanded. Then, close the file, and reopen the real path using the
2316 O_NOFOLLOW flag. This will reject following symbolic links.
2317
2318 @param file File descriptor.
2319 @param log_file_key Key for P_S instrumentation.
2320 @param open_flags Flags to use for opening the file.
2321 @param opened_file_name Name of the open fd.
2322
2323 @retval file descriptor to open file with 'real_file_name', or '-1'
2324 in case of errors.
2325 */
2326
2327 #ifndef _WIN32
mysql_file_real_name_reopen(File file,PSI_file_key log_file_key,int open_flags,const char * opened_file_name)2328 static File mysql_file_real_name_reopen(File file,
2329 #ifdef HAVE_PSI_INTERFACE
2330 PSI_file_key log_file_key,
2331 #endif
2332 int open_flags,
2333 const char *opened_file_name)
2334 {
2335 DBUG_ASSERT(file);
2336 DBUG_ASSERT(opened_file_name);
2337
2338 /* Buffer for realpath must have capacity for PATH_MAX. */
2339 char real_file_name[PATH_MAX];
2340
2341 /* Get realpath, validate, open realpath with O_NOFOLLOW. */
2342 if (realpath(opened_file_name, real_file_name) == NULL)
2343 {
2344 (void) mysql_file_close(file, MYF(0));
2345 return -1;
2346 }
2347
2348 if (mysql_file_close(file, MYF(0)))
2349 return -1;
2350
2351 if (strlen(real_file_name) > FN_REFLEN)
2352 return -1;
2353
2354 if (!is_valid_log_name(real_file_name, strlen(real_file_name)))
2355 {
2356 sql_print_error("Invalid log file name after expanding symlinks: '%s'",
2357 real_file_name);
2358 return -1;
2359 }
2360
2361 return mysql_file_open(log_file_key, real_file_name,
2362 open_flags | O_NOFOLLOW,
2363 MYF(MY_WME | ME_WAITTANG));
2364 }
2365 #endif // _WIN32
2366
2367 /*
2368 Open a (new) log file.
2369
2370 SYNOPSIS
2371 open()
2372
2373 log_name The name of the log to open
2374 log_type_arg The type of the log. E.g. LOG_NORMAL
2375 new_name The new name for the logfile. This is only needed
2376 when the method is used to open the binlog file.
2377 io_cache_type_arg The type of the IO_CACHE to use for this log file
2378
2379 DESCRIPTION
2380 Open the logfile, init IO_CACHE and write startup messages
2381 (in case of general and slow query logs).
2382
2383 RETURN VALUES
2384 0 ok
2385 1 error
2386 */
2387
open(PSI_file_key log_file_key,const char * log_name,enum_log_type log_type_arg,const char * new_name,enum cache_type io_cache_type_arg)2388 bool MYSQL_LOG::open(
2389 #ifdef HAVE_PSI_INTERFACE
2390 PSI_file_key log_file_key,
2391 #endif
2392 const char *log_name, enum_log_type log_type_arg,
2393 const char *new_name, enum cache_type io_cache_type_arg)
2394 {
2395 char buff[FN_REFLEN];
2396 MY_STAT f_stat;
2397 File file= -1;
2398 int open_flags= O_CREAT | O_BINARY;
2399 DBUG_ENTER("MYSQL_LOG::open");
2400 DBUG_PRINT("enter", ("log_type: %d", (int) log_type_arg));
2401
2402 write_error= 0;
2403
2404 if (!(name= my_strdup(log_name, MYF(MY_WME))))
2405 {
2406 name= (char *)log_name; // for the error message
2407 goto err;
2408 }
2409
2410 if (init_and_set_log_file_name(name, new_name,
2411 log_type_arg, io_cache_type_arg))
2412 goto err;
2413
2414 /* File is regular writable file */
2415 if (my_stat(log_file_name, &f_stat, MYF(0)) && !MY_S_ISREG(f_stat.st_mode))
2416 goto err;
2417
2418 if (io_cache_type == SEQ_READ_APPEND)
2419 open_flags |= O_RDWR | O_APPEND;
2420 else
2421 open_flags |= O_WRONLY | (log_type == LOG_BIN ? 0 : O_APPEND);
2422
2423 db[0]= 0;
2424
2425 #ifdef HAVE_PSI_INTERFACE
2426 /* Keep the key for reopen */
2427 m_log_file_key= log_file_key;
2428 #endif
2429
2430 if ((file= mysql_file_open(log_file_key,
2431 log_file_name, open_flags,
2432 MYF(MY_WME | ME_WAITTANG))) < 0)
2433 goto err;
2434
2435 #ifndef _WIN32
2436 /* Reopen and validate path. */
2437 if ((log_type_arg == LOG_UNKNOWN || log_type_arg == LOG_NORMAL) &&
2438 (file= mysql_file_real_name_reopen(file,
2439 #ifdef HAVE_PSI_INTERFACE
2440 log_file_key,
2441 #endif
2442 open_flags,
2443 log_file_name)) < 0)
2444 goto err;
2445 #endif // _WIN32
2446
2447 if (init_io_cache(&log_file, file, IO_SIZE, io_cache_type,
2448 mysql_file_tell(file, MYF(MY_WME)), 0,
2449 MYF(MY_WME | MY_NABP |
2450 ((log_type == LOG_BIN) ? MY_WAIT_IF_FULL : 0))))
2451 goto err;
2452
2453 if (log_type == LOG_NORMAL)
2454 {
2455 char *end;
2456 int len=my_snprintf(buff, sizeof(buff), "%s, Version: %s (%s). "
2457 #ifdef EMBEDDED_LIBRARY
2458 "embedded library\n",
2459 my_progname, server_version, MYSQL_COMPILATION_COMMENT
2460 #elif _WIN32
2461 "started with:\nTCP Port: %d, Named Pipe: %s\n",
2462 my_progname, server_version, MYSQL_COMPILATION_COMMENT,
2463 mysqld_port, mysqld_unix_port
2464 #else
2465 "started with:\nTcp port: %d Unix socket: %s\n",
2466 my_progname, server_version, MYSQL_COMPILATION_COMMENT,
2467 mysqld_port, mysqld_unix_port
2468 #endif
2469 );
2470 end= strnmov(buff + len, "Time Id Command Argument\n",
2471 sizeof(buff) - len);
2472 if (my_b_write(&log_file, (uchar*) buff, (uint) (end-buff)) ||
2473 flush_io_cache(&log_file))
2474 goto err;
2475 }
2476
2477 log_state= LOG_OPENED;
2478 DBUG_RETURN(0);
2479
2480 err:
2481 sql_print_error("Could not use %s for logging (error %d). \
2482 Turning logging off for the whole duration of the MySQL server process. \
2483 To turn it on again: fix the cause, \
2484 shutdown the MySQL server and restart it.", name, errno);
2485 if (file >= 0)
2486 mysql_file_close(file, MYF(0));
2487 end_io_cache(&log_file);
2488 my_free(name);
2489 name= NULL;
2490 log_state= LOG_CLOSED;
2491 DBUG_RETURN(1);
2492 }
2493
MYSQL_LOG()2494 MYSQL_LOG::MYSQL_LOG()
2495 : name(0), write_error(FALSE), inited(FALSE), log_type(LOG_UNKNOWN),
2496 log_state(LOG_CLOSED)
2497 {
2498 /*
2499 We don't want to initialize LOCK_Log here as such initialization depends on
2500 safe_mutex (when using safe_mutex) which depends on MY_INIT(), which is
2501 called only in main(). Doing initialization here would make it happen
2502 before main().
2503 */
2504 bzero((char*) &log_file, sizeof(log_file));
2505 }
2506
init_pthread_objects()2507 void MYSQL_LOG::init_pthread_objects()
2508 {
2509 DBUG_ASSERT(inited == 0);
2510 inited= 1;
2511 mysql_mutex_init(key_LOG_LOCK_log, &LOCK_log, MY_MUTEX_INIT_SLOW);
2512 }
2513
2514 /*
2515 Close the log file
2516
2517 SYNOPSIS
2518 close()
2519 exiting Bitmask. For the slow and general logs the only used bit is
2520 LOG_CLOSE_TO_BE_OPENED. This is used if we intend to call
2521 open at once after close.
2522
2523 NOTES
2524 One can do an open on the object at once after doing a close.
2525 The internal structures are not freed until cleanup() is called
2526 */
2527
close(uint exiting)2528 void MYSQL_LOG::close(uint exiting)
2529 { // One can't set log_type here!
2530 DBUG_ENTER("MYSQL_LOG::close");
2531 DBUG_PRINT("enter",("exiting: %d", (int) exiting));
2532 if (log_state == LOG_OPENED)
2533 {
2534 end_io_cache(&log_file);
2535
2536 if (mysql_file_sync(log_file.file, MYF(MY_WME)) && ! write_error)
2537 {
2538 write_error= 1;
2539 sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
2540 }
2541
2542 if (mysql_file_close(log_file.file, MYF(MY_WME)) && ! write_error)
2543 {
2544 write_error= 1;
2545 sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
2546 }
2547 }
2548
2549 log_state= (exiting & LOG_CLOSE_TO_BE_OPENED) ? LOG_TO_BE_OPENED : LOG_CLOSED;
2550 my_free(name);
2551 name= NULL;
2552 DBUG_VOID_RETURN;
2553 }
2554
2555 /** This is called only once. */
2556
cleanup()2557 void MYSQL_LOG::cleanup()
2558 {
2559 DBUG_ENTER("cleanup");
2560 if (inited)
2561 {
2562 inited= 0;
2563 mysql_mutex_destroy(&LOCK_log);
2564 close(0);
2565 }
2566 DBUG_VOID_RETURN;
2567 }
2568
2569
generate_new_name(char * new_name,const char * log_name)2570 int MYSQL_LOG::generate_new_name(char *new_name, const char *log_name)
2571 {
2572 fn_format(new_name, log_name, mysql_data_home, "", 4);
2573 if (log_type == LOG_BIN)
2574 {
2575 if (!fn_ext(log_name)[0])
2576 {
2577 if (find_uniq_filename(new_name))
2578 {
2579 my_printf_error(ER_NO_UNIQUE_LOGFILE, ER(ER_NO_UNIQUE_LOGFILE),
2580 MYF(ME_FATALERROR), log_name);
2581 sql_print_error(ER(ER_NO_UNIQUE_LOGFILE), log_name);
2582 return 1;
2583 }
2584 }
2585 }
2586 return 0;
2587 }
2588
2589
2590 /*
2591 Reopen the log file
2592
2593 SYNOPSIS
2594 reopen_file()
2595
2596 DESCRIPTION
2597 Reopen the log file. The method is used during FLUSH LOGS
2598 and locks LOCK_log mutex
2599 */
2600
2601
reopen_file()2602 void MYSQL_QUERY_LOG::reopen_file()
2603 {
2604 char *save_name;
2605
2606 DBUG_ENTER("MYSQL_LOG::reopen_file");
2607 if (!is_open())
2608 {
2609 DBUG_PRINT("info",("log is closed"));
2610 DBUG_VOID_RETURN;
2611 }
2612
2613 mysql_mutex_lock(&LOCK_log);
2614
2615 save_name= name;
2616 name= 0; // Don't free name
2617 close(LOG_CLOSE_TO_BE_OPENED);
2618
2619 /*
2620 Note that at this point, log_state != LOG_CLOSED (important for is_open()).
2621 */
2622
2623 open(
2624 #ifdef HAVE_PSI_INTERFACE
2625 m_log_file_key,
2626 #endif
2627 save_name, log_type, 0, io_cache_type);
2628 my_free(save_name);
2629
2630 mysql_mutex_unlock(&LOCK_log);
2631
2632 DBUG_VOID_RETURN;
2633 }
2634
2635
2636 /*
2637 Write a command to traditional general log file
2638
2639 SYNOPSIS
2640 write()
2641
2642 event_time command start timestamp
2643 user_host the pointer to the string with user@host info
2644 user_host_len length of the user_host string. this is computed once
2645 and passed to all general log event handlers
2646 thread_id Id of the thread, issued a query
2647 command_type the type of the command being logged
2648 command_type_len the length of the string above
2649 sql_text the very text of the query being executed
2650 sql_text_len the length of sql_text string
2651
2652 DESCRIPTION
2653
2654 Log given command to to normal (not rotable) log file
2655
2656 RETURN
2657 FASE - OK
2658 TRUE - error occured
2659 */
2660
write(time_t event_time,const char * user_host,uint user_host_len,int thread_id,const char * command_type,uint command_type_len,const char * sql_text,uint sql_text_len)2661 bool MYSQL_QUERY_LOG::write(time_t event_time, const char *user_host,
2662 uint user_host_len, int thread_id,
2663 const char *command_type, uint command_type_len,
2664 const char *sql_text, uint sql_text_len)
2665 {
2666 char buff[32];
2667 uint length= 0;
2668 char local_time_buff[MAX_TIME_SIZE];
2669 struct tm start;
2670 uint time_buff_len= 0;
2671
2672 mysql_mutex_lock(&LOCK_log);
2673
2674 /* Test if someone closed between the is_open test and lock */
2675 if (is_open())
2676 {
2677 /* for testing output of timestamp and thread id */
2678 DBUG_EXECUTE_IF("reset_log_last_time", last_time= 0;);
2679
2680 /* Note that my_b_write() assumes it knows the length for this */
2681 if (event_time != last_time)
2682 {
2683 last_time= event_time;
2684
2685 localtime_r(&event_time, &start);
2686
2687 time_buff_len= my_snprintf(local_time_buff, MAX_TIME_SIZE,
2688 "%02d%02d%02d %2d:%02d:%02d\t",
2689 start.tm_year % 100, start.tm_mon + 1,
2690 start.tm_mday, start.tm_hour,
2691 start.tm_min, start.tm_sec);
2692
2693 if (my_b_write(&log_file, (uchar*) local_time_buff, time_buff_len))
2694 goto err;
2695 }
2696 else
2697 if (my_b_write(&log_file, (uchar*) "\t\t" ,2) < 0)
2698 goto err;
2699
2700 /* command_type, thread_id */
2701 length= my_snprintf(buff, 32, "%5ld ", (long) thread_id);
2702
2703 if (my_b_write(&log_file, (uchar*) buff, length))
2704 goto err;
2705
2706 if (my_b_write(&log_file, (uchar*) command_type, command_type_len))
2707 goto err;
2708
2709 if (my_b_write(&log_file, (uchar*) "\t", 1))
2710 goto err;
2711
2712 /* sql_text */
2713 if (my_b_write(&log_file, (uchar*) sql_text, sql_text_len))
2714 goto err;
2715
2716 if (my_b_write(&log_file, (uchar*) "\n", 1) ||
2717 flush_io_cache(&log_file))
2718 goto err;
2719 }
2720
2721 mysql_mutex_unlock(&LOCK_log);
2722 return FALSE;
2723 err:
2724
2725 if (!write_error)
2726 {
2727 write_error= 1;
2728 sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
2729 }
2730 mysql_mutex_unlock(&LOCK_log);
2731 return TRUE;
2732 }
2733
2734
2735 /*
2736 Log a query to the traditional slow log file
2737
2738 SYNOPSIS
2739 write()
2740
2741 thd THD of the query
2742 current_time current timestamp
2743 query_start_arg command start timestamp
2744 user_host the pointer to the string with user@host info
2745 user_host_len length of the user_host string. this is computed once
2746 and passed to all general log event handlers
2747 query_utime Amount of time the query took to execute (in microseconds)
2748 lock_utime Amount of time the query was locked (in microseconds)
2749 is_command The flag, which determines, whether the sql_text is a
2750 query or an administrator command.
2751 sql_text the very text of the query or administrator command
2752 processed
2753 sql_text_len the length of sql_text string
2754
2755 DESCRIPTION
2756
2757 Log a query to the slow log file.
2758
2759 RETURN
2760 FALSE - OK
2761 TRUE - error occured
2762 */
2763
write(THD * thd,time_t current_time,time_t query_start_arg,const char * user_host,uint user_host_len,ulonglong query_utime,ulonglong lock_utime,bool is_command,const char * sql_text,uint sql_text_len)2764 bool MYSQL_QUERY_LOG::write(THD *thd, time_t current_time,
2765 time_t query_start_arg, const char *user_host,
2766 uint user_host_len, ulonglong query_utime,
2767 ulonglong lock_utime, bool is_command,
2768 const char *sql_text, uint sql_text_len)
2769 {
2770 bool error= 0;
2771 DBUG_ENTER("MYSQL_QUERY_LOG::write");
2772
2773 mysql_mutex_lock(&LOCK_log);
2774
2775 if (!is_open())
2776 {
2777 mysql_mutex_unlock(&LOCK_log);
2778 DBUG_RETURN(0);
2779 }
2780
2781 if (is_open())
2782 { // Safety agains reopen
2783 int tmp_errno= 0;
2784 char buff[80], *end;
2785 char query_time_buff[22+7], lock_time_buff[22+7];
2786 uint buff_len;
2787 end= buff;
2788
2789 if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
2790 {
2791 if (current_time != last_time)
2792 {
2793 last_time= current_time;
2794 struct tm start;
2795 localtime_r(¤t_time, &start);
2796
2797 buff_len= my_snprintf(buff, sizeof buff,
2798 "# Time: %02d%02d%02d %2d:%02d:%02d\n",
2799 start.tm_year % 100, start.tm_mon + 1,
2800 start.tm_mday, start.tm_hour,
2801 start.tm_min, start.tm_sec);
2802
2803 /* Note that my_b_write() assumes it knows the length for this */
2804 if (my_b_write(&log_file, (uchar*) buff, buff_len))
2805 tmp_errno= errno;
2806 }
2807 const uchar uh[]= "# User@Host: ";
2808 if (my_b_write(&log_file, uh, sizeof(uh) - 1))
2809 tmp_errno= errno;
2810 if (my_b_write(&log_file, (uchar*) user_host, user_host_len))
2811 tmp_errno= errno;
2812 if (my_b_write(&log_file, (uchar*) "\n", 1))
2813 tmp_errno= errno;
2814 }
2815 /* For slow query log */
2816 sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0);
2817 sprintf(lock_time_buff, "%.6f", ulonglong2double(lock_utime)/1000000.0);
2818 if (my_b_printf(&log_file,
2819 "# Query_time: %s Lock_time: %s"
2820 " Rows_sent: %lu Rows_examined: %lu\n",
2821 query_time_buff, lock_time_buff,
2822 (ulong) thd->sent_row_count,
2823 (ulong) thd->examined_row_count) == (uint) -1)
2824 tmp_errno= errno;
2825 if (thd->db && strcmp(thd->db, db))
2826 { // Database changed
2827 if (my_b_printf(&log_file,"use %s;\n",thd->db) == (uint) -1)
2828 tmp_errno= errno;
2829 strmov(db,thd->db);
2830 }
2831 if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt)
2832 {
2833 end=strmov(end, ",last_insert_id=");
2834 end=longlong10_to_str((longlong)
2835 thd->first_successful_insert_id_in_prev_stmt_for_binlog,
2836 end, -10);
2837 }
2838 // Save value if we do an insert.
2839 if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0)
2840 {
2841 if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
2842 {
2843 end=strmov(end,",insert_id=");
2844 end=longlong10_to_str((longlong)
2845 thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum(),
2846 end, -10);
2847 }
2848 }
2849
2850 /*
2851 This info used to show up randomly, depending on whether the query
2852 checked the query start time or not. now we always write current
2853 timestamp to the slow log
2854 */
2855 end= strmov(end, ",timestamp=");
2856 end= int10_to_str((long) current_time, end, 10);
2857
2858 if (end != buff)
2859 {
2860 *end++=';';
2861 *end='\n';
2862 if (my_b_write(&log_file, (uchar*) "SET ", 4) ||
2863 my_b_write(&log_file, (uchar*) buff + 1, (uint) (end-buff)))
2864 tmp_errno= errno;
2865 }
2866 if (is_command)
2867 {
2868 end= strxmov(buff, "# administrator command: ", NullS);
2869 buff_len= (ulong) (end - buff);
2870 DBUG_EXECUTE_IF("simulate_slow_log_write_error",
2871 {DBUG_SET("+d,simulate_file_write_error");});
2872 if(my_b_write(&log_file, (uchar*) buff, buff_len))
2873 tmp_errno= errno;
2874 }
2875 if (my_b_write(&log_file, (uchar*) sql_text, sql_text_len) ||
2876 my_b_write(&log_file, (uchar*) ";\n",2) ||
2877 flush_io_cache(&log_file))
2878 tmp_errno= errno;
2879 if (tmp_errno)
2880 {
2881 error= 1;
2882 if (! write_error)
2883 {
2884 write_error= 1;
2885 sql_print_error(ER(ER_ERROR_ON_WRITE), name, error);
2886 }
2887 }
2888 }
2889 mysql_mutex_unlock(&LOCK_log);
2890 DBUG_RETURN(error);
2891 }
2892
2893
2894 /**
2895 @todo
2896 The following should be using fn_format(); We just need to
2897 first change fn_format() to cut the file name if it's too long.
2898 */
generate_name(const char * log_name,const char * suffix,bool strip_ext,char * buff)2899 const char *MYSQL_LOG::generate_name(const char *log_name,
2900 const char *suffix,
2901 bool strip_ext, char *buff)
2902 {
2903 if (!log_name || !log_name[0])
2904 {
2905 strmake(buff, pidfile_name, FN_REFLEN - strlen(suffix) - 1);
2906 return (const char *)
2907 fn_format(buff, buff, "", suffix, MYF(MY_REPLACE_EXT|MY_REPLACE_DIR));
2908 }
2909 // get rid of extension if the log is binary to avoid problems
2910 if (strip_ext)
2911 {
2912 char *p= fn_ext(log_name);
2913 uint length= (uint) (p - log_name);
2914 strmake(buff, log_name, min(length, FN_REFLEN-1));
2915 return (const char*)buff;
2916 }
2917 return log_name;
2918 }
2919
2920
2921
MYSQL_BIN_LOG(uint * sync_period)2922 MYSQL_BIN_LOG::MYSQL_BIN_LOG(uint *sync_period)
2923 :bytes_written(0), prepared_xids(0), file_id(1), open_count(1),
2924 need_start_event(TRUE),
2925 sync_period_ptr(sync_period), sync_counter(0),
2926 is_relay_log(0), signal_cnt(0),
2927 description_event_for_exec(0), description_event_for_queue(0)
2928 {
2929 /*
2930 We don't want to initialize locks here as such initialization depends on
2931 safe_mutex (when using safe_mutex) which depends on MY_INIT(), which is
2932 called only in main(). Doing initialization here would make it happen
2933 before main().
2934 */
2935 index_file_name[0] = 0;
2936 bzero((char*) &index_file, sizeof(index_file));
2937 bzero((char*) &purge_index_file, sizeof(purge_index_file));
2938 }
2939
2940 /* this is called only once */
2941
cleanup()2942 void MYSQL_BIN_LOG::cleanup()
2943 {
2944 DBUG_ENTER("cleanup");
2945 if (inited)
2946 {
2947 inited= 0;
2948 close(LOG_CLOSE_INDEX|LOG_CLOSE_STOP_EVENT);
2949 delete description_event_for_queue;
2950 delete description_event_for_exec;
2951 mysql_mutex_destroy(&LOCK_log);
2952 mysql_mutex_destroy(&LOCK_index);
2953 mysql_cond_destroy(&update_cond);
2954 }
2955 DBUG_VOID_RETURN;
2956 }
2957
2958
2959 /* Init binlog-specific vars */
init(bool no_auto_events_arg,ulong max_size_arg)2960 void MYSQL_BIN_LOG::init(bool no_auto_events_arg, ulong max_size_arg)
2961 {
2962 DBUG_ENTER("MYSQL_BIN_LOG::init");
2963 no_auto_events= no_auto_events_arg;
2964 max_size= max_size_arg;
2965 DBUG_PRINT("info",("max_size: %lu", max_size));
2966 DBUG_VOID_RETURN;
2967 }
2968
2969
init_pthread_objects()2970 void MYSQL_BIN_LOG::init_pthread_objects()
2971 {
2972 MYSQL_LOG::init_pthread_objects();
2973 mysql_mutex_init(m_key_LOCK_index, &LOCK_index, MY_MUTEX_INIT_SLOW);
2974 mysql_cond_init(m_key_update_cond, &update_cond, 0);
2975 }
2976
2977
open_index_file(const char * index_file_name_arg,const char * log_name,bool need_mutex)2978 bool MYSQL_BIN_LOG::open_index_file(const char *index_file_name_arg,
2979 const char *log_name, bool need_mutex)
2980 {
2981 File index_file_nr= -1;
2982 DBUG_ASSERT(!my_b_inited(&index_file));
2983
2984 /*
2985 First open of this class instance
2986 Create an index file that will hold all file names uses for logging.
2987 Add new entries to the end of it.
2988 */
2989 myf opt= MY_UNPACK_FILENAME;
2990 if (!index_file_name_arg)
2991 {
2992 index_file_name_arg= log_name; // Use same basename for index file
2993 opt= MY_UNPACK_FILENAME | MY_REPLACE_EXT;
2994 }
2995 fn_format(index_file_name, index_file_name_arg, mysql_data_home,
2996 ".index", opt);
2997 if ((index_file_nr= mysql_file_open(m_key_file_log_index,
2998 index_file_name,
2999 O_RDWR | O_CREAT | O_BINARY,
3000 MYF(MY_WME))) < 0 ||
3001 mysql_file_sync(index_file_nr, MYF(MY_WME)) ||
3002 init_io_cache(&index_file, index_file_nr,
3003 IO_SIZE, WRITE_CACHE,
3004 mysql_file_seek(index_file_nr, 0L, MY_SEEK_END, MYF(0)),
3005 0, MYF(MY_WME | MY_WAIT_IF_FULL)) ||
3006 DBUG_EVALUATE_IF("fault_injection_openning_index", 1, 0))
3007 {
3008 /*
3009 TODO: all operations creating/deleting the index file or a log, should
3010 call my_sync_dir() or my_sync_dir_by_file() to be durable.
3011 TODO: file creation should be done with mysql_file_create()
3012 not mysql_file_open().
3013 */
3014 if (index_file_nr >= 0)
3015 mysql_file_close(index_file_nr, MYF(0));
3016 return TRUE;
3017 }
3018
3019 #ifdef HAVE_REPLICATION
3020 /*
3021 Sync the index by purging any binary log file that is not registered.
3022 In other words, either purge binary log files that were removed from
3023 the index but not purged from the file system due to a crash or purge
3024 any binary log file that was created but not register in the index
3025 due to a crash.
3026 */
3027
3028 if (set_purge_index_file_name(index_file_name_arg) ||
3029 open_purge_index_file(FALSE) ||
3030 purge_index_entry(NULL, NULL, need_mutex) ||
3031 close_purge_index_file() ||
3032 DBUG_EVALUATE_IF("fault_injection_recovering_index", 1, 0))
3033 {
3034 sql_print_error("MYSQL_BIN_LOG::open_index_file failed to sync the index "
3035 "file.");
3036 return TRUE;
3037 }
3038 #endif
3039
3040 return FALSE;
3041 }
3042
3043
3044 /**
3045 Open a (new) binlog file.
3046
3047 - Open the log file and the index file. Register the new
3048 file name in it
3049 - When calling this when the file is in use, you must have a locks
3050 on LOCK_log and LOCK_index.
3051
3052 @retval
3053 0 ok
3054 @retval
3055 1 error
3056 */
3057
open(const char * log_name,enum_log_type log_type_arg,const char * new_name,enum cache_type io_cache_type_arg,bool no_auto_events_arg,ulong max_size_arg,bool null_created_arg,bool need_mutex)3058 bool MYSQL_BIN_LOG::open(const char *log_name,
3059 enum_log_type log_type_arg,
3060 const char *new_name,
3061 enum cache_type io_cache_type_arg,
3062 bool no_auto_events_arg,
3063 ulong max_size_arg,
3064 bool null_created_arg,
3065 bool need_mutex)
3066 {
3067 File file= -1;
3068
3069 DBUG_ENTER("MYSQL_BIN_LOG::open");
3070 DBUG_PRINT("enter",("log_type: %d",(int) log_type_arg));
3071
3072 if (init_and_set_log_file_name(log_name, new_name, log_type_arg,
3073 io_cache_type_arg))
3074 {
3075 sql_print_error("MSYQL_BIN_LOG::open failed to generate new file name.");
3076 DBUG_RETURN(1);
3077 }
3078
3079 #ifdef HAVE_REPLICATION
3080 if (open_purge_index_file(TRUE) ||
3081 register_create_index_entry(log_file_name) ||
3082 sync_purge_index_file() ||
3083 DBUG_EVALUATE_IF("fault_injection_registering_index", 1, 0))
3084 {
3085 /**
3086 TODO: although this was introduced to appease valgrind
3087 when injecting emulated faults using fault_injection_registering_index
3088 it may be good to consider what actually happens when
3089 open_purge_index_file succeeds but register or sync fails.
3090
3091 Perhaps we might need the code below in MYSQL_LOG_BIN::cleanup
3092 for "real life" purposes as well?
3093 */
3094 DBUG_EXECUTE_IF("fault_injection_registering_index", {
3095 if (my_b_inited(&purge_index_file))
3096 {
3097 end_io_cache(&purge_index_file);
3098 my_close(purge_index_file.file, MYF(0));
3099 }
3100 });
3101
3102 sql_print_error("MSYQL_BIN_LOG::open failed to sync the index file.");
3103 DBUG_RETURN(1);
3104 }
3105 DBUG_EXECUTE_IF("crash_create_non_critical_before_update_index", DBUG_SUICIDE(););
3106 #endif
3107
3108 write_error= 0;
3109
3110 /* open the main log file */
3111 if (MYSQL_LOG::open(
3112 #ifdef HAVE_PSI_INTERFACE
3113 m_key_file_log,
3114 #endif
3115 log_name, log_type_arg, new_name, io_cache_type_arg))
3116 {
3117 #ifdef HAVE_REPLICATION
3118 close_purge_index_file();
3119 #endif
3120 DBUG_RETURN(1); /* all warnings issued */
3121 }
3122
3123 init(no_auto_events_arg, max_size_arg);
3124
3125 open_count++;
3126
3127 DBUG_ASSERT(log_type == LOG_BIN);
3128
3129 {
3130 bool write_file_name_to_index_file=0;
3131
3132 if (!my_b_filelength(&log_file))
3133 {
3134 /*
3135 The binary log file was empty (probably newly created)
3136 This is the normal case and happens when the user doesn't specify
3137 an extension for the binary log files.
3138 In this case we write a standard header to it.
3139 */
3140 if (my_b_safe_write(&log_file, (uchar*) BINLOG_MAGIC,
3141 BIN_LOG_HEADER_SIZE))
3142 goto err;
3143 bytes_written+= BIN_LOG_HEADER_SIZE;
3144 write_file_name_to_index_file= 1;
3145 }
3146
3147 if (need_start_event && !no_auto_events)
3148 {
3149 /*
3150 In 4.x we set need_start_event=0 here, but in 5.0 we want a Start event
3151 even if this is not the very first binlog.
3152 */
3153 Format_description_log_event s(BINLOG_VERSION);
3154 /*
3155 don't set LOG_EVENT_BINLOG_IN_USE_F for SEQ_READ_APPEND io_cache
3156 as we won't be able to reset it later
3157 */
3158 if (io_cache_type == WRITE_CACHE)
3159 s.flags|= LOG_EVENT_BINLOG_IN_USE_F;
3160 if (!s.is_valid())
3161 goto err;
3162 s.dont_set_created= null_created_arg;
3163 if (s.write(&log_file))
3164 goto err;
3165 bytes_written+= s.data_written;
3166 }
3167 if (description_event_for_queue &&
3168 description_event_for_queue->binlog_version>=4)
3169 {
3170 /*
3171 This is a relay log written to by the I/O slave thread.
3172 Write the event so that others can later know the format of this relay
3173 log.
3174 Note that this event is very close to the original event from the
3175 master (it has binlog version of the master, event types of the
3176 master), so this is suitable to parse the next relay log's event. It
3177 has been produced by
3178 Format_description_log_event::Format_description_log_event(char* buf,).
3179 Why don't we want to write the description_event_for_queue if this
3180 event is for format<4 (3.23 or 4.x): this is because in that case, the
3181 description_event_for_queue describes the data received from the
3182 master, but not the data written to the relay log (*conversion*),
3183 which is in format 4 (slave's).
3184 */
3185 /*
3186 Set 'created' to 0, so that in next relay logs this event does not
3187 trigger cleaning actions on the slave in
3188 Format_description_log_event::apply_event_impl().
3189 */
3190 description_event_for_queue->created= 0;
3191 /* Don't set log_pos in event header */
3192 description_event_for_queue->set_artificial_event();
3193
3194 if (description_event_for_queue->write(&log_file))
3195 goto err;
3196 bytes_written+= description_event_for_queue->data_written;
3197 }
3198 if (flush_io_cache(&log_file) ||
3199 mysql_file_sync(log_file.file, MYF(MY_WME)))
3200 goto err;
3201
3202 if (write_file_name_to_index_file)
3203 {
3204 #ifdef HAVE_REPLICATION
3205 DBUG_EXECUTE_IF("crash_create_critical_before_update_index", DBUG_SUICIDE(););
3206 #endif
3207
3208 DBUG_ASSERT(my_b_inited(&index_file) != 0);
3209 reinit_io_cache(&index_file, WRITE_CACHE,
3210 my_b_filelength(&index_file), 0, 0);
3211 /*
3212 As this is a new log file, we write the file name to the index
3213 file. As every time we write to the index file, we sync it.
3214 */
3215 if (DBUG_EVALUATE_IF("fault_injection_updating_index", 1, 0) ||
3216 my_b_write(&index_file, (uchar*) log_file_name,
3217 strlen(log_file_name)) ||
3218 my_b_write(&index_file, (uchar*) "\n", 1) ||
3219 flush_io_cache(&index_file) ||
3220 mysql_file_sync(index_file.file, MYF(MY_WME)))
3221 goto err;
3222
3223 #ifdef HAVE_REPLICATION
3224 DBUG_EXECUTE_IF("crash_create_after_update_index", DBUG_SUICIDE(););
3225 #endif
3226 }
3227 }
3228 log_state= LOG_OPENED;
3229
3230 #ifdef HAVE_REPLICATION
3231 close_purge_index_file();
3232 #endif
3233
3234 DBUG_RETURN(0);
3235
3236 err:
3237 #ifdef HAVE_REPLICATION
3238 if (is_inited_purge_index_file())
3239 purge_index_entry(NULL, NULL, need_mutex);
3240 close_purge_index_file();
3241 #endif
3242 sql_print_error("Could not use %s for logging (error %d). \
3243 Turning logging off for the whole duration of the MySQL server process. \
3244 To turn it on again: fix the cause, \
3245 shutdown the MySQL server and restart it.", name, errno);
3246 if (file >= 0)
3247 mysql_file_close(file, MYF(0));
3248 end_io_cache(&log_file);
3249 end_io_cache(&index_file);
3250 my_free(name);
3251 name= NULL;
3252 log_state= LOG_CLOSED;
3253 DBUG_RETURN(1);
3254 }
3255
3256
get_current_log(LOG_INFO * linfo)3257 int MYSQL_BIN_LOG::get_current_log(LOG_INFO* linfo)
3258 {
3259 mysql_mutex_lock(&LOCK_log);
3260 int ret = raw_get_current_log(linfo);
3261 mysql_mutex_unlock(&LOCK_log);
3262 return ret;
3263 }
3264
raw_get_current_log(LOG_INFO * linfo)3265 int MYSQL_BIN_LOG::raw_get_current_log(LOG_INFO* linfo)
3266 {
3267 strmake(linfo->log_file_name, log_file_name, sizeof(linfo->log_file_name)-1);
3268 linfo->pos = my_b_tell(&log_file);
3269 return 0;
3270 }
3271
3272 /**
3273 Move all data up in a file in an filename index file.
3274
3275 We do the copy outside of the IO_CACHE as the cache buffers would just
3276 make things slower and more complicated.
3277 In most cases the copy loop should only do one read.
3278
3279 @param index_file File to move
3280 @param offset Move everything from here to beginning
3281
3282 @note
3283 File will be truncated to be 'offset' shorter or filled up with newlines
3284
3285 @retval
3286 0 ok
3287 */
3288
3289 #ifdef HAVE_REPLICATION
3290
copy_up_file_and_fill(IO_CACHE * index_file,my_off_t offset)3291 static bool copy_up_file_and_fill(IO_CACHE *index_file, my_off_t offset)
3292 {
3293 int bytes_read;
3294 my_off_t init_offset= offset;
3295 File file= index_file->file;
3296 uchar io_buf[IO_SIZE*2];
3297 DBUG_ENTER("copy_up_file_and_fill");
3298
3299 for (;; offset+= bytes_read)
3300 {
3301 mysql_file_seek(file, offset, MY_SEEK_SET, MYF(0));
3302 if ((bytes_read= (int) mysql_file_read(file, io_buf, sizeof(io_buf),
3303 MYF(MY_WME)))
3304 < 0)
3305 goto err;
3306 if (!bytes_read)
3307 break; // end of file
3308 mysql_file_seek(file, offset-init_offset, MY_SEEK_SET, MYF(0));
3309 if (mysql_file_write(file, io_buf, bytes_read, MYF(MY_WME | MY_NABP)))
3310 goto err;
3311 }
3312 /* The following will either truncate the file or fill the end with \n' */
3313 if (mysql_file_chsize(file, offset - init_offset, '\n', MYF(MY_WME)) ||
3314 mysql_file_sync(file, MYF(MY_WME)))
3315 goto err;
3316
3317 /* Reset data in old index cache */
3318 reinit_io_cache(index_file, READ_CACHE, (my_off_t) 0, 0, 1);
3319 DBUG_RETURN(0);
3320
3321 err:
3322 DBUG_RETURN(1);
3323 }
3324
3325 #endif /* HAVE_REPLICATION */
3326
3327 /**
3328 Find the position in the log-index-file for the given log name.
3329
3330 @param linfo Store here the found log file name and position to
3331 the NEXT log file name in the index file.
3332 @param log_name Filename to find in the index file.
3333 Is a null pointer if we want to read the first entry
3334 @param need_lock Set this to 1 if the parent doesn't already have a
3335 lock on LOCK_index
3336
3337 @note
3338 On systems without the truncate function the file will end with one or
3339 more empty lines. These will be ignored when reading the file.
3340
3341 @retval
3342 0 ok
3343 @retval
3344 LOG_INFO_EOF End of log-index-file found
3345 @retval
3346 LOG_INFO_IO Got IO error while reading file
3347 */
3348
find_log_pos(LOG_INFO * linfo,const char * log_name,bool need_lock)3349 int MYSQL_BIN_LOG::find_log_pos(LOG_INFO *linfo, const char *log_name,
3350 bool need_lock)
3351 {
3352 int error= 0;
3353 char *full_fname= linfo->log_file_name;
3354 char full_log_name[FN_REFLEN], fname[FN_REFLEN];
3355 uint log_name_len= 0, fname_len= 0;
3356 DBUG_ENTER("find_log_pos");
3357 full_log_name[0]= full_fname[0]= 0;
3358
3359 /*
3360 Mutex needed because we need to make sure the file pointer does not
3361 move from under our feet
3362 */
3363 if (need_lock)
3364 mysql_mutex_lock(&LOCK_index);
3365 mysql_mutex_assert_owner(&LOCK_index);
3366
3367 // extend relative paths for log_name to be searched
3368 if (log_name)
3369 {
3370 if(normalize_binlog_name(full_log_name, log_name, is_relay_log))
3371 {
3372 error= LOG_INFO_EOF;
3373 goto end;
3374 }
3375 }
3376
3377 log_name_len= log_name ? (uint) strlen(full_log_name) : 0;
3378 DBUG_PRINT("enter", ("log_name: %s, full_log_name: %s",
3379 log_name ? log_name : "NULL", full_log_name));
3380
3381 /* As the file is flushed, we can't get an error here */
3382 (void) reinit_io_cache(&index_file, READ_CACHE, (my_off_t) 0, 0, 0);
3383
3384 for (;;)
3385 {
3386 uint length;
3387 my_off_t offset= my_b_tell(&index_file);
3388
3389 DBUG_EXECUTE_IF("simulate_find_log_pos_error",
3390 error= LOG_INFO_EOF; break;);
3391 /* If we get 0 or 1 characters, this is the end of the file */
3392 if ((length= my_b_gets(&index_file, fname, FN_REFLEN)) <= 1)
3393 {
3394 /* Did not find the given entry; Return not found or error */
3395 error= !index_file.error ? LOG_INFO_EOF : LOG_INFO_IO;
3396 break;
3397 }
3398
3399 // extend relative paths and match against full path
3400 if (normalize_binlog_name(full_fname, fname, is_relay_log))
3401 {
3402 error= LOG_INFO_EOF;
3403 break;
3404 }
3405 fname_len= (uint) strlen(full_fname);
3406
3407 // if the log entry matches, null string matching anything
3408 if (!log_name ||
3409 (log_name_len == fname_len-1 && full_fname[log_name_len] == '\n' &&
3410 !memcmp(full_fname, full_log_name, log_name_len)))
3411 {
3412 DBUG_PRINT("info", ("Found log file entry"));
3413 full_fname[fname_len-1]= 0; // remove last \n
3414 linfo->index_file_start_offset= offset;
3415 linfo->index_file_offset = my_b_tell(&index_file);
3416 break;
3417 }
3418 }
3419
3420 end:
3421 if (need_lock)
3422 mysql_mutex_unlock(&LOCK_index);
3423 DBUG_RETURN(error);
3424 }
3425
3426
3427 /**
3428 Find the position in the log-index-file for the given log name.
3429
3430 @param
3431 linfo Store here the next log file name and position to
3432 the file name after that.
3433 @param
3434 need_lock Set this to 1 if the parent doesn't already have a
3435 lock on LOCK_index
3436
3437 @note
3438 - Before calling this function, one has to call find_log_pos()
3439 to set up 'linfo'
3440 - Mutex needed because we need to make sure the file pointer does not move
3441 from under our feet
3442
3443 @retval
3444 0 ok
3445 @retval
3446 LOG_INFO_EOF End of log-index-file found
3447 @retval
3448 LOG_INFO_IO Got IO error while reading file
3449 */
3450
find_next_log(LOG_INFO * linfo,bool need_lock)3451 int MYSQL_BIN_LOG::find_next_log(LOG_INFO* linfo, bool need_lock)
3452 {
3453 int error= 0;
3454 uint length;
3455 char fname[FN_REFLEN];
3456 char *full_fname= linfo->log_file_name;
3457
3458 if (need_lock)
3459 mysql_mutex_lock(&LOCK_index);
3460 mysql_mutex_assert_owner(&LOCK_index);
3461
3462 /* As the file is flushed, we can't get an error here */
3463 (void) reinit_io_cache(&index_file, READ_CACHE, linfo->index_file_offset, 0,
3464 0);
3465
3466 linfo->index_file_start_offset= linfo->index_file_offset;
3467 if ((length=my_b_gets(&index_file, fname, FN_REFLEN)) <= 1)
3468 {
3469 error = !index_file.error ? LOG_INFO_EOF : LOG_INFO_IO;
3470 goto err;
3471 }
3472
3473 if (fname[0] != 0)
3474 {
3475 if(normalize_binlog_name(full_fname, fname, is_relay_log))
3476 {
3477 error= LOG_INFO_EOF;
3478 goto err;
3479 }
3480 length= strlen(full_fname);
3481 }
3482
3483 full_fname[length-1]= 0; // kill \n
3484 linfo->index_file_offset= my_b_tell(&index_file);
3485
3486 err:
3487 if (need_lock)
3488 mysql_mutex_unlock(&LOCK_index);
3489 return error;
3490 }
3491
3492
3493 /**
3494 Delete all logs refered to in the index file.
3495 Start writing to a new log file.
3496
3497 The new index file will only contain this file.
3498
3499 @param thd Thread
3500
3501 @note
3502 If not called from slave thread, write start event to new log
3503
3504 @retval
3505 0 ok
3506 @retval
3507 1 error
3508 */
3509
reset_logs(THD * thd)3510 bool MYSQL_BIN_LOG::reset_logs(THD* thd)
3511 {
3512 LOG_INFO linfo;
3513 bool error=0;
3514 int err;
3515 const char* save_name;
3516 DBUG_ENTER("reset_logs");
3517
3518 ha_reset_logs(thd);
3519
3520 /*
3521 We need to get both locks to be sure that no one is trying to
3522 write to the index log file.
3523 */
3524 mysql_mutex_lock(&LOCK_log);
3525 mysql_mutex_lock(&LOCK_index);
3526
3527 /*
3528 The following mutex is needed to ensure that no threads call
3529 'delete thd' as we would then risk missing a 'rollback' from this
3530 thread. If the transaction involved MyISAM tables, it should go
3531 into binlog even on rollback.
3532 */
3533 mysql_mutex_lock(&LOCK_thread_count);
3534
3535 /* Save variables so that we can reopen the log */
3536 save_name=name;
3537 name=0; // Protect against free
3538 close(LOG_CLOSE_TO_BE_OPENED);
3539
3540 /*
3541 First delete all old log files and then update the index file.
3542 As we first delete the log files and do not use sort of logging,
3543 a crash may lead to an inconsistent state where the index has
3544 references to non-existent files.
3545
3546 We need to invert the steps and use the purge_index_file methods
3547 in order to make the operation safe.
3548 */
3549
3550 if ((err= find_log_pos(&linfo, NullS, 0)) != 0)
3551 {
3552 uint errcode= purge_log_get_error_code(err);
3553 sql_print_error("Failed to locate old binlog or relay log files");
3554 my_message(errcode, ER(errcode), MYF(0));
3555 error= 1;
3556 goto err;
3557 }
3558
3559 for (;;)
3560 {
3561 if ((error= my_delete_allow_opened(linfo.log_file_name, MYF(0))) != 0)
3562 {
3563 if (my_errno == ENOENT)
3564 {
3565 push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3566 ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
3567 linfo.log_file_name);
3568 sql_print_information("Failed to delete file '%s'",
3569 linfo.log_file_name);
3570 my_errno= 0;
3571 error= 0;
3572 }
3573 else
3574 {
3575 push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3576 ER_BINLOG_PURGE_FATAL_ERR,
3577 "a problem with deleting %s; "
3578 "consider examining correspondence "
3579 "of your binlog index file "
3580 "to the actual binlog files",
3581 linfo.log_file_name);
3582 error= 1;
3583 goto err;
3584 }
3585 }
3586 if (find_next_log(&linfo, 0))
3587 break;
3588 }
3589
3590 /* Start logging with a new file */
3591 close(LOG_CLOSE_INDEX | LOG_CLOSE_TO_BE_OPENED);
3592 if ((error= my_delete_allow_opened(index_file_name, MYF(0)))) // Reset (open will update)
3593 {
3594 if (my_errno == ENOENT)
3595 {
3596 push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3597 ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
3598 index_file_name);
3599 sql_print_information("Failed to delete file '%s'",
3600 index_file_name);
3601 my_errno= 0;
3602 error= 0;
3603 }
3604 else
3605 {
3606 push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3607 ER_BINLOG_PURGE_FATAL_ERR,
3608 "a problem with deleting %s; "
3609 "consider examining correspondence "
3610 "of your binlog index file "
3611 "to the actual binlog files",
3612 index_file_name);
3613 error= 1;
3614 goto err;
3615 }
3616 }
3617 if (!thd->slave_thread)
3618 need_start_event=1;
3619 if (!open_index_file(index_file_name, 0, FALSE))
3620 if ((error= open(save_name, log_type, 0, io_cache_type, no_auto_events, max_size, 0, FALSE)))
3621 goto err;
3622 my_free((void *) save_name);
3623
3624 err:
3625 if (error == 1)
3626 name= const_cast<char*>(save_name);
3627 mysql_mutex_unlock(&LOCK_thread_count);
3628 mysql_mutex_unlock(&LOCK_index);
3629 mysql_mutex_unlock(&LOCK_log);
3630 DBUG_RETURN(error);
3631 }
3632
3633
3634 /**
3635 Delete relay log files prior to rli->group_relay_log_name
3636 (i.e. all logs which are not involved in a non-finished group
3637 (transaction)), remove them from the index file and start on next
3638 relay log.
3639
3640 IMPLEMENTATION
3641 - Protects index file with LOCK_index
3642 - Delete relevant relay log files
3643 - Copy all file names after these ones to the front of the index file
3644 - If the OS has truncate, truncate the file, else fill it with \n'
3645 - Read the next file name from the index file and store in rli->linfo
3646
3647 @param rli Relay log information
3648 @param included If false, all relay logs that are strictly before
3649 rli->group_relay_log_name are deleted ; if true, the
3650 latter is deleted too (i.e. all relay logs
3651 read by the SQL slave thread are deleted).
3652
3653 @note
3654 - This is only called from the slave-execute thread when it has read
3655 all commands from a relay log and want to switch to a new relay log.
3656 - When this happens, we can be in an active transaction as
3657 a transaction can span over two relay logs
3658 (although it is always written as a single block to the master's binary
3659 log, hence cannot span over two master's binary logs).
3660
3661 @retval
3662 0 ok
3663 @retval
3664 LOG_INFO_EOF End of log-index-file found
3665 @retval
3666 LOG_INFO_SEEK Could not allocate IO cache
3667 @retval
3668 LOG_INFO_IO Got IO error while reading file
3669 */
3670
3671 #ifdef HAVE_REPLICATION
3672
purge_first_log(Relay_log_info * rli,bool included)3673 int MYSQL_BIN_LOG::purge_first_log(Relay_log_info* rli, bool included)
3674 {
3675 int error;
3676 char *to_purge_if_included= NULL;
3677 DBUG_ENTER("purge_first_log");
3678
3679 DBUG_ASSERT(is_open());
3680 DBUG_ASSERT(rli->slave_running == 1);
3681 DBUG_ASSERT(!strcmp(rli->linfo.log_file_name,rli->event_relay_log_name));
3682
3683 mysql_mutex_lock(&LOCK_index);
3684 to_purge_if_included= my_strdup(rli->group_relay_log_name, MYF(0));
3685
3686 /*
3687 Read the next log file name from the index file and pass it back to
3688 the caller.
3689 */
3690 if((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0)) ||
3691 (error=find_next_log(&rli->linfo, 0)))
3692 {
3693 char buff[22];
3694 sql_print_error("next log error: %d offset: %s log: %s included: %d",
3695 error,
3696 llstr(rli->linfo.index_file_offset,buff),
3697 rli->event_relay_log_name,
3698 included);
3699 goto err;
3700 }
3701
3702 /*
3703 Reset rli's coordinates to the current log.
3704 */
3705 rli->event_relay_log_pos= BIN_LOG_HEADER_SIZE;
3706 strmake(rli->event_relay_log_name,rli->linfo.log_file_name,
3707 sizeof(rli->event_relay_log_name)-1);
3708
3709 /*
3710 If we removed the rli->group_relay_log_name file,
3711 we must update the rli->group* coordinates, otherwise do not touch it as the
3712 group's execution is not finished (e.g. COMMIT not executed)
3713 */
3714 if (included)
3715 {
3716 rli->group_relay_log_pos = BIN_LOG_HEADER_SIZE;
3717 strmake(rli->group_relay_log_name,rli->linfo.log_file_name,
3718 sizeof(rli->group_relay_log_name)-1);
3719 rli->notify_group_relay_log_name_update();
3720 }
3721
3722 /* Store where we are in the new file for the execution thread */
3723 flush_relay_log_info(rli);
3724
3725 DBUG_EXECUTE_IF("crash_before_purge_logs", DBUG_SUICIDE(););
3726
3727 mysql_mutex_lock(&rli->log_space_lock);
3728 rli->relay_log.purge_logs(to_purge_if_included, included,
3729 0, 0, &rli->log_space_total);
3730 mysql_mutex_unlock(&rli->log_space_lock);
3731
3732 /*
3733 Ok to broadcast after the critical region as there is no risk of
3734 the mutex being destroyed by this thread later - this helps save
3735 context switches
3736 */
3737 mysql_cond_broadcast(&rli->log_space_cond);
3738
3739 /*
3740 * Need to update the log pos because purge logs has been called
3741 * after fetching initially the log pos at the begining of the method.
3742 */
3743 if((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0)))
3744 {
3745 char buff[22];
3746 sql_print_error("next log error: %d offset: %s log: %s included: %d",
3747 error,
3748 llstr(rli->linfo.index_file_offset,buff),
3749 rli->group_relay_log_name,
3750 included);
3751 goto err;
3752 }
3753
3754 /* If included was passed, rli->linfo should be the first entry. */
3755 DBUG_ASSERT(!included || rli->linfo.index_file_start_offset == 0);
3756
3757 err:
3758 my_free(to_purge_if_included);
3759 mysql_mutex_unlock(&LOCK_index);
3760 DBUG_RETURN(error);
3761 }
3762
3763 /**
3764 Update log index_file.
3765 */
3766
update_log_index(LOG_INFO * log_info,bool need_update_threads)3767 int MYSQL_BIN_LOG::update_log_index(LOG_INFO* log_info, bool need_update_threads)
3768 {
3769 if (copy_up_file_and_fill(&index_file, log_info->index_file_start_offset))
3770 return LOG_INFO_IO;
3771
3772 // now update offsets in index file for running threads
3773 if (need_update_threads)
3774 adjust_linfo_offsets(log_info->index_file_start_offset);
3775 return 0;
3776 }
3777
3778 /**
3779 Remove all logs before the given log from disk and from the index file.
3780
3781 @param to_log Delete all log file name before this file.
3782 @param included If true, to_log is deleted too.
3783 @param need_mutex
3784 @param need_update_threads If we want to update the log coordinates of
3785 all threads. False for relay logs, true otherwise.
3786 @param freed_log_space If not null, decrement this variable of
3787 the amount of log space freed
3788
3789 @note
3790 If any of the logs before the deleted one is in use,
3791 only purge logs up to this one.
3792
3793 @retval
3794 0 ok
3795 @retval
3796 LOG_INFO_EOF to_log not found
3797 LOG_INFO_EMFILE too many files opened
3798 LOG_INFO_FATAL if any other than ENOENT error from
3799 mysql_file_stat() or mysql_file_delete()
3800 */
3801
purge_logs(const char * to_log,bool included,bool need_mutex,bool need_update_threads,ulonglong * decrease_log_space)3802 int MYSQL_BIN_LOG::purge_logs(const char *to_log,
3803 bool included,
3804 bool need_mutex,
3805 bool need_update_threads,
3806 ulonglong *decrease_log_space)
3807 {
3808 int error= 0;
3809 bool exit_loop= 0;
3810 LOG_INFO log_info;
3811 THD *thd= current_thd;
3812 DBUG_ENTER("purge_logs");
3813 DBUG_PRINT("info",("to_log= %s",to_log));
3814
3815 if (need_mutex)
3816 mysql_mutex_lock(&LOCK_index);
3817 if ((error=find_log_pos(&log_info, to_log, 0 /*no mutex*/)))
3818 {
3819 sql_print_error("MYSQL_BIN_LOG::purge_logs was called with file %s not "
3820 "listed in the index.", to_log);
3821 goto err;
3822 }
3823
3824 if ((error= open_purge_index_file(TRUE)))
3825 {
3826 sql_print_error("MYSQL_BIN_LOG::purge_logs failed to sync the index file.");
3827 goto err;
3828 }
3829
3830 /*
3831 File name exists in index file; delete until we find this file
3832 or a file that is used.
3833 */
3834 if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/)))
3835 goto err;
3836 while ((strcmp(to_log,log_info.log_file_name) || (exit_loop=included)) &&
3837 !is_active(log_info.log_file_name) &&
3838 !log_in_use(log_info.log_file_name))
3839 {
3840 if ((error= register_purge_index_entry(log_info.log_file_name)))
3841 {
3842 sql_print_error("MYSQL_BIN_LOG::purge_logs failed to copy %s to register file.",
3843 log_info.log_file_name);
3844 goto err;
3845 }
3846
3847 if (find_next_log(&log_info, 0) || exit_loop)
3848 break;
3849 }
3850
3851 DBUG_EXECUTE_IF("crash_purge_before_update_index", DBUG_SUICIDE(););
3852
3853 if ((error= sync_purge_index_file()))
3854 {
3855 sql_print_error("MSYQL_BIN_LOG::purge_logs failed to flush register file.");
3856 goto err;
3857 }
3858
3859 /* We know how many files to delete. Update index file. */
3860 if ((error=update_log_index(&log_info, need_update_threads)))
3861 {
3862 sql_print_error("MSYQL_BIN_LOG::purge_logs failed to update the index file");
3863 goto err;
3864 }
3865
3866 DBUG_EXECUTE_IF("crash_purge_critical_after_update_index", DBUG_SUICIDE(););
3867
3868 err:
3869 /* Read each entry from purge_index_file and delete the file. */
3870 if (is_inited_purge_index_file() &&
3871 (error= purge_index_entry(thd, decrease_log_space, FALSE)))
3872 sql_print_error("MSYQL_BIN_LOG::purge_logs failed to process registered files"
3873 " that would be purged.");
3874 close_purge_index_file();
3875
3876 DBUG_EXECUTE_IF("crash_purge_non_critical_after_update_index", DBUG_SUICIDE(););
3877
3878 if (need_mutex)
3879 mysql_mutex_unlock(&LOCK_index);
3880 DBUG_RETURN(error);
3881 }
3882
set_purge_index_file_name(const char * base_file_name)3883 int MYSQL_BIN_LOG::set_purge_index_file_name(const char *base_file_name)
3884 {
3885 int error= 0;
3886 DBUG_ENTER("MYSQL_BIN_LOG::set_purge_index_file_name");
3887 if (fn_format(purge_index_file_name, base_file_name, mysql_data_home,
3888 ".~rec~", MYF(MY_UNPACK_FILENAME | MY_SAFE_PATH |
3889 MY_REPLACE_EXT)) == NULL)
3890 {
3891 error= 1;
3892 sql_print_error("MYSQL_BIN_LOG::set_purge_index_file_name failed to set "
3893 "file name.");
3894 }
3895 DBUG_RETURN(error);
3896 }
3897
open_purge_index_file(bool destroy)3898 int MYSQL_BIN_LOG::open_purge_index_file(bool destroy)
3899 {
3900 int error= 0;
3901 File file= -1;
3902
3903 DBUG_ENTER("MYSQL_BIN_LOG::open_purge_index_file");
3904
3905 if (destroy)
3906 close_purge_index_file();
3907
3908 if (!my_b_inited(&purge_index_file))
3909 {
3910 if ((file= my_open(purge_index_file_name, O_RDWR | O_CREAT | O_BINARY,
3911 MYF(MY_WME | ME_WAITTANG))) < 0 ||
3912 init_io_cache(&purge_index_file, file, IO_SIZE,
3913 (destroy ? WRITE_CACHE : READ_CACHE),
3914 0, 0, MYF(MY_WME | MY_NABP | MY_WAIT_IF_FULL)))
3915 {
3916 error= 1;
3917 sql_print_error("MYSQL_BIN_LOG::open_purge_index_file failed to open register "
3918 " file.");
3919 }
3920 }
3921 DBUG_RETURN(error);
3922 }
3923
close_purge_index_file()3924 int MYSQL_BIN_LOG::close_purge_index_file()
3925 {
3926 int error= 0;
3927
3928 DBUG_ENTER("MYSQL_BIN_LOG::close_purge_index_file");
3929
3930 if (my_b_inited(&purge_index_file))
3931 {
3932 end_io_cache(&purge_index_file);
3933 error= my_close(purge_index_file.file, MYF(0));
3934 }
3935 my_delete(purge_index_file_name, MYF(0));
3936 bzero((char*) &purge_index_file, sizeof(purge_index_file));
3937
3938 DBUG_RETURN(error);
3939 }
3940
is_inited_purge_index_file()3941 bool MYSQL_BIN_LOG::is_inited_purge_index_file()
3942 {
3943 DBUG_ENTER("MYSQL_BIN_LOG::is_inited_purge_index_file");
3944 DBUG_RETURN (my_b_inited(&purge_index_file));
3945 }
3946
sync_purge_index_file()3947 int MYSQL_BIN_LOG::sync_purge_index_file()
3948 {
3949 int error= 0;
3950 DBUG_ENTER("MYSQL_BIN_LOG::sync_purge_index_file");
3951
3952 if ((error= flush_io_cache(&purge_index_file)) ||
3953 (error= my_sync(purge_index_file.file, MYF(MY_WME))))
3954 DBUG_RETURN(error);
3955
3956 DBUG_RETURN(error);
3957 }
3958
register_purge_index_entry(const char * entry)3959 int MYSQL_BIN_LOG::register_purge_index_entry(const char *entry)
3960 {
3961 int error= 0;
3962 DBUG_ENTER("MYSQL_BIN_LOG::register_purge_index_entry");
3963
3964 if ((error=my_b_write(&purge_index_file, (const uchar*)entry, strlen(entry))) ||
3965 (error=my_b_write(&purge_index_file, (const uchar*)"\n", 1)))
3966 DBUG_RETURN (error);
3967
3968 DBUG_RETURN(error);
3969 }
3970
register_create_index_entry(const char * entry)3971 int MYSQL_BIN_LOG::register_create_index_entry(const char *entry)
3972 {
3973 DBUG_ENTER("MYSQL_BIN_LOG::register_create_index_entry");
3974 DBUG_RETURN(register_purge_index_entry(entry));
3975 }
3976
purge_index_entry(THD * thd,ulonglong * decrease_log_space,bool need_mutex)3977 int MYSQL_BIN_LOG::purge_index_entry(THD *thd, ulonglong *decrease_log_space,
3978 bool need_mutex)
3979 {
3980 MY_STAT s;
3981 int error= 0;
3982 LOG_INFO log_info;
3983 LOG_INFO check_log_info;
3984
3985 DBUG_ENTER("MYSQL_BIN_LOG:purge_index_entry");
3986
3987 DBUG_ASSERT(my_b_inited(&purge_index_file));
3988
3989 if ((error=reinit_io_cache(&purge_index_file, READ_CACHE, 0, 0, 0)))
3990 {
3991 sql_print_error("MSYQL_BIN_LOG::purge_index_entry failed to reinit register file "
3992 "for read");
3993 goto err;
3994 }
3995
3996 for (;;)
3997 {
3998 uint length;
3999
4000 if ((length=my_b_gets(&purge_index_file, log_info.log_file_name,
4001 FN_REFLEN)) <= 1)
4002 {
4003 if (purge_index_file.error)
4004 {
4005 error= purge_index_file.error;
4006 sql_print_error("MSYQL_BIN_LOG::purge_index_entry error %d reading from "
4007 "register file.", error);
4008 goto err;
4009 }
4010
4011 /* Reached EOF */
4012 break;
4013 }
4014
4015 /* Get rid of the trailing '\n' */
4016 log_info.log_file_name[length-1]= 0;
4017
4018 if (!mysql_file_stat(m_key_file_log, log_info.log_file_name, &s, MYF(0)))
4019 {
4020 if (my_errno == ENOENT)
4021 {
4022 /*
4023 It's not fatal if we can't stat a log file that does not exist;
4024 If we could not stat, we won't delete.
4025 */
4026 if (thd)
4027 {
4028 push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4029 ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
4030 log_info.log_file_name);
4031 }
4032 sql_print_information("Failed to execute mysql_file_stat on file '%s'",
4033 log_info.log_file_name);
4034 my_errno= 0;
4035 }
4036 else
4037 {
4038 /*
4039 Other than ENOENT are fatal
4040 */
4041 if (thd)
4042 {
4043 push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4044 ER_BINLOG_PURGE_FATAL_ERR,
4045 "a problem with getting info on being purged %s; "
4046 "consider examining correspondence "
4047 "of your binlog index file "
4048 "to the actual binlog files",
4049 log_info.log_file_name);
4050 }
4051 else
4052 {
4053 sql_print_information("Failed to delete log file '%s'; "
4054 "consider examining correspondence "
4055 "of your binlog index file "
4056 "to the actual binlog files",
4057 log_info.log_file_name);
4058 }
4059 error= LOG_INFO_FATAL;
4060 goto err;
4061 }
4062 }
4063 else
4064 {
4065 if ((error= find_log_pos(&check_log_info, log_info.log_file_name, need_mutex)))
4066 {
4067 if (error != LOG_INFO_EOF)
4068 {
4069 if (thd)
4070 {
4071 push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4072 ER_BINLOG_PURGE_FATAL_ERR,
4073 "a problem with deleting %s and "
4074 "reading the binlog index file",
4075 log_info.log_file_name);
4076 }
4077 else
4078 {
4079 sql_print_information("Failed to delete file '%s' and "
4080 "read the binlog index file",
4081 log_info.log_file_name);
4082 }
4083 goto err;
4084 }
4085
4086 error= 0;
4087 if (!need_mutex)
4088 {
4089 /*
4090 This is to avoid triggering an error in NDB.
4091 */
4092 ha_binlog_index_purge_file(current_thd, log_info.log_file_name);
4093 }
4094
4095 DBUG_PRINT("info",("purging %s",log_info.log_file_name));
4096 if (!my_delete(log_info.log_file_name, MYF(0)))
4097 {
4098 if (decrease_log_space)
4099 *decrease_log_space-= s.st_size;
4100 }
4101 else
4102 {
4103 if (my_errno == ENOENT)
4104 {
4105 if (thd)
4106 {
4107 push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4108 ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
4109 log_info.log_file_name);
4110 }
4111 sql_print_information("Failed to delete file '%s'",
4112 log_info.log_file_name);
4113 my_errno= 0;
4114 }
4115 else
4116 {
4117 if (thd)
4118 {
4119 push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4120 ER_BINLOG_PURGE_FATAL_ERR,
4121 "a problem with deleting %s; "
4122 "consider examining correspondence "
4123 "of your binlog index file "
4124 "to the actual binlog files",
4125 log_info.log_file_name);
4126 }
4127 else
4128 {
4129 sql_print_information("Failed to delete file '%s'; "
4130 "consider examining correspondence "
4131 "of your binlog index file "
4132 "to the actual binlog files",
4133 log_info.log_file_name);
4134 }
4135 if (my_errno == EMFILE)
4136 {
4137 DBUG_PRINT("info",
4138 ("my_errno: %d, set ret = LOG_INFO_EMFILE", my_errno));
4139 error= LOG_INFO_EMFILE;
4140 goto err;
4141 }
4142 error= LOG_INFO_FATAL;
4143 goto err;
4144 }
4145 }
4146 }
4147 }
4148 }
4149
4150 err:
4151 DBUG_RETURN(error);
4152 }
4153
4154 /**
4155 Remove all logs before the given file date from disk and from the
4156 index file.
4157
4158 @param thd Thread pointer
4159 @param purge_time Delete all log files before given date.
4160
4161 @note
4162 If any of the logs before the deleted one is in use,
4163 only purge logs up to this one.
4164
4165 @retval
4166 0 ok
4167 @retval
4168 LOG_INFO_PURGE_NO_ROTATE Binary file that can't be rotated
4169 LOG_INFO_FATAL if any other than ENOENT error from
4170 mysql_file_stat() or mysql_file_delete()
4171 */
4172
purge_logs_before_date(time_t purge_time)4173 int MYSQL_BIN_LOG::purge_logs_before_date(time_t purge_time)
4174 {
4175 int error;
4176 char to_log[FN_REFLEN];
4177 LOG_INFO log_info;
4178 MY_STAT stat_area;
4179 THD *thd= current_thd;
4180
4181 DBUG_ENTER("purge_logs_before_date");
4182
4183 mysql_mutex_lock(&LOCK_index);
4184 to_log[0]= 0;
4185
4186 if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/)))
4187 goto err;
4188
4189 while (strcmp(log_file_name, log_info.log_file_name) &&
4190 !is_active(log_info.log_file_name) &&
4191 !log_in_use(log_info.log_file_name))
4192 {
4193 if (!mysql_file_stat(m_key_file_log,
4194 log_info.log_file_name, &stat_area, MYF(0)))
4195 {
4196 if (my_errno == ENOENT)
4197 {
4198 /*
4199 It's not fatal if we can't stat a log file that does not exist.
4200 */
4201 my_errno= 0;
4202 }
4203 else
4204 {
4205 /*
4206 Other than ENOENT are fatal
4207 */
4208 if (thd)
4209 {
4210 push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4211 ER_BINLOG_PURGE_FATAL_ERR,
4212 "a problem with getting info on being purged %s; "
4213 "consider examining correspondence "
4214 "of your binlog index file "
4215 "to the actual binlog files",
4216 log_info.log_file_name);
4217 }
4218 else
4219 {
4220 sql_print_information("Failed to delete log file '%s'",
4221 log_info.log_file_name);
4222 }
4223 error= LOG_INFO_FATAL;
4224 goto err;
4225 }
4226 }
4227 else
4228 {
4229 if (stat_area.st_mtime < purge_time)
4230 strmake(to_log,
4231 log_info.log_file_name,
4232 sizeof(log_info.log_file_name) - 1);
4233 else
4234 break;
4235 }
4236 if (find_next_log(&log_info, 0))
4237 break;
4238 }
4239
4240 error= (to_log[0] ? purge_logs(to_log, 1, 0, 1, (ulonglong *) 0) : 0);
4241
4242 err:
4243 mysql_mutex_unlock(&LOCK_index);
4244 DBUG_RETURN(error);
4245 }
4246 #endif /* HAVE_REPLICATION */
4247
4248
4249 /**
4250 Create a new log file name.
4251
4252 @param buf buf of at least FN_REFLEN where new name is stored
4253
4254 @note
4255 If file name will be longer then FN_REFLEN it will be truncated
4256 */
4257
make_log_name(char * buf,const char * log_ident)4258 void MYSQL_BIN_LOG::make_log_name(char* buf, const char* log_ident)
4259 {
4260 uint dir_len = dirname_length(log_file_name);
4261 if (dir_len >= FN_REFLEN)
4262 dir_len=FN_REFLEN-1;
4263 strnmov(buf, log_file_name, dir_len);
4264 strmake(buf+dir_len, log_ident, FN_REFLEN - dir_len -1);
4265 }
4266
4267
4268 /**
4269 Check if we are writing/reading to the given log file.
4270 */
4271
is_active(const char * log_file_name_arg)4272 bool MYSQL_BIN_LOG::is_active(const char *log_file_name_arg)
4273 {
4274 return !strcmp(log_file_name, log_file_name_arg);
4275 }
4276
4277
4278 /*
4279 Wrappers around new_file_impl to avoid using argument
4280 to control locking. The argument 1) less readable 2) breaks
4281 incapsulation 3) allows external access to the class without
4282 a lock (which is not possible with private new_file_without_locking
4283 method).
4284
4285 @retval
4286 nonzero - error
4287 */
4288
new_file()4289 int MYSQL_BIN_LOG::new_file()
4290 {
4291 return new_file_impl(1);
4292 }
4293
4294 /*
4295 @retval
4296 nonzero - error
4297 */
new_file_without_locking()4298 int MYSQL_BIN_LOG::new_file_without_locking()
4299 {
4300 return new_file_impl(0);
4301 }
4302
4303
4304 /**
4305 Start writing to a new log file or reopen the old file.
4306
4307 @param need_lock Set to 1 if caller has not locked LOCK_log
4308
4309 @retval
4310 nonzero - error
4311
4312 @note
4313 The new file name is stored last in the index file
4314 */
4315
new_file_impl(bool need_lock)4316 int MYSQL_BIN_LOG::new_file_impl(bool need_lock)
4317 {
4318 int error= 0, close_on_error= FALSE;
4319 char new_name[FN_REFLEN], *new_name_ptr, *old_name, *file_to_open;
4320
4321 DBUG_ENTER("MYSQL_BIN_LOG::new_file_impl");
4322 if (!is_open())
4323 {
4324 DBUG_PRINT("info",("log is closed"));
4325 DBUG_RETURN(error);
4326 }
4327
4328 if (need_lock)
4329 mysql_mutex_lock(&LOCK_log);
4330 mysql_mutex_lock(&LOCK_index);
4331
4332 mysql_mutex_assert_owner(&LOCK_log);
4333 mysql_mutex_assert_owner(&LOCK_index);
4334
4335 /*
4336 if binlog is used as tc log, be sure all xids are "unlogged",
4337 so that on recover we only need to scan one - latest - binlog file
4338 for prepared xids. As this is expected to be a rare event,
4339 simple wait strategy is enough. We're locking LOCK_log to be sure no
4340 new Xid_log_event's are added to the log (and prepared_xids is not
4341 increased), and waiting on COND_prep_xids for late threads to
4342 catch up.
4343 */
4344 if (prepared_xids)
4345 {
4346 tc_log_page_waits++;
4347 mysql_mutex_lock(&LOCK_prep_xids);
4348 while (prepared_xids) {
4349 DBUG_PRINT("info", ("prepared_xids=%lu", prepared_xids));
4350 mysql_cond_wait(&COND_prep_xids, &LOCK_prep_xids);
4351 }
4352 mysql_mutex_unlock(&LOCK_prep_xids);
4353 }
4354
4355 /* Reuse old name if not binlog and not update log */
4356 new_name_ptr= name;
4357
4358 /*
4359 If user hasn't specified an extension, generate a new log name
4360 We have to do this here and not in open as we want to store the
4361 new file name in the current binary log file.
4362 */
4363 if ((error= generate_new_name(new_name, name)))
4364 goto end;
4365 new_name_ptr=new_name;
4366
4367 if (log_type == LOG_BIN)
4368 {
4369 if (!no_auto_events)
4370 {
4371 /*
4372 We log the whole file name for log file as the user may decide
4373 to change base names at some point.
4374 */
4375 Rotate_log_event r(new_name+dirname_length(new_name),
4376 0, LOG_EVENT_OFFSET, is_relay_log ? Rotate_log_event::RELAY_LOG : 0);
4377 if(DBUG_EVALUATE_IF("fault_injection_new_file_rotate_event", (error=close_on_error=TRUE), FALSE) ||
4378 (error= r.write(&log_file)))
4379 {
4380 DBUG_EXECUTE_IF("fault_injection_new_file_rotate_event", errno=2;);
4381 close_on_error= TRUE;
4382 my_printf_error(ER_ERROR_ON_WRITE, ER(ER_CANT_OPEN_FILE), MYF(ME_FATALERROR), name, errno);
4383 goto end;
4384 }
4385 bytes_written += r.data_written;
4386 }
4387 /*
4388 Update needs to be signalled even if there is no rotate event
4389 log rotation should give the waiting thread a signal to
4390 discover EOF and move on to the next log.
4391 */
4392 signal_update();
4393 }
4394 old_name=name;
4395 name=0; // Don't free name
4396 close(LOG_CLOSE_TO_BE_OPENED | LOG_CLOSE_INDEX);
4397
4398 /*
4399 Note that at this point, log_state != LOG_CLOSED (important for is_open()).
4400 */
4401
4402 /*
4403 new_file() is only used for rotation (in FLUSH LOGS or because size >
4404 max_binlog_size or max_relay_log_size).
4405 If this is a binary log, the Format_description_log_event at the beginning of
4406 the new file should have created=0 (to distinguish with the
4407 Format_description_log_event written at server startup, which should
4408 trigger temp tables deletion on slaves.
4409 */
4410
4411 /* reopen index binlog file, BUG#34582 */
4412 file_to_open= index_file_name;
4413 error= open_index_file(index_file_name, 0, FALSE);
4414 if (!error)
4415 {
4416 /* reopen the binary log file. */
4417 file_to_open= new_name_ptr;
4418 error= open(old_name, log_type, new_name_ptr, io_cache_type,
4419 no_auto_events, max_size, 1, FALSE);
4420 }
4421
4422 /* handle reopening errors */
4423 if (error)
4424 {
4425 my_printf_error(ER_CANT_OPEN_FILE, ER(ER_CANT_OPEN_FILE),
4426 MYF(ME_FATALERROR), file_to_open, error);
4427 close_on_error= TRUE;
4428 }
4429
4430 my_free(old_name);
4431
4432 end:
4433
4434 if (error && close_on_error /* rotate or reopen failed */)
4435 {
4436 /*
4437 Close whatever was left opened.
4438
4439 We are keeping the behavior as it exists today, ie,
4440 we disable logging and move on (see: BUG#51014).
4441
4442 TODO: as part of WL#1790 consider other approaches:
4443 - kill mysql (safety);
4444 - try multiple locations for opening a log file;
4445 - switch server to protected/readonly mode
4446 - ...
4447 */
4448 close(LOG_CLOSE_INDEX);
4449 sql_print_error("Could not open %s for logging (error %d). "
4450 "Turning logging off for the whole duration "
4451 "of the MySQL server process. To turn it on "
4452 "again: fix the cause, shutdown the MySQL "
4453 "server and restart it.",
4454 new_name_ptr, errno);
4455 }
4456
4457 if (need_lock)
4458 mysql_mutex_unlock(&LOCK_log);
4459 mysql_mutex_unlock(&LOCK_index);
4460
4461 DBUG_RETURN(error);
4462 }
4463
4464
append(Log_event * ev)4465 bool MYSQL_BIN_LOG::append(Log_event* ev)
4466 {
4467 bool error = 0;
4468 mysql_mutex_lock(&LOCK_log);
4469 DBUG_ENTER("MYSQL_BIN_LOG::append");
4470
4471 DBUG_ASSERT(log_file.type == SEQ_READ_APPEND);
4472 /*
4473 Log_event::write() is smart enough to use my_b_write() or
4474 my_b_append() depending on the kind of cache we have.
4475 */
4476 if (ev->write(&log_file))
4477 {
4478 error=1;
4479 goto err;
4480 }
4481 bytes_written+= ev->data_written;
4482 DBUG_PRINT("info",("max_size: %lu",max_size));
4483 if (flush_and_sync(0))
4484 goto err;
4485 if ((uint) my_b_append_tell(&log_file) > max_size)
4486 error= new_file_without_locking();
4487 err:
4488 mysql_mutex_unlock(&LOCK_log);
4489 signal_update(); // Safe as we don't call close
4490 DBUG_RETURN(error);
4491 }
4492
4493
appendv(const char * buf,uint len,...)4494 bool MYSQL_BIN_LOG::appendv(const char* buf, uint len,...)
4495 {
4496 bool error= 0;
4497 DBUG_ENTER("MYSQL_BIN_LOG::appendv");
4498 va_list(args);
4499 va_start(args,len);
4500
4501 DBUG_ASSERT(log_file.type == SEQ_READ_APPEND);
4502
4503 mysql_mutex_assert_owner(&LOCK_log);
4504 do
4505 {
4506 if (my_b_append(&log_file,(uchar*) buf,len))
4507 {
4508 error= 1;
4509 goto err;
4510 }
4511 bytes_written += len;
4512 } while ((buf=va_arg(args,const char*)) && (len=va_arg(args,uint)));
4513 DBUG_PRINT("info",("max_size: %lu",max_size));
4514 if (flush_and_sync(0))
4515 goto err;
4516 if ((uint) my_b_append_tell(&log_file) > max_size)
4517 error= new_file_without_locking();
4518 err:
4519 if (!error)
4520 signal_update();
4521 DBUG_RETURN(error);
4522 }
4523
flush_and_sync(bool * synced)4524 bool MYSQL_BIN_LOG::flush_and_sync(bool *synced)
4525 {
4526 int err=0, fd=log_file.file;
4527 if (synced)
4528 *synced= 0;
4529 mysql_mutex_assert_owner(&LOCK_log);
4530 if (flush_io_cache(&log_file))
4531 return 1;
4532 uint sync_period= get_sync_period();
4533 if (sync_period && ++sync_counter >= sync_period)
4534 {
4535 sync_counter= 0;
4536 err= mysql_file_sync(fd, MYF(MY_WME));
4537 if (synced)
4538 *synced= 1;
4539 }
4540 return err;
4541 }
4542
start_union_events(THD * thd,query_id_t query_id_param)4543 void MYSQL_BIN_LOG::start_union_events(THD *thd, query_id_t query_id_param)
4544 {
4545 DBUG_ASSERT(!thd->binlog_evt_union.do_union);
4546 thd->binlog_evt_union.do_union= TRUE;
4547 thd->binlog_evt_union.unioned_events= FALSE;
4548 thd->binlog_evt_union.unioned_events_trans= FALSE;
4549 thd->binlog_evt_union.first_query_id= query_id_param;
4550 }
4551
stop_union_events(THD * thd)4552 void MYSQL_BIN_LOG::stop_union_events(THD *thd)
4553 {
4554 DBUG_ASSERT(thd->binlog_evt_union.do_union);
4555 thd->binlog_evt_union.do_union= FALSE;
4556 }
4557
is_query_in_union(THD * thd,query_id_t query_id_param)4558 bool MYSQL_BIN_LOG::is_query_in_union(THD *thd, query_id_t query_id_param)
4559 {
4560 return (thd->binlog_evt_union.do_union &&
4561 query_id_param >= thd->binlog_evt_union.first_query_id);
4562 }
4563
4564 /**
4565 This function checks if a transactional table was updated by the
4566 current transaction.
4567
4568 @param thd The client thread that executed the current statement.
4569 @return
4570 @c true if a transactional table was updated, @c false otherwise.
4571 */
4572 bool
trans_has_updated_trans_table(const THD * thd)4573 trans_has_updated_trans_table(const THD* thd)
4574 {
4575 binlog_cache_mngr *const cache_mngr=
4576 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4577
4578 return (cache_mngr ? !cache_mngr->trx_cache.empty() : 0);
4579 }
4580
4581 /**
4582 This function checks if a transactional table was updated by the
4583 current statement.
4584
4585 @param ha_list Registered storage engine handler list.
4586 @return
4587 @c true if a transactional table was updated, @c false otherwise.
4588 */
4589 bool
stmt_has_updated_trans_table(Ha_trx_info * ha_list)4590 stmt_has_updated_trans_table(Ha_trx_info* ha_list)
4591 {
4592 Ha_trx_info *ha_info;
4593 for (ha_info= ha_list; ha_info; ha_info= ha_info->next())
4594 {
4595 if (ha_info->is_trx_read_write() && ha_info->ht() != binlog_hton)
4596 return (TRUE);
4597 }
4598 return (FALSE);
4599 }
4600
4601 /**
4602 This function checks if either a trx-cache or a non-trx-cache should
4603 be used. If @c bin_log_direct_non_trans_update is active or the format
4604 is either MIXED or ROW, the cache to be used depends on the flag @c
4605 is_transactional.
4606
4607 On the other hand, if binlog_format is STMT or direct option is
4608 OFF, the trx-cache should be used if and only if the statement is
4609 transactional or the trx-cache is not empty. Otherwise, the
4610 non-trx-cache should be used.
4611
4612 @param thd The client thread.
4613 @param is_transactional The changes are related to a trx-table.
4614 @return
4615 @c true if a trx-cache should be used, @c false otherwise.
4616 */
use_trans_cache(const THD * thd,bool is_transactional)4617 bool use_trans_cache(const THD* thd, bool is_transactional)
4618 {
4619 binlog_cache_mngr *const cache_mngr=
4620 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4621
4622 return
4623 ((thd->is_current_stmt_binlog_format_row() ||
4624 thd->variables.binlog_direct_non_trans_update) ? is_transactional :
4625 (is_transactional || !cache_mngr->trx_cache.empty()));
4626 }
4627
4628 /**
4629 This function checks if a transaction, either a multi-statement
4630 or a single statement transaction is about to commit or not.
4631
4632 @param thd The client thread that executed the current statement.
4633 @param all Committing a transaction (i.e. TRUE) or a statement
4634 (i.e. FALSE).
4635 @return
4636 @c true if committing a transaction, otherwise @c false.
4637 */
ending_trans(THD * thd,const bool all)4638 bool ending_trans(THD* thd, const bool all)
4639 {
4640 return (all || ending_single_stmt_trans(thd, all));
4641 }
4642
4643 /**
4644 This function checks if a single statement transaction is about
4645 to commit or not.
4646
4647 @param thd The client thread that executed the current statement.
4648 @param all Committing a transaction (i.e. TRUE) or a statement
4649 (i.e. FALSE).
4650 @return
4651 @c true if committing a single statement transaction, otherwise
4652 @c false.
4653 */
ending_single_stmt_trans(THD * thd,const bool all)4654 bool ending_single_stmt_trans(THD* thd, const bool all)
4655 {
4656 return (!all && !thd->in_multi_stmt_transaction_mode());
4657 }
4658
4659 /**
4660 This function checks if a non-transactional table was updated by
4661 the current transaction.
4662
4663 @param thd The client thread that executed the current statement.
4664 @return
4665 @c true if a non-transactional table was updated, @c false
4666 otherwise.
4667 */
trans_has_updated_non_trans_table(const THD * thd)4668 bool trans_has_updated_non_trans_table(const THD* thd)
4669 {
4670 return (thd->transaction.all.modified_non_trans_table ||
4671 thd->transaction.stmt.modified_non_trans_table);
4672 }
4673
4674 /**
4675 This function checks if a non-transactional table was updated by the
4676 current statement.
4677
4678 @param thd The client thread that executed the current statement.
4679 @return
4680 @c true if a non-transactional table was updated, @c false otherwise.
4681 */
stmt_has_updated_non_trans_table(const THD * thd)4682 bool stmt_has_updated_non_trans_table(const THD* thd)
4683 {
4684 return (thd->transaction.stmt.modified_non_trans_table);
4685 }
4686
4687 /*
4688 These functions are placed in this file since they need access to
4689 binlog_hton, which has internal linkage.
4690 */
4691
binlog_setup_trx_data()4692 int THD::binlog_setup_trx_data()
4693 {
4694 DBUG_ENTER("THD::binlog_setup_trx_data");
4695 binlog_cache_mngr *cache_mngr=
4696 (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4697
4698 if (cache_mngr)
4699 DBUG_RETURN(0); // Already set up
4700
4701 cache_mngr= (binlog_cache_mngr*) my_malloc(sizeof(binlog_cache_mngr), MYF(MY_ZEROFILL));
4702 if (!cache_mngr ||
4703 open_cached_file(&cache_mngr->stmt_cache.cache_log, mysql_tmpdir,
4704 LOG_PREFIX, binlog_stmt_cache_size, MYF(MY_WME)) ||
4705 open_cached_file(&cache_mngr->trx_cache.cache_log, mysql_tmpdir,
4706 LOG_PREFIX, binlog_cache_size, MYF(MY_WME)))
4707 {
4708 my_free(cache_mngr);
4709 DBUG_RETURN(1); // Didn't manage to set it up
4710 }
4711 thd_set_ha_data(this, binlog_hton, cache_mngr);
4712
4713 cache_mngr= new (thd_get_ha_data(this, binlog_hton))
4714 binlog_cache_mngr(max_binlog_stmt_cache_size,
4715 max_binlog_cache_size,
4716 &binlog_stmt_cache_use,
4717 &binlog_stmt_cache_disk_use,
4718 &binlog_cache_use,
4719 &binlog_cache_disk_use);
4720 DBUG_RETURN(0);
4721 }
4722
4723 /*
4724 Function to start a statement and optionally a transaction for the
4725 binary log.
4726
4727 SYNOPSIS
4728 binlog_start_trans_and_stmt()
4729
4730 DESCRIPTION
4731
4732 This function does three things:
4733 - Start a transaction if not in autocommit mode or if a BEGIN
4734 statement has been seen.
4735
4736 - Start a statement transaction to allow us to truncate the cache.
4737
4738 - Save the currrent binlog position so that we can roll back the
4739 statement by truncating the cache.
4740
4741 We only update the saved position if the old one was undefined,
4742 the reason is that there are some cases (e.g., for CREATE-SELECT)
4743 where the position is saved twice (e.g., both in
4744 select_create::prepare() and THD::binlog_write_table_map()) , but
4745 we should use the first. This means that calls to this function
4746 can be used to start the statement before the first table map
4747 event, to include some extra events.
4748 */
4749
4750 void
binlog_start_trans_and_stmt()4751 THD::binlog_start_trans_and_stmt()
4752 {
4753 binlog_cache_mngr *cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4754 DBUG_ENTER("binlog_start_trans_and_stmt");
4755 DBUG_PRINT("enter", ("cache_mngr: %p cache_mngr->trx_cache.get_prev_position(): %lu",
4756 cache_mngr,
4757 (cache_mngr ? (ulong) cache_mngr->trx_cache.get_prev_position() :
4758 (ulong) 0)));
4759
4760 if (cache_mngr == NULL ||
4761 cache_mngr->trx_cache.get_prev_position() == MY_OFF_T_UNDEF)
4762 {
4763 this->binlog_set_stmt_begin();
4764 if (in_multi_stmt_transaction_mode())
4765 trans_register_ha(this, TRUE, binlog_hton);
4766 trans_register_ha(this, FALSE, binlog_hton);
4767 /*
4768 Mark statement transaction as read/write. We never start
4769 a binary log transaction and keep it read-only,
4770 therefore it's best to mark the transaction read/write just
4771 at the same time we start it.
4772 Not necessary to mark the normal transaction read/write
4773 since the statement-level flag will be propagated automatically
4774 inside ha_commit_trans.
4775 */
4776 ha_data[binlog_hton->slot].ha_info[0].set_trx_read_write();
4777 }
4778 DBUG_VOID_RETURN;
4779 }
4780
binlog_set_stmt_begin()4781 void THD::binlog_set_stmt_begin() {
4782 binlog_cache_mngr *cache_mngr=
4783 (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4784
4785 /*
4786 The call to binlog_trans_log_savepos() might create the cache_mngr
4787 structure, if it didn't exist before, so we save the position
4788 into an auto variable and then write it into the transaction
4789 data for the binary log (i.e., cache_mngr).
4790 */
4791 my_off_t pos= 0;
4792 binlog_trans_log_savepos(this, &pos);
4793 cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4794 cache_mngr->trx_cache.set_prev_position(pos);
4795 }
4796
4797
4798 /**
4799 This function writes a table map to the binary log.
4800 Note that in order to keep the signature uniform with related methods,
4801 we use a redundant parameter to indicate whether a transactional table
4802 was changed or not.
4803
4804 @param table a pointer to the table.
4805 @param is_transactional @c true indicates a transactional table,
4806 otherwise @c false a non-transactional.
4807 @return
4808 nonzero if an error pops up when writing the table map event.
4809 */
binlog_write_table_map(TABLE * table,bool is_transactional)4810 int THD::binlog_write_table_map(TABLE *table, bool is_transactional)
4811 {
4812 int error;
4813 DBUG_ENTER("THD::binlog_write_table_map");
4814 DBUG_PRINT("enter", ("table: 0x%lx (%s: #%lu)",
4815 (long) table, table->s->table_name.str,
4816 table->s->table_map_id));
4817
4818 /* Pre-conditions */
4819 DBUG_ASSERT(is_current_stmt_binlog_format_row() && mysql_bin_log.is_open());
4820 DBUG_ASSERT(table->s->table_map_id != ULONG_MAX);
4821
4822 Table_map_log_event
4823 the_event(this, table, table->s->table_map_id, is_transactional);
4824
4825 if (binlog_table_maps == 0)
4826 binlog_start_trans_and_stmt();
4827
4828 binlog_cache_mngr *const cache_mngr=
4829 (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4830
4831 IO_CACHE *file=
4832 cache_mngr->get_binlog_cache_log(use_trans_cache(this, is_transactional));
4833 if ((error= the_event.write(file)))
4834 DBUG_RETURN(error);
4835
4836 binlog_table_maps++;
4837 DBUG_RETURN(0);
4838 }
4839
4840 /**
4841 This function retrieves a pending row event from a cache which is
4842 specified through the parameter @c is_transactional. Respectively, when it
4843 is @c true, the pending event is returned from the transactional cache.
4844 Otherwise from the non-transactional cache.
4845
4846 @param is_transactional @c true indicates a transactional cache,
4847 otherwise @c false a non-transactional.
4848 @return
4849 The row event if any.
4850 */
4851 Rows_log_event*
binlog_get_pending_rows_event(bool is_transactional) const4852 THD::binlog_get_pending_rows_event(bool is_transactional) const
4853 {
4854 Rows_log_event* rows= NULL;
4855 binlog_cache_mngr *const cache_mngr=
4856 (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4857
4858 /*
4859 This is less than ideal, but here's the story: If there is no cache_mngr,
4860 prepare_pending_rows_event() has never been called (since the cache_mngr
4861 is set up there). In that case, we just return NULL.
4862 */
4863 if (cache_mngr)
4864 {
4865 binlog_cache_data *cache_data=
4866 cache_mngr->get_binlog_cache_data(use_trans_cache(this, is_transactional));
4867
4868 rows= cache_data->pending();
4869 }
4870 return (rows);
4871 }
4872
4873 /**
4874 This function stores a pending row event into a cache which is specified
4875 through the parameter @c is_transactional. Respectively, when it is @c
4876 true, the pending event is stored into the transactional cache. Otherwise
4877 into the non-transactional cache.
4878
4879 @param evt a pointer to the row event.
4880 @param is_transactional @c true indicates a transactional cache,
4881 otherwise @c false a non-transactional.
4882 */
4883 void
binlog_set_pending_rows_event(Rows_log_event * ev,bool is_transactional)4884 THD::binlog_set_pending_rows_event(Rows_log_event* ev, bool is_transactional)
4885 {
4886 if (thd_get_ha_data(this, binlog_hton) == NULL)
4887 binlog_setup_trx_data();
4888
4889 binlog_cache_mngr *const cache_mngr=
4890 (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4891
4892 DBUG_ASSERT(cache_mngr);
4893
4894 binlog_cache_data *cache_data=
4895 cache_mngr->get_binlog_cache_data(use_trans_cache(this, is_transactional));
4896
4897 cache_data->set_pending(ev);
4898 }
4899
4900
4901 /**
4902 This function removes the pending rows event, discarding any outstanding
4903 rows. If there is no pending rows event available, this is effectively a
4904 no-op.
4905
4906 @param thd a pointer to the user thread.
4907 @param is_transactional @c true indicates a transactional cache,
4908 otherwise @c false a non-transactional.
4909 */
4910 int
remove_pending_rows_event(THD * thd,bool is_transactional)4911 MYSQL_BIN_LOG::remove_pending_rows_event(THD *thd, bool is_transactional)
4912 {
4913 DBUG_ENTER("MYSQL_BIN_LOG::remove_pending_rows_event");
4914
4915 binlog_cache_mngr *const cache_mngr=
4916 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4917
4918 DBUG_ASSERT(cache_mngr);
4919
4920 binlog_cache_data *cache_data=
4921 cache_mngr->get_binlog_cache_data(use_trans_cache(thd, is_transactional));
4922
4923 if (Rows_log_event* pending= cache_data->pending())
4924 {
4925 delete pending;
4926 cache_data->set_pending(NULL);
4927 }
4928
4929 DBUG_RETURN(0);
4930 }
4931
4932 /*
4933 Moves the last bunch of rows from the pending Rows event to a cache (either
4934 transactional cache if is_transaction is @c true, or the non-transactional
4935 cache otherwise. Sets a new pending event.
4936
4937 @param thd a pointer to the user thread.
4938 @param evt a pointer to the row event.
4939 @param is_transactional @c true indicates a transactional cache,
4940 otherwise @c false a non-transactional.
4941 */
4942 int
flush_and_set_pending_rows_event(THD * thd,Rows_log_event * event,bool is_transactional)4943 MYSQL_BIN_LOG::flush_and_set_pending_rows_event(THD *thd,
4944 Rows_log_event* event,
4945 bool is_transactional)
4946 {
4947 DBUG_ENTER("MYSQL_BIN_LOG::flush_and_set_pending_rows_event(event)");
4948 DBUG_ASSERT(mysql_bin_log.is_open());
4949 DBUG_PRINT("enter", ("event: 0x%lx", (long) event));
4950
4951 int error= 0;
4952 binlog_cache_mngr *const cache_mngr=
4953 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4954
4955 DBUG_ASSERT(cache_mngr);
4956
4957 binlog_cache_data *cache_data=
4958 cache_mngr->get_binlog_cache_data(use_trans_cache(thd, is_transactional));
4959
4960 DBUG_PRINT("info", ("cache_mngr->pending(): 0x%lx", (long) cache_data->pending()));
4961
4962 if (Rows_log_event* pending= cache_data->pending())
4963 {
4964 IO_CACHE *file= &cache_data->cache_log;
4965
4966 /*
4967 Write pending event to the cache.
4968 */
4969 DBUG_EXECUTE_IF("simulate_disk_full_at_flush_pending",
4970 {DBUG_SET("+d,simulate_file_write_error");});
4971 if (pending->write(file))
4972 {
4973 set_write_error(thd, is_transactional);
4974 if (check_write_error(thd) && cache_data &&
4975 stmt_has_updated_non_trans_table(thd))
4976 cache_data->set_incident();
4977 delete pending;
4978 cache_data->set_pending(NULL);
4979 DBUG_EXECUTE_IF("simulate_disk_full_at_flush_pending",
4980 {DBUG_SET("-d,simulate_file_write_error");});
4981 DBUG_RETURN(1);
4982 }
4983
4984 delete pending;
4985 }
4986
4987 thd->binlog_set_pending_rows_event(event, is_transactional);
4988
4989 DBUG_RETURN(error);
4990 }
4991
4992 /**
4993 Write an event to the binary log.
4994 */
4995
write(Log_event * event_info)4996 bool MYSQL_BIN_LOG::write(Log_event *event_info)
4997 {
4998 THD *thd= event_info->thd;
4999 bool error= 1;
5000 DBUG_ENTER("MYSQL_BIN_LOG::write(Log_event *)");
5001 binlog_cache_data *cache_data= 0;
5002 bool is_trans_cache= FALSE;
5003
5004 if (thd->binlog_evt_union.do_union)
5005 {
5006 /*
5007 In Stored function; Remember that function call caused an update.
5008 We will log the function call to the binary log on function exit
5009 */
5010 thd->binlog_evt_union.unioned_events= TRUE;
5011 thd->binlog_evt_union.unioned_events_trans |=
5012 event_info->use_trans_cache();
5013 DBUG_RETURN(0);
5014 }
5015
5016 /*
5017 We only end the statement if we are in a top-level statement. If
5018 we are inside a stored function, we do not end the statement since
5019 this will close all tables on the slave.
5020 */
5021 bool const end_stmt=
5022 thd->locked_tables_mode && thd->lex->requires_prelocking();
5023 if (thd->binlog_flush_pending_rows_event(end_stmt,
5024 event_info->use_trans_cache()))
5025 DBUG_RETURN(error);
5026
5027 /*
5028 In most cases this is only called if 'is_open()' is true; in fact this is
5029 mostly called if is_open() *was* true a few instructions before, but it
5030 could have changed since.
5031 */
5032 if (likely(is_open()))
5033 {
5034 #ifdef HAVE_REPLICATION
5035 /*
5036 In the future we need to add to the following if tests like
5037 "do the involved tables match (to be implemented)
5038 binlog_[wild_]{do|ignore}_table?" (WL#1049)"
5039 */
5040 const char *local_db= event_info->get_db();
5041 if ((thd && !(thd->variables.option_bits & OPTION_BIN_LOG)) ||
5042 (thd->lex->sql_command != SQLCOM_ROLLBACK_TO_SAVEPOINT &&
5043 thd->lex->sql_command != SQLCOM_SAVEPOINT &&
5044 !binlog_filter->db_ok(local_db)))
5045 DBUG_RETURN(0);
5046 #endif /* HAVE_REPLICATION */
5047
5048 IO_CACHE *file= NULL;
5049
5050 if (event_info->use_direct_logging())
5051 {
5052 file= &log_file;
5053 mysql_mutex_lock(&LOCK_log);
5054 }
5055 else
5056 {
5057 if (thd->binlog_setup_trx_data())
5058 goto err;
5059
5060 binlog_cache_mngr *const cache_mngr=
5061 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
5062
5063 is_trans_cache= use_trans_cache(thd, event_info->use_trans_cache());
5064 file= cache_mngr->get_binlog_cache_log(is_trans_cache);
5065 cache_data= cache_mngr->get_binlog_cache_data(is_trans_cache);
5066
5067 if (thd->lex->stmt_accessed_non_trans_temp_table())
5068 cache_data->set_changes_to_non_trans_temp_table();
5069
5070 thd->binlog_start_trans_and_stmt();
5071 }
5072 DBUG_PRINT("info",("event type: %d",event_info->get_type_code()));
5073
5074 /*
5075 No check for auto events flag here - this write method should
5076 never be called if auto-events are enabled.
5077
5078 Write first log events which describe the 'run environment'
5079 of the SQL command. If row-based binlogging, Insert_id, Rand
5080 and other kind of "setting context" events are not needed.
5081 */
5082 if (thd)
5083 {
5084 if (!thd->is_current_stmt_binlog_format_row())
5085 {
5086 if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt)
5087 {
5088 Intvar_log_event e(thd,(uchar) LAST_INSERT_ID_EVENT,
5089 thd->first_successful_insert_id_in_prev_stmt_for_binlog);
5090 if (e.write(file))
5091 goto err;
5092 }
5093 if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0)
5094 {
5095 DBUG_PRINT("info",("number of auto_inc intervals: %u",
5096 thd->auto_inc_intervals_in_cur_stmt_for_binlog.
5097 nb_elements()));
5098 Intvar_log_event e(thd, (uchar) INSERT_ID_EVENT,
5099 thd->auto_inc_intervals_in_cur_stmt_for_binlog.
5100 minimum());
5101 if (e.write(file))
5102 goto err;
5103 }
5104 if (thd->rand_used)
5105 {
5106 Rand_log_event e(thd,thd->rand_saved_seed1,thd->rand_saved_seed2);
5107 if (e.write(file))
5108 goto err;
5109 }
5110 if (thd->user_var_events.elements)
5111 {
5112 for (uint i= 0; i < thd->user_var_events.elements; i++)
5113 {
5114 BINLOG_USER_VAR_EVENT *user_var_event;
5115 get_dynamic(&thd->user_var_events,(uchar*) &user_var_event, i);
5116
5117 /* setting flags for user var log event */
5118 uchar flags= User_var_log_event::UNDEF_F;
5119 if (user_var_event->unsigned_flag)
5120 flags|= User_var_log_event::UNSIGNED_F;
5121
5122 User_var_log_event e(thd, user_var_event->user_var_event->name.str,
5123 user_var_event->user_var_event->name.length,
5124 user_var_event->value,
5125 user_var_event->length,
5126 user_var_event->type,
5127 user_var_event->charset_number,
5128 flags);
5129 if (e.write(file))
5130 goto err;
5131 }
5132 }
5133 }
5134 }
5135
5136 /*
5137 Write the event.
5138 */
5139 if (event_info->write(file) ||
5140 DBUG_EVALUATE_IF("injecting_fault_writing", 1, 0))
5141 goto err;
5142
5143 error= 0;
5144 err:
5145 if (event_info->use_direct_logging())
5146 {
5147 if (!error)
5148 {
5149 bool synced;
5150 if ((error= flush_and_sync(&synced)))
5151 {
5152 mysql_mutex_unlock(&LOCK_log);
5153 }
5154 else if ((error= RUN_HOOK(binlog_storage, after_flush,
5155 (thd, log_file_name, file->pos_in_file, synced))))
5156 {
5157 sql_print_error("Failed to run 'after_flush' hooks");
5158 mysql_mutex_unlock(&LOCK_log);
5159 }
5160 else
5161 {
5162 bool check_purge;
5163 signal_update();
5164 error= rotate(false, &check_purge);
5165 mysql_mutex_unlock(&LOCK_log);
5166 if (!error && check_purge)
5167 purge();
5168 }
5169 }
5170 else
5171 {
5172 mysql_mutex_unlock(&LOCK_log);
5173 }
5174 }
5175
5176 if (error)
5177 {
5178 set_write_error(thd, is_trans_cache);
5179 if (check_write_error(thd) && cache_data &&
5180 stmt_has_updated_non_trans_table(thd))
5181 cache_data->set_incident();
5182 }
5183 }
5184
5185 DBUG_RETURN(error);
5186 }
5187
5188
error_log_print(enum loglevel level,const char * format,va_list args)5189 int error_log_print(enum loglevel level, const char *format,
5190 va_list args)
5191 {
5192 return logger.error_log_print(level, format, args);
5193 }
5194
5195
slow_log_print(THD * thd,const char * query,uint query_length,ulonglong current_utime)5196 bool slow_log_print(THD *thd, const char *query, uint query_length,
5197 ulonglong current_utime)
5198 {
5199 return logger.slow_log_print(thd, query, query_length, current_utime);
5200 }
5201
5202
log_command(THD * thd,enum enum_server_command command)5203 bool LOGGER::log_command(THD *thd, enum enum_server_command command)
5204 {
5205 #ifndef NO_EMBEDDED_ACCESS_CHECKS
5206 Security_context *sctx= thd->security_ctx;
5207 #endif
5208 /*
5209 Log command if we have at least one log event handler enabled and want
5210 to log this king of commands
5211 */
5212 if (*general_log_handler_list && (what_to_log & (1L << (uint) command)))
5213 {
5214 if ((thd->variables.option_bits & OPTION_LOG_OFF)
5215 #ifndef NO_EMBEDDED_ACCESS_CHECKS
5216 && (sctx->master_access & SUPER_ACL)
5217 #endif
5218 )
5219 {
5220 /* No logging */
5221 return FALSE;
5222 }
5223
5224 return TRUE;
5225 }
5226
5227 return FALSE;
5228 }
5229
5230
general_log_print(THD * thd,enum enum_server_command command,const char * format,...)5231 bool general_log_print(THD *thd, enum enum_server_command command,
5232 const char *format, ...)
5233 {
5234 va_list args;
5235 uint error= 0;
5236
5237 /* Print the message to the buffer if we want to log this king of commands */
5238 if (! logger.log_command(thd, command))
5239 return FALSE;
5240
5241 va_start(args, format);
5242 error= logger.general_log_print(thd, command, format, args);
5243 va_end(args);
5244
5245 return error;
5246 }
5247
general_log_write(THD * thd,enum enum_server_command command,const char * query,uint query_length)5248 bool general_log_write(THD *thd, enum enum_server_command command,
5249 const char *query, uint query_length)
5250 {
5251 /* Write the message to the log if we want to log this king of commands */
5252 if (logger.log_command(thd, command))
5253 return logger.general_log_write(thd, command, query, query_length);
5254
5255 return FALSE;
5256 }
5257
5258 /**
5259 The method executes rotation when LOCK_log is already acquired
5260 by the caller.
5261
5262 @param force_rotate caller can request the log rotation
5263 @param check_purge is set to true if rotation took place
5264
5265 @note
5266 If rotation fails, for instance the server was unable
5267 to create a new log file, we still try to write an
5268 incident event to the current log.
5269
5270 @retval
5271 nonzero - error in rotating routine.
5272 */
rotate(bool force_rotate,bool * check_purge)5273 int MYSQL_BIN_LOG::rotate(bool force_rotate, bool* check_purge)
5274 {
5275 int error= 0;
5276 DBUG_ENTER("MYSQL_BIN_LOG::rotate");
5277
5278 //todo: fix the macro def and restore safe_mutex_assert_owner(&LOCK_log);
5279 *check_purge= false;
5280
5281 if (force_rotate || (my_b_tell(&log_file) >= (my_off_t) max_size))
5282 {
5283 if ((error= new_file_without_locking()))
5284 /**
5285 Be conservative... There are possible lost events (eg,
5286 failing to log the Execute_load_query_log_event
5287 on a LOAD DATA while using a non-transactional
5288 table)!
5289
5290 We give it a shot and try to write an incident event anyway
5291 to the current log.
5292 */
5293 if (!write_incident(current_thd, FALSE))
5294 flush_and_sync(0);
5295
5296 *check_purge= true;
5297 }
5298 DBUG_RETURN(error);
5299 }
5300
5301 /**
5302 The method executes logs purging routine.
5303
5304 @retval
5305 nonzero - error in rotating routine.
5306 */
purge()5307 void MYSQL_BIN_LOG::purge()
5308 {
5309 #ifdef HAVE_REPLICATION
5310 if (expire_logs_days)
5311 {
5312 DEBUG_SYNC(current_thd, "at_purge_logs_before_date");
5313 time_t purge_time= my_time(0) - expire_logs_days*24*60*60;
5314 if (purge_time >= 0)
5315 {
5316 purge_logs_before_date(purge_time);
5317 }
5318 }
5319 #endif
5320 }
5321
5322 /**
5323 The method is a shortcut of @c rotate() and @c purge().
5324 LOCK_log is acquired prior to rotate and is released after it.
5325
5326 @param force_rotate caller can request the log rotation
5327
5328 @retval
5329 nonzero - error in rotating routine.
5330 */
rotate_and_purge(bool force_rotate)5331 int MYSQL_BIN_LOG::rotate_and_purge(bool force_rotate)
5332 {
5333 int error= 0;
5334 DBUG_ENTER("MYSQL_BIN_LOG::rotate_and_purge");
5335 bool check_purge= false;
5336
5337 //todo: fix the macro def and restore safe_mutex_assert_not_owner(&LOCK_log);
5338 mysql_mutex_lock(&LOCK_log);
5339 error= rotate(force_rotate, &check_purge);
5340 /*
5341 NOTE: Run purge_logs wo/ holding LOCK_log because it does not need
5342 the mutex. Otherwise causes various deadlocks.
5343 */
5344 mysql_mutex_unlock(&LOCK_log);
5345
5346 if (!error && check_purge)
5347 purge();
5348
5349 DBUG_RETURN(error);
5350 }
5351
next_file_id()5352 uint MYSQL_BIN_LOG::next_file_id()
5353 {
5354 uint res;
5355 mysql_mutex_lock(&LOCK_log);
5356 res = file_id++;
5357 mysql_mutex_unlock(&LOCK_log);
5358 return res;
5359 }
5360
5361
5362 /*
5363 Write the contents of a cache to the binary log.
5364
5365 SYNOPSIS
5366 write_cache()
5367 cache Cache to write to the binary log
5368 lock_log True if the LOCK_log mutex should be aquired, false otherwise
5369 sync_log True if the log should be flushed and synced
5370
5371 DESCRIPTION
5372 Write the contents of the cache to the binary log. The cache will
5373 be reset as a READ_CACHE to be able to read the contents from it.
5374 */
5375
write_cache(IO_CACHE * cache,bool lock_log,bool sync_log)5376 int MYSQL_BIN_LOG::write_cache(IO_CACHE *cache, bool lock_log, bool sync_log)
5377 {
5378 Mutex_sentry sentry(lock_log ? &LOCK_log : NULL);
5379
5380 if (reinit_io_cache(cache, READ_CACHE, 0, 0, 0))
5381 return ER_ERROR_ON_WRITE;
5382 uint length= my_b_bytes_in_cache(cache), group, carry, hdr_offs;
5383 long val;
5384 uchar header[LOG_EVENT_HEADER_LEN];
5385
5386 /*
5387 The events in the buffer have incorrect end_log_pos data
5388 (relative to beginning of group rather than absolute),
5389 so we'll recalculate them in situ so the binlog is always
5390 correct, even in the middle of a group. This is possible
5391 because we now know the start position of the group (the
5392 offset of this cache in the log, if you will); all we need
5393 to do is to find all event-headers, and add the position of
5394 the group to the end_log_pos of each event. This is pretty
5395 straight forward, except that we read the cache in segments,
5396 so an event-header might end up on the cache-border and get
5397 split.
5398 */
5399
5400 group= (uint)my_b_tell(&log_file);
5401 hdr_offs= carry= 0;
5402
5403 do
5404 {
5405 /*
5406 if we only got a partial header in the last iteration,
5407 get the other half now and process a full header.
5408 */
5409 if (unlikely(carry > 0))
5410 {
5411 DBUG_ASSERT(carry < LOG_EVENT_HEADER_LEN);
5412
5413 /* assemble both halves */
5414 memcpy(&header[carry], (char *)cache->read_pos, LOG_EVENT_HEADER_LEN - carry);
5415
5416 /* fix end_log_pos */
5417 val= uint4korr(&header[LOG_POS_OFFSET]) + group;
5418 int4store(&header[LOG_POS_OFFSET], val);
5419
5420 /* write the first half of the split header */
5421 if (my_b_write(&log_file, header, carry))
5422 return ER_ERROR_ON_WRITE;
5423
5424 /*
5425 copy fixed second half of header to cache so the correct
5426 version will be written later.
5427 */
5428 memcpy((char *)cache->read_pos, &header[carry], LOG_EVENT_HEADER_LEN - carry);
5429
5430 /* next event header at ... */
5431 hdr_offs = uint4korr(&header[EVENT_LEN_OFFSET]) - carry;
5432
5433 carry= 0;
5434 }
5435
5436 /* if there is anything to write, process it. */
5437
5438 if (likely(length > 0))
5439 {
5440 /*
5441 process all event-headers in this (partial) cache.
5442 if next header is beyond current read-buffer,
5443 we'll get it later (though not necessarily in the
5444 very next iteration, just "eventually").
5445 */
5446
5447 while (hdr_offs < length)
5448 {
5449 /*
5450 partial header only? save what we can get, process once
5451 we get the rest.
5452 */
5453
5454 if (hdr_offs + LOG_EVENT_HEADER_LEN > length)
5455 {
5456 carry= length - hdr_offs;
5457 memcpy(header, (char *)cache->read_pos + hdr_offs, carry);
5458 length= hdr_offs;
5459 }
5460 else
5461 {
5462 /* we've got a full event-header, and it came in one piece */
5463
5464 uchar *log_pos= (uchar *)cache->read_pos + hdr_offs + LOG_POS_OFFSET;
5465
5466 /* fix end_log_pos */
5467 val= uint4korr(log_pos) + group;
5468 int4store(log_pos, val);
5469
5470 /* next event header at ... */
5471 log_pos= (uchar *)cache->read_pos + hdr_offs + EVENT_LEN_OFFSET;
5472 hdr_offs += uint4korr(log_pos);
5473
5474 }
5475 }
5476
5477 /*
5478 Adjust hdr_offs. Note that it may still point beyond the segment
5479 read in the next iteration; if the current event is very long,
5480 it may take a couple of read-iterations (and subsequent adjustments
5481 of hdr_offs) for it to point into the then-current segment.
5482 If we have a split header (!carry), hdr_offs will be set at the
5483 beginning of the next iteration, overwriting the value we set here:
5484 */
5485 hdr_offs -= length;
5486 }
5487
5488 /* Write data to the binary log file */
5489 if (my_b_write(&log_file, cache->read_pos, length))
5490 return ER_ERROR_ON_WRITE;
5491 cache->read_pos=cache->read_end; // Mark buffer used up
5492 } while ((length= my_b_fill(cache)));
5493
5494 DBUG_ASSERT(carry == 0);
5495
5496 if (sync_log)
5497 return flush_and_sync(0);
5498
5499 return 0; // All OK
5500 }
5501
5502 /*
5503 Helper function to get the error code of the query to be binlogged.
5504 */
query_error_code(THD * thd,bool not_killed)5505 int query_error_code(THD *thd, bool not_killed)
5506 {
5507 int error;
5508
5509 if (not_killed || (thd->killed == THD::KILL_BAD_DATA))
5510 {
5511 error= thd->is_error() ? thd->stmt_da->sql_errno() : 0;
5512
5513 /* thd->stmt_da->sql_errno() might be ER_SERVER_SHUTDOWN or
5514 ER_QUERY_INTERRUPTED, So here we need to make sure that error
5515 is not set to these errors when specified not_killed by the
5516 caller.
5517 */
5518 if (error == ER_SERVER_SHUTDOWN || error == ER_QUERY_INTERRUPTED)
5519 error= 0;
5520 }
5521 else
5522 {
5523 /* killed status for DELAYED INSERT thread should never be used */
5524 DBUG_ASSERT(!(thd->system_thread & SYSTEM_THREAD_DELAYED_INSERT));
5525 error= thd->killed_errno();
5526 }
5527
5528 return error;
5529 }
5530
write_incident(THD * thd,bool lock)5531 bool MYSQL_BIN_LOG::write_incident(THD *thd, bool lock)
5532 {
5533 uint error= 0;
5534 DBUG_ENTER("MYSQL_BIN_LOG::write_incident");
5535
5536 if (!is_open())
5537 DBUG_RETURN(error);
5538
5539 LEX_STRING const write_error_msg=
5540 { C_STRING_WITH_LEN("error writing to the binary log") };
5541 Incident incident= INCIDENT_LOST_EVENTS;
5542 Incident_log_event ev(thd, incident, write_error_msg);
5543 if (lock)
5544 mysql_mutex_lock(&LOCK_log);
5545 error= ev.write(&log_file);
5546 if (lock)
5547 {
5548 if (!error && !(error= flush_and_sync(0)))
5549 {
5550 bool check_purge= false;
5551 signal_update();
5552 error= rotate(false, &check_purge);
5553 mysql_mutex_unlock(&LOCK_log);
5554 if (!error && check_purge)
5555 purge();
5556 }
5557 else
5558 {
5559 mysql_mutex_unlock(&LOCK_log);
5560 }
5561 }
5562 DBUG_RETURN(error);
5563 }
5564
5565 /**
5566 Write a cached log entry to the binary log.
5567 - To support transaction over replication, we wrap the transaction
5568 with BEGIN/COMMIT or BEGIN/ROLLBACK in the binary log.
5569 We want to write a BEGIN/ROLLBACK block when a non-transactional table
5570 was updated in a transaction which was rolled back. This is to ensure
5571 that the same updates are run on the slave.
5572
5573 @param thd
5574 @param cache The cache to copy to the binlog
5575 @param commit_event The commit event to print after writing the
5576 contents of the cache.
5577 @param incident Defines if an incident event should be created to
5578 notify that some non-transactional changes did
5579 not get into the binlog.
5580
5581 @note
5582 We only come here if there is something in the cache.
5583 @note
5584 The thing in the cache is always a complete transaction.
5585 @note
5586 'cache' needs to be reinitialized after this functions returns.
5587 */
5588
write(THD * thd,IO_CACHE * cache,Log_event * commit_event,bool incident)5589 bool MYSQL_BIN_LOG::write(THD *thd, IO_CACHE *cache, Log_event *commit_event,
5590 bool incident)
5591 {
5592 DBUG_ENTER("MYSQL_BIN_LOG::write(THD *, IO_CACHE *, Log_event *)");
5593
5594 DBUG_ASSERT(is_open());
5595 if (likely(is_open())) // Should always be true
5596 {
5597 bool check_purge;
5598
5599 mysql_mutex_lock(&LOCK_log);
5600 /*
5601 We only bother to write to the binary log if there is anything
5602 to write.
5603 */
5604 if (my_b_tell(cache) > 0)
5605 {
5606 /*
5607 Log "BEGIN" at the beginning of every transaction. Here, a
5608 transaction is either a BEGIN..COMMIT block or a single
5609 statement in autocommit mode.
5610 */
5611 Query_log_event qinfo(thd, STRING_WITH_LEN("BEGIN"), TRUE, FALSE, TRUE, 0);
5612 if (qinfo.write(&log_file))
5613 goto err;
5614 DBUG_EXECUTE_IF("crash_before_writing_xid",
5615 {
5616 if ((write_error= write_cache(cache, false, true)))
5617 DBUG_PRINT("info", ("error writing binlog cache: %d",
5618 write_error));
5619 DBUG_PRINT("info", ("crashing before writing xid"));
5620 DBUG_SUICIDE();
5621 });
5622
5623 if ((write_error= write_cache(cache, false, false)))
5624 goto err;
5625
5626 if (commit_event && commit_event->write(&log_file))
5627 goto err;
5628
5629 if (incident && write_incident(thd, FALSE))
5630 goto err;
5631
5632 bool synced= 0;
5633 if (flush_and_sync(&synced))
5634 goto err;
5635 DBUG_EXECUTE_IF("half_binlogged_transaction", DBUG_SUICIDE(););
5636 if (cache->error) // Error on read
5637 {
5638 sql_print_error(ER(ER_ERROR_ON_READ), cache->file_name, errno);
5639 write_error=1; // Don't give more errors
5640 goto err;
5641 }
5642
5643 if (RUN_HOOK(binlog_storage, after_flush,
5644 (thd, log_file_name, log_file.pos_in_file, synced)))
5645 {
5646 sql_print_error("Failed to run 'after_flush' hooks");
5647 write_error=1;
5648 goto err;
5649 }
5650
5651 signal_update();
5652 }
5653
5654 /*
5655 if commit_event is Xid_log_event, increase the number of
5656 prepared_xids (it's decreasd in ::unlog()). Binlog cannot be rotated
5657 if there're prepared xids in it - see the comment in new_file() for
5658 an explanation.
5659 If the commit_event is not Xid_log_event (then it's a Query_log_event)
5660 rotate binlog, if necessary.
5661 */
5662 if (commit_event && commit_event->get_type_code() == XID_EVENT)
5663 {
5664 mysql_mutex_lock(&LOCK_prep_xids);
5665 prepared_xids++;
5666 mysql_mutex_unlock(&LOCK_prep_xids);
5667 mysql_mutex_unlock(&LOCK_log);
5668 }
5669 else
5670 {
5671 if (rotate(false, &check_purge))
5672 goto err;
5673 mysql_mutex_unlock(&LOCK_log);
5674 if (check_purge)
5675 purge();
5676 }
5677 }
5678
5679 DBUG_RETURN(0);
5680
5681 err:
5682 if (!write_error)
5683 {
5684 write_error= 1;
5685 sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
5686 }
5687 mysql_mutex_unlock(&LOCK_log);
5688 DBUG_RETURN(1);
5689 }
5690
5691
5692 /**
5693 Wait until we get a signal that the relay log has been updated.
5694
5695 @param thd Thread variable
5696
5697 @note
5698 One must have a lock on LOCK_log before calling this function.
5699 This lock will be released before return! That's required by
5700 THD::enter_cond() (see NOTES in sql_class.h).
5701 */
5702
wait_for_update_relay_log(THD * thd)5703 void MYSQL_BIN_LOG::wait_for_update_relay_log(THD* thd)
5704 {
5705 const char *old_msg;
5706 DBUG_ENTER("wait_for_update_relay_log");
5707
5708 old_msg= thd->enter_cond(&update_cond, &LOCK_log,
5709 "Slave has read all relay log; "
5710 "waiting for the slave I/O "
5711 "thread to update it" );
5712 mysql_cond_wait(&update_cond, &LOCK_log);
5713 thd->exit_cond(old_msg);
5714 DBUG_VOID_RETURN;
5715 }
5716
5717 /**
5718 Wait until we get a signal that the binary log has been updated.
5719 Applies to master only.
5720
5721 NOTES
5722 @param[in] thd a THD struct
5723 @param[in] timeout a pointer to a timespec;
5724 NULL means to wait w/o timeout.
5725 @retval 0 if got signalled on update
5726 @retval non-0 if wait timeout elapsed
5727 @note
5728 LOCK_log must be taken before calling this function.
5729 LOCK_log is being released while the thread is waiting.
5730 LOCK_log is released by the caller.
5731 */
5732
wait_for_update_bin_log(THD * thd,const struct timespec * timeout)5733 int MYSQL_BIN_LOG::wait_for_update_bin_log(THD* thd,
5734 const struct timespec *timeout)
5735 {
5736 int ret= 0;
5737 DBUG_ENTER("wait_for_update_bin_log");
5738
5739 if (!timeout)
5740 mysql_cond_wait(&update_cond, &LOCK_log);
5741 else
5742 ret= mysql_cond_timedwait(&update_cond, &LOCK_log,
5743 const_cast<struct timespec *>(timeout));
5744 DBUG_RETURN(ret);
5745 }
5746
5747
5748 /**
5749 Close the log file.
5750
5751 @param exiting Bitmask for one or more of the following bits:
5752 - LOG_CLOSE_INDEX : if we should close the index file
5753 - LOG_CLOSE_TO_BE_OPENED : if we intend to call open
5754 at once after close.
5755 - LOG_CLOSE_STOP_EVENT : write a 'stop' event to the log
5756
5757 @note
5758 One can do an open on the object at once after doing a close.
5759 The internal structures are not freed until cleanup() is called
5760 */
5761
close(uint exiting)5762 void MYSQL_BIN_LOG::close(uint exiting)
5763 { // One can't set log_type here!
5764 DBUG_ENTER("MYSQL_BIN_LOG::close");
5765 DBUG_PRINT("enter",("exiting: %d", (int) exiting));
5766 if (log_state == LOG_OPENED)
5767 {
5768 #ifdef HAVE_REPLICATION
5769 if (log_type == LOG_BIN && !no_auto_events &&
5770 (exiting & LOG_CLOSE_STOP_EVENT))
5771 {
5772 Stop_log_event s;
5773 s.write(&log_file);
5774 bytes_written+= s.data_written;
5775 signal_update();
5776 }
5777 #endif /* HAVE_REPLICATION */
5778
5779 /* don't pwrite in a file opened with O_APPEND - it doesn't work */
5780 if (log_file.type == WRITE_CACHE && log_type == LOG_BIN)
5781 {
5782 my_off_t offset= BIN_LOG_HEADER_SIZE + FLAGS_OFFSET;
5783 my_off_t org_position= mysql_file_tell(log_file.file, MYF(0));
5784 uchar flags= 0; // clearing LOG_EVENT_BINLOG_IN_USE_F
5785 mysql_file_pwrite(log_file.file, &flags, 1, offset, MYF(0));
5786 /*
5787 Restore position so that anything we have in the IO_cache is written
5788 to the correct position.
5789 We need the seek here, as mysql_file_pwrite() is not guaranteed to keep the
5790 original position on system that doesn't support pwrite().
5791 */
5792 mysql_file_seek(log_file.file, org_position, MY_SEEK_SET, MYF(0));
5793 }
5794
5795 /* this will cleanup IO_CACHE, sync and close the file */
5796 MYSQL_LOG::close(exiting);
5797 }
5798
5799 /*
5800 The following test is needed even if is_open() is not set, as we may have
5801 called a not complete close earlier and the index file is still open.
5802 */
5803
5804 if ((exiting & LOG_CLOSE_INDEX) && my_b_inited(&index_file))
5805 {
5806 end_io_cache(&index_file);
5807 if (mysql_file_close(index_file.file, MYF(0)) < 0 && ! write_error)
5808 {
5809 write_error= 1;
5810 sql_print_error(ER(ER_ERROR_ON_WRITE), index_file_name, errno);
5811 }
5812 }
5813 log_state= (exiting & LOG_CLOSE_TO_BE_OPENED) ? LOG_TO_BE_OPENED : LOG_CLOSED;
5814 my_free(name);
5815 name= NULL;
5816 DBUG_VOID_RETURN;
5817 }
5818
5819
set_max_size(ulong max_size_arg)5820 void MYSQL_BIN_LOG::set_max_size(ulong max_size_arg)
5821 {
5822 /*
5823 We need to take locks, otherwise this may happen:
5824 new_file() is called, calls open(old_max_size), then before open() starts,
5825 set_max_size() sets max_size to max_size_arg, then open() starts and
5826 uses the old_max_size argument, so max_size_arg has been overwritten and
5827 it's like if the SET command was never run.
5828 */
5829 DBUG_ENTER("MYSQL_BIN_LOG::set_max_size");
5830 mysql_mutex_lock(&LOCK_log);
5831 if (is_open())
5832 max_size= max_size_arg;
5833 mysql_mutex_unlock(&LOCK_log);
5834 DBUG_VOID_RETURN;
5835 }
5836
5837
5838 /**
5839 Check if a string is a valid number.
5840
5841 @param str String to test
5842 @param res Store value here
5843 @param allow_wildcards Set to 1 if we should ignore '%' and '_'
5844
5845 @note
5846 For the moment the allow_wildcards argument is not used
5847 Should be move to some other file.
5848
5849 @retval
5850 1 String is a number
5851 @retval
5852 0 String is not a number
5853 */
5854
test_if_number(register const char * str,ulong * res,bool allow_wildcards)5855 static bool test_if_number(register const char *str,
5856 ulong *res, bool allow_wildcards)
5857 {
5858 reg2 int flag;
5859 const char *start;
5860 DBUG_ENTER("test_if_number");
5861
5862 flag=0; start=str;
5863 while (*str++ == ' ') ;
5864 if (*--str == '-' || *str == '+')
5865 str++;
5866 while (my_isdigit(files_charset_info,*str) ||
5867 (allow_wildcards && (*str == wild_many || *str == wild_one)))
5868 {
5869 flag=1;
5870 str++;
5871 }
5872 if (*str == '.')
5873 {
5874 for (str++ ;
5875 my_isdigit(files_charset_info,*str) ||
5876 (allow_wildcards && (*str == wild_many || *str == wild_one)) ;
5877 str++, flag=1) ;
5878 }
5879 if (*str != 0 || flag == 0)
5880 DBUG_RETURN(0);
5881 if (res)
5882 *res=atol(start);
5883 DBUG_RETURN(1); /* Number ok */
5884 } /* test_if_number */
5885
5886
sql_perror(const char * message)5887 void sql_perror(const char *message)
5888 {
5889 #ifdef HAVE_STRERROR
5890 sql_print_error("%s: %s",message, strerror(errno));
5891 #else
5892 perror(message);
5893 #endif
5894 }
5895
5896
5897 /*
5898 Change the file associated with two output streams. Used to
5899 redirect stdout and stderr to a file. The streams are reopened
5900 only for appending (writing at end of file).
5901 */
reopen_fstreams(const char * filename,FILE * outstream,FILE * errstream)5902 extern "C" my_bool reopen_fstreams(const char *filename,
5903 FILE *outstream, FILE *errstream)
5904 {
5905 if (outstream && !my_freopen(filename, "a", outstream))
5906 return TRUE;
5907
5908 if (errstream && !my_freopen(filename, "a", errstream))
5909 return TRUE;
5910
5911 /* The error stream must be unbuffered. */
5912 if (errstream)
5913 setbuf(errstream, NULL);
5914
5915 return FALSE;
5916 }
5917
5918
5919 /*
5920 Unfortunately, there seems to be no good way
5921 to restore the original streams upon failure.
5922 */
redirect_std_streams(const char * file)5923 static bool redirect_std_streams(const char *file)
5924 {
5925 if (reopen_fstreams(file, stdout, stderr))
5926 return TRUE;
5927
5928 setbuf(stderr, NULL);
5929 return FALSE;
5930 }
5931
5932
flush_error_log()5933 bool flush_error_log()
5934 {
5935 bool result= 0;
5936 if (opt_error_log)
5937 {
5938 mysql_mutex_lock(&LOCK_error_log);
5939 if (redirect_std_streams(log_error_file))
5940 result= 1;
5941 mysql_mutex_unlock(&LOCK_error_log);
5942 }
5943 return result;
5944 }
5945
signal_update()5946 void MYSQL_BIN_LOG::signal_update()
5947 {
5948 DBUG_ENTER("MYSQL_BIN_LOG::signal_update");
5949 signal_cnt++;
5950 mysql_cond_broadcast(&update_cond);
5951 DBUG_VOID_RETURN;
5952 }
5953
5954 #ifdef _WIN32
print_buffer_to_nt_eventlog(enum loglevel level,char * buff,size_t length,size_t buffLen)5955 static void print_buffer_to_nt_eventlog(enum loglevel level, char *buff,
5956 size_t length, size_t buffLen)
5957 {
5958 HANDLE event;
5959 char *buffptr= buff;
5960 DBUG_ENTER("print_buffer_to_nt_eventlog");
5961
5962 /* Add ending CR/LF's to string, overwrite last chars if necessary */
5963 strmov(buffptr+min(length, buffLen-5), "\r\n\r\n");
5964
5965 setup_windows_event_source();
5966 if ((event= RegisterEventSource(NULL,"MySQL")))
5967 {
5968 switch (level) {
5969 case ERROR_LEVEL:
5970 ReportEvent(event, EVENTLOG_ERROR_TYPE, 0, MSG_DEFAULT, NULL, 1, 0,
5971 (LPCSTR*)&buffptr, NULL);
5972 break;
5973 case WARNING_LEVEL:
5974 ReportEvent(event, EVENTLOG_WARNING_TYPE, 0, MSG_DEFAULT, NULL, 1, 0,
5975 (LPCSTR*) &buffptr, NULL);
5976 break;
5977 case INFORMATION_LEVEL:
5978 ReportEvent(event, EVENTLOG_INFORMATION_TYPE, 0, MSG_DEFAULT, NULL, 1,
5979 0, (LPCSTR*) &buffptr, NULL);
5980 break;
5981 }
5982 DeregisterEventSource(event);
5983 }
5984
5985 DBUG_VOID_RETURN;
5986 }
5987 #endif /* _WIN32 */
5988
5989
5990 #ifndef EMBEDDED_LIBRARY
print_buffer_to_file(enum loglevel level,const char * buffer,size_t length)5991 static void print_buffer_to_file(enum loglevel level, const char *buffer,
5992 size_t length)
5993 {
5994 time_t skr;
5995 struct tm tm_tmp;
5996 struct tm *start;
5997 DBUG_ENTER("print_buffer_to_file");
5998 DBUG_PRINT("enter",("buffer: %s", buffer));
5999
6000 mysql_mutex_lock(&LOCK_error_log);
6001
6002 skr= my_time(0);
6003 localtime_r(&skr, &tm_tmp);
6004 start=&tm_tmp;
6005
6006 fprintf(stderr, "%02d%02d%02d %2d:%02d:%02d [%s] %.*s\n",
6007 start->tm_year % 100,
6008 start->tm_mon+1,
6009 start->tm_mday,
6010 start->tm_hour,
6011 start->tm_min,
6012 start->tm_sec,
6013 (level == ERROR_LEVEL ? "ERROR" : level == WARNING_LEVEL ?
6014 "Warning" : "Note"),
6015 (int) length, buffer);
6016
6017 fflush(stderr);
6018
6019 mysql_mutex_unlock(&LOCK_error_log);
6020 DBUG_VOID_RETURN;
6021 }
6022
6023 /**
6024 Prints a printf style message to the error log and, under NT, to the
6025 Windows event log.
6026
6027 This function prints the message into a buffer and then sends that buffer
6028 to other functions to write that message to other logging sources.
6029
6030 @param level The level of the msg significance
6031 @param format Printf style format of message
6032 @param args va_list list of arguments for the message
6033
6034 @returns
6035 The function always returns 0. The return value is present in the
6036 signature to be compatible with other logging routines, which could
6037 return an error (e.g. logging to the log tables)
6038 */
vprint_msg_to_log(enum loglevel level,const char * format,va_list args)6039 int vprint_msg_to_log(enum loglevel level, const char *format, va_list args)
6040 {
6041 char buff[1024];
6042 size_t length;
6043 DBUG_ENTER("vprint_msg_to_log");
6044
6045 length= my_vsnprintf(buff, sizeof(buff), format, args);
6046 print_buffer_to_file(level, buff, length);
6047
6048 #ifdef _WIN32
6049 print_buffer_to_nt_eventlog(level, buff, length, sizeof(buff));
6050 #endif
6051
6052 DBUG_RETURN(0);
6053 }
6054 #endif /* EMBEDDED_LIBRARY */
6055
6056
sql_print_error(const char * format,...)6057 void sql_print_error(const char *format, ...)
6058 {
6059 va_list args;
6060 DBUG_ENTER("sql_print_error");
6061
6062 va_start(args, format);
6063 error_log_print(ERROR_LEVEL, format, args);
6064 va_end(args);
6065
6066 DBUG_VOID_RETURN;
6067 }
6068
6069
sql_print_warning(const char * format,...)6070 void sql_print_warning(const char *format, ...)
6071 {
6072 va_list args;
6073 DBUG_ENTER("sql_print_warning");
6074
6075 va_start(args, format);
6076 error_log_print(WARNING_LEVEL, format, args);
6077 va_end(args);
6078
6079 DBUG_VOID_RETURN;
6080 }
6081
6082
sql_print_information(const char * format,...)6083 void sql_print_information(const char *format, ...)
6084 {
6085 va_list args;
6086 DBUG_ENTER("sql_print_information");
6087
6088 va_start(args, format);
6089 error_log_print(INFORMATION_LEVEL, format, args);
6090 va_end(args);
6091
6092 DBUG_VOID_RETURN;
6093 }
6094
6095
6096 /********* transaction coordinator log for 2pc - mmap() based solution *******/
6097
6098 /*
6099 the log consists of a file, mmapped to a memory.
6100 file is divided on pages of tc_log_page_size size.
6101 (usable size of the first page is smaller because of log header)
6102 there's PAGE control structure for each page
6103 each page (or rather PAGE control structure) can be in one of three
6104 states - active, syncing, pool.
6105 there could be only one page in active or syncing states,
6106 but many in pool - pool is fifo queue.
6107 usual lifecycle of a page is pool->active->syncing->pool
6108 "active" page - is a page where new xid's are logged.
6109 the page stays active as long as syncing slot is taken.
6110 "syncing" page is being synced to disk. no new xid can be added to it.
6111 when the sync is done the page is moved to a pool and an active page
6112 becomes "syncing".
6113
6114 the result of such an architecture is a natural "commit grouping" -
6115 If commits are coming faster than the system can sync, they do not
6116 stall. Instead, all commit that came since the last sync are
6117 logged to the same page, and they all are synced with the next -
6118 one - sync. Thus, thought individual commits are delayed, throughput
6119 is not decreasing.
6120
6121 when a xid is added to an active page, the thread of this xid waits
6122 for a page's condition until the page is synced. when syncing slot
6123 becomes vacant one of these waiters is awaken to take care of syncing.
6124 it syncs the page and signals all waiters that the page is synced.
6125 PAGE::waiters is used to count these waiters, and a page may never
6126 become active again until waiters==0 (that is all waiters from the
6127 previous sync have noticed the sync was completed)
6128
6129 note, that the page becomes "dirty" and has to be synced only when a
6130 new xid is added into it. Removing a xid from a page does not make it
6131 dirty - we don't sync removals to disk.
6132 */
6133
6134 ulong tc_log_page_waits= 0;
6135
6136 #ifdef HAVE_MMAP
6137
6138 #define TC_LOG_HEADER_SIZE (sizeof(tc_log_magic)+1)
6139
6140 static const char tc_log_magic[]={(char) 254, 0x23, 0x05, 0x74};
6141
6142 ulong opt_tc_log_size= TC_LOG_MIN_SIZE;
6143 ulong tc_log_max_pages_used=0, tc_log_page_size=0, tc_log_cur_pages_used=0;
6144
open(const char * opt_name)6145 int TC_LOG_MMAP::open(const char *opt_name)
6146 {
6147 uint i;
6148 bool crashed=FALSE;
6149 PAGE *pg;
6150
6151 DBUG_ASSERT(total_ha_2pc > 1);
6152 DBUG_ASSERT(opt_name && opt_name[0]);
6153
6154 tc_log_page_size= my_getpagesize();
6155 DBUG_ASSERT(TC_LOG_PAGE_SIZE % tc_log_page_size == 0);
6156
6157 fn_format(logname,opt_name,mysql_data_home,"",MY_UNPACK_FILENAME);
6158 if ((fd= mysql_file_open(key_file_tclog, logname, O_RDWR, MYF(0))) < 0)
6159 {
6160 if (my_errno != ENOENT)
6161 goto err;
6162 if (using_heuristic_recover())
6163 return 1;
6164 if ((fd= mysql_file_create(key_file_tclog, logname, CREATE_MODE,
6165 O_RDWR, MYF(MY_WME))) < 0)
6166 goto err;
6167 inited=1;
6168 file_length= opt_tc_log_size;
6169 if (mysql_file_chsize(fd, file_length, 0, MYF(MY_WME)))
6170 goto err;
6171 }
6172 else
6173 {
6174 inited= 1;
6175 crashed= TRUE;
6176 sql_print_information("Recovering after a crash using %s", opt_name);
6177 if (tc_heuristic_recover)
6178 {
6179 sql_print_error("Cannot perform automatic crash recovery when "
6180 "--tc-heuristic-recover is used");
6181 goto err;
6182 }
6183 file_length= mysql_file_seek(fd, 0L, MY_SEEK_END, MYF(MY_WME+MY_FAE));
6184 if (file_length == MY_FILEPOS_ERROR || file_length % tc_log_page_size)
6185 goto err;
6186 }
6187
6188 data= (uchar *)my_mmap(0, (size_t)file_length, PROT_READ|PROT_WRITE,
6189 MAP_NOSYNC|MAP_SHARED, fd, 0);
6190 if (data == MAP_FAILED)
6191 {
6192 my_errno=errno;
6193 goto err;
6194 }
6195 inited=2;
6196
6197 npages=(uint)file_length/tc_log_page_size;
6198 DBUG_ASSERT(npages >= 3); // to guarantee non-empty pool
6199 if (!(pages=(PAGE *)my_malloc(npages*sizeof(PAGE), MYF(MY_WME|MY_ZEROFILL))))
6200 goto err;
6201 inited=3;
6202 for (pg=pages, i=0; i < npages; i++, pg++)
6203 {
6204 pg->next=pg+1;
6205 pg->waiters=0;
6206 pg->state=PS_POOL;
6207 mysql_mutex_init(key_PAGE_lock, &pg->lock, MY_MUTEX_INIT_FAST);
6208 mysql_cond_init(key_PAGE_cond, &pg->cond, 0);
6209 pg->start=(my_xid *)(data + i*tc_log_page_size);
6210 pg->end=(my_xid *)(pg->start + tc_log_page_size);
6211 pg->size=pg->free=tc_log_page_size/sizeof(my_xid);
6212 }
6213 pages[0].size=pages[0].free=
6214 (tc_log_page_size-TC_LOG_HEADER_SIZE)/sizeof(my_xid);
6215 pages[0].start=pages[0].end-pages[0].size;
6216 pages[npages-1].next=0;
6217 inited=4;
6218
6219 if (crashed && recover())
6220 goto err;
6221
6222 memcpy(data, tc_log_magic, sizeof(tc_log_magic));
6223 data[sizeof(tc_log_magic)]= (uchar)total_ha_2pc;
6224 my_msync(fd, data, tc_log_page_size, MS_SYNC);
6225 inited=5;
6226
6227 mysql_mutex_init(key_LOCK_sync, &LOCK_sync, MY_MUTEX_INIT_FAST);
6228 mysql_mutex_init(key_LOCK_active, &LOCK_active, MY_MUTEX_INIT_FAST);
6229 mysql_mutex_init(key_LOCK_pool, &LOCK_pool, MY_MUTEX_INIT_FAST);
6230 mysql_cond_init(key_COND_active, &COND_active, 0);
6231 mysql_cond_init(key_COND_pool, &COND_pool, 0);
6232
6233 inited=6;
6234
6235 syncing= 0;
6236 active=pages;
6237 pool=pages+1;
6238 pool_last=pages+npages-1;
6239
6240 return 0;
6241
6242 err:
6243 close();
6244 return 1;
6245 }
6246
6247 /**
6248 there is no active page, let's got one from the pool.
6249
6250 Two strategies here:
6251 -# take the first from the pool
6252 -# if there're waiters - take the one with the most free space.
6253
6254 @todo
6255 TODO page merging. try to allocate adjacent page first,
6256 so that they can be flushed both in one sync
6257 */
6258
get_active_from_pool()6259 void TC_LOG_MMAP::get_active_from_pool()
6260 {
6261 PAGE **p, **best_p=0;
6262 int best_free;
6263
6264 if (syncing)
6265 mysql_mutex_lock(&LOCK_pool);
6266
6267 do
6268 {
6269 best_p= p= &pool;
6270 if ((*p)->waiters == 0) // can the first page be used ?
6271 break; // yes - take it.
6272
6273 best_free=0; // no - trying second strategy
6274 for (p=&(*p)->next; *p; p=&(*p)->next)
6275 {
6276 if ((*p)->waiters == 0 && (*p)->free > best_free)
6277 {
6278 best_free=(*p)->free;
6279 best_p=p;
6280 }
6281 }
6282 }
6283 while ((*best_p == 0 || best_free == 0) && overflow());
6284
6285 active=*best_p;
6286 if (active->free == active->size) // we've chosen an empty page
6287 {
6288 tc_log_cur_pages_used++;
6289 set_if_bigger(tc_log_max_pages_used, tc_log_cur_pages_used);
6290 }
6291
6292 if ((*best_p)->next) // unlink the page from the pool
6293 *best_p=(*best_p)->next;
6294 else
6295 pool_last=*best_p;
6296
6297 if (syncing)
6298 mysql_mutex_unlock(&LOCK_pool);
6299 }
6300
6301 /**
6302 @todo
6303 perhaps, increase log size ?
6304 */
overflow()6305 int TC_LOG_MMAP::overflow()
6306 {
6307 /*
6308 simple overflow handling - just wait
6309 TODO perhaps, increase log size ?
6310 let's check the behaviour of tc_log_page_waits first
6311 */
6312 tc_log_page_waits++;
6313 mysql_cond_wait(&COND_pool, &LOCK_pool);
6314 return 1; // always return 1
6315 }
6316
6317 /**
6318 Record that transaction XID is committed on the persistent storage.
6319
6320 This function is called in the middle of two-phase commit:
6321 First all resources prepare the transaction, then tc_log->log() is called,
6322 then all resources commit the transaction, then tc_log->unlog() is called.
6323
6324 All access to active page is serialized but it's not a problem, as
6325 we're assuming that fsync() will be a main bottleneck.
6326 That is, parallelizing writes to log pages we'll decrease number of
6327 threads waiting for a page, but then all these threads will be waiting
6328 for a fsync() anyway
6329
6330 If tc_log == MYSQL_LOG then tc_log writes transaction to binlog and
6331 records XID in a special Xid_log_event.
6332 If tc_log = TC_LOG_MMAP then xid is written in a special memory-mapped
6333 log.
6334
6335 @retval
6336 0 - error
6337 @retval
6338 \# - otherwise, "cookie", a number that will be passed as an argument
6339 to unlog() call. tc_log can define it any way it wants,
6340 and use for whatever purposes. TC_LOG_MMAP sets it
6341 to the position in memory where xid was logged to.
6342 */
6343
log_xid(THD * thd,my_xid xid)6344 int TC_LOG_MMAP::log_xid(THD *thd, my_xid xid)
6345 {
6346 int err;
6347 PAGE *p;
6348 ulong cookie;
6349
6350 mysql_mutex_lock(&LOCK_active);
6351
6352 /*
6353 if active page is full - just wait...
6354 frankly speaking, active->free here accessed outside of mutex
6355 protection, but it's safe, because it only means we may miss an
6356 unlog() for the active page, and we're not waiting for it here -
6357 unlog() does not signal COND_active.
6358 */
6359 while (unlikely(active && active->free == 0))
6360 mysql_cond_wait(&COND_active, &LOCK_active);
6361
6362 /* no active page ? take one from the pool */
6363 if (active == 0)
6364 get_active_from_pool();
6365
6366 p=active;
6367 mysql_mutex_lock(&p->lock);
6368
6369 /* searching for an empty slot */
6370 while (*p->ptr)
6371 {
6372 p->ptr++;
6373 DBUG_ASSERT(p->ptr < p->end); // because p->free > 0
6374 }
6375
6376 /* found! store xid there and mark the page dirty */
6377 cookie= (ulong)((uchar *)p->ptr - data); // can never be zero
6378 *p->ptr++= xid;
6379 p->free--;
6380 p->state= PS_DIRTY;
6381
6382 /* to sync or not to sync - this is the question */
6383 mysql_mutex_unlock(&LOCK_active);
6384 mysql_mutex_lock(&LOCK_sync);
6385 mysql_mutex_unlock(&p->lock);
6386
6387 if (syncing)
6388 { // somebody's syncing. let's wait
6389 p->waiters++;
6390 /*
6391 note - it must be while (), not do ... while () here
6392 as p->state may be not PS_DIRTY when we come here
6393 */
6394 while (p->state == PS_DIRTY && syncing)
6395 mysql_cond_wait(&p->cond, &LOCK_sync);
6396 p->waiters--;
6397 err= p->state == PS_ERROR;
6398 if (p->state != PS_DIRTY) // page was synced
6399 {
6400 if (p->waiters == 0)
6401 mysql_cond_signal(&COND_pool); // in case somebody's waiting
6402 mysql_mutex_unlock(&LOCK_sync);
6403 goto done; // we're done
6404 }
6405 } // page was not synced! do it now
6406 DBUG_ASSERT(active == p && syncing == 0);
6407 mysql_mutex_lock(&LOCK_active);
6408 syncing=p; // place is vacant - take it
6409 active=0; // page is not active anymore
6410 mysql_cond_broadcast(&COND_active); // in case somebody's waiting
6411 mysql_mutex_unlock(&LOCK_active);
6412 mysql_mutex_unlock(&LOCK_sync);
6413 err= sync();
6414
6415 done:
6416 return err ? 0 : cookie;
6417 }
6418
sync()6419 int TC_LOG_MMAP::sync()
6420 {
6421 int err;
6422
6423 DBUG_ASSERT(syncing != active);
6424
6425 /*
6426 sit down and relax - this can take a while...
6427 note - no locks are held at this point
6428 */
6429 err= my_msync(fd, syncing->start, 1, MS_SYNC);
6430
6431 /* page is synced. let's move it to the pool */
6432 mysql_mutex_lock(&LOCK_pool);
6433 pool_last->next=syncing;
6434 pool_last=syncing;
6435 syncing->next=0;
6436 syncing->state= err ? PS_ERROR : PS_POOL;
6437 mysql_cond_broadcast(&syncing->cond); // signal "sync done"
6438 mysql_cond_signal(&COND_pool); // in case somebody's waiting
6439 mysql_mutex_unlock(&LOCK_pool);
6440
6441 /* marking 'syncing' slot free */
6442 mysql_mutex_lock(&LOCK_sync);
6443 syncing=0;
6444 mysql_cond_signal(&active->cond); // wake up a new syncer
6445 mysql_mutex_unlock(&LOCK_sync);
6446 return err;
6447 }
6448
6449 /**
6450 erase xid from the page, update page free space counters/pointers.
6451 cookie points directly to the memory where xid was logged.
6452 */
6453
unlog(ulong cookie,my_xid xid)6454 int TC_LOG_MMAP::unlog(ulong cookie, my_xid xid)
6455 {
6456 PAGE *p=pages+(cookie/tc_log_page_size);
6457 my_xid *x=(my_xid *)(data+cookie);
6458
6459 DBUG_ASSERT(*x == xid);
6460 DBUG_ASSERT(x >= p->start && x < p->end);
6461 *x=0;
6462
6463 mysql_mutex_lock(&p->lock);
6464 p->free++;
6465 DBUG_ASSERT(p->free <= p->size);
6466 set_if_smaller(p->ptr, x);
6467 if (p->free == p->size) // the page is completely empty
6468 statistic_decrement(tc_log_cur_pages_used, &LOCK_status);
6469 if (p->waiters == 0) // the page is in pool and ready to rock
6470 mysql_cond_signal(&COND_pool); // ping ... for overflow()
6471 mysql_mutex_unlock(&p->lock);
6472 return 0;
6473 }
6474
close()6475 void TC_LOG_MMAP::close()
6476 {
6477 uint i;
6478 switch (inited) {
6479 case 6:
6480 mysql_mutex_destroy(&LOCK_sync);
6481 mysql_mutex_destroy(&LOCK_active);
6482 mysql_mutex_destroy(&LOCK_pool);
6483 mysql_cond_destroy(&COND_pool);
6484 case 5:
6485 data[0]='A'; // garble the first (signature) byte, in case mysql_file_delete fails
6486 case 4:
6487 for (i=0; i < npages; i++)
6488 {
6489 if (pages[i].ptr == 0)
6490 break;
6491 mysql_mutex_destroy(&pages[i].lock);
6492 mysql_cond_destroy(&pages[i].cond);
6493 }
6494 case 3:
6495 my_free(pages);
6496 case 2:
6497 my_munmap((char*)data, (size_t)file_length);
6498 case 1:
6499 mysql_file_close(fd, MYF(0));
6500 }
6501 if (inited>=5) // cannot do in the switch because of Windows
6502 mysql_file_delete(key_file_tclog, logname, MYF(MY_WME));
6503 inited=0;
6504 }
6505
recover()6506 int TC_LOG_MMAP::recover()
6507 {
6508 HASH xids;
6509 PAGE *p=pages, *end_p=pages+npages;
6510
6511 if (memcmp(data, tc_log_magic, sizeof(tc_log_magic)))
6512 {
6513 sql_print_error("Bad magic header in tc log");
6514 goto err1;
6515 }
6516
6517 /*
6518 the first byte after magic signature is set to current
6519 number of storage engines on startup
6520 */
6521 if (data[sizeof(tc_log_magic)] != total_ha_2pc)
6522 {
6523 sql_print_error("Recovery failed! You must enable "
6524 "exactly %d storage engines that support "
6525 "two-phase commit protocol",
6526 data[sizeof(tc_log_magic)]);
6527 goto err1;
6528 }
6529
6530 if (my_hash_init(&xids, &my_charset_bin, tc_log_page_size/3, 0,
6531 sizeof(my_xid), 0, 0, MYF(0)))
6532 goto err1;
6533
6534 for ( ; p < end_p ; p++)
6535 {
6536 for (my_xid *x=p->start; x < p->end; x++)
6537 if (*x && my_hash_insert(&xids, (uchar *)x))
6538 goto err2; // OOM
6539 }
6540
6541 if (ha_recover(&xids))
6542 goto err2;
6543
6544 my_hash_free(&xids);
6545 bzero(data, (size_t)file_length);
6546 return 0;
6547
6548 err2:
6549 my_hash_free(&xids);
6550 err1:
6551 sql_print_error("Crash recovery failed. Either correct the problem "
6552 "(if it's, for example, out of memory error) and restart, "
6553 "or delete tc log and start mysqld with "
6554 "--tc-heuristic-recover={commit|rollback}");
6555 return 1;
6556 }
6557 #endif
6558
6559 TC_LOG *tc_log;
6560 TC_LOG_DUMMY tc_log_dummy;
6561 TC_LOG_MMAP tc_log_mmap;
6562
6563 /**
6564 Perform heuristic recovery, if --tc-heuristic-recover was used.
6565
6566 @note
6567 no matter whether heuristic recovery was successful or not
6568 mysqld must exit. So, return value is the same in both cases.
6569
6570 @retval
6571 0 no heuristic recovery was requested
6572 @retval
6573 1 heuristic recovery was performed
6574 */
6575
using_heuristic_recover()6576 int TC_LOG::using_heuristic_recover()
6577 {
6578 if (!tc_heuristic_recover)
6579 return 0;
6580
6581 sql_print_information("Heuristic crash recovery mode");
6582 if (ha_recover(0))
6583 sql_print_error("Heuristic crash recovery failed");
6584 sql_print_information("Please restart mysqld without --tc-heuristic-recover");
6585 return 1;
6586 }
6587
6588 /****** transaction coordinator log for 2pc - binlog() based solution ******/
6589 #define TC_LOG_BINLOG MYSQL_BIN_LOG
6590
6591 /**
6592 @todo
6593 keep in-memory list of prepared transactions
6594 (add to list in log(), remove on unlog())
6595 and copy it to the new binlog if rotated
6596 but let's check the behaviour of tc_log_page_waits first!
6597 */
6598
open(const char * opt_name)6599 int TC_LOG_BINLOG::open(const char *opt_name)
6600 {
6601 LOG_INFO log_info;
6602 int error= 1;
6603
6604 DBUG_ASSERT(total_ha_2pc > 1);
6605 DBUG_ASSERT(opt_name && opt_name[0]);
6606
6607 mysql_mutex_init(key_BINLOG_LOCK_prep_xids,
6608 &LOCK_prep_xids, MY_MUTEX_INIT_FAST);
6609 mysql_cond_init(key_BINLOG_COND_prep_xids, &COND_prep_xids, 0);
6610
6611 if (!my_b_inited(&index_file))
6612 {
6613 /* There was a failure to open the index file, can't open the binlog */
6614 cleanup();
6615 return 1;
6616 }
6617
6618 if (using_heuristic_recover())
6619 {
6620 /* generate a new binlog to mask a corrupted one */
6621 open(opt_name, LOG_BIN, 0, WRITE_CACHE, 0, max_binlog_size, 0, TRUE);
6622 cleanup();
6623 return 1;
6624 }
6625
6626 if ((error= find_log_pos(&log_info, NullS, 1)))
6627 {
6628 if (error != LOG_INFO_EOF)
6629 sql_print_error("find_log_pos() failed (error: %d)", error);
6630 else
6631 error= 0;
6632 goto err;
6633 }
6634
6635 {
6636 const char *errmsg;
6637 IO_CACHE log;
6638 File file;
6639 Log_event *ev=0;
6640 Format_description_log_event fdle(BINLOG_VERSION);
6641 char log_name[FN_REFLEN];
6642
6643 if (! fdle.is_valid())
6644 goto err;
6645
6646 do
6647 {
6648 strmake(log_name, log_info.log_file_name, sizeof(log_name)-1);
6649 } while (!(error= find_next_log(&log_info, 1)));
6650
6651 if (error != LOG_INFO_EOF)
6652 {
6653 sql_print_error("find_log_pos() failed (error: %d)", error);
6654 goto err;
6655 }
6656
6657 if ((file= open_binlog(&log, log_name, &errmsg)) < 0)
6658 {
6659 sql_print_error("%s", errmsg);
6660 goto err;
6661 }
6662
6663 if ((ev= Log_event::read_log_event(&log, 0, &fdle)) &&
6664 ev->get_type_code() == FORMAT_DESCRIPTION_EVENT &&
6665 ev->flags & LOG_EVENT_BINLOG_IN_USE_F)
6666 {
6667 sql_print_information("Recovering after a crash using %s", opt_name);
6668 error= recover(&log, (Format_description_log_event *)ev);
6669 }
6670 else
6671 error=0;
6672
6673 delete ev;
6674 end_io_cache(&log);
6675 mysql_file_close(file, MYF(MY_WME));
6676
6677 if (error)
6678 goto err;
6679 }
6680
6681 err:
6682 return error;
6683 }
6684
6685 /** This is called on shutdown, after ha_panic. */
close()6686 void TC_LOG_BINLOG::close()
6687 {
6688 DBUG_ASSERT(prepared_xids==0);
6689 mysql_mutex_destroy(&LOCK_prep_xids);
6690 mysql_cond_destroy(&COND_prep_xids);
6691 }
6692
6693 /**
6694 @todo
6695 group commit
6696
6697 @retval
6698 0 error
6699 @retval
6700 1 success
6701 */
log_xid(THD * thd,my_xid xid)6702 int TC_LOG_BINLOG::log_xid(THD *thd, my_xid xid)
6703 {
6704 DBUG_ENTER("TC_LOG_BINLOG::log");
6705 binlog_cache_mngr *cache_mngr=
6706 (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
6707 /*
6708 We always commit the entire transaction when writing an XID. Also
6709 note that the return value is inverted.
6710 */
6711 DBUG_RETURN(!binlog_commit_flush_stmt_cache(thd, cache_mngr) &&
6712 !binlog_commit_flush_trx_cache(thd, cache_mngr, xid));
6713 }
6714
unlog(ulong cookie,my_xid xid)6715 int TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid)
6716 {
6717 DBUG_ENTER("TC_LOG_BINLOG::unlog");
6718 mysql_mutex_lock(&LOCK_prep_xids);
6719 // prepared_xids can be 0 if the transaction had ignorable errors.
6720 DBUG_ASSERT(prepared_xids >= 0);
6721 if (prepared_xids > 0)
6722 prepared_xids--;
6723 if (prepared_xids == 0) {
6724 DBUG_PRINT("info", ("prepared_xids=%lu", prepared_xids));
6725 mysql_cond_signal(&COND_prep_xids);
6726 }
6727 mysql_mutex_unlock(&LOCK_prep_xids);
6728 DBUG_RETURN(rotate_and_purge(0)); // as ::write() did not rotate
6729 }
6730
recover(IO_CACHE * log,Format_description_log_event * fdle)6731 int TC_LOG_BINLOG::recover(IO_CACHE *log, Format_description_log_event *fdle)
6732 {
6733 Log_event *ev;
6734 HASH xids;
6735 MEM_ROOT mem_root;
6736
6737 if (! fdle->is_valid() ||
6738 my_hash_init(&xids, &my_charset_bin, TC_LOG_PAGE_SIZE/3, 0,
6739 sizeof(my_xid), 0, 0, MYF(0)))
6740 goto err1;
6741
6742 init_alloc_root(&mem_root, TC_LOG_PAGE_SIZE, TC_LOG_PAGE_SIZE);
6743
6744 fdle->flags&= ~LOG_EVENT_BINLOG_IN_USE_F; // abort on the first error
6745
6746 while ((ev= Log_event::read_log_event(log,0,fdle)) && ev->is_valid())
6747 {
6748 if (ev->get_type_code() == XID_EVENT)
6749 {
6750 Xid_log_event *xev=(Xid_log_event *)ev;
6751 uchar *x= (uchar *) memdup_root(&mem_root, (uchar*) &xev->xid,
6752 sizeof(xev->xid));
6753 if (!x || my_hash_insert(&xids, x))
6754 goto err2;
6755 }
6756 delete ev;
6757 }
6758
6759 if (ha_recover(&xids))
6760 goto err2;
6761
6762 free_root(&mem_root, MYF(0));
6763 my_hash_free(&xids);
6764 return 0;
6765
6766 err2:
6767 free_root(&mem_root, MYF(0));
6768 my_hash_free(&xids);
6769 err1:
6770 sql_print_error("Crash recovery failed. Either correct the problem "
6771 "(if it's, for example, out of memory error) and restart, "
6772 "or delete (or rename) binary log and start mysqld with "
6773 "--tc-heuristic-recover={commit|rollback}");
6774 return 1;
6775 }
6776
6777
6778 #ifdef INNODB_COMPATIBILITY_HOOKS
6779 /**
6780 Get the file name of the MySQL binlog.
6781 @return the name of the binlog file
6782 */
6783 extern "C"
mysql_bin_log_file_name(void)6784 const char* mysql_bin_log_file_name(void)
6785 {
6786 return mysql_bin_log.get_log_fname();
6787 }
6788 /**
6789 Get the current position of the MySQL binlog.
6790 @return byte offset from the beginning of the binlog
6791 */
6792 extern "C"
mysql_bin_log_file_pos(void)6793 ulonglong mysql_bin_log_file_pos(void)
6794 {
6795 return (ulonglong) mysql_bin_log.get_log_file()->pos_in_file;
6796 }
6797 #endif /* INNODB_COMPATIBILITY_HOOKS */
6798
6799
6800 struct st_mysql_storage_engine binlog_storage_engine=
6801 { MYSQL_HANDLERTON_INTERFACE_VERSION };
6802
mysql_declare_plugin(binlog)6803 mysql_declare_plugin(binlog)
6804 {
6805 MYSQL_STORAGE_ENGINE_PLUGIN,
6806 &binlog_storage_engine,
6807 "binlog",
6808 "MySQL AB",
6809 "This is a pseudo storage engine to represent the binlog in a transaction",
6810 PLUGIN_LICENSE_GPL,
6811 binlog_init, /* Plugin Init */
6812 NULL, /* Plugin Deinit */
6813 0x0100 /* 1.0 */,
6814 NULL, /* status variables */
6815 NULL, /* system variables */
6816 NULL, /* config options */
6817 0, /* flags */
6818 }
6819 mysql_declare_plugin_end;
6820