1
/* Copyright (c) 2000, 2011, Oracle and/or its affiliates.
2
Copyright (c) 2009, 2013, Monty Program Ab
4
This program is free software; you can redistribute it and/or modify
5
it under the terms of the GNU General Public License as published by
6
the Free Software Foundation; version 2 of the License.
8
This program is distributed in the hope that it will be useful,
9
but WITHOUT ANY WARRANTY; without even the implied warranty of
10
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
11
GNU General Public License for more details.
13
You should have received a copy of the GNU General Public License
14
along with this program; if not, write to the Free Software
15
Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA */
25
Abort logging when we get an error in reading or writing log files
28
#include "my_global.h" /* NO_EMBEDDED_ACCESS_CHECKS */
31
#include "sql_base.h" // open_log_table
33
#include "sql_delete.h" // mysql_truncate
34
#include "sql_parse.h" // command_name
35
#include "sql_time.h" // calc_time_from_sec, my_time_compare
36
#include "tztime.h" // my_tz_OFFSET0, struct Time_zone
37
#include "sql_acl.h" // SUPER_ACL
38
#include "log_event.h" // Query_log_event
39
#include "rpl_filter.h"
41
#include "sql_audit.h"
46
#include <m_ctype.h> // For test_if_number
52
#include "sql_plugin.h"
53
#include "rpl_handler.h"
54
#include "debug_sync.h"
57
/* max size of the log message */
58
#define MAX_LOG_BUFFER_SIZE 1024
59
#define MAX_TIME_SIZE 32
60
#define MY_OFF_T_UNDEF (~(my_off_t)0UL)
62
#define FLAGSTR(V,F) ((V)&(F)?#F" ":"")
66
MYSQL_BIN_LOG mysql_bin_log(&sync_binlog_period);
68
static bool test_if_number(const char *str,
69
ulong *res, bool allow_wildcards);
70
static int binlog_init(void *p);
71
static int binlog_close_connection(handlerton *hton, THD *thd);
72
static int binlog_savepoint_set(handlerton *hton, THD *thd, void *sv);
73
static int binlog_savepoint_rollback(handlerton *hton, THD *thd, void *sv);
74
static int binlog_commit(handlerton *hton, THD *thd, bool all);
75
static int binlog_rollback(handlerton *hton, THD *thd, bool all);
76
static int binlog_prepare(handlerton *hton, THD *thd, bool all);
77
static int binlog_start_consistent_snapshot(handlerton *hton, THD *thd);
79
static LEX_STRING const write_error_msg=
80
{ C_STRING_WITH_LEN("error writing to the binary log") };
82
static my_bool opt_optimize_thread_scheduling= TRUE;
83
ulong binlog_checksum_options;
85
ulong opt_binlog_dbug_fsync_sleep= 0;
88
mysql_mutex_t LOCK_prepare_ordered;
89
mysql_mutex_t LOCK_commit_ordered;
91
static ulonglong binlog_status_var_num_commits;
92
static ulonglong binlog_status_var_num_group_commits;
93
static char binlog_snapshot_file[FN_REFLEN];
94
static ulonglong binlog_snapshot_position;
96
static SHOW_VAR binlog_status_vars_detail[]=
99
(char *)&binlog_status_var_num_commits, SHOW_LONGLONG},
101
(char *)&binlog_status_var_num_group_commits, SHOW_LONGLONG},
103
(char *)&binlog_snapshot_file, SHOW_CHAR},
104
{"snapshot_position",
105
(char *)&binlog_snapshot_position, SHOW_LONGLONG},
106
{NullS, NullS, SHOW_LONG}
111
purge logs, master and slave sides both, related error code
113
Called from @c purge_error_message(), @c MYSQL_BIN_LOG::reset_logs()
115
@param res an internal to purging routines error code
117
@return the user level error code ER_*
119
uint purge_log_get_error_code(int res)
125
case LOG_INFO_EOF: errcode= ER_UNKNOWN_TARGET_BINLOG; break;
126
case LOG_INFO_IO: errcode= ER_IO_ERR_LOG_INDEX_READ; break;
127
case LOG_INFO_INVALID:errcode= ER_BINLOG_PURGE_PROHIBITED; break;
128
case LOG_INFO_SEEK: errcode= ER_FSEEK_FAIL; break;
129
case LOG_INFO_MEM: errcode= ER_OUT_OF_RESOURCES; break;
130
case LOG_INFO_FATAL: errcode= ER_BINLOG_PURGE_FATAL_ERR; break;
131
case LOG_INFO_IN_USE: errcode= ER_LOG_IN_USE; break;
132
case LOG_INFO_EMFILE: errcode= ER_BINLOG_PURGE_EMFILE; break;
133
default: errcode= ER_LOG_PURGE_UNKNOWN_ERR; break;
140
Silence all errors and warnings reported when performing a write
142
Errors and warnings are not reported to the client or SQL exception
143
handlers, so that the presence of logging does not interfere and affect
144
the logic of an application.
146
class Silence_log_table_errors : public Internal_error_handler
148
char m_message[MYSQL_ERRMSG_SIZE];
150
Silence_log_table_errors()
155
virtual ~Silence_log_table_errors() {}
157
virtual bool handle_condition(THD *thd,
159
const char* sql_state,
160
MYSQL_ERROR::enum_warning_level level,
162
MYSQL_ERROR ** cond_hdl);
163
const char *message() const { return m_message; }
167
Silence_log_table_errors::handle_condition(THD *,
170
MYSQL_ERROR::enum_warning_level,
172
MYSQL_ERROR ** cond_hdl)
175
strmake_buf(m_message, msg);
179
sql_print_message_func sql_print_message_handlers[3] =
181
sql_print_information,
188
Create the name of the log file
190
@param[OUT] out a pointer to a new allocated name will go there
191
@param[IN] log_ext The extension for the file (e.g .log)
192
@param[IN] once whether to use malloc_once or a normal malloc.
194
void make_default_log_name(char **out, const char* log_ext, bool once)
196
char buff[FN_REFLEN+10];
197
fn_format(buff, opt_log_basename, "", log_ext, MYF(MY_REPLACE_EXT));
199
*out= my_once_strdup(buff, MYF(MY_WME));
203
*out= my_strdup(buff, MYF(MY_WME));
209
Helper classes to store non-transactional and transactional data
210
before copying it to the binary log.
212
class binlog_cache_data
215
binlog_cache_data(): m_pending(0), before_stmt_pos(MY_OFF_T_UNDEF),
216
incident(FALSE), changes_to_non_trans_temp_table_flag(FALSE),
217
saved_max_binlog_cache_size(0), ptr_binlog_cache_use(0),
218
ptr_binlog_cache_disk_use(0)
223
DBUG_ASSERT(empty());
224
close_cached_file(&cache_log);
229
return pending() == NULL && my_b_tell(&cache_log) == 0;
232
Rows_log_event *pending() const
237
void set_pending(Rows_log_event *const pending)
242
void set_incident(void)
247
bool has_incident(void)
252
void set_changes_to_non_trans_temp_table()
254
changes_to_non_trans_temp_table_flag= TRUE;
257
bool changes_to_non_trans_temp_table()
259
return (changes_to_non_trans_temp_table_flag);
264
compute_statistics();
266
changes_to_non_trans_temp_table_flag= FALSE;
268
before_stmt_pos= MY_OFF_T_UNDEF;
270
The truncate function calls reinit_io_cache that calls my_b_flush_io_cache
271
which may increase disk_writes. This breaks the disk_writes use by the
272
binary log which aims to compute the ratio between in-memory cache usage
273
and disk cache usage. To avoid this undesirable behavior, we reset the
274
variable after truncating the cache.
276
cache_log.disk_writes= 0;
277
DBUG_ASSERT(empty());
280
my_off_t get_byte_position() const
282
return my_b_tell(&cache_log);
285
my_off_t get_prev_position()
287
return(before_stmt_pos);
290
void set_prev_position(my_off_t pos)
292
before_stmt_pos= pos;
295
void restore_prev_position()
297
truncate(before_stmt_pos);
300
void restore_savepoint(my_off_t pos)
303
if (pos < before_stmt_pos)
304
before_stmt_pos= MY_OFF_T_UNDEF;
307
void set_binlog_cache_info(my_off_t param_max_binlog_cache_size,
308
ulong *param_ptr_binlog_cache_use,
309
ulong *param_ptr_binlog_cache_disk_use)
312
The assertions guarantee that the set_binlog_cache_info is
313
called just once and information passed as parameters are
316
This is done while calling the constructor binlog_cache_mngr.
317
We cannot set informaton in the constructor binlog_cache_data
318
because the space for binlog_cache_mngr is allocated through
321
In the future, we can refactor this and change it to avoid
324
DBUG_ASSERT(saved_max_binlog_cache_size == 0 &&
325
param_max_binlog_cache_size != 0 &&
326
ptr_binlog_cache_use == 0 &&
327
param_ptr_binlog_cache_use != 0 &&
328
ptr_binlog_cache_disk_use == 0 &&
329
param_ptr_binlog_cache_disk_use != 0);
331
saved_max_binlog_cache_size= param_max_binlog_cache_size;
332
ptr_binlog_cache_use= param_ptr_binlog_cache_use;
333
ptr_binlog_cache_disk_use= param_ptr_binlog_cache_disk_use;
334
cache_log.end_of_file= saved_max_binlog_cache_size;
338
Cache to store data before copying it to the binary log.
344
Pending binrows event. This event is the event where the rows are currently
347
Rows_log_event *m_pending;
350
Binlog position before the start of the current statement.
352
my_off_t before_stmt_pos;
355
This indicates that some events did not get into the cache and most likely
361
This flag indicates if the cache has changes to temporary tables.
362
@TODO This a temporary fix and should be removed after BUG#54562.
364
bool changes_to_non_trans_temp_table_flag;
367
This function computes binlog cache and disk usage.
369
void compute_statistics()
373
statistic_increment(*ptr_binlog_cache_use, &LOCK_status);
374
if (cache_log.disk_writes != 0)
375
statistic_increment(*ptr_binlog_cache_disk_use, &LOCK_status);
380
Stores the values of maximum size of the cache allowed when this cache
381
is configured. This corresponds to either
382
. max_binlog_cache_size or max_binlog_stmt_cache_size.
384
my_off_t saved_max_binlog_cache_size;
387
Stores a pointer to the status variable that keeps track of the in-memory
388
cache usage. This corresponds to either
389
. binlog_cache_use or binlog_stmt_cache_use.
391
ulong *ptr_binlog_cache_use;
394
Stores a pointer to the status variable that keeps track of the disk
395
cache usage. This corresponds to either
396
. binlog_cache_disk_use or binlog_stmt_cache_disk_use.
398
ulong *ptr_binlog_cache_disk_use;
401
It truncates the cache to a certain position. This includes deleting the
404
void truncate(my_off_t pos)
406
DBUG_PRINT("info", ("truncating to position %lu", (ulong) pos));
412
reinit_io_cache(&cache_log, WRITE_CACHE, pos, 0, 0);
413
cache_log.end_of_file= saved_max_binlog_cache_size;
416
binlog_cache_data& operator=(const binlog_cache_data& info);
417
binlog_cache_data(const binlog_cache_data& info);
420
class binlog_cache_mngr {
422
binlog_cache_mngr(my_off_t param_max_binlog_stmt_cache_size,
423
my_off_t param_max_binlog_cache_size,
424
ulong *param_ptr_binlog_stmt_cache_use,
425
ulong *param_ptr_binlog_stmt_cache_disk_use,
426
ulong *param_ptr_binlog_cache_use,
427
ulong *param_ptr_binlog_cache_disk_use)
428
: last_commit_pos_offset(0), using_xa(FALSE), xa_xid(0)
430
stmt_cache.set_binlog_cache_info(param_max_binlog_stmt_cache_size,
431
param_ptr_binlog_stmt_cache_use,
432
param_ptr_binlog_stmt_cache_disk_use);
433
trx_cache.set_binlog_cache_info(param_max_binlog_cache_size,
434
param_ptr_binlog_cache_use,
435
param_ptr_binlog_cache_disk_use);
436
last_commit_pos_file[0]= 0;
439
void reset(bool do_stmt, bool do_trx)
447
last_commit_pos_file[0]= 0;
448
last_commit_pos_offset= 0;
452
binlog_cache_data* get_binlog_cache_data(bool is_transactional)
454
return (is_transactional ? &trx_cache : &stmt_cache);
457
IO_CACHE* get_binlog_cache_log(bool is_transactional)
459
return (is_transactional ? &trx_cache.cache_log : &stmt_cache.cache_log);
462
binlog_cache_data stmt_cache;
464
binlog_cache_data trx_cache;
467
Binlog position for current transaction.
468
For START TRANSACTION WITH CONSISTENT SNAPSHOT, this is the binlog
469
position corresponding to the snapshot taken. During (and after) commit,
470
this is set to the binlog position corresponding to just after the
471
commit (so storage engines can store it in their transaction log).
473
char last_commit_pos_file[FN_REFLEN];
474
my_off_t last_commit_pos_offset;
477
Flag set true if this transaction is committed with log_xid() as part of
485
binlog_cache_mngr& operator=(const binlog_cache_mngr& info);
486
binlog_cache_mngr(const binlog_cache_mngr& info);
489
handlerton *binlog_hton;
491
bool LOGGER::is_log_table_enabled(uint log_table_type)
493
switch (log_table_type) {
495
return (table_log_handler != NULL) && opt_slow_log;
496
case QUERY_LOG_GENERAL:
497
return (table_log_handler != NULL) && opt_log ;
500
return FALSE; /* make compiler happy */
505
/* Check if a given table is opened log table */
506
int check_if_log_table(size_t db_len, const char *db, size_t table_name_len,
507
const char *table_name, bool check_if_opened)
510
!(lower_case_table_names ?
511
my_strcasecmp(system_charset_info, db, "mysql") :
512
strcmp(db, "mysql")))
514
if (table_name_len == 11 && !(lower_case_table_names ?
515
my_strcasecmp(system_charset_info,
516
table_name, "general_log") :
517
strcmp(table_name, "general_log")))
519
if (!check_if_opened || logger.is_log_table_enabled(QUERY_LOG_GENERAL))
520
return QUERY_LOG_GENERAL;
524
if (table_name_len == 8 && !(lower_case_table_names ?
525
my_strcasecmp(system_charset_info, table_name, "slow_log") :
526
strcmp(table_name, "slow_log")))
528
if (!check_if_opened || logger.is_log_table_enabled(QUERY_LOG_SLOW))
529
return QUERY_LOG_SLOW;
537
Log_to_csv_event_handler::Log_to_csv_event_handler()
542
Log_to_csv_event_handler::~Log_to_csv_event_handler()
547
void Log_to_csv_event_handler::cleanup()
549
logger.is_log_tables_initialized= FALSE;
552
/* log event handlers */
555
Log command to the general log table
557
Log given command to the general log table.
559
@param event_time command start timestamp
560
@param user_host the pointer to the string with user@host info
561
@param user_host_len length of the user_host string. this is computed
562
once and passed to all general log event handlers
563
@param thread_id Id of the thread, issued a query
564
@param command_type the type of the command being logged
565
@param command_type_len the length of the string above
566
@param sql_text the very text of the query being executed
567
@param sql_text_len the length of sql_text string
570
@return This function attempts to never call my_error(). This is
571
necessary, because general logging happens already after a statement
572
status has been sent to the client, so the client can not see the
573
error anyway. Besides, the error is not related to the statement
574
being executed and is internal, and thus should be handled
575
internally (@todo: how?).
576
If a write to the table has failed, the function attempts to
577
write to a short error message to the file. The failure is also
578
indicated in the return value.
581
@retval TRUE error occured
584
bool Log_to_csv_event_handler::
585
log_general(THD *thd, my_hrtime_t event_time, const char *user_host,
586
uint user_host_len, int thread_id,
587
const char *command_type, uint command_type_len,
588
const char *sql_text, uint sql_text_len,
589
CHARSET_INFO *client_cs)
591
TABLE_LIST table_list;
594
bool need_close= FALSE;
595
bool need_pop= FALSE;
596
bool need_rnd_end= FALSE;
598
Silence_log_table_errors error_handler;
599
Open_tables_backup open_tables_backup;
600
ulonglong save_thd_options;
601
bool save_time_zone_used;
602
DBUG_ENTER("log_general");
605
CSV uses TIME_to_timestamp() internally if table needs to be repaired
606
which will set thd->time_zone_used
608
save_time_zone_used= thd->time_zone_used;
610
save_thd_options= thd->variables.option_bits;
611
thd->variables.option_bits&= ~OPTION_BIN_LOG;
613
table_list.init_one_table(MYSQL_SCHEMA_NAME.str, MYSQL_SCHEMA_NAME.length,
614
GENERAL_LOG_NAME.str, GENERAL_LOG_NAME.length,
615
GENERAL_LOG_NAME.str,
616
TL_WRITE_CONCURRENT_INSERT);
619
1) open_log_table generates an error of the
620
table can not be opened or is corrupted.
621
2) "INSERT INTO general_log" can generate warning sometimes.
623
Suppress these warnings and errors, they can't be dealt with
626
QQ: this problem needs to be studied in more detail.
627
Comment this 2 lines and run "cast.test" to see what's happening.
629
thd->push_internal_handler(& error_handler);
632
if (!(table= open_log_table(thd, &table_list, &open_tables_backup)))
637
if (table->file->extra(HA_EXTRA_MARK_AS_LOG_TABLE) ||
638
table->file->ha_rnd_init_with_error(0))
643
/* Honor next number columns if present */
644
table->next_number_field= table->found_next_number_field;
647
NOTE: we do not call restore_record() here, as all fields are
648
filled by the Logger (=> no need to load default ones).
652
We do not set a value for table->field[0], as it will use
653
default value (which is CURRENT_TIMESTAMP).
656
/* check that all columns exist */
657
if (table->s->fields < 6)
660
DBUG_ASSERT(table->field[0]->type() == MYSQL_TYPE_TIMESTAMP);
662
((Field_timestamp*) table->field[0])->store_TIME(
663
hrtime_to_my_time(event_time), hrtime_sec_part(event_time));
666
if (table->field[1]->store(user_host, user_host_len, client_cs) ||
667
table->field[2]->store((longlong) thread_id, TRUE) ||
668
table->field[3]->store((longlong) server_id, TRUE) ||
669
table->field[4]->store(command_type, command_type_len, client_cs))
673
A positive return value in store() means truncation.
674
Still logging a message in the log in this case.
676
table->field[5]->flags|= FIELDFLAG_HEX_ESCAPE;
677
if (table->field[5]->store(sql_text, sql_text_len, client_cs) < 0)
680
/* mark all fields as not null */
681
table->field[1]->set_notnull();
682
table->field[2]->set_notnull();
683
table->field[3]->set_notnull();
684
table->field[4]->set_notnull();
685
table->field[5]->set_notnull();
687
/* Set any extra columns to their default values */
688
for (field_index= 6 ; field_index < table->s->fields ; field_index++)
690
table->field[field_index]->set_default();
693
/* log table entries are not replicated */
694
if (table->file->ha_write_row(table->record[0]))
700
if (result && !thd->killed)
701
sql_print_error("Failed to write to mysql.general_log: %s",
702
error_handler.message());
706
table->file->ha_rnd_end();
707
table->file->ha_release_auto_increment();
710
thd->pop_internal_handler();
712
close_log_table(thd, &open_tables_backup);
714
thd->variables.option_bits= save_thd_options;
715
thd->time_zone_used= save_time_zone_used;
721
Log a query to the slow log table
726
current_time current timestamp
727
user_host the pointer to the string with user@host info
728
user_host_len length of the user_host string. this is computed once
729
and passed to all general log event handlers
730
query_time Amount of time the query took to execute (in microseconds)
731
lock_time Amount of time the query was locked (in microseconds)
732
is_command The flag, which determines, whether the sql_text is a
733
query or an administrator command (these are treated
734
differently by the old logging routines)
735
sql_text the very text of the query or administrator command
737
sql_text_len the length of sql_text string
741
Log a query to the slow log table
748
bool Log_to_csv_event_handler::
749
log_slow(THD *thd, my_hrtime_t current_time,
750
const char *user_host, uint user_host_len,
751
ulonglong query_utime, ulonglong lock_utime, bool is_command,
752
const char *sql_text, uint sql_text_len)
754
TABLE_LIST table_list;
757
bool need_close= FALSE;
758
bool need_rnd_end= FALSE;
759
Silence_log_table_errors error_handler;
760
Open_tables_backup open_tables_backup;
761
CHARSET_INFO *client_cs= thd->variables.character_set_client;
762
bool save_time_zone_used;
763
long query_time= (long) min(query_utime/1000000, TIME_MAX_VALUE_SECONDS);
764
long lock_time= (long) min(lock_utime/1000000, TIME_MAX_VALUE_SECONDS);
765
long query_time_micro= (long) (query_utime % 1000000);
766
long lock_time_micro= (long) (lock_utime % 1000000);
768
DBUG_ENTER("Log_to_csv_event_handler::log_slow");
770
thd->push_internal_handler(& error_handler);
772
CSV uses TIME_to_timestamp() internally if table needs to be repaired
773
which will set thd->time_zone_used
775
save_time_zone_used= thd->time_zone_used;
777
table_list.init_one_table(MYSQL_SCHEMA_NAME.str, MYSQL_SCHEMA_NAME.length,
778
SLOW_LOG_NAME.str, SLOW_LOG_NAME.length,
780
TL_WRITE_CONCURRENT_INSERT);
782
if (!(table= open_log_table(thd, &table_list, &open_tables_backup)))
787
if (table->file->extra(HA_EXTRA_MARK_AS_LOG_TABLE) ||
788
table->file->ha_rnd_init_with_error(0))
793
/* Honor next number columns if present */
794
table->next_number_field= table->found_next_number_field;
796
restore_record(table, s->default_values); // Get empty record
798
/* check that all columns exist */
799
if (table->s->fields < 11)
802
/* store the time and user values */
803
DBUG_ASSERT(table->field[0]->type() == MYSQL_TYPE_TIMESTAMP);
804
((Field_timestamp*) table->field[0])->store_TIME(
805
hrtime_to_my_time(current_time), hrtime_sec_part(current_time));
806
if (table->field[1]->store(user_host, user_host_len, client_cs))
810
A TIME field can not hold the full longlong range; query_time or
811
lock_time may be truncated without warning here, if greater than
817
/* fill in query_time field */
818
calc_time_from_sec(&t, query_time, query_time_micro);
819
if (table->field[2]->store_time(&t))
822
calc_time_from_sec(&t, lock_time, lock_time_micro);
823
if (table->field[3]->store_time(&t))
826
if (table->field[4]->store((longlong) thd->sent_row_count, TRUE))
829
if (table->field[5]->store((longlong) thd->examined_row_count, TRUE))
832
/* fill database field */
835
if (table->field[6]->store(thd->db, thd->db_length, client_cs))
837
table->field[6]->set_notnull();
840
if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt)
843
field[7]->store((longlong)
844
thd->first_successful_insert_id_in_prev_stmt_for_binlog,
847
table->field[7]->set_notnull();
851
Set value if we do an insert on autoincrement column. Note that for
852
some engines (those for which get_auto_increment() does not leave a
853
table lock until the statement ends), this is just the first value and
854
the next ones used may not be contiguous to it.
856
if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0)
859
field[8]->store((longlong)
860
thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum(), TRUE))
862
table->field[8]->set_notnull();
865
if (table->field[9]->store((longlong) server_id, TRUE))
867
table->field[9]->set_notnull();
871
A positive return value in store() means truncation.
872
Still logging a message in the log in this case.
874
if (table->field[10]->store(sql_text, sql_text_len, client_cs) < 0)
877
/* log table entries are not replicated */
878
if (table->file->ha_write_row(table->record[0]))
884
thd->pop_internal_handler();
886
if (result && !thd->killed)
887
sql_print_error("Failed to write to mysql.slow_log: %s",
888
error_handler.message());
892
table->file->ha_rnd_end();
893
table->file->ha_release_auto_increment();
896
close_log_table(thd, &open_tables_backup);
897
thd->time_zone_used= save_time_zone_used;
901
int Log_to_csv_event_handler::
902
activate_log(THD *thd, uint log_table_type)
904
TABLE_LIST table_list;
906
LEX_STRING *UNINIT_VAR(log_name);
908
Open_tables_backup open_tables_backup;
910
DBUG_ENTER("Log_to_csv_event_handler::activate_log");
912
if (log_table_type == QUERY_LOG_GENERAL)
914
log_name= &GENERAL_LOG_NAME;
918
DBUG_ASSERT(log_table_type == QUERY_LOG_SLOW);
920
log_name= &SLOW_LOG_NAME;
922
table_list.init_one_table(MYSQL_SCHEMA_NAME.str, MYSQL_SCHEMA_NAME.length,
923
log_name->str, log_name->length, log_name->str,
924
TL_WRITE_CONCURRENT_INSERT);
926
table= open_log_table(thd, &table_list, &open_tables_backup);
930
close_log_table(thd, &open_tables_backup);
938
bool Log_to_csv_event_handler::
939
log_error(enum loglevel level, const char *format, va_list args)
941
/* No log table is implemented */
946
bool Log_to_file_event_handler::
947
log_error(enum loglevel level, const char *format,
950
return vprint_msg_to_log(level, format, args);
953
void Log_to_file_event_handler::init_pthread_objects()
955
mysql_log.init_pthread_objects();
956
mysql_slow_log.init_pthread_objects();
960
/** Wrapper around MYSQL_LOG::write() for slow log. */
962
bool Log_to_file_event_handler::
963
log_slow(THD *thd, my_hrtime_t current_time,
964
const char *user_host, uint user_host_len,
965
ulonglong query_utime, ulonglong lock_utime, bool is_command,
966
const char *sql_text, uint sql_text_len)
968
Silence_log_table_errors error_handler;
969
thd->push_internal_handler(&error_handler);
970
bool retval= mysql_slow_log.write(thd, hrtime_to_my_time(current_time),
971
user_host, user_host_len,
972
query_utime, lock_utime, is_command,
973
sql_text, sql_text_len);
974
thd->pop_internal_handler();
980
Wrapper around MYSQL_LOG::write() for general log. We need it since we
981
want all log event handlers to have the same signature.
984
bool Log_to_file_event_handler::
985
log_general(THD *thd, my_hrtime_t event_time, const char *user_host,
986
uint user_host_len, int thread_id,
987
const char *command_type, uint command_type_len,
988
const char *sql_text, uint sql_text_len,
989
CHARSET_INFO *client_cs)
991
Silence_log_table_errors error_handler;
992
thd->push_internal_handler(&error_handler);
993
bool retval= mysql_log.write(hrtime_to_time(event_time), user_host,
995
thread_id, command_type, command_type_len,
996
sql_text, sql_text_len);
997
thd->pop_internal_handler();
1002
bool Log_to_file_event_handler::init()
1004
if (!is_initialized)
1007
mysql_slow_log.open_slow_log(opt_slow_logname);
1010
mysql_log.open_query_log(opt_logname);
1012
is_initialized= TRUE;
1019
void Log_to_file_event_handler::cleanup()
1021
mysql_log.cleanup();
1022
mysql_slow_log.cleanup();
1025
void Log_to_file_event_handler::flush()
1027
/* reopen log files */
1029
mysql_log.reopen_file();
1031
mysql_slow_log.reopen_file();
1035
Log error with all enabled log event handlers
1040
level The level of the error significance: NOTE,
1042
format format string for the error message
1043
args list of arguments for the format string
1047
TRUE - error occured
1050
bool LOGGER::error_log_print(enum loglevel level, const char *format,
1054
Log_event_handler **current_handler;
1056
/* currently we don't need locking here as there is no error_log table */
1057
for (current_handler= error_log_handler_list ; *current_handler ;)
1058
error= (*current_handler++)->log_error(level, format, args) || error;
1064
void LOGGER::cleanup_base()
1066
DBUG_ASSERT(inited == 1);
1067
mysql_rwlock_destroy(&LOCK_logger);
1068
if (table_log_handler)
1070
table_log_handler->cleanup();
1071
delete table_log_handler;
1072
table_log_handler= NULL;
1074
if (file_log_handler)
1075
file_log_handler->cleanup();
1079
void LOGGER::cleanup_end()
1081
DBUG_ASSERT(inited == 1);
1082
if (file_log_handler)
1084
delete file_log_handler;
1085
file_log_handler=NULL;
1092
Perform basic log initialization: create file-based log handler and
1095
void LOGGER::init_base()
1097
DBUG_ASSERT(inited == 0);
1101
Here we create file log handler. We don't do it for the table log handler
1102
here as it cannot be created so early. The reason is THD initialization,
1103
which depends on the system variables (parsed later).
1105
if (!file_log_handler)
1106
file_log_handler= new Log_to_file_event_handler;
1108
/* by default we use traditional error log */
1109
init_error_log(LOG_FILE);
1111
file_log_handler->init_pthread_objects();
1112
mysql_rwlock_init(key_rwlock_LOCK_logger, &LOCK_logger);
1116
void LOGGER::init_log_tables()
1118
if (!table_log_handler)
1119
table_log_handler= new Log_to_csv_event_handler;
1121
if (!is_log_tables_initialized &&
1122
!table_log_handler->init() && !file_log_handler->init())
1123
is_log_tables_initialized= TRUE;
1127
bool LOGGER::flush_logs(THD *thd)
1130
Now we lock logger, as nobody should be able to use logging routines while
1131
log tables are closed
1133
logger.lock_exclusive();
1135
/* reopen log files */
1136
file_log_handler->flush();
1138
/* end of log flush */
1145
Close and reopen the slow log (with locks).
1149
bool LOGGER::flush_slow_log()
1152
Now we lock logger, as nobody should be able to use logging routines while
1153
log tables are closed
1155
logger.lock_exclusive();
1157
/* Reopen slow log file */
1159
file_log_handler->get_mysql_slow_log()->reopen_file();
1161
/* End of log flush */
1169
Close and reopen the general log (with locks).
1173
bool LOGGER::flush_general_log()
1176
Now we lock logger, as nobody should be able to use logging routines while
1177
log tables are closed
1179
logger.lock_exclusive();
1181
/* Reopen general log file */
1183
file_log_handler->get_mysql_log()->reopen_file();
1185
/* End of log flush */
1193
Log slow query with all enabled log event handlers
1198
thd THD of the query being logged
1199
query The query being logged
1200
query_length The length of the query string
1201
current_utime Current time in microseconds (from undefined start)
1208
bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length,
1209
ulonglong current_utime)
1213
Log_event_handler **current_handler;
1214
bool is_command= FALSE;
1215
char user_host_buff[MAX_USER_HOST_SIZE + 1];
1216
Security_context *sctx= thd->security_ctx;
1217
uint user_host_len= 0;
1218
ulonglong query_utime, lock_utime;
1220
DBUG_ASSERT(thd->enable_slow_log);
1222
Print the message to the buffer if we have slow log enabled
1225
if (*slow_log_handler_list)
1227
/* do not log slow queries from replication threads */
1228
if (thd->slave_thread && !opt_log_slow_slave_statements)
1238
/* fill in user_host value: the format is "%s[%s] @ %s [%s]" */
1239
user_host_len= (strxnmov(user_host_buff, MAX_USER_HOST_SIZE,
1240
sctx->priv_user ? sctx->priv_user : "", "[",
1241
sctx->user ? sctx->user : (thd->slave_thread ? "SQL_SLAVE" : ""), "] @ ",
1242
sctx->host ? sctx->host : "", " [",
1243
sctx->ip ? sctx->ip : "", "]", NullS) -
1246
DBUG_ASSERT(thd->start_utime);
1247
DBUG_ASSERT(thd->start_time);
1248
query_utime= (current_utime - thd->start_utime);
1249
lock_utime= (thd->utime_after_lock - thd->start_utime);
1250
my_hrtime_t current_time= { hrtime_from_time(thd->start_time) +
1251
thd->start_time_sec_part + query_utime };
1256
query= command_name[thd->command].str;
1257
query_length= command_name[thd->command].length;
1260
for (current_handler= slow_log_handler_list; *current_handler ;)
1261
error= (*current_handler++)->log_slow(thd, current_time,
1262
user_host_buff, user_host_len,
1263
query_utime, lock_utime, is_command,
1264
query, query_length) || error;
1271
bool LOGGER::general_log_write(THD *thd, enum enum_server_command command,
1272
const char *query, uint query_length)
1275
Log_event_handler **current_handler= general_log_handler_list;
1276
char user_host_buff[MAX_USER_HOST_SIZE + 1];
1277
uint user_host_len= 0;
1278
my_hrtime_t current_time;
1282
user_host_len= make_user_name(thd, user_host_buff);
1284
current_time= my_hrtime();
1286
mysql_audit_general_log(thd, hrtime_to_time(current_time),
1287
user_host_buff, user_host_len,
1288
command_name[(uint) command].str,
1289
command_name[(uint) command].length,
1290
query, query_length);
1292
if (opt_log && log_command(thd, command))
1295
while (*current_handler)
1296
error|= (*current_handler++)->
1297
log_general(thd, current_time, user_host_buff,
1298
user_host_len, thd->thread_id,
1299
command_name[(uint) command].str,
1300
command_name[(uint) command].length,
1301
query, query_length,
1302
thd->variables.character_set_client) || error;
1309
bool LOGGER::general_log_print(THD *thd, enum enum_server_command command,
1310
const char *format, va_list args)
1312
uint message_buff_len= 0;
1313
char message_buff[MAX_LOG_BUFFER_SIZE];
1315
/* prepare message */
1317
message_buff_len= my_vsnprintf(message_buff, sizeof(message_buff),
1320
message_buff[0]= '\0';
1322
return general_log_write(thd, command, message_buff, message_buff_len);
1325
void LOGGER::init_error_log(ulonglong error_log_printer)
1327
if (error_log_printer & LOG_NONE)
1329
error_log_handler_list[0]= 0;
1333
switch (error_log_printer) {
1335
error_log_handler_list[0]= file_log_handler;
1336
error_log_handler_list[1]= 0;
1338
/* these two are disabled for now */
1342
case LOG_TABLE|LOG_FILE:
1348
void LOGGER::init_slow_log(ulonglong slow_log_printer)
1350
if (slow_log_printer & LOG_NONE)
1352
slow_log_handler_list[0]= 0;
1356
switch (slow_log_printer) {
1358
slow_log_handler_list[0]= file_log_handler;
1359
slow_log_handler_list[1]= 0;
1362
slow_log_handler_list[0]= table_log_handler;
1363
slow_log_handler_list[1]= 0;
1365
case LOG_TABLE|LOG_FILE:
1366
slow_log_handler_list[0]= file_log_handler;
1367
slow_log_handler_list[1]= table_log_handler;
1368
slow_log_handler_list[2]= 0;
1373
void LOGGER::init_general_log(ulonglong general_log_printer)
1375
if (general_log_printer & LOG_NONE)
1377
general_log_handler_list[0]= 0;
1381
switch (general_log_printer) {
1383
general_log_handler_list[0]= file_log_handler;
1384
general_log_handler_list[1]= 0;
1387
general_log_handler_list[0]= table_log_handler;
1388
general_log_handler_list[1]= 0;
1390
case LOG_TABLE|LOG_FILE:
1391
general_log_handler_list[0]= file_log_handler;
1392
general_log_handler_list[1]= table_log_handler;
1393
general_log_handler_list[2]= 0;
1399
bool LOGGER::activate_log_handler(THD* thd, uint log_type)
1401
MYSQL_QUERY_LOG *file_log;
1405
case QUERY_LOG_SLOW:
1408
file_log= file_log_handler->get_mysql_slow_log();
1410
file_log->open_slow_log(opt_slow_logname);
1411
if (table_log_handler->activate_log(thd, QUERY_LOG_SLOW))
1413
/* Error printed by open table in activate_log() */
1419
init_slow_log(log_output_options);
1424
case QUERY_LOG_GENERAL:
1427
file_log= file_log_handler->get_mysql_log();
1429
file_log->open_query_log(opt_logname);
1430
if (table_log_handler->activate_log(thd, QUERY_LOG_GENERAL))
1432
/* Error printed by open table in activate_log() */
1438
init_general_log(log_output_options);
1451
void LOGGER::deactivate_log_handler(THD *thd, uint log_type)
1453
my_bool *tmp_opt= 0;
1454
MYSQL_LOG *file_log;
1455
LINT_INIT(file_log);
1458
case QUERY_LOG_SLOW:
1459
tmp_opt= &opt_slow_log;
1460
file_log= file_log_handler->get_mysql_slow_log();
1462
case QUERY_LOG_GENERAL:
1464
file_log= file_log_handler->get_mysql_log();
1467
MY_ASSERT_UNREACHABLE();
1480
/* the parameters are unused for the log tables */
1481
bool Log_to_csv_event_handler::init()
1486
int LOGGER::set_handlers(ulonglong error_log_printer,
1487
ulonglong slow_log_printer,
1488
ulonglong general_log_printer)
1490
/* error log table is not supported yet */
1491
DBUG_ASSERT(error_log_printer < LOG_TABLE);
1495
if ((slow_log_printer & LOG_TABLE || general_log_printer & LOG_TABLE) &&
1496
!is_log_tables_initialized)
1498
slow_log_printer= (slow_log_printer & ~LOG_TABLE) | LOG_FILE;
1499
general_log_printer= (general_log_printer & ~LOG_TABLE) | LOG_FILE;
1501
sql_print_error("Failed to initialize log tables. "
1502
"Falling back to the old-fashioned logs");
1505
init_error_log(error_log_printer);
1506
init_slow_log(slow_log_printer);
1507
init_general_log(general_log_printer);
1515
Save position of binary log transaction cache.
1518
binlog_trans_log_savepos()
1520
thd The thread to take the binlog data from
1521
pos Pointer to variable where the position will be stored
1525
Save the current position in the binary log transaction cache into
1526
the variable pointed to by 'pos'
1530
binlog_trans_log_savepos(THD *thd, my_off_t *pos)
1532
DBUG_ENTER("binlog_trans_log_savepos");
1533
DBUG_ASSERT(pos != NULL);
1534
binlog_cache_mngr *const cache_mngr= thd->binlog_setup_trx_data();
1535
DBUG_ASSERT(mysql_bin_log.is_open());
1536
*pos= cache_mngr->trx_cache.get_byte_position();
1537
DBUG_PRINT("return", ("*pos: %lu", (ulong) *pos));
1543
Truncate the binary log transaction cache.
1546
binlog_trans_log_truncate()
1548
thd The thread to take the binlog data from
1549
pos Position to truncate to
1553
Truncate the binary log to the given position. Will not change
1558
binlog_trans_log_truncate(THD *thd, my_off_t pos)
1560
DBUG_ENTER("binlog_trans_log_truncate");
1561
DBUG_PRINT("enter", ("pos: %lu", (ulong) pos));
1563
DBUG_ASSERT(thd_get_ha_data(thd, binlog_hton) != NULL);
1564
/* Only true if binlog_trans_log_savepos() wasn't called before */
1565
DBUG_ASSERT(pos != ~(my_off_t) 0);
1567
binlog_cache_mngr *const cache_mngr=
1568
(binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1569
cache_mngr->trx_cache.restore_savepoint(pos);
1575
this function is mostly a placeholder.
1576
conceptually, binlog initialization (now mostly done in MYSQL_BIN_LOG::open)
1577
should be moved here.
1580
int binlog_init(void *p)
1582
binlog_hton= (handlerton *)p;
1583
binlog_hton->state=opt_bin_log ? SHOW_OPTION_YES : SHOW_OPTION_NO;
1584
binlog_hton->db_type=DB_TYPE_BINLOG;
1585
binlog_hton->savepoint_offset= sizeof(my_off_t);
1586
binlog_hton->close_connection= binlog_close_connection;
1587
binlog_hton->savepoint_set= binlog_savepoint_set;
1588
binlog_hton->savepoint_rollback= binlog_savepoint_rollback;
1589
binlog_hton->commit= binlog_commit;
1590
binlog_hton->rollback= binlog_rollback;
1591
binlog_hton->prepare= binlog_prepare;
1592
binlog_hton->start_consistent_snapshot= binlog_start_consistent_snapshot;
1593
binlog_hton->flags= HTON_NOT_USER_SELECTABLE | HTON_HIDDEN;
1597
static int binlog_close_connection(handlerton *hton, THD *thd)
1599
binlog_cache_mngr *const cache_mngr=
1600
(binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1601
DBUG_ASSERT(cache_mngr->trx_cache.empty() && cache_mngr->stmt_cache.empty());
1602
thd_set_ha_data(thd, binlog_hton, NULL);
1603
cache_mngr->~binlog_cache_mngr();
1604
my_free(cache_mngr);
1609
This function flushes a cache upon commit/rollback.
1612
binlog_flush_cache()
1614
thd The thread whose transaction should be ended
1615
cache_mngr Pointer to the binlog_cache_mngr to use
1616
all True if the entire transaction should be ended, false if
1617
only the statement transaction should be ended.
1618
end_ev The end event to use (COMMIT, ROLLBACK, or commit XID)
1619
using_stmt True if the statement cache should be flushed
1620
using_trx True if the transaction cache should be flushed
1624
End the currently transaction or statement. The transaction can be either
1625
a real transaction or a statement transaction.
1627
This can be to commit a transaction, with a COMMIT query event or an XA
1628
commit XID event. But it can also be to rollback a transaction with a
1629
ROLLBACK query event, used for rolling back transactions which also
1630
contain updates to non-transactional tables. Or it can be a flush of
1634
binlog_flush_cache(THD *thd, binlog_cache_mngr *cache_mngr,
1635
Log_event *end_ev, bool all, bool using_stmt,
1639
DBUG_ENTER("binlog_flush_cache");
1641
if ((using_stmt && !cache_mngr->stmt_cache.empty()) ||
1642
(using_trx && !cache_mngr->trx_cache.empty()))
1644
if (using_stmt && thd->binlog_flush_pending_rows_event(TRUE, FALSE))
1646
if (using_trx && thd->binlog_flush_pending_rows_event(TRUE, TRUE))
1650
Doing a commit or a rollback including non-transactional tables,
1651
i.e., ending a transaction where we might write the transaction
1652
cache to the binary log.
1654
We can always end the statement when ending a transaction since
1655
transactions are not allowed inside stored functions. If they
1656
were, we would have to ensure that we're not ending a statement
1657
inside a stored function.
1659
error= mysql_bin_log.write_transaction_to_binlog(thd, cache_mngr,
1661
using_stmt, using_trx);
1663
cache_mngr->reset(using_stmt, using_trx);
1665
DBUG_ASSERT((!using_stmt || cache_mngr->stmt_cache.empty()) &&
1666
(!using_trx || cache_mngr->trx_cache.empty()));
1672
This function flushes the stmt-cache upon commit.
1674
@param thd The thread whose transaction should be flushed
1675
@param cache_mngr Pointer to the cache manager
1678
nonzero if an error pops up when flushing the cache.
1681
binlog_commit_flush_stmt_cache(THD *thd, bool all,
1682
binlog_cache_mngr *cache_mngr)
1684
Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"),
1685
FALSE, TRUE, TRUE, 0);
1686
return (binlog_flush_cache(thd, cache_mngr, &end_evt, all, TRUE, FALSE));
1690
This function flushes the trx-cache upon commit.
1692
@param thd The thread whose transaction should be flushed
1693
@param cache_mngr Pointer to the cache manager
1696
nonzero if an error pops up when flushing the cache.
1699
binlog_commit_flush_trx_cache(THD *thd, bool all, binlog_cache_mngr *cache_mngr)
1701
Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"),
1702
TRUE, TRUE, TRUE, 0);
1703
return (binlog_flush_cache(thd, cache_mngr, &end_evt, all, FALSE, TRUE));
1707
This function flushes the trx-cache upon rollback.
1709
@param thd The thread whose transaction should be flushed
1710
@param cache_mngr Pointer to the cache manager
1713
nonzero if an error pops up when flushing the cache.
1716
binlog_rollback_flush_trx_cache(THD *thd, bool all,
1717
binlog_cache_mngr *cache_mngr)
1719
Query_log_event end_evt(thd, STRING_WITH_LEN("ROLLBACK"),
1720
TRUE, TRUE, TRUE, 0);
1721
return (binlog_flush_cache(thd, cache_mngr, &end_evt, all, FALSE, TRUE));
1725
This function flushes the trx-cache upon commit.
1727
@param thd The thread whose transaction should be flushed
1728
@param cache_mngr Pointer to the cache manager
1729
@param xid Transaction Id
1732
nonzero if an error pops up when flushing the cache.
1735
binlog_commit_flush_xid_caches(THD *thd, binlog_cache_mngr *cache_mngr,
1736
bool all, my_xid xid)
1740
Xid_log_event end_evt(thd, xid, TRUE);
1741
return (binlog_flush_cache(thd, cache_mngr, &end_evt, all, TRUE, TRUE));
1746
Empty xid occurs in XA COMMIT ... ONE PHASE.
1747
In this case, we do not have a MySQL xid for the transaction, and the
1748
external XA transaction coordinator will have to handle recovery if
1749
needed. So we end the transaction with a plain COMMIT query event.
1751
Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"),
1752
TRUE, TRUE, TRUE, 0);
1753
return (binlog_flush_cache(thd, cache_mngr, &end_evt, all, TRUE, TRUE));
1758
This function truncates the transactional cache upon committing or rolling
1759
back either a transaction or a statement.
1761
@param thd The thread whose transaction should be flushed
1762
@param cache_mngr Pointer to the cache data to be flushed
1763
@param all @c true means truncate the transaction, otherwise the
1764
statement must be truncated.
1767
nonzero if an error pops up when truncating the transactional cache.
1770
binlog_truncate_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr, bool all)
1772
DBUG_ENTER("binlog_truncate_trx_cache");
1775
This function handles transactional changes and as such this flag
1778
bool const is_transactional= TRUE;
1780
DBUG_PRINT("info", ("thd->options={ %s %s}, transaction: %s",
1781
FLAGSTR(thd->variables.option_bits, OPTION_NOT_AUTOCOMMIT),
1782
FLAGSTR(thd->variables.option_bits, OPTION_BEGIN),
1783
all ? "all" : "stmt"));
1785
thd->binlog_remove_pending_rows_event(TRUE, is_transactional);
1787
If rolling back an entire transaction or a single statement not
1788
inside a transaction, we reset the transaction cache.
1790
if (ending_trans(thd, all))
1792
if (cache_mngr->trx_cache.has_incident())
1793
error= mysql_bin_log.write_incident(thd);
1795
thd->clear_binlog_table_maps();
1797
cache_mngr->reset(false, true);
1800
If rolling back a statement in a transaction, we truncate the
1801
transaction cache to remove the statement.
1804
cache_mngr->trx_cache.restore_prev_position();
1806
DBUG_ASSERT(thd->binlog_get_pending_rows_event(is_transactional) == NULL);
1810
static int binlog_prepare(handlerton *hton, THD *thd, bool all)
1814
just pretend we can do 2pc, so that MySQL won't
1816
real work will be done in MYSQL_BIN_LOG::log_and_order()
1822
This function is called once after each statement.
1824
It has the responsibility to flush the caches to the binary log on commits.
1826
@param hton The binlog handlerton.
1827
@param thd The client thread that executes the transaction.
1828
@param all This is @c true if this is a real transaction commit, and
1831
@see handlerton::commit
1833
static int binlog_commit(handlerton *hton, THD *thd, bool all)
1836
DBUG_ENTER("binlog_commit");
1837
binlog_cache_mngr *const cache_mngr=
1838
(binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1841
("all: %d, in_transaction: %s, all.modified_non_trans_table: %s, stmt.modified_non_trans_table: %s",
1843
YESNO(thd->in_multi_stmt_transaction_mode()),
1844
YESNO(thd->transaction.all.modified_non_trans_table),
1845
YESNO(thd->transaction.stmt.modified_non_trans_table)));
1847
if (!cache_mngr->stmt_cache.empty())
1849
error= binlog_commit_flush_stmt_cache(thd, all, cache_mngr);
1852
if (cache_mngr->trx_cache.empty())
1855
we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid()
1857
cache_mngr->reset(false, true);
1862
We commit the transaction if:
1863
- We are not in a transaction and committing a statement, or
1864
- We are in a transaction and a full transaction is committed.
1865
Otherwise, we accumulate the changes.
1867
if (!error && ending_trans(thd, all))
1868
error= binlog_commit_flush_trx_cache(thd, all, cache_mngr);
1871
This is part of the stmt rollback.
1874
cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF);
1880
This function is called when a transaction or a statement is rolled back.
1882
@param hton The binlog handlerton.
1883
@param thd The client thread that executes the transaction.
1884
@param all This is @c true if this is a real transaction rollback, and
1887
@see handlerton::rollback
1889
static int binlog_rollback(handlerton *hton, THD *thd, bool all)
1891
DBUG_ENTER("binlog_rollback");
1893
binlog_cache_mngr *const cache_mngr=
1894
(binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
1896
DBUG_PRINT("debug", ("all: %s, all.modified_non_trans_table: %s, stmt.modified_non_trans_table: %s",
1898
YESNO(thd->transaction.all.modified_non_trans_table),
1899
YESNO(thd->transaction.stmt.modified_non_trans_table)));
1902
If an incident event is set we do not flush the content of the statement
1903
cache because it may be corrupted.
1905
if (cache_mngr->stmt_cache.has_incident())
1907
error= mysql_bin_log.write_incident(thd);
1908
cache_mngr->reset(true, false);
1910
else if (!cache_mngr->stmt_cache.empty())
1912
error= binlog_commit_flush_stmt_cache(thd, all, cache_mngr);
1915
if (cache_mngr->trx_cache.empty())
1918
we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid()
1920
cache_mngr->reset(false, true);
1924
if (mysql_bin_log.check_write_error(thd))
1927
"all == true" means that a "rollback statement" triggered the error and
1928
this function was called. However, this must not happen as a rollback
1929
is written directly to the binary log. And in auto-commit mode, a single
1930
statement that is rolled back has the flag all == false.
1934
We reach this point if the effect of a statement did not properly get into
1935
a cache and need to be rolled back.
1937
error |= binlog_truncate_trx_cache(thd, cache_mngr, all);
1942
We flush the cache wrapped in a beging/rollback if:
1943
. aborting a single or multi-statement transaction and;
1944
. the OPTION_KEEP_LOG is active or;
1945
. the format is STMT and a non-trans table was updated or;
1946
. the format is MIXED and a temporary non-trans table was
1948
. the format is MIXED, non-trans table was updated and
1949
aborting a single statement transaction;
1951
if (ending_trans(thd, all) &&
1952
((thd->variables.option_bits & OPTION_KEEP_LOG) ||
1953
(trans_has_updated_non_trans_table(thd) &&
1954
thd->variables.binlog_format == BINLOG_FORMAT_STMT) ||
1955
(cache_mngr->trx_cache.changes_to_non_trans_temp_table() &&
1956
thd->variables.binlog_format == BINLOG_FORMAT_MIXED) ||
1957
(trans_has_updated_non_trans_table(thd) &&
1958
ending_single_stmt_trans(thd,all) &&
1959
thd->variables.binlog_format == BINLOG_FORMAT_MIXED)))
1960
error= binlog_rollback_flush_trx_cache(thd, all, cache_mngr);
1962
Truncate the cache if:
1963
. aborting a single or multi-statement transaction or;
1964
. the OPTION_KEEP_LOG is not active and;
1965
. the format is not STMT or no non-trans table was
1967
. the format is not MIXED or no temporary non-trans table
1970
else if (ending_trans(thd, all) ||
1971
(!(thd->variables.option_bits & OPTION_KEEP_LOG) &&
1972
(!stmt_has_updated_non_trans_table(thd) ||
1973
thd->variables.binlog_format != BINLOG_FORMAT_STMT) &&
1974
(!cache_mngr->trx_cache.changes_to_non_trans_temp_table() ||
1975
thd->variables.binlog_format != BINLOG_FORMAT_MIXED)))
1976
error= binlog_truncate_trx_cache(thd, cache_mngr, all);
1980
This is part of the stmt rollback.
1983
cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF);
1988
void MYSQL_BIN_LOG::set_write_error(THD *thd, bool is_transactional)
1990
DBUG_ENTER("MYSQL_BIN_LOG::set_write_error");
1994
if (check_write_error(thd))
1997
if (my_errno == EFBIG)
1999
if (is_transactional)
2001
my_message(ER_TRANS_CACHE_FULL, ER(ER_TRANS_CACHE_FULL), MYF(MY_WME));
2005
my_message(ER_STMT_CACHE_FULL, ER(ER_STMT_CACHE_FULL), MYF(MY_WME));
2010
my_error(ER_ERROR_ON_WRITE, MYF(MY_WME), name, errno);
2016
bool MYSQL_BIN_LOG::check_write_error(THD *thd)
2018
DBUG_ENTER("MYSQL_BIN_LOG::check_write_error");
2020
bool checked= FALSE;
2022
if (!thd->is_error())
2023
DBUG_RETURN(checked);
2025
switch (thd->stmt_da->sql_errno())
2027
case ER_TRANS_CACHE_FULL:
2028
case ER_STMT_CACHE_FULL:
2029
case ER_ERROR_ON_WRITE:
2030
case ER_BINLOG_LOGGING_IMPOSSIBLE:
2035
DBUG_RETURN(checked);
2041
How do we handle this (unlikely but legal) case:
2043
[transaction] + [update to non-trans table] + [rollback to savepoint] ?
2045
The problem occurs when a savepoint is before the update to the
2046
non-transactional table. Then when there's a rollback to the savepoint, if we
2047
simply truncate the binlog cache, we lose the part of the binlog cache where
2048
the update is. If we want to not lose it, we need to write the SAVEPOINT
2049
command and the ROLLBACK TO SAVEPOINT command to the binlog cache. The latter
2050
is easy: it's just write at the end of the binlog cache, but the former
2051
should be *inserted* to the place where the user called SAVEPOINT. The
2052
solution is that when the user calls SAVEPOINT, we write it to the binlog
2053
cache (so no need to later insert it). As transactions are never intermixed
2054
in the binary log (i.e. they are serialized), we won't have conflicts with
2055
savepoint names when using mysqlbinlog or in the slave SQL thread.
2056
Then when ROLLBACK TO SAVEPOINT is called, if we updated some
2057
non-transactional table, we don't truncate the binlog cache but instead write
2058
ROLLBACK TO SAVEPOINT to it; otherwise we truncate the binlog cache (which
2059
will chop the SAVEPOINT command from the binlog cache, which is good as in
2060
that case there is no need to have it in the binlog).
2063
static int binlog_savepoint_set(handlerton *hton, THD *thd, void *sv)
2065
DBUG_ENTER("binlog_savepoint_set");
2067
binlog_trans_log_savepos(thd, (my_off_t*) sv);
2068
/* Write it to the binary log */
2071
String log_query(buf, sizeof(buf), &my_charset_bin);
2072
if (log_query.copy(STRING_WITH_LEN("SAVEPOINT "), &my_charset_bin) ||
2073
append_identifier(thd, &log_query,
2074
thd->lex->ident.str, thd->lex->ident.length))
2076
int errcode= query_error_code(thd, thd->killed == NOT_KILLED);
2077
Query_log_event qinfo(thd, log_query.ptr(), log_query.length(),
2078
TRUE, FALSE, TRUE, errcode);
2079
int ret= mysql_bin_log.write(&qinfo);
2083
static int binlog_savepoint_rollback(handlerton *hton, THD *thd, void *sv)
2085
DBUG_ENTER("binlog_savepoint_rollback");
2088
Write ROLLBACK TO SAVEPOINT to the binlog cache if we have updated some
2089
non-transactional table. Otherwise, truncate the binlog cache starting
2090
from the SAVEPOINT command.
2092
if (unlikely(trans_has_updated_non_trans_table(thd) ||
2093
(thd->variables.option_bits & OPTION_KEEP_LOG)))
2096
String log_query(buf, sizeof(buf), &my_charset_bin);
2097
if (log_query.copy(STRING_WITH_LEN("ROLLBACK TO "), &my_charset_bin) ||
2098
append_identifier(thd, &log_query,
2099
thd->lex->ident.str, thd->lex->ident.length))
2101
int errcode= query_error_code(thd, thd->killed == NOT_KILLED);
2102
Query_log_event qinfo(thd, log_query.ptr(), log_query.length(),
2103
TRUE, FALSE, TRUE, errcode);
2104
DBUG_RETURN(mysql_bin_log.write(&qinfo));
2106
binlog_trans_log_truncate(thd, *(my_off_t*)sv);
2111
int check_binlog_magic(IO_CACHE* log, const char** errmsg)
2114
DBUG_ASSERT(my_b_tell(log) == 0);
2116
if (my_b_read(log, magic, sizeof(magic)))
2118
*errmsg = "I/O error reading the header from the binary log";
2119
sql_print_error("%s, errno=%d, io cache code=%d", *errmsg, my_errno,
2123
if (bcmp(magic, BINLOG_MAGIC, sizeof(magic)))
2125
*errmsg = "Binlog has bad magic number; It's not a binary log file that can be used by this version of MySQL";
2132
File open_binlog(IO_CACHE *log, const char *log_file_name, const char **errmsg)
2135
DBUG_ENTER("open_binlog");
2137
if ((file= mysql_file_open(key_file_binlog,
2138
log_file_name, O_RDONLY | O_BINARY | O_SHARE,
2141
sql_print_error("Failed to open log (file '%s', errno %d)",
2142
log_file_name, my_errno);
2143
*errmsg = "Could not open log file";
2146
if (init_io_cache(log, file, IO_SIZE*2, READ_CACHE, 0, 0,
2147
MYF(MY_WME|MY_DONT_CHECK_FILESIZE)))
2149
sql_print_error("Failed to create a cache on log (file '%s')",
2151
*errmsg = "Could not open log file";
2154
if (check_binlog_magic(log,errmsg))
2161
mysql_file_close(file, MYF(0));
2168
static int eventSource = 0;
2170
static void setup_windows_event_source()
2174
TCHAR szPath[MAX_PATH];
2177
if (eventSource) // Ensure that we are only called once
2181
// Create the event source registry key
2182
dwError= RegCreateKey(HKEY_LOCAL_MACHINE,
2183
"SYSTEM\\CurrentControlSet\\Services\\EventLog\\Application\\MySQL",
2186
/* Name of the PE module that contains the message resource */
2187
GetModuleFileName(NULL, szPath, MAX_PATH);
2189
/* Register EventMessageFile */
2190
dwError = RegSetValueEx(hRegKey, "EventMessageFile", 0, REG_EXPAND_SZ,
2191
(PBYTE) szPath, (DWORD) (strlen(szPath) + 1));
2193
/* Register supported event types */
2194
dwTypes= (EVENTLOG_ERROR_TYPE | EVENTLOG_WARNING_TYPE |
2195
EVENTLOG_INFORMATION_TYPE);
2196
dwError= RegSetValueEx(hRegKey, "TypesSupported", 0, REG_DWORD,
2197
(LPBYTE) &dwTypes, sizeof dwTypes);
2199
RegCloseKey(hRegKey);
2206
Find a unique filename for 'filename.#'.
2208
Set '#' to the number next to the maximum found in the most
2209
recent log file extension.
2211
This function will return nonzero if: (i) the generated name
2212
exceeds FN_REFLEN; (ii) if the number of extensions is exhausted;
2213
or (iii) some other error happened while examining the filesystem.
2216
nonzero if not possible to get unique filename.
2219
static int find_uniq_filename(char *name)
2222
char buff[FN_REFLEN], ext_buf[FN_REFLEN];
2223
struct st_my_dir *dir_info;
2224
reg1 struct fileinfo *file_info;
2225
ulong max_found= 0, next= 0, number= 0;
2226
size_t buf_length, length;
2229
DBUG_ENTER("find_uniq_filename");
2231
length= dirname_part(buff, name, &buf_length);
2232
start= name + length;
2236
length= (size_t) (end - start + 1);
2238
if ((DBUG_EVALUATE_IF("error_unique_log_filename", 1,
2239
!(dir_info= my_dir(buff,MYF(MY_DONT_SORT))))))
2240
{ // This shouldn't happen
2241
strmov(end,".1"); // use name+1
2244
file_info= dir_info->dir_entry;
2245
for (i= dir_info->number_off_files ; i-- ; file_info++)
2247
if (memcmp(file_info->name, start, length) == 0 &&
2248
test_if_number(file_info->name+length, &number,0))
2250
set_if_bigger(max_found,(ulong) number);
2253
my_dirend(dir_info);
2255
/* check if reached the maximum possible extension number */
2256
if (max_found == MAX_LOG_UNIQUE_FN_EXT)
2258
sql_print_error("Log filename extension number exhausted: %06lu. \
2259
Please fix this by archiving old logs and \
2260
updating the index files.", max_found);
2265
next= max_found + 1;
2266
if (sprintf(ext_buf, "%06lu", next)<0)
2274
Check if the generated extension size + the file name exceeds the
2275
buffer size used. If one did not check this, then the filename might be
2276
truncated, resulting in error.
2278
if (((strlen(ext_buf) + (end - name)) >= FN_REFLEN))
2280
sql_print_error("Log filename too large: %s%s (%zu). \
2281
Please fix this by archiving old logs and updating the \
2282
index files.", name, ext_buf, (strlen(ext_buf) + (end - name)));
2287
if (sprintf(end, "%06lu", next)<0)
2293
/* print warning if reaching the end of available extensions. */
2294
if ((next > (MAX_LOG_UNIQUE_FN_EXT - LOG_WARN_UNIQUE_FN_EXT_LEFT)))
2295
sql_print_warning("Next log extension: %lu. \
2296
Remaining log filename extensions: %lu. \
2297
Please consider archiving some logs.", next, (MAX_LOG_UNIQUE_FN_EXT - next));
2304
void MYSQL_LOG::init(enum_log_type log_type_arg,
2305
enum cache_type io_cache_type_arg)
2307
DBUG_ENTER("MYSQL_LOG::init");
2308
log_type= log_type_arg;
2309
io_cache_type= io_cache_type_arg;
2310
DBUG_PRINT("info",("log_type: %d", log_type));
2315
bool MYSQL_LOG::init_and_set_log_file_name(const char *log_name,
2316
const char *new_name,
2317
enum_log_type log_type_arg,
2318
enum cache_type io_cache_type_arg)
2320
init(log_type_arg, io_cache_type_arg);
2322
if (new_name && !strmov(log_file_name, new_name))
2324
else if (!new_name && generate_new_name(log_file_name, log_name))
2332
Open a (new) log file.
2337
log_name The name of the log to open
2338
log_type_arg The type of the log. E.g. LOG_NORMAL
2339
new_name The new name for the logfile. This is only needed
2340
when the method is used to open the binlog file.
2341
io_cache_type_arg The type of the IO_CACHE to use for this log file
2344
Open the logfile, init IO_CACHE and write startup messages
2345
(in case of general and slow query logs).
2352
bool MYSQL_LOG::open(
2353
#ifdef HAVE_PSI_INTERFACE
2354
PSI_file_key log_file_key,
2356
const char *log_name, enum_log_type log_type_arg,
2357
const char *new_name, enum cache_type io_cache_type_arg)
2359
char buff[FN_REFLEN];
2361
int open_flags= O_CREAT | O_BINARY;
2362
DBUG_ENTER("MYSQL_LOG::open");
2363
DBUG_PRINT("enter", ("log_type: %d", (int) log_type_arg));
2367
if (!(name= my_strdup(log_name, MYF(MY_WME))))
2369
name= (char *)log_name; // for the error message
2373
if (init_and_set_log_file_name(name, new_name,
2374
log_type_arg, io_cache_type_arg))
2377
if (io_cache_type == SEQ_READ_APPEND)
2378
open_flags |= O_RDWR | O_APPEND;
2380
open_flags |= O_WRONLY | (log_type == LOG_BIN ? 0 : O_APPEND);
2384
#ifdef HAVE_PSI_INTERFACE
2385
/* Keep the key for reopen */
2386
m_log_file_key= log_file_key;
2389
if ((file= mysql_file_open(log_file_key,
2390
log_file_name, open_flags,
2391
MYF(MY_WME | ME_WAITTANG))) < 0 ||
2392
init_io_cache(&log_file, file, IO_SIZE, io_cache_type,
2393
mysql_file_tell(file, MYF(MY_WME)), 0,
2394
MYF(MY_WME | MY_NABP |
2395
((log_type == LOG_BIN) ? MY_WAIT_IF_FULL : 0))))
2398
if (log_type == LOG_NORMAL)
2401
int len=my_snprintf(buff, sizeof(buff), "%s, Version: %s (%s). "
2402
#ifdef EMBEDDED_LIBRARY
2403
"embedded library\n",
2404
my_progname, server_version, MYSQL_COMPILATION_COMMENT
2406
"started with:\nTCP Port: %d, Named Pipe: %s\n",
2407
my_progname, server_version, MYSQL_COMPILATION_COMMENT,
2408
mysqld_port, mysqld_unix_port
2410
"started with:\nTcp port: %d Unix socket: %s\n",
2411
my_progname, server_version, MYSQL_COMPILATION_COMMENT,
2412
mysqld_port, mysqld_unix_port
2415
end= strnmov(buff + len, "Time Id Command Argument\n",
2416
sizeof(buff) - len);
2417
if (my_b_write(&log_file, (uchar*) buff, (uint) (end-buff)) ||
2418
flush_io_cache(&log_file))
2422
log_state= LOG_OPENED;
2426
sql_print_error("Could not use %s for logging (error %d). \
2427
Turning logging off for the whole duration of the MySQL server process. \
2428
To turn it on again: fix the cause, \
2429
shutdown the MySQL server and restart it.", name, errno);
2431
mysql_file_close(file, MYF(0));
2432
end_io_cache(&log_file);
2435
log_state= LOG_CLOSED;
2439
MYSQL_LOG::MYSQL_LOG()
2440
: name(0), write_error(FALSE), inited(FALSE), log_type(LOG_UNKNOWN),
2441
log_state(LOG_CLOSED)
2444
We don't want to initialize LOCK_Log here as such initialization depends on
2445
safe_mutex (when using safe_mutex) which depends on MY_INIT(), which is
2446
called only in main(). Doing initialization here would make it happen
2449
bzero((char*) &log_file, sizeof(log_file));
2452
void MYSQL_LOG::init_pthread_objects()
2454
DBUG_ASSERT(inited == 0);
2456
mysql_mutex_init(key_LOG_LOCK_log, &LOCK_log, MY_MUTEX_INIT_SLOW);
2464
exiting Bitmask. LOG_CLOSE_TO_BE_OPENED is used if we intend to call
2465
open at once after close. LOG_CLOSE_DELAYED_CLOSE is used for
2466
binlog rotation, to delay actual close of the old file until
2467
we have successfully created the new file.
2470
One can do an open on the object at once after doing a close.
2471
The internal structures are not freed until cleanup() is called
2474
void MYSQL_LOG::close(uint exiting)
2475
{ // One can't set log_type here!
2476
DBUG_ENTER("MYSQL_LOG::close");
2477
DBUG_PRINT("enter",("exiting: %d", (int) exiting));
2478
if (log_state == LOG_OPENED)
2480
end_io_cache(&log_file);
2482
if (mysql_file_sync(log_file.file, MYF(MY_WME)) && ! write_error)
2485
sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
2488
if (!(exiting & LOG_CLOSE_DELAYED_CLOSE) &&
2489
mysql_file_close(log_file.file, MYF(MY_WME)) && ! write_error)
2492
sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
2496
log_state= (exiting & LOG_CLOSE_TO_BE_OPENED) ? LOG_TO_BE_OPENED : LOG_CLOSED;
2502
/** This is called only once. */
2504
void MYSQL_LOG::cleanup()
2506
DBUG_ENTER("cleanup");
2510
mysql_mutex_destroy(&LOCK_log);
2517
int MYSQL_LOG::generate_new_name(char *new_name, const char *log_name)
2519
fn_format(new_name, log_name, mysql_data_home, "", 4);
2520
if (log_type == LOG_BIN)
2522
if (!fn_ext(log_name)[0])
2524
if (find_uniq_filename(new_name))
2526
my_printf_error(ER_NO_UNIQUE_LOGFILE, ER(ER_NO_UNIQUE_LOGFILE),
2527
MYF(ME_FATALERROR), log_name);
2528
sql_print_error(ER(ER_NO_UNIQUE_LOGFILE), log_name);
2544
Reopen the log file. The method is used during FLUSH LOGS
2545
and locks LOCK_log mutex
2549
void MYSQL_QUERY_LOG::reopen_file()
2553
DBUG_ENTER("MYSQL_LOG::reopen_file");
2556
DBUG_PRINT("info",("log is closed"));
2560
mysql_mutex_lock(&LOCK_log);
2563
name= 0; // Don't free name
2564
close(LOG_CLOSE_TO_BE_OPENED);
2567
Note that at this point, log_state != LOG_CLOSED (important for is_open()).
2571
#ifdef HAVE_PSI_INTERFACE
2574
save_name, log_type, 0, io_cache_type);
2577
mysql_mutex_unlock(&LOCK_log);
2584
Write a command to traditional general log file
2589
event_time command start timestamp
2590
user_host the pointer to the string with user@host info
2591
user_host_len length of the user_host string. this is computed once
2592
and passed to all general log event handlers
2593
thread_id Id of the thread, issued a query
2594
command_type the type of the command being logged
2595
command_type_len the length of the string above
2596
sql_text the very text of the query being executed
2597
sql_text_len the length of sql_text string
2601
Log given command to to normal (not rotable) log file
2605
TRUE - error occured
2608
bool MYSQL_QUERY_LOG::write(time_t event_time, const char *user_host,
2609
uint user_host_len, int thread_id,
2610
const char *command_type, uint command_type_len,
2611
const char *sql_text, uint sql_text_len)
2615
char local_time_buff[MAX_TIME_SIZE];
2617
uint time_buff_len= 0;
2619
mysql_mutex_lock(&LOCK_log);
2621
/* Test if someone closed between the is_open test and lock */
2624
/* for testing output of timestamp and thread id */
2625
DBUG_EXECUTE_IF("reset_log_last_time", last_time= 0;);
2627
/* Note that my_b_write() assumes it knows the length for this */
2628
if (event_time != last_time)
2630
last_time= event_time;
2632
localtime_r(&event_time, &start);
2634
time_buff_len= my_snprintf(local_time_buff, MAX_TIME_SIZE,
2635
"%02d%02d%02d %2d:%02d:%02d\t",
2636
start.tm_year % 100, start.tm_mon + 1,
2637
start.tm_mday, start.tm_hour,
2638
start.tm_min, start.tm_sec);
2640
if (my_b_write(&log_file, (uchar*) local_time_buff, time_buff_len))
2644
if (my_b_write(&log_file, (uchar*) "\t\t" ,2) < 0)
2647
/* command_type, thread_id */
2648
length= my_snprintf(buff, 32, "%5ld ", (long) thread_id);
2650
if (my_b_write(&log_file, (uchar*) buff, length))
2653
if (my_b_write(&log_file, (uchar*) command_type, command_type_len))
2656
if (my_b_write(&log_file, (uchar*) "\t", 1))
2660
if (my_b_write(&log_file, (uchar*) sql_text, sql_text_len))
2663
if (my_b_write(&log_file, (uchar*) "\n", 1) ||
2664
flush_io_cache(&log_file))
2668
mysql_mutex_unlock(&LOCK_log);
2675
sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno);
2677
mysql_mutex_unlock(&LOCK_log);
2683
Log a query to the traditional slow log file
2688
thd THD of the query
2689
current_time current timestamp
2690
user_host the pointer to the string with user@host info
2691
user_host_len length of the user_host string. this is computed once
2692
and passed to all general log event handlers
2693
query_utime Amount of time the query took to execute (in microseconds)
2694
lock_utime Amount of time the query was locked (in microseconds)
2695
is_command The flag, which determines, whether the sql_text is a
2696
query or an administrator command.
2697
sql_text the very text of the query or administrator command
2699
sql_text_len the length of sql_text string
2703
Log a query to the slow log file.
2707
TRUE - error occured
2710
bool MYSQL_QUERY_LOG::write(THD *thd, time_t current_time,
2711
const char *user_host,
2712
uint user_host_len, ulonglong query_utime,
2713
ulonglong lock_utime, bool is_command,
2714
const char *sql_text, uint sql_text_len)
2717
DBUG_ENTER("MYSQL_QUERY_LOG::write");
2719
mysql_mutex_lock(&LOCK_log);
2723
mysql_mutex_unlock(&LOCK_log);
2728
{ // Safety agains reopen
2730
char buff[80], *end;
2731
char query_time_buff[22+7], lock_time_buff[22+7];
2735
if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
2737
if (current_time != last_time)
2739
last_time= current_time;
2741
localtime_r(¤t_time, &start);
2743
buff_len= my_snprintf(buff, sizeof buff,
2744
"# Time: %02d%02d%02d %2d:%02d:%02d\n",
2745
start.tm_year % 100, start.tm_mon + 1,
2746
start.tm_mday, start.tm_hour,
2747
start.tm_min, start.tm_sec);
2749
/* Note that my_b_write() assumes it knows the length for this */
2750
if (my_b_write(&log_file, (uchar*) buff, buff_len))
2753
const uchar uh[]= "# User@Host: ";
2754
if (my_b_write(&log_file, uh, sizeof(uh) - 1))
2756
if (my_b_write(&log_file, (uchar*) user_host, user_host_len))
2758
if (my_b_write(&log_file, (uchar*) "\n", 1))
2762
/* For slow query log */
2763
sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0);
2764
sprintf(lock_time_buff, "%.6f", ulonglong2double(lock_utime)/1000000.0);
2765
if (my_b_printf(&log_file,
2766
"# Thread_id: %lu Schema: %s QC_hit: %s\n" \
2767
"# Query_time: %s Lock_time: %s Rows_sent: %lu Rows_examined: %lu\n",
2768
(ulong) thd->thread_id, (thd->db ? thd->db : ""),
2769
((thd->query_plan_flags & QPLAN_QC) ? "Yes" : "No"),
2770
query_time_buff, lock_time_buff,
2771
(ulong) thd->sent_row_count,
2772
(ulong) thd->examined_row_count) == (size_t) -1)
2774
if ((thd->variables.log_slow_verbosity & LOG_SLOW_VERBOSITY_QUERY_PLAN) &&
2775
(thd->query_plan_flags &
2776
(QPLAN_FULL_SCAN | QPLAN_FULL_JOIN | QPLAN_TMP_TABLE |
2777
QPLAN_TMP_DISK | QPLAN_FILESORT | QPLAN_FILESORT_DISK)) &&
2778
my_b_printf(&log_file,
2779
"# Full_scan: %s Full_join: %s "
2780
"Tmp_table: %s Tmp_table_on_disk: %s\n"
2781
"# Filesort: %s Filesort_on_disk: %s Merge_passes: %lu\n",
2782
((thd->query_plan_flags & QPLAN_FULL_SCAN) ? "Yes" : "No"),
2783
((thd->query_plan_flags & QPLAN_FULL_JOIN) ? "Yes" : "No"),
2784
((thd->query_plan_flags & QPLAN_TMP_TABLE) ? "Yes" : "No"),
2785
((thd->query_plan_flags & QPLAN_TMP_DISK) ? "Yes" : "No"),
2786
((thd->query_plan_flags & QPLAN_FILESORT) ? "Yes" : "No"),
2787
((thd->query_plan_flags & QPLAN_FILESORT_DISK) ?
2789
thd->query_plan_fsort_passes) == (size_t) -1)
2791
if (thd->db && strcmp(thd->db, db))
2792
{ // Database changed
2793
if (my_b_printf(&log_file,"use %s;\n",thd->db) == (size_t) -1)
2797
if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt)
2799
end=strmov(end, ",last_insert_id=");
2800
end=longlong10_to_str((longlong)
2801
thd->first_successful_insert_id_in_prev_stmt_for_binlog,
2804
// Save value if we do an insert.
2805
if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0)
2807
if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
2809
end=strmov(end,",insert_id=");
2810
end=longlong10_to_str((longlong)
2811
thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum(),
2817
This info used to show up randomly, depending on whether the query
2818
checked the query start time or not. now we always write current
2819
timestamp to the slow log
2821
end= strmov(end, ",timestamp=");
2822
end= int10_to_str((long) current_time, end, 10);
2828
if (my_b_write(&log_file, (uchar*) "SET ", 4) ||
2829
my_b_write(&log_file, (uchar*) buff + 1, (uint) (end-buff)))
2834
end= strxmov(buff, "# administrator command: ", NullS);
2835
buff_len= (ulong) (end - buff);
2836
DBUG_EXECUTE_IF("simulate_slow_log_write_error",
2837
{DBUG_SET("+d,simulate_file_write_error");});
2838
if(my_b_write(&log_file, (uchar*) buff, buff_len))
2841
if (my_b_write(&log_file, (uchar*) sql_text, sql_text_len) ||
2842
my_b_write(&log_file, (uchar*) ";\n",2) ||
2843
flush_io_cache(&log_file))
2851
sql_print_error(ER(ER_ERROR_ON_WRITE), name, error);
2855
mysql_mutex_unlock(&LOCK_log);
2862
The following should be using fn_format(); We just need to
2863
first change fn_format() to cut the file name if it's too long.
2865
const char *MYSQL_LOG::generate_name(const char *log_name,
2867
bool strip_ext, char *buff)
2869
if (!log_name || !log_name[0])
2871
strmake(buff, pidfile_name, FN_REFLEN - strlen(suffix) - 1);
2872
return (const char *)
2873
fn_format(buff, buff, "", suffix, MYF(MY_REPLACE_EXT|MY_REPLACE_DIR));
2875
// get rid of extension if the log is binary to avoid problems
2878
char *p= fn_ext(log_name);
2879
uint length= (uint) (p - log_name);
2880
strmake(buff, log_name, min(length, FN_REFLEN-1));
2881
return (const char*)buff;
2888
MYSQL_BIN_LOG::MYSQL_BIN_LOG(uint *sync_period)
2889
:bytes_written(0), prepared_xids(0), file_id(1), open_count(1),
2890
need_start_event(TRUE),
2891
group_commit_queue(0), group_commit_queue_busy(FALSE),
2892
num_commits(0), num_group_commits(0),
2893
sync_period_ptr(sync_period), sync_counter(0),
2894
is_relay_log(0), signal_cnt(0),
2895
checksum_alg_reset(BINLOG_CHECKSUM_ALG_UNDEF),
2896
relay_log_checksum_alg(BINLOG_CHECKSUM_ALG_UNDEF),
2897
description_event_for_exec(0), description_event_for_queue(0)
2900
We don't want to initialize locks here as such initialization depends on
2901
safe_mutex (when using safe_mutex) which depends on MY_INIT(), which is
2902
called only in main(). Doing initialization here would make it happen
2905
index_file_name[0] = 0;
2906
bzero((char*) &index_file, sizeof(index_file));
2907
bzero((char*) &purge_index_file, sizeof(purge_index_file));
2910
/* this is called only once */
2912
void MYSQL_BIN_LOG::cleanup()
2914
DBUG_ENTER("cleanup");
2918
close(LOG_CLOSE_INDEX|LOG_CLOSE_STOP_EVENT);
2919
delete description_event_for_queue;
2920
delete description_event_for_exec;
2921
mysql_mutex_destroy(&LOCK_log);
2922
mysql_mutex_destroy(&LOCK_index);
2923
mysql_cond_destroy(&update_cond);
2929
/* Init binlog-specific vars */
2930
void MYSQL_BIN_LOG::init(bool no_auto_events_arg, ulong max_size_arg)
2932
DBUG_ENTER("MYSQL_BIN_LOG::init");
2933
no_auto_events= no_auto_events_arg;
2934
max_size= max_size_arg;
2935
DBUG_PRINT("info",("max_size: %lu", max_size));
2940
void MYSQL_BIN_LOG::init_pthread_objects()
2942
MYSQL_LOG::init_pthread_objects();
2943
mysql_mutex_init(m_key_LOCK_index, &LOCK_index, MY_MUTEX_INIT_SLOW);
2944
mysql_mutex_setflags(&LOCK_index, MYF_NO_DEADLOCK_DETECTION);
2945
mysql_cond_init(m_key_update_cond, &update_cond, 0);
2946
mysql_cond_init(m_key_COND_queue_busy, &COND_queue_busy, 0);
2950
bool MYSQL_BIN_LOG::open_index_file(const char *index_file_name_arg,
2951
const char *log_name, bool need_mutex)
2953
File index_file_nr= -1;
2954
DBUG_ASSERT(!my_b_inited(&index_file));
2957
First open of this class instance
2958
Create an index file that will hold all file names uses for logging.
2959
Add new entries to the end of it.
2961
myf opt= MY_UNPACK_FILENAME;
2962
if (!index_file_name_arg)
2964
index_file_name_arg= log_name; // Use same basename for index file
2965
opt= MY_UNPACK_FILENAME | MY_REPLACE_EXT;
2967
fn_format(index_file_name, index_file_name_arg, mysql_data_home,
2969
if ((index_file_nr= mysql_file_open(m_key_file_log_index,
2971
O_RDWR | O_CREAT | O_BINARY,
2972
MYF(MY_WME))) < 0 ||
2973
mysql_file_sync(index_file_nr, MYF(MY_WME)) ||
2974
init_io_cache(&index_file, index_file_nr,
2975
IO_SIZE, WRITE_CACHE,
2976
mysql_file_seek(index_file_nr, 0L, MY_SEEK_END, MYF(0)),
2977
0, MYF(MY_WME | MY_WAIT_IF_FULL)) ||
2978
DBUG_EVALUATE_IF("fault_injection_openning_index", 1, 0))
2981
TODO: all operations creating/deleting the index file or a log, should
2982
call my_sync_dir() or my_sync_dir_by_file() to be durable.
2983
TODO: file creation should be done with mysql_file_create()
2984
not mysql_file_open().
2986
if (index_file_nr >= 0)
2987
mysql_file_close(index_file_nr, MYF(0));
2991
#ifdef HAVE_REPLICATION
2993
Sync the index by purging any binary log file that is not registered.
2994
In other words, either purge binary log files that were removed from
2995
the index but not purged from the file system due to a crash or purge
2996
any binary log file that was created but not register in the index
3000
if (set_purge_index_file_name(index_file_name_arg) ||
3001
open_purge_index_file(FALSE) ||
3002
purge_index_entry(NULL, NULL, need_mutex) ||
3003
close_purge_index_file() ||
3004
DBUG_EVALUATE_IF("fault_injection_recovering_index", 1, 0))
3006
sql_print_error("MYSQL_BIN_LOG::open_index_file failed to sync the index "
3017
Open a (new) binlog file.
3019
- Open the log file and the index file. Register the new
3021
- When calling this when the file is in use, you must have a locks
3022
on LOCK_log and LOCK_index.
3030
bool MYSQL_BIN_LOG::open(const char *log_name,
3031
enum_log_type log_type_arg,
3032
const char *new_name,
3033
enum cache_type io_cache_type_arg,
3034
bool no_auto_events_arg,
3036
bool null_created_arg,
3041
DBUG_ENTER("MYSQL_BIN_LOG::open");
3042
DBUG_PRINT("enter",("log_type: %d",(int) log_type_arg));
3044
if (init_and_set_log_file_name(log_name, new_name, log_type_arg,
3047
sql_print_error("MSYQL_BIN_LOG::open failed to generate new file name.");
3051
#ifdef HAVE_REPLICATION
3052
if (open_purge_index_file(TRUE) ||
3053
register_create_index_entry(log_file_name) ||
3054
sync_purge_index_file() ||
3055
DBUG_EVALUATE_IF("fault_injection_registering_index", 1, 0))
3058
TODO: although this was introduced to appease valgrind
3059
when injecting emulated faults using fault_injection_registering_index
3060
it may be good to consider what actually happens when
3061
open_purge_index_file succeeds but register or sync fails.
3063
Perhaps we might need the code below in MYSQL_LOG_BIN::cleanup
3064
for "real life" purposes as well?
3066
DBUG_EXECUTE_IF("fault_injection_registering_index", {
3067
if (my_b_inited(&purge_index_file))
3069
end_io_cache(&purge_index_file);
3070
my_close(purge_index_file.file, MYF(0));
3074
sql_print_error("MSYQL_BIN_LOG::open failed to sync the index file.");
3077
DBUG_EXECUTE_IF("crash_create_non_critical_before_update_index", DBUG_SUICIDE(););
3082
/* open the main log file */
3083
if (MYSQL_LOG::open(
3084
#ifdef HAVE_PSI_INTERFACE
3087
log_name, log_type_arg, new_name, io_cache_type_arg))
3089
#ifdef HAVE_REPLICATION
3090
close_purge_index_file();
3092
DBUG_RETURN(1); /* all warnings issued */
3095
init(no_auto_events_arg, max_size_arg);
3099
DBUG_ASSERT(log_type == LOG_BIN);
3102
bool write_file_name_to_index_file=0;
3104
if (!my_b_filelength(&log_file))
3107
The binary log file was empty (probably newly created)
3108
This is the normal case and happens when the user doesn't specify
3109
an extension for the binary log files.
3110
In this case we write a standard header to it.
3112
if (my_b_safe_write(&log_file, BINLOG_MAGIC,
3113
BIN_LOG_HEADER_SIZE))
3115
bytes_written+= BIN_LOG_HEADER_SIZE;
3116
write_file_name_to_index_file= 1;
3119
if (need_start_event && !no_auto_events)
3122
In 4.x we set need_start_event=0 here, but in 5.0 we want a Start event
3123
even if this is not the very first binlog.
3125
Format_description_log_event s(BINLOG_VERSION);
3127
don't set LOG_EVENT_BINLOG_IN_USE_F for SEQ_READ_APPEND io_cache
3128
as we won't be able to reset it later
3130
if (io_cache_type == WRITE_CACHE)
3131
s.flags |= LOG_EVENT_BINLOG_IN_USE_F;
3132
s.checksum_alg= is_relay_log ?
3134
/* inherit master's A descriptor if one has been received */
3135
(relay_log_checksum_alg=
3136
(relay_log_checksum_alg != BINLOG_CHECKSUM_ALG_UNDEF) ?
3137
relay_log_checksum_alg :
3138
/* otherwise use slave's local preference of RL events verification */
3139
(opt_slave_sql_verify_checksum == 0) ?
3140
(uint8) BINLOG_CHECKSUM_ALG_OFF : (uint8) binlog_checksum_options):
3142
(uint8) binlog_checksum_options;
3143
DBUG_ASSERT(s.checksum_alg != BINLOG_CHECKSUM_ALG_UNDEF);
3146
s.dont_set_created= null_created_arg;
3147
if (s.write(&log_file))
3149
bytes_written+= s.data_written;
3151
if (description_event_for_queue &&
3152
description_event_for_queue->binlog_version>=4)
3155
This is a relay log written to by the I/O slave thread.
3156
Write the event so that others can later know the format of this relay
3158
Note that this event is very close to the original event from the
3159
master (it has binlog version of the master, event types of the
3160
master), so this is suitable to parse the next relay log's event. It
3161
has been produced by
3162
Format_description_log_event::Format_description_log_event(char* buf,).
3163
Why don't we want to write the description_event_for_queue if this
3164
event is for format<4 (3.23 or 4.x): this is because in that case, the
3165
description_event_for_queue describes the data received from the
3166
master, but not the data written to the relay log (*conversion*),
3167
which is in format 4 (slave's).
3170
Set 'created' to 0, so that in next relay logs this event does not
3171
trigger cleaning actions on the slave in
3172
Format_description_log_event::apply_event_impl().
3174
description_event_for_queue->created= 0;
3175
/* Don't set log_pos in event header */
3176
description_event_for_queue->set_artificial_event();
3178
if (description_event_for_queue->write(&log_file))
3180
bytes_written+= description_event_for_queue->data_written;
3182
if (flush_io_cache(&log_file) ||
3183
mysql_file_sync(log_file.file, MYF(MY_WME|MY_SYNC_FILESIZE)))
3185
mysql_mutex_lock(&LOCK_commit_ordered);
3186
strmake_buf(last_commit_pos_file, log_file_name);
3187
last_commit_pos_offset= my_b_tell(&log_file);
3188
mysql_mutex_unlock(&LOCK_commit_ordered);
3190
if (write_file_name_to_index_file)
3192
#ifdef HAVE_REPLICATION
3193
#ifdef ENABLED_DEBUG_SYNC
3195
DEBUG_SYNC(current_thd, "binlog_open_before_update_index");
3197
DBUG_EXECUTE_IF("crash_create_critical_before_update_index", DBUG_SUICIDE(););
3200
DBUG_ASSERT(my_b_inited(&index_file) != 0);
3201
reinit_io_cache(&index_file, WRITE_CACHE,
3202
my_b_filelength(&index_file), 0, 0);
3204
As this is a new log file, we write the file name to the index
3205
file. As every time we write to the index file, we sync it.
3207
if (DBUG_EVALUATE_IF("fault_injection_updating_index", 1, 0) ||
3208
my_b_write(&index_file, (uchar*) log_file_name,
3209
strlen(log_file_name)) ||
3210
my_b_write(&index_file, (uchar*) "\n", 1) ||
3211
flush_io_cache(&index_file) ||
3212
mysql_file_sync(index_file.file, MYF(MY_WME|MY_SYNC_FILESIZE)))
3215
#ifdef HAVE_REPLICATION
3216
DBUG_EXECUTE_IF("crash_create_after_update_index", DBUG_SUICIDE(););
3220
log_state= LOG_OPENED;
3222
#ifdef HAVE_REPLICATION
3223
close_purge_index_file();
3229
#ifdef HAVE_REPLICATION
3230
if (is_inited_purge_index_file())
3231
purge_index_entry(NULL, NULL, need_mutex);
3232
close_purge_index_file();
3234
sql_print_error("Could not use %s for logging (error %d). \
3235
Turning logging off for the whole duration of the MySQL server process. \
3236
To turn it on again: fix the cause, \
3237
shutdown the MySQL server and restart it.", name, errno);
3239
mysql_file_close(file, MYF(0));
3240
close(LOG_CLOSE_INDEX);
3245
int MYSQL_BIN_LOG::get_current_log(LOG_INFO* linfo)
3247
mysql_mutex_lock(&LOCK_log);
3248
int ret = raw_get_current_log(linfo);
3249
mysql_mutex_unlock(&LOCK_log);
3253
int MYSQL_BIN_LOG::raw_get_current_log(LOG_INFO* linfo)
3255
strmake_buf(linfo->log_file_name, log_file_name);
3256
linfo->pos = my_b_tell(&log_file);
3261
Move all data up in a file in an filename index file.
3263
We do the copy outside of the IO_CACHE as the cache buffers would just
3264
make things slower and more complicated.
3265
In most cases the copy loop should only do one read.
3267
@param index_file File to move
3268
@param offset Move everything from here to beginning
3271
File will be truncated to be 'offset' shorter or filled up with newlines
3277
#ifdef HAVE_REPLICATION
3279
static bool copy_up_file_and_fill(IO_CACHE *index_file, my_off_t offset)
3282
my_off_t init_offset= offset;
3283
File file= index_file->file;
3284
uchar io_buf[IO_SIZE*2];
3285
DBUG_ENTER("copy_up_file_and_fill");
3287
for (;; offset+= bytes_read)
3289
mysql_file_seek(file, offset, MY_SEEK_SET, MYF(0));
3290
if ((bytes_read= (int) mysql_file_read(file, io_buf, sizeof(io_buf),
3295
break; // end of file
3296
mysql_file_seek(file, offset-init_offset, MY_SEEK_SET, MYF(0));
3297
if (mysql_file_write(file, io_buf, bytes_read, MYF(MY_WME | MY_NABP)))
3300
/* The following will either truncate the file or fill the end with \n' */
3301
if (mysql_file_chsize(file, offset - init_offset, '\n', MYF(MY_WME)) ||
3302
mysql_file_sync(file, MYF(MY_WME|MY_SYNC_FILESIZE)))
3305
/* Reset data in old index cache */
3306
reinit_io_cache(index_file, READ_CACHE, (my_off_t) 0, 0, 1);
3313
#endif /* HAVE_REPLICATION */
3316
Find the position in the log-index-file for the given log name.
3318
@param linfo Store here the found log file name and position to
3319
the NEXT log file name in the index file.
3320
@param log_name Filename to find in the index file.
3321
Is a null pointer if we want to read the first entry
3322
@param need_lock Set this to 1 if the parent doesn't already have a
3326
On systems without the truncate function the file will end with one or
3327
more empty lines. These will be ignored when reading the file.
3332
LOG_INFO_EOF End of log-index-file found
3334
LOG_INFO_IO Got IO error while reading file
3337
int MYSQL_BIN_LOG::find_log_pos(LOG_INFO *linfo, const char *log_name,
3341
char *full_fname= linfo->log_file_name;
3342
char full_log_name[FN_REFLEN], fname[FN_REFLEN];
3343
uint log_name_len= 0, fname_len= 0;
3344
DBUG_ENTER("find_log_pos");
3345
full_log_name[0]= full_fname[0]= 0;
3348
Mutex needed because we need to make sure the file pointer does not
3349
move from under our feet
3352
mysql_mutex_lock(&LOCK_index);
3353
mysql_mutex_assert_owner(&LOCK_index);
3355
// extend relative paths for log_name to be searched
3358
if(normalize_binlog_name(full_log_name, log_name, is_relay_log))
3360
error= LOG_INFO_EOF;
3365
log_name_len= log_name ? (uint) strlen(full_log_name) : 0;
3366
DBUG_PRINT("enter", ("log_name: %s, full_log_name: %s",
3367
log_name ? log_name : "NULL", full_log_name));
3369
/* As the file is flushed, we can't get an error here */
3370
(void) reinit_io_cache(&index_file, READ_CACHE, (my_off_t) 0, 0, 0);
3375
my_off_t offset= my_b_tell(&index_file);
3377
DBUG_EXECUTE_IF("simulate_find_log_pos_error",
3378
error= LOG_INFO_EOF; break;);
3379
/* If we get 0 or 1 characters, this is the end of the file */
3380
if ((length= my_b_gets(&index_file, fname, FN_REFLEN)) <= 1)
3382
/* Did not find the given entry; Return not found or error */
3383
error= !index_file.error ? LOG_INFO_EOF : LOG_INFO_IO;
3387
// extend relative paths and match against full path
3388
if (normalize_binlog_name(full_fname, fname, is_relay_log))
3390
error= LOG_INFO_EOF;
3393
fname_len= (uint) strlen(full_fname);
3395
// if the log entry matches, null string matching anything
3397
(log_name_len == fname_len-1 && full_fname[log_name_len] == '\n' &&
3398
!memcmp(full_fname, full_log_name, log_name_len)))
3400
DBUG_PRINT("info", ("Found log file entry"));
3401
full_fname[fname_len-1]= 0; // remove last \n
3402
linfo->index_file_start_offset= offset;
3403
linfo->index_file_offset = my_b_tell(&index_file);
3410
mysql_mutex_unlock(&LOCK_index);
3416
Find the position in the log-index-file for the given log name.
3419
linfo Store here the next log file name and position to
3420
the file name after that.
3422
need_lock Set this to 1 if the parent doesn't already have a
3426
- Before calling this function, one has to call find_log_pos()
3428
- Mutex needed because we need to make sure the file pointer does not move
3434
LOG_INFO_EOF End of log-index-file found
3436
LOG_INFO_IO Got IO error while reading file
3439
int MYSQL_BIN_LOG::find_next_log(LOG_INFO* linfo, bool need_lock)
3443
char fname[FN_REFLEN];
3444
char *full_fname= linfo->log_file_name;
3447
mysql_mutex_lock(&LOCK_index);
3448
mysql_mutex_assert_owner(&LOCK_index);
3450
/* As the file is flushed, we can't get an error here */
3451
(void) reinit_io_cache(&index_file, READ_CACHE, linfo->index_file_offset, 0,
3454
linfo->index_file_start_offset= linfo->index_file_offset;
3455
if ((length=my_b_gets(&index_file, fname, FN_REFLEN)) <= 1)
3457
error = !index_file.error ? LOG_INFO_EOF : LOG_INFO_IO;
3463
if(normalize_binlog_name(full_fname, fname, is_relay_log))
3465
error= LOG_INFO_EOF;
3468
length= strlen(full_fname);
3471
full_fname[length-1]= 0; // kill \n
3472
linfo->index_file_offset= my_b_tell(&index_file);
3476
mysql_mutex_unlock(&LOCK_index);
3482
Delete all logs refered to in the index file.
3483
Start writing to a new log file.
3485
The new index file will only contain this file.
3490
If not called from slave thread, write start event to new log
3498
bool MYSQL_BIN_LOG::reset_logs(THD* thd)
3503
const char* save_name;
3504
DBUG_ENTER("reset_logs");
3508
We need to get both locks to be sure that no one is trying to
3509
write to the index log file.
3511
mysql_mutex_lock(&LOCK_log);
3512
mysql_mutex_lock(&LOCK_index);
3515
The following mutex is needed to ensure that no threads call
3516
'delete thd' as we would then risk missing a 'rollback' from this
3517
thread. If the transaction involved MyISAM tables, it should go
3518
into binlog even on rollback.
3520
mysql_mutex_lock(&LOCK_thread_count);
3522
/* Save variables so that we can reopen the log */
3524
name=0; // Protect against free
3525
close(LOG_CLOSE_TO_BE_OPENED);
3528
First delete all old log files and then update the index file.
3529
As we first delete the log files and do not use sort of logging,
3530
a crash may lead to an inconsistent state where the index has
3531
references to non-existent files.
3533
We need to invert the steps and use the purge_index_file methods
3534
in order to make the operation safe.
3537
if ((err= find_log_pos(&linfo, NullS, 0)) != 0)
3539
uint errcode= purge_log_get_error_code(err);
3540
sql_print_error("Failed to locate old binlog or relay log files");
3541
my_message(errcode, ER(errcode), MYF(0));
3548
if ((error= my_delete(linfo.log_file_name, MYF(0))) != 0)
3550
if (my_errno == ENOENT)
3552
push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3553
ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
3554
linfo.log_file_name);
3555
sql_print_information("Failed to delete file '%s'",
3556
linfo.log_file_name);
3562
push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3563
ER_BINLOG_PURGE_FATAL_ERR,
3564
"a problem with deleting %s; "
3565
"consider examining correspondence "
3566
"of your binlog index file "
3567
"to the actual binlog files",
3568
linfo.log_file_name);
3573
if (find_next_log(&linfo, 0))
3577
/* Start logging with a new file */
3578
close(LOG_CLOSE_INDEX | LOG_CLOSE_TO_BE_OPENED);
3579
if ((error= my_delete(index_file_name, MYF(0)))) // Reset (open will update)
3581
if (my_errno == ENOENT)
3583
push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3584
ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
3586
sql_print_information("Failed to delete file '%s'",
3593
push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN,
3594
ER_BINLOG_PURGE_FATAL_ERR,
3595
"a problem with deleting %s; "
3596
"consider examining correspondence "
3597
"of your binlog index file "
3598
"to the actual binlog files",
3604
if (!thd->slave_thread)
3606
if (!open_index_file(index_file_name, 0, FALSE))
3607
if ((error= open(save_name, log_type, 0, io_cache_type, no_auto_events, max_size, 0, FALSE)))
3609
my_free((void *) save_name);
3613
name= const_cast<char*>(save_name);
3614
mysql_mutex_unlock(&LOCK_thread_count);
3615
mysql_mutex_unlock(&LOCK_index);
3616
mysql_mutex_unlock(&LOCK_log);
3622
Delete relay log files prior to rli->group_relay_log_name
3623
(i.e. all logs which are not involved in a non-finished group
3624
(transaction)), remove them from the index file and start on next
3628
- Protects index file with LOCK_index
3629
- Delete relevant relay log files
3630
- Copy all file names after these ones to the front of the index file
3631
- If the OS has truncate, truncate the file, else fill it with \n'
3632
- Read the next file name from the index file and store in rli->linfo
3634
@param rli Relay log information
3635
@param included If false, all relay logs that are strictly before
3636
rli->group_relay_log_name are deleted ; if true, the
3637
latter is deleted too (i.e. all relay logs
3638
read by the SQL slave thread are deleted).
3641
- This is only called from the slave-execute thread when it has read
3642
all commands from a relay log and want to switch to a new relay log.
3643
- When this happens, we can be in an active transaction as
3644
a transaction can span over two relay logs
3645
(although it is always written as a single block to the master's binary
3646
log, hence cannot span over two master's binary logs).
3651
LOG_INFO_EOF End of log-index-file found
3653
LOG_INFO_SEEK Could not allocate IO cache
3655
LOG_INFO_IO Got IO error while reading file
3658
#ifdef HAVE_REPLICATION
3660
int MYSQL_BIN_LOG::purge_first_log(Relay_log_info* rli, bool included)
3663
char *to_purge_if_included= NULL;
3664
DBUG_ENTER("purge_first_log");
3666
DBUG_ASSERT(is_open());
3667
DBUG_ASSERT(rli->slave_running == 1);
3668
DBUG_ASSERT(!strcmp(rli->linfo.log_file_name,rli->event_relay_log_name));
3670
mysql_mutex_lock(&LOCK_index);
3671
to_purge_if_included= my_strdup(rli->group_relay_log_name, MYF(0));
3674
Read the next log file name from the index file and pass it back to
3677
if((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0)) ||
3678
(error=find_next_log(&rli->linfo, 0)))
3681
sql_print_error("next log error: %d offset: %s log: %s included: %d",
3683
llstr(rli->linfo.index_file_offset,buff),
3684
rli->event_relay_log_name,
3690
Reset rli's coordinates to the current log.
3692
rli->event_relay_log_pos= BIN_LOG_HEADER_SIZE;
3693
strmake_buf(rli->event_relay_log_name,rli->linfo.log_file_name);
3696
If we removed the rli->group_relay_log_name file,
3697
we must update the rli->group* coordinates, otherwise do not touch it as the
3698
group's execution is not finished (e.g. COMMIT not executed)
3702
rli->group_relay_log_pos = BIN_LOG_HEADER_SIZE;
3703
strmake_buf(rli->group_relay_log_name,rli->linfo.log_file_name);
3704
rli->notify_group_relay_log_name_update();
3707
/* Store where we are in the new file for the execution thread */
3708
flush_relay_log_info(rli);
3710
DBUG_EXECUTE_IF("crash_before_purge_logs", DBUG_SUICIDE(););
3712
mysql_mutex_lock(&rli->log_space_lock);
3713
rli->relay_log.purge_logs(to_purge_if_included, included,
3714
0, 0, &rli->log_space_total);
3715
mysql_mutex_unlock(&rli->log_space_lock);
3718
Ok to broadcast after the critical region as there is no risk of
3719
the mutex being destroyed by this thread later - this helps save
3722
mysql_cond_broadcast(&rli->log_space_cond);
3725
* Need to update the log pos because purge logs has been called
3726
* after fetching initially the log pos at the begining of the method.
3728
if((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0)))
3731
sql_print_error("next log error: %d offset: %s log: %s included: %d",
3733
llstr(rli->linfo.index_file_offset,buff),
3734
rli->group_relay_log_name,
3739
/* If included was passed, rli->linfo should be the first entry. */
3740
DBUG_ASSERT(!included || rli->linfo.index_file_start_offset == 0);
3743
my_free(to_purge_if_included);
3744
mysql_mutex_unlock(&LOCK_index);
3749
Update log index_file.
3752
int MYSQL_BIN_LOG::update_log_index(LOG_INFO* log_info, bool need_update_threads)
3754
if (copy_up_file_and_fill(&index_file, log_info->index_file_start_offset))
3757
// now update offsets in index file for running threads
3758
if (need_update_threads)
3759
adjust_linfo_offsets(log_info->index_file_start_offset);
3764
Remove all logs before the given log from disk and from the index file.
3766
@param to_log Delete all log file name before this file.
3767
@param included If true, to_log is deleted too.
3769
@param need_update_threads If we want to update the log coordinates of
3770
all threads. False for relay logs, true otherwise.
3771
@param freed_log_space If not null, decrement this variable of
3772
the amount of log space freed
3775
If any of the logs before the deleted one is in use,
3776
only purge logs up to this one.
3781
LOG_INFO_EOF to_log not found
3782
LOG_INFO_EMFILE too many files opened
3783
LOG_INFO_FATAL if any other than ENOENT error from
3784
mysql_file_stat() or mysql_file_delete()
3787
int MYSQL_BIN_LOG::purge_logs(const char *to_log,
3790
bool need_update_threads,
3791
ulonglong *decrease_log_space)
3796
THD *thd= current_thd;
3797
DBUG_ENTER("purge_logs");
3798
DBUG_PRINT("info",("to_log= %s",to_log));
3801
mysql_mutex_lock(&LOCK_index);
3802
if ((error=find_log_pos(&log_info, to_log, 0 /*no mutex*/)))
3804
sql_print_error("MYSQL_BIN_LOG::purge_logs was called with file %s not "
3805
"listed in the index.", to_log);
3809
if ((error= open_purge_index_file(TRUE)))
3811
sql_print_error("MYSQL_BIN_LOG::purge_logs failed to sync the index file.");
3816
File name exists in index file; delete until we find this file
3817
or a file that is used.
3819
if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/)))
3821
while ((strcmp(to_log,log_info.log_file_name) || (exit_loop=included)) &&
3822
!is_active(log_info.log_file_name) &&
3823
!log_in_use(log_info.log_file_name))
3825
if ((error= register_purge_index_entry(log_info.log_file_name)))
3827
sql_print_error("MYSQL_BIN_LOG::purge_logs failed to copy %s to register file.",
3828
log_info.log_file_name);
3832
if (find_next_log(&log_info, 0) || exit_loop)
3836
DBUG_EXECUTE_IF("crash_purge_before_update_index", DBUG_SUICIDE(););
3838
if ((error= sync_purge_index_file()))
3840
sql_print_error("MSYQL_BIN_LOG::purge_logs failed to flush register file.");
3844
/* We know how many files to delete. Update index file. */
3845
if ((error=update_log_index(&log_info, need_update_threads)))
3847
sql_print_error("MSYQL_BIN_LOG::purge_logs failed to update the index file");
3851
DBUG_EXECUTE_IF("crash_purge_critical_after_update_index", DBUG_SUICIDE(););
3854
/* Read each entry from purge_index_file and delete the file. */
3855
if (is_inited_purge_index_file() &&
3856
(error= purge_index_entry(thd, decrease_log_space, FALSE)))
3857
sql_print_error("MSYQL_BIN_LOG::purge_logs failed to process registered files"
3858
" that would be purged.");
3859
close_purge_index_file();
3861
DBUG_EXECUTE_IF("crash_purge_non_critical_after_update_index", DBUG_SUICIDE(););
3864
mysql_mutex_unlock(&LOCK_index);
3868
int MYSQL_BIN_LOG::set_purge_index_file_name(const char *base_file_name)
3871
DBUG_ENTER("MYSQL_BIN_LOG::set_purge_index_file_name");
3872
if (fn_format(purge_index_file_name, base_file_name, mysql_data_home,
3873
".~rec~", MYF(MY_UNPACK_FILENAME | MY_SAFE_PATH |
3874
MY_REPLACE_EXT)) == NULL)
3877
sql_print_error("MYSQL_BIN_LOG::set_purge_index_file_name failed to set "
3883
int MYSQL_BIN_LOG::open_purge_index_file(bool destroy)
3888
DBUG_ENTER("MYSQL_BIN_LOG::open_purge_index_file");
3891
close_purge_index_file();
3893
if (!my_b_inited(&purge_index_file))
3895
if ((file= my_open(purge_index_file_name, O_RDWR | O_CREAT | O_BINARY,
3896
MYF(MY_WME | ME_WAITTANG))) < 0 ||
3897
init_io_cache(&purge_index_file, file, IO_SIZE,
3898
(destroy ? WRITE_CACHE : READ_CACHE),
3899
0, 0, MYF(MY_WME | MY_NABP | MY_WAIT_IF_FULL)))
3902
sql_print_error("MYSQL_BIN_LOG::open_purge_index_file failed to open register "
3909
int MYSQL_BIN_LOG::close_purge_index_file()
3913
DBUG_ENTER("MYSQL_BIN_LOG::close_purge_index_file");
3915
if (my_b_inited(&purge_index_file))
3917
end_io_cache(&purge_index_file);
3918
error= my_close(purge_index_file.file, MYF(0));
3920
my_delete(purge_index_file_name, MYF(0));
3921
bzero((char*) &purge_index_file, sizeof(purge_index_file));
3926
bool MYSQL_BIN_LOG::is_inited_purge_index_file()
3928
return my_b_inited(&purge_index_file);
3931
int MYSQL_BIN_LOG::sync_purge_index_file()
3934
DBUG_ENTER("MYSQL_BIN_LOG::sync_purge_index_file");
3936
if ((error= flush_io_cache(&purge_index_file)) ||
3937
(error= my_sync(purge_index_file.file, MYF(MY_WME|MY_SYNC_FILESIZE))))
3943
int MYSQL_BIN_LOG::register_purge_index_entry(const char *entry)
3946
DBUG_ENTER("MYSQL_BIN_LOG::register_purge_index_entry");
3948
if ((error=my_b_write(&purge_index_file, (const uchar*)entry, strlen(entry))) ||
3949
(error=my_b_write(&purge_index_file, (const uchar*)"\n", 1)))
3950
DBUG_RETURN (error);
3955
int MYSQL_BIN_LOG::register_create_index_entry(const char *entry)
3957
DBUG_ENTER("MYSQL_BIN_LOG::register_create_index_entry");
3958
DBUG_RETURN(register_purge_index_entry(entry));
3961
int MYSQL_BIN_LOG::purge_index_entry(THD *thd, ulonglong *decrease_log_space,
3964
DBUG_ENTER("MYSQL_BIN_LOG:purge_index_entry");
3968
LOG_INFO check_log_info;
3970
DBUG_ASSERT(my_b_inited(&purge_index_file));
3972
if ((error=reinit_io_cache(&purge_index_file, READ_CACHE, 0, 0, 0)))
3974
sql_print_error("MSYQL_BIN_LOG::purge_index_entry failed to reinit register file "
3983
if ((length=my_b_gets(&purge_index_file, log_info.log_file_name,
3986
if (purge_index_file.error)
3988
error= purge_index_file.error;
3989
sql_print_error("MSYQL_BIN_LOG::purge_index_entry error %d reading from "
3990
"register file.", error);
3998
/* Get rid of the trailing '\n' */
3999
log_info.log_file_name[length-1]= 0;
4001
if (!mysql_file_stat(m_key_file_log, log_info.log_file_name, &s, MYF(0)))
4003
if (my_errno == ENOENT)
4006
It's not fatal if we can't stat a log file that does not exist;
4007
If we could not stat, we won't delete.
4011
push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4012
ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
4013
log_info.log_file_name);
4015
sql_print_information("Failed to execute mysql_file_stat on file '%s'",
4016
log_info.log_file_name);
4022
Other than ENOENT are fatal
4026
push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4027
ER_BINLOG_PURGE_FATAL_ERR,
4028
"a problem with getting info on being purged %s; "
4029
"consider examining correspondence "
4030
"of your binlog index file "
4031
"to the actual binlog files",
4032
log_info.log_file_name);
4036
sql_print_information("Failed to delete log file '%s'; "
4037
"consider examining correspondence "
4038
"of your binlog index file "
4039
"to the actual binlog files",
4040
log_info.log_file_name);
4042
error= LOG_INFO_FATAL;
4048
if ((error= find_log_pos(&check_log_info, log_info.log_file_name, need_mutex)))
4050
if (error != LOG_INFO_EOF)
4054
push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4055
ER_BINLOG_PURGE_FATAL_ERR,
4056
"a problem with deleting %s and "
4057
"reading the binlog index file",
4058
log_info.log_file_name);
4062
sql_print_information("Failed to delete file '%s' and "
4063
"read the binlog index file",
4064
log_info.log_file_name);
4073
This is to avoid triggering an error in NDB.
4075
ha_binlog_index_purge_file(current_thd, log_info.log_file_name);
4078
DBUG_PRINT("info",("purging %s",log_info.log_file_name));
4079
if (!my_delete(log_info.log_file_name, MYF(0)))
4081
if (decrease_log_space)
4082
*decrease_log_space-= s.st_size;
4086
if (my_errno == ENOENT)
4090
push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4091
ER_LOG_PURGE_NO_FILE, ER(ER_LOG_PURGE_NO_FILE),
4092
log_info.log_file_name);
4094
sql_print_information("Failed to delete file '%s'",
4095
log_info.log_file_name);
4102
push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4103
ER_BINLOG_PURGE_FATAL_ERR,
4104
"a problem with deleting %s; "
4105
"consider examining correspondence "
4106
"of your binlog index file "
4107
"to the actual binlog files",
4108
log_info.log_file_name);
4112
sql_print_information("Failed to delete file '%s'; "
4113
"consider examining correspondence "
4114
"of your binlog index file "
4115
"to the actual binlog files",
4116
log_info.log_file_name);
4118
if (my_errno == EMFILE)
4121
("my_errno: %d, set ret = LOG_INFO_EMFILE", my_errno));
4122
error= LOG_INFO_EMFILE;
4125
error= LOG_INFO_FATAL;
4138
Remove all logs before the given file date from disk and from the
4141
@param thd Thread pointer
4142
@param purge_time Delete all log files before given date.
4145
If any of the logs before the deleted one is in use,
4146
only purge logs up to this one.
4151
LOG_INFO_PURGE_NO_ROTATE Binary file that can't be rotated
4152
LOG_INFO_FATAL if any other than ENOENT error from
4153
mysql_file_stat() or mysql_file_delete()
4156
int MYSQL_BIN_LOG::purge_logs_before_date(time_t purge_time)
4159
char to_log[FN_REFLEN];
4162
THD *thd= current_thd;
4164
DBUG_ENTER("purge_logs_before_date");
4166
mysql_mutex_lock(&LOCK_index);
4169
if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/)))
4172
while (strcmp(log_file_name, log_info.log_file_name) &&
4173
!is_active(log_info.log_file_name) &&
4174
!log_in_use(log_info.log_file_name))
4176
if (!mysql_file_stat(m_key_file_log,
4177
log_info.log_file_name, &stat_area, MYF(0)))
4179
if (my_errno == ENOENT)
4182
It's not fatal if we can't stat a log file that does not exist.
4189
Other than ENOENT are fatal
4193
push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
4194
ER_BINLOG_PURGE_FATAL_ERR,
4195
"a problem with getting info on being purged %s; "
4196
"consider examining correspondence "
4197
"of your binlog index file "
4198
"to the actual binlog files",
4199
log_info.log_file_name);
4203
sql_print_information("Failed to delete log file '%s'",
4204
log_info.log_file_name);
4206
error= LOG_INFO_FATAL;
4212
if (stat_area.st_mtime < purge_time)
4213
strmake_buf(to_log, log_info.log_file_name);
4217
if (find_next_log(&log_info, 0))
4221
error= (to_log[0] ? purge_logs(to_log, 1, 0, 1, (ulonglong *) 0) : 0);
4224
mysql_mutex_unlock(&LOCK_index);
4227
#endif /* HAVE_REPLICATION */
4231
Create a new log file name.
4233
@param buf buf of at least FN_REFLEN where new name is stored
4236
If file name will be longer then FN_REFLEN it will be truncated
4239
void MYSQL_BIN_LOG::make_log_name(char* buf, const char* log_ident)
4241
uint dir_len = dirname_length(log_file_name);
4242
if (dir_len >= FN_REFLEN)
4243
dir_len=FN_REFLEN-1;
4244
strnmov(buf, log_file_name, dir_len);
4245
strmake(buf+dir_len, log_ident, FN_REFLEN - dir_len -1);
4250
Check if we are writing/reading to the given log file.
4253
bool MYSQL_BIN_LOG::is_active(const char *log_file_name_arg)
4255
return !strcmp(log_file_name, log_file_name_arg);
4260
Wrappers around new_file_impl to avoid using argument
4261
to control locking. The argument 1) less readable 2) breaks
4262
incapsulation 3) allows external access to the class without
4263
a lock (which is not possible with private new_file_without_locking
4270
int MYSQL_BIN_LOG::new_file()
4272
return new_file_impl(1);
4279
int MYSQL_BIN_LOG::new_file_without_locking()
4281
return new_file_impl(0);
4286
Start writing to a new log file or reopen the old file.
4288
@param need_lock Set to 1 if caller has not locked LOCK_log
4294
The new file name is stored last in the index file
4297
int MYSQL_BIN_LOG::new_file_impl(bool need_lock)
4299
int error= 0, close_on_error= FALSE;
4300
char new_name[FN_REFLEN], *new_name_ptr, *old_name, *file_to_open;
4302
bool delay_close= false;
4304
LINT_INIT(old_file);
4306
DBUG_ENTER("MYSQL_BIN_LOG::new_file_impl");
4309
DBUG_PRINT("info",("log is closed"));
4314
mysql_mutex_lock(&LOCK_log);
4315
mysql_mutex_lock(&LOCK_index);
4317
mysql_mutex_assert_owner(&LOCK_log);
4318
mysql_mutex_assert_owner(&LOCK_index);
4321
if binlog is used as tc log, be sure all xids are "unlogged",
4322
so that on recover we only need to scan one - latest - binlog file
4323
for prepared xids. As this is expected to be a rare event,
4324
simple wait strategy is enough. We're locking LOCK_log to be sure no
4325
new Xid_log_event's are added to the log (and prepared_xids is not
4326
increased), and waiting on COND_prep_xids for late threads to
4331
tc_log_page_waits++;
4332
mysql_mutex_lock(&LOCK_prep_xids);
4333
while (prepared_xids) {
4334
DBUG_PRINT("info", ("prepared_xids=%lu", prepared_xids));
4335
mysql_cond_wait(&COND_prep_xids, &LOCK_prep_xids);
4337
mysql_mutex_unlock(&LOCK_prep_xids);
4340
/* Reuse old name if not binlog and not update log */
4344
If user hasn't specified an extension, generate a new log name
4345
We have to do this here and not in open as we want to store the
4346
new file name in the current binary log file.
4348
if ((error= generate_new_name(new_name, name)))
4350
new_name_ptr=new_name;
4352
if (log_type == LOG_BIN)
4354
if (!no_auto_events)
4357
We log the whole file name for log file as the user may decide
4358
to change base names at some point.
4360
Rotate_log_event r(new_name+dirname_length(new_name), 0, LOG_EVENT_OFFSET,
4361
is_relay_log ? Rotate_log_event::RELAY_LOG : 0);
4363
The current relay-log's closing Rotate event must have checksum
4364
value computed with an algorithm of the last relay-logged FD event.
4367
r.checksum_alg= relay_log_checksum_alg;
4368
DBUG_ASSERT(!is_relay_log || relay_log_checksum_alg != BINLOG_CHECKSUM_ALG_UNDEF);
4369
if(DBUG_EVALUATE_IF("fault_injection_new_file_rotate_event", (error=close_on_error=TRUE), FALSE) ||
4370
(error= r.write(&log_file)))
4372
DBUG_EXECUTE_IF("fault_injection_new_file_rotate_event", errno=2;);
4373
close_on_error= TRUE;
4374
my_printf_error(ER_ERROR_ON_WRITE, ER(ER_CANT_OPEN_FILE), MYF(ME_FATALERROR), name, errno);
4377
bytes_written += r.data_written;
4380
Update needs to be signalled even if there is no rotate event
4381
log rotation should give the waiting thread a signal to
4382
discover EOF and move on to the next log.
4387
name=0; // Don't free name
4388
close_flag= LOG_CLOSE_TO_BE_OPENED | LOG_CLOSE_INDEX;
4392
We need to keep the old binlog file open (and marked as in-use) until
4393
the new one is fully created and synced to disk and index. Otherwise we
4394
leave a window where if we crash, there is no binlog file marked as
4395
crashed for server restart to detect the need for recovery.
4397
old_file= log_file.file;
4398
close_flag|= LOG_CLOSE_DELAYED_CLOSE;
4402
if (log_type == LOG_BIN && checksum_alg_reset != BINLOG_CHECKSUM_ALG_UNDEF)
4404
DBUG_ASSERT(!is_relay_log);
4405
DBUG_ASSERT(binlog_checksum_options != checksum_alg_reset);
4406
binlog_checksum_options= checksum_alg_reset;
4409
Note that at this point, log_state != LOG_CLOSED (important for is_open()).
4413
new_file() is only used for rotation (in FLUSH LOGS or because size >
4414
max_binlog_size or max_relay_log_size).
4415
If this is a binary log, the Format_description_log_event at the beginning of
4416
the new file should have created=0 (to distinguish with the
4417
Format_description_log_event written at server startup, which should
4418
trigger temp tables deletion on slaves.
4421
/* reopen index binlog file, BUG#34582 */
4422
file_to_open= index_file_name;
4423
error= open_index_file(index_file_name, 0, FALSE);
4426
/* reopen the binary log file. */
4427
file_to_open= new_name_ptr;
4428
error= open(old_name, log_type, new_name_ptr, io_cache_type,
4429
no_auto_events, max_size, 1, FALSE);
4432
/* handle reopening errors */
4435
my_printf_error(ER_CANT_OPEN_FILE, ER(ER_CANT_OPEN_FILE),
4436
MYF(ME_FATALERROR), file_to_open, error);
4437
close_on_error= TRUE;
4446
clear_inuse_flag_when_closing(old_file);
4447
mysql_file_close(old_file, MYF(MY_WME));
4450
if (error && close_on_error /* rotate or reopen failed */)
4453
Close whatever was left opened.
4455
We are keeping the behavior as it exists today, ie,
4456
we disable logging and move on (see: BUG#51014).
4458
TODO: as part of WL#1790 consider other approaches:
4459
- kill mysql (safety);
4460
- try multiple locations for opening a log file;
4461
- switch server to protected/readonly mode
4464
close(LOG_CLOSE_INDEX);
4465
sql_print_error("Could not open %s for logging (error %d). "
4466
"Turning logging off for the whole duration "
4467
"of the MySQL server process. To turn it on "
4468
"again: fix the cause, shutdown the MySQL "
4469
"server and restart it.",
4470
new_name_ptr, errno);
4474
mysql_mutex_unlock(&LOCK_log);
4475
mysql_mutex_unlock(&LOCK_index);
4481
bool MYSQL_BIN_LOG::append(Log_event* ev)
4484
mysql_mutex_lock(&LOCK_log);
4485
DBUG_ENTER("MYSQL_BIN_LOG::append");
4487
DBUG_ASSERT(log_file.type == SEQ_READ_APPEND);
4489
Log_event::write() is smart enough to use my_b_write() or
4490
my_b_append() depending on the kind of cache we have.
4492
if (ev->write(&log_file))
4497
bytes_written+= ev->data_written;
4498
DBUG_PRINT("info",("max_size: %lu",max_size));
4499
if (flush_and_sync(0))
4501
if ((uint) my_b_append_tell(&log_file) > max_size)
4502
error= new_file_without_locking();
4504
mysql_mutex_unlock(&LOCK_log);
4505
signal_update(); // Safe as we don't call close
4510
bool MYSQL_BIN_LOG::appendv(const char* buf, uint len,...)
4513
DBUG_ENTER("MYSQL_BIN_LOG::appendv");
4517
DBUG_ASSERT(log_file.type == SEQ_READ_APPEND);
4519
mysql_mutex_assert_owner(&LOCK_log);
4522
if (my_b_append(&log_file,(uchar*) buf,len))
4527
bytes_written += len;
4528
} while ((buf=va_arg(args,const char*)) && (len=va_arg(args,uint)));
4529
DBUG_PRINT("info",("max_size: %lu",max_size));
4530
if (flush_and_sync(0))
4532
if ((uint) my_b_append_tell(&log_file) > max_size)
4533
error= new_file_without_locking();
4540
bool MYSQL_BIN_LOG::flush_and_sync(bool *synced)
4542
int err=0, fd=log_file.file;
4545
mysql_mutex_assert_owner(&LOCK_log);
4546
if (flush_io_cache(&log_file))
4548
uint sync_period= get_sync_period();
4549
if (sync_period && ++sync_counter >= sync_period)
4552
err= mysql_file_sync(fd, MYF(MY_WME|MY_SYNC_FILESIZE));
4556
if (opt_binlog_dbug_fsync_sleep > 0)
4557
my_sleep(opt_binlog_dbug_fsync_sleep);
4563
void MYSQL_BIN_LOG::start_union_events(THD *thd, query_id_t query_id_param)
4565
DBUG_ASSERT(!thd->binlog_evt_union.do_union);
4566
thd->binlog_evt_union.do_union= TRUE;
4567
thd->binlog_evt_union.unioned_events= FALSE;
4568
thd->binlog_evt_union.unioned_events_trans= FALSE;
4569
thd->binlog_evt_union.first_query_id= query_id_param;
4572
void MYSQL_BIN_LOG::stop_union_events(THD *thd)
4574
DBUG_ASSERT(thd->binlog_evt_union.do_union);
4575
thd->binlog_evt_union.do_union= FALSE;
4578
bool MYSQL_BIN_LOG::is_query_in_union(THD *thd, query_id_t query_id_param)
4580
return (thd->binlog_evt_union.do_union &&
4581
query_id_param >= thd->binlog_evt_union.first_query_id);
4585
This function checks if a transactional table was updated by the
4586
current transaction.
4588
@param thd The client thread that executed the current statement.
4590
@c true if a transactional table was updated, @c false otherwise.
4593
trans_has_updated_trans_table(const THD* thd)
4595
binlog_cache_mngr *const cache_mngr=
4596
(binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4598
return (cache_mngr ? !cache_mngr->trx_cache.empty() : 0);
4602
This function checks if a transactional table was updated by the
4605
@param thd The client thread that executed the current statement.
4607
@c true if a transactional table was updated, @c false otherwise.
4610
stmt_has_updated_trans_table(const THD *thd)
4612
Ha_trx_info *ha_info;
4614
for (ha_info= thd->transaction.stmt.ha_list; ha_info;
4615
ha_info= ha_info->next())
4617
if (ha_info->is_trx_read_write() && ha_info->ht() != binlog_hton)
4624
This function checks if either a trx-cache or a non-trx-cache should
4625
be used. If @c bin_log_direct_non_trans_update is active or the format
4626
is either MIXED or ROW, the cache to be used depends on the flag @c
4629
On the other hand, if binlog_format is STMT or direct option is
4630
OFF, the trx-cache should be used if and only if the statement is
4631
transactional or the trx-cache is not empty. Otherwise, the
4632
non-trx-cache should be used.
4634
@param thd The client thread.
4635
@param is_transactional The changes are related to a trx-table.
4637
@c true if a trx-cache should be used, @c false otherwise.
4639
bool use_trans_cache(const THD* thd, bool is_transactional)
4641
binlog_cache_mngr *const cache_mngr=
4642
(binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4645
((thd->is_current_stmt_binlog_format_row() ||
4646
thd->variables.binlog_direct_non_trans_update) ? is_transactional :
4647
(is_transactional || !cache_mngr->trx_cache.empty()));
4651
This function checks if a transaction, either a multi-statement
4652
or a single statement transaction is about to commit or not.
4654
@param thd The client thread that executed the current statement.
4655
@param all Committing a transaction (i.e. TRUE) or a statement
4658
@c true if committing a transaction, otherwise @c false.
4660
bool ending_trans(THD* thd, const bool all)
4662
return (all || ending_single_stmt_trans(thd, all));
4666
This function checks if a single statement transaction is about
4669
@param thd The client thread that executed the current statement.
4670
@param all Committing a transaction (i.e. TRUE) or a statement
4673
@c true if committing a single statement transaction, otherwise
4676
bool ending_single_stmt_trans(THD* thd, const bool all)
4678
return (!all && !thd->in_multi_stmt_transaction_mode());
4682
This function checks if a non-transactional table was updated by
4683
the current transaction.
4685
@param thd The client thread that executed the current statement.
4687
@c true if a non-transactional table was updated, @c false
4690
bool trans_has_updated_non_trans_table(const THD* thd)
4692
return (thd->transaction.all.modified_non_trans_table ||
4693
thd->transaction.stmt.modified_non_trans_table);
4697
This function checks if a non-transactional table was updated by the
4700
@param thd The client thread that executed the current statement.
4702
@c true if a non-transactional table was updated, @c false otherwise.
4704
bool stmt_has_updated_non_trans_table(const THD* thd)
4706
return (thd->transaction.stmt.modified_non_trans_table);
4710
These functions are placed in this file since they need access to
4711
binlog_hton, which has internal linkage.
4714
binlog_cache_mngr *THD::binlog_setup_trx_data()
4716
DBUG_ENTER("THD::binlog_setup_trx_data");
4717
binlog_cache_mngr *cache_mngr=
4718
(binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4721
DBUG_RETURN(cache_mngr); // Already set up
4723
cache_mngr= (binlog_cache_mngr*) my_malloc(sizeof(binlog_cache_mngr), MYF(MY_ZEROFILL));
4725
open_cached_file(&cache_mngr->stmt_cache.cache_log, mysql_tmpdir,
4726
LOG_PREFIX, binlog_stmt_cache_size, MYF(MY_WME)) ||
4727
open_cached_file(&cache_mngr->trx_cache.cache_log, mysql_tmpdir,
4728
LOG_PREFIX, binlog_cache_size, MYF(MY_WME)))
4730
my_free(cache_mngr);
4731
DBUG_RETURN(0); // Didn't manage to set it up
4733
thd_set_ha_data(this, binlog_hton, cache_mngr);
4735
cache_mngr= new (cache_mngr)
4736
binlog_cache_mngr(max_binlog_stmt_cache_size,
4737
max_binlog_cache_size,
4738
&binlog_stmt_cache_use,
4739
&binlog_stmt_cache_disk_use,
4741
&binlog_cache_disk_use);
4742
DBUG_RETURN(cache_mngr);
4746
Function to start a statement and optionally a transaction for the
4750
binlog_start_trans_and_stmt()
4754
This function does three things:
4755
- Start a transaction if not in autocommit mode or if a BEGIN
4756
statement has been seen.
4758
- Start a statement transaction to allow us to truncate the cache.
4760
- Save the currrent binlog position so that we can roll back the
4761
statement by truncating the cache.
4763
We only update the saved position if the old one was undefined,
4764
the reason is that there are some cases (e.g., for CREATE-SELECT)
4765
where the position is saved twice (e.g., both in
4766
select_create::prepare() and THD::binlog_write_table_map()) , but
4767
we should use the first. This means that calls to this function
4768
can be used to start the statement before the first table map
4769
event, to include some extra events.
4773
THD::binlog_start_trans_and_stmt()
4775
binlog_cache_mngr *cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4776
DBUG_ENTER("binlog_start_trans_and_stmt");
4777
DBUG_PRINT("enter", ("cache_mngr: %p cache_mngr->trx_cache.get_prev_position(): %lu",
4779
(cache_mngr ? (ulong) cache_mngr->trx_cache.get_prev_position() :
4782
if (cache_mngr == NULL ||
4783
cache_mngr->trx_cache.get_prev_position() == MY_OFF_T_UNDEF)
4785
this->binlog_set_stmt_begin();
4786
if (in_multi_stmt_transaction_mode())
4787
trans_register_ha(this, TRUE, binlog_hton);
4788
trans_register_ha(this, FALSE, binlog_hton);
4790
Mark statement transaction as read/write. We never start
4791
a binary log transaction and keep it read-only,
4792
therefore it's best to mark the transaction read/write just
4793
at the same time we start it.
4794
Not necessary to mark the normal transaction read/write
4795
since the statement-level flag will be propagated automatically
4796
inside ha_commit_trans.
4798
ha_data[binlog_hton->slot].ha_info[0].set_trx_read_write();
4803
void THD::binlog_set_stmt_begin() {
4804
binlog_cache_mngr *cache_mngr=
4805
(binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4808
The call to binlog_trans_log_savepos() might create the cache_mngr
4809
structure, if it didn't exist before, so we save the position
4810
into an auto variable and then write it into the transaction
4811
data for the binary log (i.e., cache_mngr).
4814
binlog_trans_log_savepos(this, &pos);
4815
cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4816
cache_mngr->trx_cache.set_prev_position(pos);
4820
binlog_start_consistent_snapshot(handlerton *hton, THD *thd)
4823
DBUG_ENTER("binlog_start_consistent_snapshot");
4825
binlog_cache_mngr *const cache_mngr= thd->binlog_setup_trx_data();
4827
/* Server layer calls us with LOCK_commit_ordered locked, so this is safe. */
4828
strmake_buf(cache_mngr->last_commit_pos_file, mysql_bin_log.last_commit_pos_file);
4829
cache_mngr->last_commit_pos_offset= mysql_bin_log.last_commit_pos_offset;
4831
trans_register_ha(thd, TRUE, hton);
4837
This function writes a table map to the binary log.
4838
Note that in order to keep the signature uniform with related methods,
4839
we use a redundant parameter to indicate whether a transactional table
4842
If with_annotate != NULL and
4843
*with_annotate = TRUE write also Annotate_rows before the table map.
4845
@param table a pointer to the table.
4846
@param is_transactional @c true indicates a transactional table,
4847
otherwise @c false a non-transactional.
4849
nonzero if an error pops up when writing the table map event.
4851
int THD::binlog_write_table_map(TABLE *table, bool is_transactional,
4852
my_bool *with_annotate)
4855
DBUG_ENTER("THD::binlog_write_table_map");
4856
DBUG_PRINT("enter", ("table: 0x%lx (%s: #%lu)",
4857
(long) table, table->s->table_name.str,
4858
table->s->table_map_id));
4860
/* Pre-conditions */
4861
DBUG_ASSERT(is_current_stmt_binlog_format_row() && mysql_bin_log.is_open());
4862
DBUG_ASSERT(table->s->table_map_id != ULONG_MAX);
4865
the_event(this, table, table->s->table_map_id, is_transactional);
4867
if (binlog_table_maps == 0)
4868
binlog_start_trans_and_stmt();
4870
binlog_cache_mngr *const cache_mngr=
4871
(binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4874
cache_mngr->get_binlog_cache_log(use_trans_cache(this, is_transactional));
4875
if (with_annotate && *with_annotate)
4877
Annotate_rows_log_event anno(current_thd, is_transactional, false);
4878
/* Annotate event should be written not more than once */
4880
if ((error= anno.write(file)))
4883
if ((error= the_event.write(file)))
4886
binlog_table_maps++;
4891
This function retrieves a pending row event from a cache which is
4892
specified through the parameter @c is_transactional. Respectively, when it
4893
is @c true, the pending event is returned from the transactional cache.
4894
Otherwise from the non-transactional cache.
4896
@param is_transactional @c true indicates a transactional cache,
4897
otherwise @c false a non-transactional.
4899
The row event if any.
4902
THD::binlog_get_pending_rows_event(bool is_transactional) const
4904
Rows_log_event* rows= NULL;
4905
binlog_cache_mngr *const cache_mngr=
4906
(binlog_cache_mngr*) thd_get_ha_data(this, binlog_hton);
4909
This is less than ideal, but here's the story: If there is no cache_mngr,
4910
prepare_pending_rows_event() has never been called (since the cache_mngr
4911
is set up there). In that case, we just return NULL.
4915
binlog_cache_data *cache_data=
4916
cache_mngr->get_binlog_cache_data(use_trans_cache(this, is_transactional));
4918
rows= cache_data->pending();
4924
This function stores a pending row event into a cache which is specified
4925
through the parameter @c is_transactional. Respectively, when it is @c
4926
true, the pending event is stored into the transactional cache. Otherwise
4927
into the non-transactional cache.
4929
@param evt a pointer to the row event.
4930
@param is_transactional @c true indicates a transactional cache,
4931
otherwise @c false a non-transactional.
4934
THD::binlog_set_pending_rows_event(Rows_log_event* ev, bool is_transactional)
4936
binlog_cache_mngr *const cache_mngr= binlog_setup_trx_data();
4938
DBUG_ASSERT(cache_mngr);
4940
binlog_cache_data *cache_data=
4941
cache_mngr->get_binlog_cache_data(use_trans_cache(this, is_transactional));
4943
cache_data->set_pending(ev);
4948
This function removes the pending rows event, discarding any outstanding
4949
rows. If there is no pending rows event available, this is effectively a
4952
@param thd a pointer to the user thread.
4953
@param is_transactional @c true indicates a transactional cache,
4954
otherwise @c false a non-transactional.
4957
MYSQL_BIN_LOG::remove_pending_rows_event(THD *thd, bool is_transactional)
4959
DBUG_ENTER("MYSQL_BIN_LOG::remove_pending_rows_event");
4961
binlog_cache_mngr *const cache_mngr=
4962
(binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
4964
DBUG_ASSERT(cache_mngr);
4966
binlog_cache_data *cache_data=
4967
cache_mngr->get_binlog_cache_data(use_trans_cache(thd, is_transactional));
4969
if (Rows_log_event* pending= cache_data->pending())
4972
cache_data->set_pending(NULL);
4979
Moves the last bunch of rows from the pending Rows event to a cache (either
4980
transactional cache if is_transaction is @c true, or the non-transactional
4981
cache otherwise. Sets a new pending event.
4983
@param thd a pointer to the user thread.
4984
@param evt a pointer to the row event.
4985
@param is_transactional @c true indicates a transactional cache,
4986
otherwise @c false a non-transactional.
4989
MYSQL_BIN_LOG::flush_and_set_pending_rows_event(THD *thd,
4990
Rows_log_event* event,
4991
bool is_transactional)
4993
DBUG_ENTER("MYSQL_BIN_LOG::flush_and_set_pending_rows_event(event)");
4994
DBUG_ASSERT(mysql_bin_log.is_open());
4995
DBUG_PRINT("enter", ("event: 0x%lx", (long) event));
4998
binlog_cache_mngr *const cache_mngr=
4999
(binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
5001
DBUG_ASSERT(cache_mngr);
5003
binlog_cache_data *cache_data=
5004
cache_mngr->get_binlog_cache_data(use_trans_cache(thd, is_transactional));
5006
DBUG_PRINT("info", ("cache_mngr->pending(): 0x%lx", (long) cache_data->pending()));
5008
if (Rows_log_event* pending= cache_data->pending())
5010
IO_CACHE *file= &cache_data->cache_log;
5013
Write pending event to the cache.
5015
DBUG_EXECUTE_IF("simulate_disk_full_at_flush_pending",
5016
{DBUG_SET("+d,simulate_file_write_error");});
5017
if (pending->write(file))
5019
set_write_error(thd, is_transactional);
5020
if (check_write_error(thd) && cache_data &&
5021
stmt_has_updated_non_trans_table(thd))
5022
cache_data->set_incident();
5024
cache_data->set_pending(NULL);
5025
DBUG_EXECUTE_IF("simulate_disk_full_at_flush_pending",
5026
{DBUG_SET("-d,simulate_file_write_error");});
5033
thd->binlog_set_pending_rows_event(event, is_transactional);
5039
Write an event to the binary log. If with_annotate != NULL and
5040
*with_annotate = TRUE write also Annotate_rows before the event
5041
(this should happen only if the event is a Table_map).
5044
bool MYSQL_BIN_LOG::write(Log_event *event_info, my_bool *with_annotate)
5046
THD *thd= event_info->thd;
5048
DBUG_ENTER("MYSQL_BIN_LOG::write(Log_event *)");
5049
binlog_cache_data *cache_data= 0;
5050
bool is_trans_cache= FALSE;
5051
bool using_trans= event_info->use_trans_cache();
5052
bool direct= event_info->use_direct_logging();
5054
if (thd->binlog_evt_union.do_union)
5057
In Stored function; Remember that function call caused an update.
5058
We will log the function call to the binary log on function exit
5060
thd->binlog_evt_union.unioned_events= TRUE;
5061
thd->binlog_evt_union.unioned_events_trans |= using_trans;
5066
We only end the statement if we are in a top-level statement. If
5067
we are inside a stored function, we do not end the statement since
5068
this will close all tables on the slave.
5070
bool const end_stmt=
5071
thd->locked_tables_mode && thd->lex->requires_prelocking();
5072
if (thd->binlog_flush_pending_rows_event(end_stmt, using_trans))
5076
In most cases this is only called if 'is_open()' is true; in fact this is
5077
mostly called if is_open() *was* true a few instructions before, but it
5078
could have changed since.
5080
if (likely(is_open()))
5082
my_off_t UNINIT_VAR(my_org_b_tell);
5083
#ifdef HAVE_REPLICATION
5085
In the future we need to add to the following if tests like
5086
"do the involved tables match (to be implemented)
5087
binlog_[wild_]{do|ignore}_table?" (WL#1049)"
5089
const char *local_db= event_info->get_db();
5090
if ((!(thd->variables.option_bits & OPTION_BIN_LOG)) ||
5091
(thd->lex->sql_command != SQLCOM_ROLLBACK_TO_SAVEPOINT &&
5092
thd->lex->sql_command != SQLCOM_SAVEPOINT &&
5093
!binlog_filter->db_ok(local_db)))
5095
#endif /* HAVE_REPLICATION */
5097
IO_CACHE *file= NULL;
5102
my_org_b_tell= my_b_tell(file);
5103
mysql_mutex_lock(&LOCK_log);
5107
binlog_cache_mngr *const cache_mngr= thd->binlog_setup_trx_data();
5111
is_trans_cache= use_trans_cache(thd, using_trans);
5112
file= cache_mngr->get_binlog_cache_log(is_trans_cache);
5113
cache_data= cache_mngr->get_binlog_cache_data(is_trans_cache);
5115
if (thd->lex->stmt_accessed_non_trans_temp_table())
5116
cache_data->set_changes_to_non_trans_temp_table();
5118
thd->binlog_start_trans_and_stmt();
5120
DBUG_PRINT("info",("event type: %d",event_info->get_type_code()));
5123
No check for auto events flag here - this write method should
5124
never be called if auto-events are enabled.
5126
Write first log events which describe the 'run environment'
5127
of the SQL command. If row-based binlogging, Insert_id, Rand
5128
and other kind of "setting context" events are not needed.
5131
if (with_annotate && *with_annotate)
5133
DBUG_ASSERT(event_info->get_type_code() == TABLE_MAP_EVENT);
5134
Annotate_rows_log_event anno(thd, using_trans, direct);
5135
/* Annotate event should be written not more than once */
5137
if (anno.write(file))
5143
if (!thd->is_current_stmt_binlog_format_row())
5146
if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt)
5148
Intvar_log_event e(thd,(uchar) LAST_INSERT_ID_EVENT,
5149
thd->first_successful_insert_id_in_prev_stmt_for_binlog,
5150
using_trans, direct);
5154
if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0)
5156
DBUG_PRINT("info",("number of auto_inc intervals: %u",
5157
thd->auto_inc_intervals_in_cur_stmt_for_binlog.
5159
Intvar_log_event e(thd, (uchar) INSERT_ID_EVENT,
5160
thd->auto_inc_intervals_in_cur_stmt_for_binlog.
5161
minimum(), using_trans, direct);
5167
Rand_log_event e(thd,thd->rand_saved_seed1,thd->rand_saved_seed2,
5168
using_trans, direct);
5172
if (thd->user_var_events.elements)
5174
for (uint i= 0; i < thd->user_var_events.elements; i++)
5176
BINLOG_USER_VAR_EVENT *user_var_event;
5177
get_dynamic(&thd->user_var_events,(uchar*) &user_var_event, i);
5179
/* setting flags for user var log event */
5180
uchar flags= User_var_log_event::UNDEF_F;
5181
if (user_var_event->unsigned_flag)
5182
flags|= User_var_log_event::UNSIGNED_F;
5184
User_var_log_event e(thd, user_var_event->user_var_event->name.str,
5185
user_var_event->user_var_event->name.length,
5186
user_var_event->value,
5187
user_var_event->length,
5188
user_var_event->type,
5189
user_var_event->charset_number,
5203
if (event_info->write(file) ||
5204
DBUG_EVALUATE_IF("injecting_fault_writing", 1, 0))
5211
my_off_t offset= my_b_tell(file);
5212
bool check_purge= false;
5218
if ((error= flush_and_sync(&synced)))
5221
else if ((error= RUN_HOOK(binlog_storage, after_flush,
5222
(thd, log_file_name, file->pos_in_file, synced))))
5224
sql_print_error("Failed to run 'after_flush' hooks");
5229
if ((error= rotate(false, &check_purge)))
5234
status_var_add(thd->status_var.binlog_bytes_written,
5235
offset - my_org_b_tell);
5238
Take mutex to protect against a reader seeing partial writes of 64-bit
5239
offset on 32-bit CPUs.
5241
mysql_mutex_lock(&LOCK_commit_ordered);
5242
last_commit_pos_offset= offset;
5243
mysql_mutex_unlock(&LOCK_commit_ordered);
5244
mysql_mutex_unlock(&LOCK_log);
5252
set_write_error(thd, is_trans_cache);
5253
if (check_write_error(thd) && cache_data &&
5254
stmt_has_updated_non_trans_table(thd))
5255
cache_data->set_incident();
5263
int error_log_print(enum loglevel level, const char *format,
5266
return logger.error_log_print(level, format, args);
5270
bool slow_log_print(THD *thd, const char *query, uint query_length,
5271
ulonglong current_utime)
5273
return logger.slow_log_print(thd, query, query_length, current_utime);
5277
bool LOGGER::log_command(THD *thd, enum enum_server_command command)
5279
#ifndef NO_EMBEDDED_ACCESS_CHECKS
5280
Security_context *sctx= thd->security_ctx;
5283
Log command if we have at least one log event handler enabled and want
5284
to log this king of commands
5286
if (*general_log_handler_list && (what_to_log & (1L << (uint) command)))
5288
if ((thd->variables.option_bits & OPTION_LOG_OFF)
5289
#ifndef NO_EMBEDDED_ACCESS_CHECKS
5290
&& (sctx->master_access & SUPER_ACL)
5305
bool general_log_print(THD *thd, enum enum_server_command command,
5306
const char *format, ...)
5311
/* Print the message to the buffer if we want to log this king of commands */
5312
if (! logger.log_command(thd, command))
5315
va_start(args, format);
5316
error= logger.general_log_print(thd, command, format, args);
5322
bool general_log_write(THD *thd, enum enum_server_command command,
5323
const char *query, uint query_length)
5325
/* Write the message to the log if we want to log this king of commands */
5326
if (logger.log_command(thd, command) || mysql_audit_general_enabled())
5327
return logger.general_log_write(thd, command, query, query_length);
5333
The method executes rotation when LOCK_log is already acquired
5336
@param force_rotate caller can request the log rotation
5337
@param check_purge is set to true if rotation took place
5340
If rotation fails, for instance the server was unable
5341
to create a new log file, we still try to write an
5342
incident event to the current log.
5345
nonzero - error in rotating routine.
5347
int MYSQL_BIN_LOG::rotate(bool force_rotate, bool* check_purge)
5350
DBUG_ENTER("MYSQL_BIN_LOG::rotate");
5352
//todo: fix the macro def and restore safe_mutex_assert_owner(&LOCK_log);
5353
*check_purge= false;
5355
if (force_rotate || (my_b_tell(&log_file) >= (my_off_t) max_size))
5357
if ((error= new_file_without_locking()))
5359
Be conservative... There are possible lost events (eg,
5360
failing to log the Execute_load_query_log_event
5361
on a LOAD DATA while using a non-transactional
5364
We give it a shot and try to write an incident event anyway
5367
if (!write_incident_already_locked(current_thd))
5376
The method executes logs purging routine.
5379
nonzero - error in rotating routine.
5381
void MYSQL_BIN_LOG::purge()
5383
mysql_mutex_assert_not_owner(&LOCK_log);
5384
#ifdef HAVE_REPLICATION
5385
if (expire_logs_days)
5387
DEBUG_SYNC(current_thd, "at_purge_logs_before_date");
5388
time_t purge_time= my_time(0) - expire_logs_days*24*60*60;
5389
if (purge_time >= 0)
5391
purge_logs_before_date(purge_time);
5393
DEBUG_SYNC(current_thd, "after_purge_logs_before_date");
5399
The method is a shortcut of @c rotate() and @c purge().
5400
LOCK_log is acquired prior to rotate and is released after it.
5402
@param force_rotate caller can request the log rotation
5405
nonzero - error in rotating routine.
5407
int MYSQL_BIN_LOG::rotate_and_purge(bool force_rotate)
5410
DBUG_ENTER("MYSQL_BIN_LOG::rotate_and_purge");
5411
bool check_purge= false;
5413
//todo: fix the macro def and restore safe_mutex_assert_not_owner(&LOCK_log);
5414
mysql_mutex_lock(&LOCK_log);
5415
if ((error= rotate(force_rotate, &check_purge)))
5418
NOTE: Run purge_logs wo/ holding LOCK_log because it does not need
5419
the mutex. Otherwise causes various deadlocks.
5421
mysql_mutex_unlock(&LOCK_log);
5429
uint MYSQL_BIN_LOG::next_file_id()
5432
mysql_mutex_lock(&LOCK_log);
5434
mysql_mutex_unlock(&LOCK_log);
5440
Calculate checksum of possibly a part of an event containing at least
5441
the whole common header.
5443
@param buf the pointer to trans cache's buffer
5444
@param off the offset of the beginning of the event in the buffer
5445
@param event_len no-checksum length of the event
5446
@param length the current size of the buffer
5448
@param crc [in-out] the checksum
5450
Event size in incremented by @c BINLOG_CHECKSUM_LEN.
5452
@return 0 or number of unprocessed yet bytes of the event excluding
5455
static ulong fix_log_event_crc(uchar *buf, uint off, uint event_len,
5456
uint length, ha_checksum *crc)
5459
uchar *event_begin= buf + off;
5461
ret= length >= off + event_len ? 0 : off + event_len - length;
5462
*crc= my_checksum(*crc, event_begin, event_len - ret);
5467
Write the contents of a cache to the binary log.
5472
cache Cache to write to the binary log
5475
Write the contents of the cache to the binary log. The cache will
5476
be reset as a READ_CACHE to be able to read the contents from it.
5478
Reading from the trans cache with possible (per @c binlog_checksum_options)
5479
adding checksum value and then fixing the length and the end_log_pos of
5480
events prior to fill in the binlog cache.
5483
int MYSQL_BIN_LOG::write_cache(THD *thd, IO_CACHE *cache)
5485
mysql_mutex_assert_owner(&LOCK_log);
5486
if (reinit_io_cache(cache, READ_CACHE, 0, 0, 0))
5487
return ER_ERROR_ON_WRITE;
5488
uint length= my_b_bytes_in_cache(cache), group, carry, hdr_offs;
5489
ulong remains= 0; // part of unprocessed yet netto length of the event
5491
ulong end_log_pos_inc= 0; // each event processed adds BINLOG_CHECKSUM_LEN 2 t
5492
uchar header[LOG_EVENT_HEADER_LEN];
5493
ha_checksum crc= 0, crc_0= 0; // assignments to keep compiler happy
5494
my_bool do_checksum= (binlog_checksum_options != BINLOG_CHECKSUM_ALG_OFF);
5495
uchar buf[BINLOG_CHECKSUM_LEN];
5497
// while there is just one alg the following must hold:
5498
DBUG_ASSERT(!do_checksum ||
5499
binlog_checksum_options == BINLOG_CHECKSUM_ALG_CRC32);
5502
The events in the buffer have incorrect end_log_pos data
5503
(relative to beginning of group rather than absolute),
5504
so we'll recalculate them in situ so the binlog is always
5505
correct, even in the middle of a group. This is possible
5506
because we now know the start position of the group (the
5507
offset of this cache in the log, if you will); all we need
5508
to do is to find all event-headers, and add the position of
5509
the group to the end_log_pos of each event. This is pretty
5510
straight forward, except that we read the cache in segments,
5511
so an event-header might end up on the cache-border and get
5515
group= (uint)my_b_tell(&log_file);
5518
crc= crc_0= my_checksum(0L, NULL, 0);
5523
if we only got a partial header in the last iteration,
5524
get the other half now and process a full header.
5526
if (unlikely(carry > 0))
5528
DBUG_ASSERT(carry < LOG_EVENT_HEADER_LEN);
5530
/* assemble both halves */
5531
memcpy(&header[carry], (char *)cache->read_pos,
5532
LOG_EVENT_HEADER_LEN - carry);
5534
/* fix end_log_pos */
5535
val= uint4korr(&header[LOG_POS_OFFSET]) + group +
5536
(end_log_pos_inc+= (do_checksum ? BINLOG_CHECKSUM_LEN : 0));
5537
int4store(&header[LOG_POS_OFFSET], val);
5541
ulong len= uint4korr(&header[EVENT_LEN_OFFSET]);
5543
int4store(&header[EVENT_LEN_OFFSET], len + BINLOG_CHECKSUM_LEN);
5546
/* write the first half of the split header */
5547
if (my_b_write(&log_file, header, carry))
5548
return ER_ERROR_ON_WRITE;
5549
status_var_add(thd->status_var.binlog_bytes_written, carry);
5552
copy fixed second half of header to cache so the correct
5553
version will be written later.
5555
memcpy((char *)cache->read_pos, &header[carry],
5556
LOG_EVENT_HEADER_LEN - carry);
5558
/* next event header at ... */
5559
hdr_offs= uint4korr(&header[EVENT_LEN_OFFSET]) - carry -
5560
(do_checksum ? BINLOG_CHECKSUM_LEN : 0);
5564
DBUG_ASSERT(crc == crc_0 && remains == 0);
5565
crc= my_checksum(crc, header, carry);
5566
remains= uint4korr(header + EVENT_LEN_OFFSET) - carry -
5567
BINLOG_CHECKSUM_LEN;
5572
/* if there is anything to write, process it. */
5574
if (likely(length > 0))
5577
process all event-headers in this (partial) cache.
5578
if next header is beyond current read-buffer,
5579
we'll get it later (though not necessarily in the
5580
very next iteration, just "eventually").
5583
/* crc-calc the whole buffer */
5584
if (do_checksum && hdr_offs >= length)
5587
DBUG_ASSERT(remains != 0 && crc != crc_0);
5589
crc= my_checksum(crc, cache->read_pos, length);
5591
if (my_b_write(&log_file, cache->read_pos, length))
5592
return ER_ERROR_ON_WRITE;
5595
int4store(buf, crc);
5596
if (my_b_write(&log_file, buf, BINLOG_CHECKSUM_LEN))
5597
return ER_ERROR_ON_WRITE;
5602
while (hdr_offs < length)
5605
partial header only? save what we can get, process once
5614
finish off with remains of the last event that crawls
5615
from previous into the current buffer
5617
DBUG_ASSERT(crc != crc_0);
5618
crc= my_checksum(crc, cache->read_pos, hdr_offs);
5619
int4store(buf, crc);
5620
remains -= hdr_offs;
5621
DBUG_ASSERT(remains == 0);
5622
if (my_b_write(&log_file, cache->read_pos, hdr_offs) ||
5623
my_b_write(&log_file, buf, BINLOG_CHECKSUM_LEN))
5624
return ER_ERROR_ON_WRITE;
5629
if (hdr_offs + LOG_EVENT_HEADER_LEN > length)
5631
carry= length - hdr_offs;
5632
memcpy(header, (char *)cache->read_pos + hdr_offs, carry);
5637
/* we've got a full event-header, and it came in one piece */
5638
uchar *ev= (uchar *)cache->read_pos + hdr_offs;
5639
uint event_len= uint4korr(ev + EVENT_LEN_OFFSET); // netto len
5640
uchar *log_pos= ev + LOG_POS_OFFSET;
5642
/* fix end_log_pos */
5643
val= uint4korr(log_pos) + group +
5644
(end_log_pos_inc += (do_checksum ? BINLOG_CHECKSUM_LEN : 0));
5645
int4store(log_pos, val);
5651
int4store(ev + EVENT_LEN_OFFSET, event_len + BINLOG_CHECKSUM_LEN);
5652
remains= fix_log_event_crc(cache->read_pos, hdr_offs, event_len,
5654
if (my_b_write(&log_file, ev,
5655
remains == 0 ? event_len : length - hdr_offs))
5656
return ER_ERROR_ON_WRITE;
5659
int4store(buf, crc);
5660
if (my_b_write(&log_file, buf, BINLOG_CHECKSUM_LEN))
5661
return ER_ERROR_ON_WRITE;
5662
crc= crc_0; // crc is complete
5666
/* next event header at ... */
5667
hdr_offs += event_len; // incr by the netto len
5669
DBUG_ASSERT(!do_checksum || remains == 0 || hdr_offs >= length);
5674
Adjust hdr_offs. Note that it may still point beyond the segment
5675
read in the next iteration; if the current event is very long,
5676
it may take a couple of read-iterations (and subsequent adjustments
5677
of hdr_offs) for it to point into the then-current segment.
5678
If we have a split header (!carry), hdr_offs will be set at the
5679
beginning of the next iteration, overwriting the value we set here:
5684
/* Write data to the binary log file */
5685
DBUG_EXECUTE_IF("fail_binlog_write_1",
5686
errno= 28; return ER_ERROR_ON_WRITE;);
5688
if (my_b_write(&log_file, cache->read_pos, length))
5689
return ER_ERROR_ON_WRITE;
5690
status_var_add(thd->status_var.binlog_bytes_written, length);
5692
cache->read_pos=cache->read_end; // Mark buffer used up
5693
} while ((length= my_b_fill(cache)));
5695
DBUG_ASSERT(carry == 0);
5696
DBUG_ASSERT(!do_checksum || remains == 0);
5697
DBUG_ASSERT(!do_checksum || crc == crc_0);
5703
Helper function to get the error code of the query to be binlogged.
5705
int query_error_code(THD *thd, bool not_killed)
5709
if (not_killed || (killed_mask_hard(thd->killed) == KILL_BAD_DATA))
5711
error= thd->is_error() ? thd->stmt_da->sql_errno() : 0;
5713
/* thd->stmt_da->sql_errno() might be ER_SERVER_SHUTDOWN or
5714
ER_QUERY_INTERRUPTED, So here we need to make sure that error
5715
is not set to these errors when specified not_killed by the
5718
if (error == ER_SERVER_SHUTDOWN || error == ER_QUERY_INTERRUPTED ||
5719
error == ER_NEW_ABORTING_CONNECTION || error == ER_CONNECTION_KILLED)
5724
/* killed status for DELAYED INSERT thread should never be used */
5725
DBUG_ASSERT(!(thd->system_thread & SYSTEM_THREAD_DELAYED_INSERT));
5726
error= thd->killed_errno();
5733
bool MYSQL_BIN_LOG::write_incident_already_locked(THD *thd)
5736
DBUG_ENTER("MYSQL_BIN_LOG::write_incident_already_locked");
5737
Incident incident= INCIDENT_LOST_EVENTS;
5738
Incident_log_event ev(thd, incident, write_error_msg);
5740
if (likely(is_open()))
5742
error= ev.write(&log_file);
5743
status_var_add(thd->status_var.binlog_bytes_written, ev.data_written);
5750
bool MYSQL_BIN_LOG::write_incident(THD *thd)
5754
bool check_purge= false;
5755
DBUG_ENTER("MYSQL_BIN_LOG::write_incident");
5757
mysql_mutex_lock(&LOCK_log);
5758
if (likely(is_open()))
5760
if (!(error= write_incident_already_locked(thd)) &&
5761
!(error= flush_and_sync(0)))
5764
if ((error= rotate(false, &check_purge)))
5768
offset= my_b_tell(&log_file);
5770
Take mutex to protect against a reader seeing partial writes of 64-bit
5771
offset on 32-bit CPUs.
5773
mysql_mutex_lock(&LOCK_commit_ordered);
5774
last_commit_pos_offset= offset;
5775
mysql_mutex_unlock(&LOCK_commit_ordered);
5776
mysql_mutex_unlock(&LOCK_log);
5786
Write a cached log entry to the binary log.
5787
- To support transaction over replication, we wrap the transaction
5788
with BEGIN/COMMIT or BEGIN/ROLLBACK in the binary log.
5789
We want to write a BEGIN/ROLLBACK block when a non-transactional table
5790
was updated in a transaction which was rolled back. This is to ensure
5791
that the same updates are run on the slave.
5794
@param cache The cache to copy to the binlog
5795
@param commit_event The commit event to print after writing the
5796
contents of the cache.
5797
@param incident Defines if an incident event should be created to
5798
notify that some non-transactional changes did
5799
not get into the binlog.
5802
We only come here if there is something in the cache.
5804
The thing in the cache is always a complete transaction.
5806
'cache' needs to be reinitialized after this functions returns.
5810
MYSQL_BIN_LOG::write_transaction_to_binlog(THD *thd,
5811
binlog_cache_mngr *cache_mngr,
5812
Log_event *end_ev, bool all,
5813
bool using_stmt_cache,
5814
bool using_trx_cache)
5816
group_commit_entry entry;
5817
DBUG_ENTER("MYSQL_BIN_LOG::write_transaction_to_binlog");
5820
entry.cache_mngr= cache_mngr;
5823
entry.using_stmt_cache= using_stmt_cache;
5824
entry.using_trx_cache= using_trx_cache;
5827
Log "BEGIN" at the beginning of every transaction. Here, a transaction is
5828
either a BEGIN..COMMIT block or a single statement in autocommit mode.
5830
Create the necessary events here, where we have the correct THD (and
5833
Due to group commit the actual writing to binlog may happen in a different
5836
Query_log_event qinfo(thd, STRING_WITH_LEN("BEGIN"), using_trx_cache, TRUE,
5838
entry.begin_event= &qinfo;
5839
entry.end_event= end_ev;
5840
if (cache_mngr->stmt_cache.has_incident() ||
5841
cache_mngr->trx_cache.has_incident())
5843
Incident_log_event inc_ev(thd, INCIDENT_LOST_EVENTS, write_error_msg);
5844
entry.incident_event= &inc_ev;
5845
DBUG_RETURN(write_transaction_to_binlog_events(&entry));
5849
entry.incident_event= NULL;
5850
DBUG_RETURN(write_transaction_to_binlog_events(&entry));
5855
MYSQL_BIN_LOG::write_transaction_to_binlog_events(group_commit_entry *entry)
5858
To facilitate group commit for the binlog, we first queue up ourselves in
5859
the group commit queue. Then the first thread to enter the queue waits for
5860
the LOCK_log mutex, and commits for everyone in the queue once it gets the
5861
lock. Any other threads in the queue just wait for the first one to finish
5862
the commit and wake them up.
5865
entry->thd->clear_wakeup_ready();
5866
mysql_mutex_lock(&LOCK_prepare_ordered);
5867
group_commit_entry *orig_queue= group_commit_queue;
5868
entry->next= orig_queue;
5869
group_commit_queue= entry;
5871
if (entry->cache_mngr->using_xa)
5873
DEBUG_SYNC(entry->thd, "commit_before_prepare_ordered");
5874
run_prepare_ordered(entry->thd, entry->all);
5875
DEBUG_SYNC(entry->thd, "commit_after_prepare_ordered");
5877
mysql_mutex_unlock(&LOCK_prepare_ordered);
5878
DEBUG_SYNC(entry->thd, "commit_after_release_LOCK_prepare_ordered");
5881
The first in the queue handle group commit for all; the others just wait
5882
to be signalled when group commit is done.
5884
if (orig_queue != NULL)
5885
entry->thd->wait_for_wakeup_ready();
5887
trx_group_commit_leader(entry);
5889
if (!opt_optimize_thread_scheduling)
5891
/* For the leader, trx_group_commit_leader() already took the lock. */
5892
if (orig_queue != NULL)
5893
mysql_mutex_lock(&LOCK_commit_ordered);
5895
DEBUG_SYNC(entry->thd, "commit_loop_entry_commit_ordered");
5897
if (entry->cache_mngr->using_xa && !entry->error)
5898
run_commit_ordered(entry->thd, entry->all);
5900
group_commit_entry *next= entry->next;
5903
group_commit_queue_busy= FALSE;
5904
mysql_cond_signal(&COND_queue_busy);
5905
DEBUG_SYNC(entry->thd, "commit_after_group_run_commit_ordered");
5907
mysql_mutex_unlock(&LOCK_commit_ordered);
5911
next->thd->signal_wakeup_ready();
5915
if (likely(!entry->error))
5918
switch (entry->error)
5920
case ER_ERROR_ON_WRITE:
5921
my_error(ER_ERROR_ON_WRITE, MYF(ME_NOREFRESH), name, entry->commit_errno);
5923
case ER_ERROR_ON_READ:
5924
my_error(ER_ERROR_ON_READ, MYF(ME_NOREFRESH),
5925
entry->error_cache->file_name, entry->commit_errno);
5929
There are not (and should not be) any errors thrown not covered above.
5930
But just in case one is added later without updating the above switch
5931
statement, include a catch-all.
5933
my_printf_error(entry->error,
5934
"Error writing transaction to binary log: %d",
5935
MYF(ME_NOREFRESH), entry->error);
5939
Since we return error, this transaction XID will not be committed, so
5940
we need to mark it as not needed for recovery (unlog() is not called
5941
for a transaction if log_xid() fails).
5943
if (entry->cache_mngr->using_xa && entry->cache_mngr->xa_xid)
5950
Do binlog group commit as the lead thread.
5952
This must be called when this statement/transaction is queued at the start of
5953
the group_commit_queue. It will wait to obtain the LOCK_log mutex, then group
5954
commit all the transactions in the queue (more may have entered while waiting
5955
for LOCK_log). After commit is done, all other threads in the queue will be
5960
MYSQL_BIN_LOG::trx_group_commit_leader(group_commit_entry *leader)
5963
my_off_t UNINIT_VAR(commit_offset);
5964
group_commit_entry *current;
5965
group_commit_entry *last_in_queue;
5966
group_commit_entry *queue= NULL;
5967
bool check_purge= false;
5968
DBUG_ENTER("MYSQL_BIN_LOG::trx_group_commit_leader");
5970
DBUG_ASSERT(is_open());
5971
if (likely(is_open())) // Should always be true
5974
Lock the LOCK_log(), and once we get it, collect any additional writes
5975
that queued up while we were waiting.
5977
mysql_mutex_lock(&LOCK_log);
5978
DEBUG_SYNC(leader->thd, "commit_after_get_LOCK_log");
5980
mysql_mutex_lock(&LOCK_prepare_ordered);
5981
current= group_commit_queue;
5982
group_commit_queue= NULL;
5983
mysql_mutex_unlock(&LOCK_prepare_ordered);
5985
/* As the queue is in reverse order of entering, reverse it. */
5986
last_in_queue= current;
5989
group_commit_entry *next= current->next;
5990
current->next= queue;
5994
DBUG_ASSERT(leader == queue /* the leader should be first in queue */);
5996
/* Now we have in queue the list of transactions to be committed in order. */
5999
Commit every transaction in the queue.
6001
Note that we are doing this in a different thread than the one running
6002
the transaction! So we are limited in the operations we can do. In
6003
particular, we cannot call my_error() on behalf of a transaction, as
6004
that obtains the THD from thread local storage. Instead, we must set
6005
current->error and let the thread do the error reporting itself once
6008
for (current= queue; current != NULL; current= current->next)
6010
binlog_cache_mngr *cache_mngr= current->cache_mngr;
6013
We already checked before that at least one cache is non-empty; if both
6014
are empty we would have skipped calling into here.
6016
DBUG_ASSERT(!cache_mngr->stmt_cache.empty() || !cache_mngr->trx_cache.empty());
6018
current->error= write_transaction_or_stmt(current);
6020
strmake_buf(cache_mngr->last_commit_pos_file, log_file_name);
6021
commit_offset= my_b_write_tell(&log_file);
6022
cache_mngr->last_commit_pos_offset= commit_offset;
6023
if (cache_mngr->using_xa && cache_mngr->xa_xid)
6028
if (flush_and_sync(&synced))
6030
for (current= queue; current != NULL; current= current->next)
6032
if (!current->error)
6034
current->error= ER_ERROR_ON_WRITE;
6035
current->commit_errno= errno;
6036
current->error_cache= NULL;
6042
bool any_error= false;
6043
bool all_error= true;
6044
for (current= queue; current != NULL; current= current->next)
6046
if (!current->error &&
6047
RUN_HOOK(binlog_storage, after_flush,
6048
(current->thd, log_file_name,
6049
current->cache_mngr->last_commit_pos_offset, synced)))
6051
current->error= ER_ERROR_ON_WRITE;
6052
current->commit_errno= -1;
6053
current->error_cache= NULL;
6061
sql_print_error("Failed to run 'after_flush' hooks");
6067
if any commit_events are Xid_log_event, increase the number of
6068
prepared_xids (it's decreased in ::unlog()). Binlog cannot be rotated
6069
if there're prepared xids in it - see the comment in new_file() for
6071
If no Xid_log_events (then it's all Query_log_event) rotate binlog,
6076
mark_xids_active(xid_count);
6080
if (rotate(false, &check_purge))
6083
If we fail to rotate, which thread should get the error?
6084
We give the error to the *last* transaction thread; that seems to
6085
make the most sense, as it was the last to write to the log.
6087
last_in_queue->error= ER_ERROR_ON_WRITE;
6088
last_in_queue->commit_errno= errno;
6094
DEBUG_SYNC(leader->thd, "commit_before_get_LOCK_commit_ordered");
6095
mysql_mutex_lock(&LOCK_commit_ordered);
6096
last_commit_pos_offset= commit_offset;
6098
We cannot unlock LOCK_log until we have locked LOCK_commit_ordered;
6099
otherwise scheduling could allow the next group commit to run ahead of us,
6100
messing up the order of commit_ordered() calls. But as soon as
6101
LOCK_commit_ordered is obtained, we can let the next group commit start.
6103
mysql_mutex_unlock(&LOCK_log);
6108
DEBUG_SYNC(leader->thd, "commit_after_release_LOCK_log");
6109
++num_group_commits;
6111
if (!opt_optimize_thread_scheduling)
6114
If we want to run commit_ordered() each in the transaction's own thread
6115
context, then we need to mark the queue reserved; we need to finish all
6116
threads in one group commit before the next group commit can be allowed
6117
to proceed, and we cannot unlock a simple pthreads mutex in a different
6118
thread from the one that locked it.
6121
while (group_commit_queue_busy)
6122
mysql_cond_wait(&COND_queue_busy, &LOCK_commit_ordered);
6123
group_commit_queue_busy= TRUE;
6125
/* Note that we return with LOCK_commit_ordered locked! */
6130
Wakeup each participant waiting for our group commit, first calling the
6131
commit_ordered() methods for any transactions doing 2-phase commit.
6134
while (current != NULL)
6136
group_commit_entry *next;
6138
DEBUG_SYNC(leader->thd, "commit_loop_entry_commit_ordered");
6140
if (current->cache_mngr->using_xa && !current->error)
6141
run_commit_ordered(current->thd, current->all);
6144
Careful not to access current->next after waking up the other thread! As
6145
it may change immediately after wakeup.
6147
next= current->next;
6148
if (current != leader) // Don't wake up ourself
6149
current->thd->signal_wakeup_ready();
6152
DEBUG_SYNC(leader->thd, "commit_after_group_run_commit_ordered");
6153
mysql_mutex_unlock(&LOCK_commit_ordered);
6160
MYSQL_BIN_LOG::write_transaction_or_stmt(group_commit_entry *entry)
6162
binlog_cache_mngr *mngr= entry->cache_mngr;
6164
if (entry->begin_event->write(&log_file))
6165
return ER_ERROR_ON_WRITE;
6166
status_var_add(entry->thd->status_var.binlog_bytes_written,
6167
entry->begin_event->data_written);
6169
if (entry->using_stmt_cache && !mngr->stmt_cache.empty() &&
6170
write_cache(entry->thd, mngr->get_binlog_cache_log(FALSE)))
6172
entry->error_cache= &mngr->stmt_cache.cache_log;
6173
entry->commit_errno= errno;
6174
return ER_ERROR_ON_WRITE;
6177
if (entry->using_trx_cache && !mngr->trx_cache.empty())
6179
DBUG_EXECUTE_IF("crash_before_writing_xid",
6181
if ((write_cache(entry->thd,
6182
mngr->get_binlog_cache_log(TRUE))))
6183
DBUG_PRINT("info", ("error writing binlog cache"));
6187
DBUG_PRINT("info", ("crashing before writing xid"));
6191
if (write_cache(entry->thd, mngr->get_binlog_cache_log(TRUE)))
6193
entry->error_cache= &mngr->trx_cache.cache_log;
6194
entry->commit_errno= errno;
6195
return ER_ERROR_ON_WRITE;
6199
if (entry->end_event->write(&log_file))
6201
entry->error_cache= NULL;
6202
entry->commit_errno= errno;
6203
return ER_ERROR_ON_WRITE;
6205
status_var_add(entry->thd->status_var.binlog_bytes_written,
6206
entry->end_event->data_written);
6208
if (entry->incident_event)
6210
if (entry->incident_event->write(&log_file))
6212
entry->error_cache= NULL;
6213
entry->commit_errno= errno;
6214
return ER_ERROR_ON_WRITE;
6218
if (mngr->get_binlog_cache_log(FALSE)->error) // Error on read
6220
entry->error_cache= &mngr->stmt_cache.cache_log;
6221
entry->commit_errno= errno;
6222
return ER_ERROR_ON_READ;
6224
if (mngr->get_binlog_cache_log(TRUE)->error) // Error on read
6226
entry->error_cache= &mngr->trx_cache.cache_log;
6227
entry->commit_errno= errno;
6228
return ER_ERROR_ON_READ;
6235
Wait until we get a signal that the relay log has been updated.
6237
@param thd Thread variable
6240
One must have a lock on LOCK_log before calling this function.
6241
This lock will be released before return! That's required by
6242
THD::enter_cond() (see NOTES in sql_class.h).
6245
void MYSQL_BIN_LOG::wait_for_update_relay_log(THD* thd)
6247
const char *old_msg;
6248
DBUG_ENTER("wait_for_update_relay_log");
6250
old_msg= thd->enter_cond(&update_cond, &LOCK_log,
6251
"Slave has read all relay log; "
6252
"waiting for the slave I/O "
6253
"thread to update it" );
6254
mysql_cond_wait(&update_cond, &LOCK_log);
6255
thd->exit_cond(old_msg);
6260
Wait until we get a signal that the binary log has been updated.
6261
Applies to master only.
6264
@param[in] thd a THD struct
6265
@param[in] timeout a pointer to a timespec;
6266
NULL means to wait w/o timeout.
6267
@retval 0 if got signalled on update
6268
@retval non-0 if wait timeout elapsed
6270
LOCK_log must be taken before calling this function.
6271
LOCK_log is being released while the thread is waiting.
6272
LOCK_log is released by the caller.
6275
int MYSQL_BIN_LOG::wait_for_update_bin_log(THD* thd,
6276
const struct timespec *timeout)
6279
DBUG_ENTER("wait_for_update_bin_log");
6282
mysql_cond_wait(&update_cond, &LOCK_log);
6284
ret= mysql_cond_timedwait(&update_cond, &LOCK_log,
6285
const_cast<struct timespec *>(timeout));
6293
@param exiting Bitmask for one or more of the following bits:
6294
- LOG_CLOSE_INDEX : if we should close the index file
6295
- LOG_CLOSE_TO_BE_OPENED : if we intend to call open
6296
at once after close.
6297
- LOG_CLOSE_STOP_EVENT : write a 'stop' event to the log
6298
- LOG_CLOSE_DELAYED_CLOSE : do not yet close the file and clear the
6299
LOG_EVENT_BINLOG_IN_USE_F flag
6302
One can do an open on the object at once after doing a close.
6303
The internal structures are not freed until cleanup() is called
6306
void MYSQL_BIN_LOG::close(uint exiting)
6307
{ // One can't set log_type here!
6308
DBUG_ENTER("MYSQL_BIN_LOG::close");
6309
DBUG_PRINT("enter",("exiting: %d", (int) exiting));
6310
if (log_state == LOG_OPENED)
6312
#ifdef HAVE_REPLICATION
6313
if (log_type == LOG_BIN && !no_auto_events &&
6314
(exiting & LOG_CLOSE_STOP_EVENT))
6317
// the checksumming rule for relay-log case is similar to Rotate
6318
s.checksum_alg= is_relay_log ?
6319
(uint8) relay_log_checksum_alg : (uint8) binlog_checksum_options;
6320
DBUG_ASSERT(!is_relay_log ||
6321
relay_log_checksum_alg != BINLOG_CHECKSUM_ALG_UNDEF);
6323
bytes_written+= s.data_written;
6326
#endif /* HAVE_REPLICATION */
6328
/* don't pwrite in a file opened with O_APPEND - it doesn't work */
6329
if (log_file.type == WRITE_CACHE && log_type == LOG_BIN
6330
&& !(exiting & LOG_CLOSE_DELAYED_CLOSE))
6332
my_off_t org_position= mysql_file_tell(log_file.file, MYF(0));
6333
clear_inuse_flag_when_closing(log_file.file);
6335
Restore position so that anything we have in the IO_cache is written
6336
to the correct position.
6337
We need the seek here, as mysql_file_pwrite() is not guaranteed to keep the
6338
original position on system that doesn't support pwrite().
6340
mysql_file_seek(log_file.file, org_position, MY_SEEK_SET, MYF(0));
6343
/* this will cleanup IO_CACHE, sync and close the file */
6344
MYSQL_LOG::close(exiting);
6348
The following test is needed even if is_open() is not set, as we may have
6349
called a not complete close earlier and the index file is still open.
6352
if ((exiting & LOG_CLOSE_INDEX) && my_b_inited(&index_file))
6354
end_io_cache(&index_file);
6355
if (mysql_file_close(index_file.file, MYF(0)) < 0 && ! write_error)
6358
sql_print_error(ER(ER_ERROR_ON_WRITE), index_file_name, errno);
6361
log_state= (exiting & LOG_CLOSE_TO_BE_OPENED) ? LOG_TO_BE_OPENED : LOG_CLOSED;
6369
Clear the LOG_EVENT_BINLOG_IN_USE_F; this marks the binlog file as cleanly
6370
closed and not needing crash recovery.
6372
void MYSQL_BIN_LOG::clear_inuse_flag_when_closing(File file)
6374
my_off_t offset= BIN_LOG_HEADER_SIZE + FLAGS_OFFSET;
6375
uchar flags= 0; // clearing LOG_EVENT_BINLOG_IN_USE_F
6376
mysql_file_pwrite(file, &flags, 1, offset, MYF(0));
6380
void MYSQL_BIN_LOG::set_max_size(ulong max_size_arg)
6383
We need to take locks, otherwise this may happen:
6384
new_file() is called, calls open(old_max_size), then before open() starts,
6385
set_max_size() sets max_size to max_size_arg, then open() starts and
6386
uses the old_max_size argument, so max_size_arg has been overwritten and
6387
it's like if the SET command was never run.
6389
DBUG_ENTER("MYSQL_BIN_LOG::set_max_size");
6390
mysql_mutex_lock(&LOCK_log);
6392
max_size= max_size_arg;
6393
mysql_mutex_unlock(&LOCK_log);
6399
Check if a string is a valid number.
6401
@param str String to test
6402
@param res Store value here
6403
@param allow_wildcards Set to 1 if we should ignore '%' and '_'
6406
For the moment the allow_wildcards argument is not used
6407
Should be move to some other file.
6410
1 String is a number
6412
0 String is not a number
6415
static bool test_if_number(register const char *str,
6416
ulong *res, bool allow_wildcards)
6420
DBUG_ENTER("test_if_number");
6423
while (*str++ == ' ') ;
6424
if (*--str == '-' || *str == '+')
6426
while (my_isdigit(files_charset_info,*str) ||
6427
(allow_wildcards && (*str == wild_many || *str == wild_one)))
6435
my_isdigit(files_charset_info,*str) ||
6436
(allow_wildcards && (*str == wild_many || *str == wild_one)) ;
6439
if (*str != 0 || flag == 0)
6443
DBUG_RETURN(1); /* Number ok */
6444
} /* test_if_number */
6447
void sql_perror(const char *message)
6451
DWORD dw= GetLastError();
6452
if (FormatMessage(FORMAT_MESSAGE_ALLOCATE_BUFFER | FORMAT_MESSAGE_FROM_SYSTEM |
6453
FORMAT_MESSAGE_IGNORE_INSERTS, NULL, dw,
6454
MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT), (LPSTR)&buf, 0, NULL ) > 0)
6456
sql_print_error("%s: %s",message, buf);
6457
LocalFree((HLOCAL)buf);
6461
sql_print_error("%s", message);
6463
#elif defined(HAVE_STRERROR)
6464
sql_print_error("%s: %s",message, strerror(errno));
6472
Change the file associated with two output streams. Used to
6473
redirect stdout and stderr to a file. The streams are reopened
6474
only for appending (writing at end of file).
6476
extern "C" my_bool reopen_fstreams(const char *filename,
6477
FILE *outstream, FILE *errstream)
6479
if (outstream && !my_freopen(filename, "a", outstream))
6482
if (errstream && !my_freopen(filename, "a", errstream))
6485
/* The error stream must be unbuffered. */
6487
setbuf(errstream, NULL);
6494
Unfortunately, there seems to be no good way
6495
to restore the original streams upon failure.
6497
static bool redirect_std_streams(const char *file)
6499
if (reopen_fstreams(file, stdout, stderr))
6502
setbuf(stderr, NULL);
6507
bool flush_error_log()
6512
mysql_mutex_lock(&LOCK_error_log);
6513
if (redirect_std_streams(log_error_file))
6515
mysql_mutex_unlock(&LOCK_error_log);
6520
void MYSQL_BIN_LOG::signal_update()
6522
DBUG_ENTER("MYSQL_BIN_LOG::signal_update");
6524
mysql_cond_broadcast(&update_cond);
6529
static void print_buffer_to_nt_eventlog(enum loglevel level, char *buff,
6530
size_t length, size_t buffLen)
6533
char *buffptr= buff;
6534
DBUG_ENTER("print_buffer_to_nt_eventlog");
6536
/* Add ending CR/LF's to string, overwrite last chars if necessary */
6537
strmov(buffptr+min(length, buffLen-5), "\r\n\r\n");
6539
setup_windows_event_source();
6540
if ((event= RegisterEventSource(NULL,"MySQL")))
6544
ReportEvent(event, EVENTLOG_ERROR_TYPE, 0, MSG_DEFAULT, NULL, 1, 0,
6545
(LPCSTR*)&buffptr, NULL);
6548
ReportEvent(event, EVENTLOG_WARNING_TYPE, 0, MSG_DEFAULT, NULL, 1, 0,
6549
(LPCSTR*) &buffptr, NULL);
6551
case INFORMATION_LEVEL:
6552
ReportEvent(event, EVENTLOG_INFORMATION_TYPE, 0, MSG_DEFAULT, NULL, 1,
6553
0, (LPCSTR*) &buffptr, NULL);
6556
DeregisterEventSource(event);
6564
#ifndef EMBEDDED_LIBRARY
6565
static void print_buffer_to_file(enum loglevel level, const char *buffer,
6571
DBUG_ENTER("print_buffer_to_file");
6572
DBUG_PRINT("enter",("buffer: %s", buffer));
6574
mysql_mutex_lock(&LOCK_error_log);
6577
localtime_r(&skr, &tm_tmp);
6580
fprintf(stderr, "%02d%02d%02d %2d:%02d:%02d [%s] %.*s\n",
6581
start->tm_year % 100,
6587
(level == ERROR_LEVEL ? "ERROR" : level == WARNING_LEVEL ?
6588
"Warning" : "Note"),
6589
(int) length, buffer);
6593
mysql_mutex_unlock(&LOCK_error_log);
6598
Prints a printf style message to the error log and, under NT, to the
6601
This function prints the message into a buffer and then sends that buffer
6602
to other functions to write that message to other logging sources.
6604
@param level The level of the msg significance
6605
@param format Printf style format of message
6606
@param args va_list list of arguments for the message
6609
The function always returns 0. The return value is present in the
6610
signature to be compatible with other logging routines, which could
6611
return an error (e.g. logging to the log tables)
6613
int vprint_msg_to_log(enum loglevel level, const char *format, va_list args)
6617
DBUG_ENTER("vprint_msg_to_log");
6619
length= my_vsnprintf(buff, sizeof(buff), format, args);
6620
print_buffer_to_file(level, buff, length);
6623
print_buffer_to_nt_eventlog(level, buff, length, sizeof(buff));
6628
#endif /* EMBEDDED_LIBRARY */
6631
void sql_print_error(const char *format, ...)
6634
DBUG_ENTER("sql_print_error");
6636
va_start(args, format);
6637
error_log_print(ERROR_LEVEL, format, args);
6644
void sql_print_warning(const char *format, ...)
6647
DBUG_ENTER("sql_print_warning");
6649
va_start(args, format);
6650
error_log_print(WARNING_LEVEL, format, args);
6657
void sql_print_information(const char *format, ...)
6660
DBUG_ENTER("sql_print_information");
6662
va_start(args, format);
6663
error_log_print(INFORMATION_LEVEL, format, args);
6671
TC_LOG::run_prepare_ordered(THD *thd, bool all)
6673
Ha_trx_info *ha_info=
6674
all ? thd->transaction.all.ha_list : thd->transaction.stmt.ha_list;
6676
mysql_mutex_assert_owner(&LOCK_prepare_ordered);
6677
for (; ha_info; ha_info= ha_info->next())
6679
handlerton *ht= ha_info->ht();
6680
if (!ht->prepare_ordered)
6682
ht->prepare_ordered(ht, thd, all);
6688
TC_LOG::run_commit_ordered(THD *thd, bool all)
6690
Ha_trx_info *ha_info=
6691
all ? thd->transaction.all.ha_list : thd->transaction.stmt.ha_list;
6693
mysql_mutex_assert_owner(&LOCK_commit_ordered);
6694
for (; ha_info; ha_info= ha_info->next())
6696
handlerton *ht= ha_info->ht();
6697
if (!ht->commit_ordered)
6699
ht->commit_ordered(ht, thd, all);
6700
DEBUG_SYNC(thd, "commit_after_run_commit_ordered");
6705
int TC_LOG_MMAP::log_and_order(THD *thd, my_xid xid, bool all,
6706
bool need_prepare_ordered,
6707
bool need_commit_ordered)
6710
struct commit_entry entry;
6711
bool is_group_commit_leader;
6712
LINT_INIT(is_group_commit_leader);
6714
if (need_prepare_ordered)
6716
mysql_mutex_lock(&LOCK_prepare_ordered);
6717
run_prepare_ordered(thd, all);
6718
if (need_commit_ordered)
6721
Must put us in queue so we can run_commit_ordered() in same sequence
6722
as we did run_prepare_ordered().
6724
thd->clear_wakeup_ready();
6726
commit_entry *previous_queue= commit_ordered_queue;
6727
entry.next= previous_queue;
6728
commit_ordered_queue= &entry;
6729
is_group_commit_leader= (previous_queue == NULL);
6731
mysql_mutex_unlock(&LOCK_prepare_ordered);
6736
cookie= log_one_transaction(xid);
6738
if (need_commit_ordered)
6740
if (need_prepare_ordered)
6743
We did the run_prepare_ordered() serialised, then ran the log_xid() in
6744
parallel. Now we have to do run_commit_ordered() serialised in the
6745
same sequence as run_prepare_ordered().
6747
We do this starting from the head of the queue, each thread doing
6748
run_commit_ordered() and signalling the next in queue.
6750
if (is_group_commit_leader)
6752
/* The first in queue starts the ball rolling. */
6753
mysql_mutex_lock(&LOCK_prepare_ordered);
6754
while (commit_ordered_queue_busy)
6755
mysql_cond_wait(&COND_queue_busy, &LOCK_prepare_ordered);
6756
commit_entry *queue= commit_ordered_queue;
6757
commit_ordered_queue= NULL;
6759
Mark the queue busy while we bounce it from one thread to the
6762
commit_ordered_queue_busy= true;
6763
mysql_mutex_unlock(&LOCK_prepare_ordered);
6765
/* Reverse the queue list so we get correct order. */
6766
commit_entry *prev= NULL;
6769
commit_entry *next= queue->next;
6774
DBUG_ASSERT(prev == &entry && prev->thd == thd);
6778
/* Not first in queue; just wait until previous thread wakes us up. */
6779
thd->wait_for_wakeup_ready();
6783
/* Only run commit_ordered() if log_xid was successful. */
6786
mysql_mutex_lock(&LOCK_commit_ordered);
6787
run_commit_ordered(thd, all);
6788
mysql_mutex_unlock(&LOCK_commit_ordered);
6791
if (need_prepare_ordered)
6793
commit_entry *next= entry.next;
6796
next->thd->signal_wakeup_ready();
6800
mysql_mutex_lock(&LOCK_prepare_ordered);
6801
commit_ordered_queue_busy= false;
6802
mysql_cond_signal(&COND_queue_busy);
6803
mysql_mutex_unlock(&LOCK_prepare_ordered);
6812
/********* transaction coordinator log for 2pc - mmap() based solution *******/
6815
the log consists of a file, mapped to memory.
6816
file is divided into pages of tc_log_page_size size.
6817
(usable size of the first page is smaller because of the log header)
6818
there is a PAGE control structure for each page
6819
each page (or rather its PAGE control structure) can be in one of
6820
the three states - active, syncing, pool.
6821
there could be only one page in the active or syncing state,
6822
but many in pool - pool is a fifo queue.
6823
the usual lifecycle of a page is pool->active->syncing->pool.
6824
the "active" page is a page where new xid's are logged.
6825
the page stays active as long as the syncing slot is taken.
6826
the "syncing" page is being synced to disk. no new xid can be added to it.
6827
when the syncing is done the page is moved to a pool and an active page
6830
the result of such an architecture is a natural "commit grouping" -
6831
If commits are coming faster than the system can sync, they do not
6832
stall. Instead, all commits that came since the last sync are
6833
logged to the same "active" page, and they all are synced with the next -
6834
one - sync. Thus, thought individual commits are delayed, throughput
6837
when an xid is added to an active page, the thread of this xid waits
6838
for a page's condition until the page is synced. when syncing slot
6839
becomes vacant one of these waiters is awaken to take care of syncing.
6840
it syncs the page and signals all waiters that the page is synced.
6841
PAGE::waiters is used to count these waiters, and a page may never
6842
become active again until waiters==0 (that is all waiters from the
6843
previous sync have noticed that the sync was completed)
6845
note, that the page becomes "dirty" and has to be synced only when a
6846
new xid is added into it. Removing a xid from a page does not make it
6847
dirty - we don't sync xid removals to disk.
6850
ulong tc_log_page_waits= 0;
6854
#define TC_LOG_HEADER_SIZE (sizeof(tc_log_magic)+1)
6856
static const uchar tc_log_magic[]={(uchar) 254, 0x23, 0x05, 0x74};
6858
ulong opt_tc_log_size= TC_LOG_MIN_SIZE;
6859
ulong tc_log_max_pages_used=0, tc_log_page_size=0, tc_log_cur_pages_used=0;
6861
int TC_LOG_MMAP::open(const char *opt_name)
6867
DBUG_ASSERT(total_ha_2pc > 1);
6868
DBUG_ASSERT(opt_name && opt_name[0]);
6870
tc_log_page_size= my_getpagesize();
6871
DBUG_ASSERT(TC_LOG_PAGE_SIZE % tc_log_page_size == 0);
6873
fn_format(logname,opt_name,mysql_data_home,"",MY_UNPACK_FILENAME);
6874
if ((fd= mysql_file_open(key_file_tclog, logname, O_RDWR, MYF(0))) < 0)
6876
if (my_errno != ENOENT)
6878
if (using_heuristic_recover())
6880
if ((fd= mysql_file_create(key_file_tclog, logname, CREATE_MODE,
6881
O_RDWR, MYF(MY_WME))) < 0)
6884
file_length= opt_tc_log_size;
6885
if (mysql_file_chsize(fd, file_length, 0, MYF(MY_WME)))
6892
sql_print_information("Recovering after a crash using %s", opt_name);
6893
if (tc_heuristic_recover)
6895
sql_print_error("Cannot perform automatic crash recovery when "
6896
"--tc-heuristic-recover is used");
6899
file_length= mysql_file_seek(fd, 0L, MY_SEEK_END, MYF(MY_WME+MY_FAE));
6900
if (file_length == MY_FILEPOS_ERROR || file_length % tc_log_page_size)
6904
data= (uchar *)my_mmap(0, (size_t)file_length, PROT_READ|PROT_WRITE,
6905
MAP_NOSYNC|MAP_SHARED, fd, 0);
6906
if (data == MAP_FAILED)
6913
npages=(uint)file_length/tc_log_page_size;
6914
if (npages < 3) // to guarantee non-empty pool
6916
if (!(pages=(PAGE *)my_malloc(npages*sizeof(PAGE), MYF(MY_WME|MY_ZEROFILL))))
6919
for (pg=pages, i=0; i < npages; i++, pg++)
6924
mysql_mutex_init(key_PAGE_lock, &pg->lock, MY_MUTEX_INIT_FAST);
6925
mysql_cond_init(key_PAGE_cond, &pg->cond, 0);
6926
pg->ptr= pg->start=(my_xid *)(data + i*tc_log_page_size);
6927
pg->size=pg->free=tc_log_page_size/sizeof(my_xid);
6928
pg->end=pg->start + pg->size;
6930
pages[0].size=pages[0].free=
6931
(tc_log_page_size-TC_LOG_HEADER_SIZE)/sizeof(my_xid);
6932
pages[0].start=pages[0].end-pages[0].size;
6933
pages[npages-1].next=0;
6936
if (crashed && recover())
6939
memcpy(data, tc_log_magic, sizeof(tc_log_magic));
6940
data[sizeof(tc_log_magic)]= (uchar)total_ha_2pc;
6941
my_msync(fd, data, tc_log_page_size, MS_SYNC);
6944
mysql_mutex_init(key_LOCK_sync, &LOCK_sync, MY_MUTEX_INIT_FAST);
6945
mysql_mutex_init(key_LOCK_active, &LOCK_active, MY_MUTEX_INIT_FAST);
6946
mysql_mutex_init(key_LOCK_pool, &LOCK_pool, MY_MUTEX_INIT_FAST);
6947
mysql_cond_init(key_COND_active, &COND_active, 0);
6948
mysql_cond_init(key_COND_pool, &COND_pool, 0);
6949
mysql_cond_init(key_TC_LOG_MMAP_COND_queue_busy, &COND_queue_busy, 0);
6955
DBUG_ASSERT(npages >= 2);
6957
pool_last_ptr= &((pages+npages-1)->next);
6958
commit_ordered_queue= NULL;
6959
commit_ordered_queue_busy= false;
6969
there is no active page, let's got one from the pool.
6971
Two strategies here:
6972
-# take the first from the pool
6973
-# if there're waiters - take the one with the most free space.
6976
page merging. try to allocate adjacent page first,
6977
so that they can be flushed both in one sync
6980
void TC_LOG_MMAP::get_active_from_pool()
6982
PAGE **p, **best_p=0;
6985
mysql_mutex_lock(&LOCK_pool);
6990
if ((*p)->waiters == 0 && (*p)->free > 0) // can the first page be used ?
6991
break; // yes - take it.
6993
best_free=0; // no - trying second strategy
6994
for (p=&(*p)->next; *p; p=&(*p)->next)
6996
if ((*p)->waiters == 0 && (*p)->free > best_free)
6998
best_free=(*p)->free;
7003
while ((*best_p == 0 || best_free == 0) && overflow());
7005
mysql_mutex_assert_owner(&LOCK_active);
7008
/* Unlink the page from the pool. */
7009
if (!(*best_p)->next)
7010
pool_last_ptr= best_p;
7011
*best_p=(*best_p)->next;
7012
mysql_mutex_unlock(&LOCK_pool);
7014
mysql_mutex_lock(&active->lock);
7015
if (active->free == active->size) // we've chosen an empty page
7017
tc_log_cur_pages_used++;
7018
set_if_bigger(tc_log_max_pages_used, tc_log_cur_pages_used);
7024
perhaps, increase log size ?
7026
int TC_LOG_MMAP::overflow()
7029
simple overflow handling - just wait
7030
TODO perhaps, increase log size ?
7031
let's check the behaviour of tc_log_page_waits first
7033
tc_log_page_waits++;
7034
mysql_cond_wait(&COND_pool, &LOCK_pool);
7035
return 1; // always return 1
7039
Record that transaction XID is committed on the persistent storage.
7041
This function is called in the middle of two-phase commit:
7042
First all resources prepare the transaction, then tc_log->log() is called,
7043
then all resources commit the transaction, then tc_log->unlog() is called.
7045
All access to active page is serialized but it's not a problem, as
7046
we're assuming that fsync() will be a main bottleneck.
7047
That is, parallelizing writes to log pages we'll decrease number of
7048
threads waiting for a page, but then all these threads will be waiting
7049
for a fsync() anyway
7051
If tc_log == MYSQL_LOG then tc_log writes transaction to binlog and
7052
records XID in a special Xid_log_event.
7053
If tc_log = TC_LOG_MMAP then xid is written in a special memory-mapped
7059
\# - otherwise, "cookie", a number that will be passed as an argument
7060
to unlog() call. tc_log can define it any way it wants,
7061
and use for whatever purposes. TC_LOG_MMAP sets it
7062
to the position in memory where xid was logged to.
7065
int TC_LOG_MMAP::log_one_transaction(my_xid xid)
7071
mysql_mutex_lock(&LOCK_active);
7074
if the active page is full - just wait...
7075
frankly speaking, active->free here accessed outside of mutex
7076
protection, but it's safe, because it only means we may miss an
7077
unlog() for the active page, and we're not waiting for it here -
7078
unlog() does not signal COND_active.
7080
while (unlikely(active && active->free == 0))
7081
mysql_cond_wait(&COND_active, &LOCK_active);
7083
/* no active page ? take one from the pool */
7085
get_active_from_pool();
7087
mysql_mutex_lock(&active->lock);
7092
p->free is always > 0 here because to decrease it one needs
7093
to take p->lock and before it one needs to take LOCK_active.
7094
But checked that active->free > 0 under LOCK_active and
7095
haven't release it ever since
7098
/* searching for an empty slot */
7102
DBUG_ASSERT(p->ptr < p->end); // because p->free > 0
7105
/* found! store xid there and mark the page dirty */
7106
cookie= (ulong)((uchar *)p->ptr - data); // can never be zero
7110
mysql_mutex_unlock(&p->lock);
7112
mysql_mutex_lock(&LOCK_sync);
7114
{ // somebody's syncing. let's wait
7115
mysql_mutex_unlock(&LOCK_active);
7116
mysql_mutex_lock(&p->lock);
7118
while (p->state == PS_DIRTY && syncing)
7120
mysql_mutex_unlock(&p->lock);
7121
mysql_cond_wait(&p->cond, &LOCK_sync);
7122
mysql_mutex_lock(&p->lock);
7125
err= p->state == PS_ERROR;
7126
if (p->state != PS_DIRTY) // page was synced
7128
mysql_mutex_unlock(&LOCK_sync);
7129
if (p->waiters == 0)
7130
mysql_cond_signal(&COND_pool); // in case somebody's waiting
7131
mysql_mutex_unlock(&p->lock);
7132
goto done; // we're done
7134
DBUG_ASSERT(!syncing);
7135
mysql_mutex_unlock(&p->lock);
7137
mysql_mutex_unlock(&LOCK_sync);
7139
mysql_mutex_lock(&LOCK_active);
7140
active=0; // page is not active anymore
7141
mysql_cond_broadcast(&COND_active);
7142
mysql_mutex_unlock(&LOCK_active);
7146
syncing = p; // place is vacant - take it
7147
mysql_mutex_unlock(&LOCK_sync);
7148
active = 0; // page is not active anymore
7149
mysql_cond_broadcast(&COND_active);
7150
mysql_mutex_unlock(&LOCK_active);
7155
return err ? 0 : cookie;
7158
int TC_LOG_MMAP::sync()
7162
DBUG_ASSERT(syncing != active);
7165
sit down and relax - this can take a while...
7166
note - no locks are held at this point
7168
err= my_msync(fd, syncing->start, syncing->size * sizeof(my_xid), MS_SYNC);
7170
/* page is synced. let's move it to the pool */
7171
mysql_mutex_lock(&LOCK_pool);
7172
(*pool_last_ptr)=syncing;
7173
pool_last_ptr=&(syncing->next);
7175
syncing->state= err ? PS_ERROR : PS_POOL;
7176
mysql_cond_signal(&COND_pool); // in case somebody's waiting
7177
mysql_mutex_unlock(&LOCK_pool);
7179
/* marking 'syncing' slot free */
7180
mysql_mutex_lock(&LOCK_sync);
7181
mysql_cond_broadcast(&syncing->cond); // signal "sync done"
7184
we check the "active" pointer without LOCK_active. Still, it's safe -
7185
"active" can change from NULL to not NULL any time, but it
7186
will take LOCK_sync before waiting on active->cond. That is, it can never
7188
And "active" can change to NULL only by the syncing thread
7189
(the thread that will send a signal below)
7192
mysql_cond_signal(&active->cond); // wake up a new syncer
7193
mysql_mutex_unlock(&LOCK_sync);
7198
erase xid from the page, update page free space counters/pointers.
7199
cookie points directly to the memory where xid was logged.
7202
int TC_LOG_MMAP::unlog(ulong cookie, my_xid xid)
7204
PAGE *p=pages+(cookie/tc_log_page_size);
7205
my_xid *x=(my_xid *)(data+cookie);
7207
DBUG_ASSERT(*x == xid);
7208
DBUG_ASSERT(x >= p->start && x < p->end);
7210
mysql_mutex_lock(&p->lock);
7213
DBUG_ASSERT(p->free <= p->size);
7214
set_if_smaller(p->ptr, x);
7215
if (p->free == p->size) // the page is completely empty
7216
statistic_decrement(tc_log_cur_pages_used, &LOCK_status);
7217
if (p->waiters == 0) // the page is in pool and ready to rock
7218
mysql_cond_signal(&COND_pool); // ping ... for overflow()
7219
mysql_mutex_unlock(&p->lock);
7223
void TC_LOG_MMAP::close()
7228
mysql_mutex_destroy(&LOCK_sync);
7229
mysql_mutex_destroy(&LOCK_active);
7230
mysql_mutex_destroy(&LOCK_pool);
7231
mysql_cond_destroy(&COND_pool);
7232
mysql_cond_destroy(&COND_active);
7233
mysql_cond_destroy(&COND_queue_busy);
7235
data[0]='A'; // garble the first (signature) byte, in case mysql_file_delete fails
7237
for (i=0; i < npages; i++)
7239
if (pages[i].ptr == 0)
7241
mysql_mutex_destroy(&pages[i].lock);
7242
mysql_cond_destroy(&pages[i].cond);
7247
my_munmap((char*)data, (size_t)file_length);
7249
mysql_file_close(fd, MYF(0));
7251
if (inited>=5) // cannot do in the switch because of Windows
7252
mysql_file_delete(key_file_tclog, logname, MYF(MY_WME));
7256
int TC_LOG_MMAP::recover()
7259
PAGE *p=pages, *end_p=pages+npages;
7261
if (bcmp(data, tc_log_magic, sizeof(tc_log_magic)))
7263
sql_print_error("Bad magic header in tc log");
7268
the first byte after magic signature is set to current
7269
number of storage engines on startup
7271
if (data[sizeof(tc_log_magic)] != total_ha_2pc)
7273
sql_print_error("Recovery failed! You must enable "
7274
"exactly %d storage engines that support "
7275
"two-phase commit protocol",
7276
data[sizeof(tc_log_magic)]);
7280
if (my_hash_init(&xids, &my_charset_bin, tc_log_page_size/3, 0,
7281
sizeof(my_xid), 0, 0, MYF(0)))
7284
for ( ; p < end_p ; p++)
7286
for (my_xid *x=p->start; x < p->end; x++)
7287
if (*x && my_hash_insert(&xids, (uchar *)x))
7291
if (ha_recover(&xids))
7294
my_hash_free(&xids);
7295
bzero(data, (size_t)file_length);
7299
my_hash_free(&xids);
7301
sql_print_error("Crash recovery failed. Either correct the problem "
7302
"(if it's, for example, out of memory error) and restart, "
7303
"or delete tc log and start mysqld with "
7304
"--tc-heuristic-recover={commit|rollback}");
7310
TC_LOG_DUMMY tc_log_dummy;
7311
TC_LOG_MMAP tc_log_mmap;
7314
Perform heuristic recovery, if --tc-heuristic-recover was used.
7317
no matter whether heuristic recovery was successful or not
7318
mysqld must exit. So, return value is the same in both cases.
7321
0 no heuristic recovery was requested
7323
1 heuristic recovery was performed
7326
int TC_LOG::using_heuristic_recover()
7328
if (!tc_heuristic_recover)
7331
sql_print_information("Heuristic crash recovery mode");
7333
sql_print_error("Heuristic crash recovery failed");
7334
sql_print_information("Please restart mysqld without --tc-heuristic-recover");
7338
/****** transaction coordinator log for 2pc - binlog() based solution ******/
7339
#define TC_LOG_BINLOG MYSQL_BIN_LOG
7343
keep in-memory list of prepared transactions
7344
(add to list in log(), remove on unlog())
7345
and copy it to the new binlog if rotated
7346
but let's check the behaviour of tc_log_page_waits first!
7349
int TC_LOG_BINLOG::open(const char *opt_name)
7354
DBUG_ASSERT(total_ha_2pc > 1);
7355
DBUG_ASSERT(opt_name && opt_name[0]);
7357
mysql_mutex_init(key_BINLOG_LOCK_prep_xids,
7358
&LOCK_prep_xids, MY_MUTEX_INIT_FAST);
7359
mysql_cond_init(key_BINLOG_COND_prep_xids, &COND_prep_xids, 0);
7361
if (!my_b_inited(&index_file))
7363
/* There was a failure to open the index file, can't open the binlog */
7368
if (using_heuristic_recover())
7370
/* generate a new binlog to mask a corrupted one */
7371
open(opt_name, LOG_BIN, 0, WRITE_CACHE, 0, max_binlog_size, 0, TRUE);
7376
if ((error= find_log_pos(&log_info, NullS, 1)))
7378
if (error != LOG_INFO_EOF)
7379
sql_print_error("find_log_pos() failed (error: %d)", error);
7390
Format_description_log_event fdle(BINLOG_VERSION);
7391
char log_name[FN_REFLEN];
7393
if (! fdle.is_valid())
7398
strmake_buf(log_name, log_info.log_file_name);
7399
} while (!(error= find_next_log(&log_info, 1)));
7401
if (error != LOG_INFO_EOF)
7403
sql_print_error("find_log_pos() failed (error: %d)", error);
7407
if ((file= open_binlog(&log, log_name, &errmsg)) < 0)
7409
sql_print_error("%s", errmsg);
7413
if ((ev= Log_event::read_log_event(&log, 0, &fdle,
7414
opt_master_verify_checksum)) &&
7415
ev->get_type_code() == FORMAT_DESCRIPTION_EVENT &&
7416
ev->flags & LOG_EVENT_BINLOG_IN_USE_F)
7418
sql_print_information("Recovering after a crash using %s", opt_name);
7419
error= recover(&log, (Format_description_log_event *)ev);
7426
mysql_file_close(file, MYF(MY_WME));
7436
/** This is called on shutdown, after ha_panic. */
7437
void TC_LOG_BINLOG::close()
7439
DBUG_ASSERT(prepared_xids==0);
7440
mysql_mutex_destroy(&LOCK_prep_xids);
7441
mysql_cond_destroy(&COND_prep_xids);
7445
Do a binlog log_xid() for a group of transactions, linked through
7446
thd->next_commit_ordered.
7449
TC_LOG_BINLOG::log_and_order(THD *thd, my_xid xid, bool all,
7450
bool need_prepare_ordered __attribute__((unused)),
7451
bool need_commit_ordered __attribute__((unused)))
7454
DBUG_ENTER("TC_LOG_BINLOG::log_and_order");
7456
binlog_cache_mngr *cache_mngr= thd->binlog_setup_trx_data();
7460
cache_mngr->using_xa= TRUE;
7461
cache_mngr->xa_xid= xid;
7462
err= binlog_commit_flush_xid_caches(thd, cache_mngr, all, xid);
7464
DEBUG_SYNC(thd, "binlog_after_log_and_order");
7470
After an XID is logged, we need to hold on to the current binlog file until
7471
it is fully committed in the storage engine. The reason is that crash
7472
recovery only looks at the latest binlog, so we must make sure there are no
7473
outstanding prepared (but not committed) transactions before rotating the
7476
To handle this, we keep a count of outstanding XIDs. This function is used
7477
to increase this count when committing one or more transactions to the
7481
TC_LOG_BINLOG::mark_xids_active(uint xid_count)
7483
DBUG_ENTER("TC_LOG_BINLOG::mark_xids_active");
7484
DBUG_PRINT("info", ("xid_count=%u", xid_count));
7485
mysql_mutex_lock(&LOCK_prep_xids);
7486
prepared_xids+= xid_count;
7487
mysql_mutex_unlock(&LOCK_prep_xids);
7492
Once an XID is committed, it is safe to rotate the binary log, as it can no
7493
longer be needed during crash recovery.
7495
This function is called to mark an XID this way. It needs to decrease the
7496
count of pending XIDs, and signal the log rotator thread when it reaches zero.
7499
TC_LOG_BINLOG::mark_xid_done()
7501
my_bool send_signal;
7503
DBUG_ENTER("TC_LOG_BINLOG::mark_xid_done");
7504
mysql_mutex_lock(&LOCK_prep_xids);
7505
// prepared_xids can be 0 if the transaction had ignorable errors.
7506
DBUG_ASSERT(prepared_xids >= 0);
7507
if (prepared_xids > 0)
7509
send_signal= (prepared_xids == 0);
7510
mysql_mutex_unlock(&LOCK_prep_xids);
7512
DBUG_PRINT("info", ("prepared_xids=%lu", prepared_xids));
7513
mysql_cond_signal(&COND_prep_xids);
7518
int TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid)
7520
DBUG_ENTER("TC_LOG_BINLOG::unlog");
7523
/* As ::write_transaction_to_binlog() did not rotate, do it here. */
7524
DBUG_RETURN(rotate_and_purge(0));
7527
int TC_LOG_BINLOG::recover(IO_CACHE *log, Format_description_log_event *fdle)
7533
if (! fdle->is_valid() ||
7534
my_hash_init(&xids, &my_charset_bin, TC_LOG_PAGE_SIZE/3, 0,
7535
sizeof(my_xid), 0, 0, MYF(0)))
7538
init_alloc_root(&mem_root, TC_LOG_PAGE_SIZE, TC_LOG_PAGE_SIZE);
7540
fdle->flags&= ~LOG_EVENT_BINLOG_IN_USE_F; // abort on the first error
7542
while ((ev= Log_event::read_log_event(log, 0, fdle,
7543
opt_master_verify_checksum))
7546
if (ev->get_type_code() == XID_EVENT)
7548
Xid_log_event *xev=(Xid_log_event *)ev;
7549
uchar *x= (uchar *) memdup_root(&mem_root, (uchar*) &xev->xid,
7551
if (!x || my_hash_insert(&xids, x))
7557
if (ha_recover(&xids))
7560
free_root(&mem_root, MYF(0));
7561
my_hash_free(&xids);
7565
free_root(&mem_root, MYF(0));
7566
my_hash_free(&xids);
7568
sql_print_error("Crash recovery failed. Either correct the problem "
7569
"(if it's, for example, out of memory error) and restart, "
7570
"or delete (or rename) binary log and start mysqld with "
7571
"--tc-heuristic-recover={commit|rollback}");
7576
#ifdef INNODB_COMPATIBILITY_HOOKS
7578
Get the file name of the MySQL binlog.
7579
@return the name of the binlog file
7582
const char* mysql_bin_log_file_name(void)
7584
return mysql_bin_log.get_log_fname();
7587
Get the current position of the MySQL binlog.
7588
@return byte offset from the beginning of the binlog
7591
ulonglong mysql_bin_log_file_pos(void)
7593
return (ulonglong) mysql_bin_log.get_log_file()->pos_in_file;
7596
Get the current position of the MySQL binlog for transaction currently being
7599
This is valid to call from within storage engine commit_ordered() and
7600
commit() methods only.
7602
Since it stores the position inside THD, it is safe to call without any
7606
mysql_bin_log_commit_pos(THD *thd, ulonglong *out_pos, const char **out_file)
7608
binlog_cache_mngr *cache_mngr;
7610
(cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton)))
7612
*out_file= cache_mngr->last_commit_pos_file;
7613
*out_pos= (ulonglong)(cache_mngr->last_commit_pos_offset);
7621
#endif /* INNODB_COMPATIBILITY_HOOKS */
7625
binlog_checksum_update(MYSQL_THD thd, struct st_mysql_sys_var *var,
7626
void *var_ptr, const void *save)
7628
ulong value= *((ulong *)save);
7629
bool check_purge= false;
7631
mysql_mutex_lock(mysql_bin_log.get_log_lock());
7632
if(mysql_bin_log.is_open())
7634
if (binlog_checksum_options != value)
7635
mysql_bin_log.checksum_alg_reset= (uint8) value;
7636
if (mysql_bin_log.rotate(true, &check_purge))
7641
binlog_checksum_options= value;
7643
DBUG_ASSERT(binlog_checksum_options == value);
7644
mysql_bin_log.checksum_alg_reset= BINLOG_CHECKSUM_ALG_UNDEF;
7645
mysql_mutex_unlock(mysql_bin_log.get_log_lock());
7647
mysql_bin_log.purge();
7651
static int show_binlog_vars(THD *thd, SHOW_VAR *var, char *buff)
7653
mysql_bin_log.set_status_variables(thd);
7654
var->type= SHOW_ARRAY;
7655
var->value= (char *)&binlog_status_vars_detail;
7659
static SHOW_VAR binlog_status_vars_top[]= {
7660
{"Binlog", (char *) &show_binlog_vars, SHOW_FUNC},
7661
{NullS, NullS, SHOW_LONG}
7664
static MYSQL_SYSVAR_BOOL(
7665
optimize_thread_scheduling,
7666
opt_optimize_thread_scheduling,
7667
PLUGIN_VAR_READONLY,
7668
"Run fast part of group commit in a single thread, to optimize kernel "
7669
"thread scheduling. On by default. Disable to run each transaction in group "
7670
"commit in its own thread, which can be slower at very high concurrency. "
7671
"This option is mostly for testing one algorithm versus the other, and it "
7672
"should not normally be necessary to change it.",
7677
static MYSQL_SYSVAR_ENUM(
7679
binlog_checksum_options,
7680
PLUGIN_VAR_RQCMDARG,
7681
"Type of BINLOG_CHECKSUM_ALG. Include checksum for "
7682
"log events in the binary log. Possible values are NONE and CRC32; "
7685
binlog_checksum_update,
7686
BINLOG_CHECKSUM_ALG_OFF,
7687
&binlog_checksum_typelib);
7689
static struct st_mysql_sys_var *binlog_sys_vars[]=
7691
MYSQL_SYSVAR(optimize_thread_scheduling),
7692
MYSQL_SYSVAR(checksum),
7698
Copy out the non-directory part of binlog position filename for the
7699
`binlog_snapshot_file' status variable, same way as it is done for
7703
set_binlog_snapshot_file(const char *src)
7705
int dir_len = dirname_length(src);
7706
strmake_buf(binlog_snapshot_file, src + dir_len);
7710
Copy out current values of status variables, for SHOW STATUS or
7711
information_schema.global_status.
7713
This is called only under LOCK_status, so we can fill in a static array.
7716
TC_LOG_BINLOG::set_status_variables(THD *thd)
7718
binlog_cache_mngr *cache_mngr;
7720
if (thd && opt_bin_log)
7721
cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
7725
bool have_snapshot= (cache_mngr && cache_mngr->last_commit_pos_file[0] != 0);
7726
mysql_mutex_lock(&LOCK_commit_ordered);
7727
binlog_status_var_num_commits= this->num_commits;
7728
binlog_status_var_num_group_commits= this->num_group_commits;
7731
set_binlog_snapshot_file(last_commit_pos_file);
7732
binlog_snapshot_position= last_commit_pos_offset;
7734
mysql_mutex_unlock(&LOCK_commit_ordered);
7738
set_binlog_snapshot_file(cache_mngr->last_commit_pos_file);
7739
binlog_snapshot_position= cache_mngr->last_commit_pos_offset;
7743
struct st_mysql_storage_engine binlog_storage_engine=
7744
{ MYSQL_HANDLERTON_INTERFACE_VERSION };
7746
maria_declare_plugin(binlog)
7748
MYSQL_STORAGE_ENGINE_PLUGIN,
7749
&binlog_storage_engine,
7752
"This is a pseudo storage engine to represent the binlog in a transaction",
7754
binlog_init, /* Plugin Init */
7755
NULL, /* Plugin Deinit */
7757
binlog_status_vars_top, /* status variables */
7758
binlog_sys_vars, /* system variables */
7759
"1.0", /* string version */
7760
MariaDB_PLUGIN_MATURITY_STABLE /* maturity */
7762
maria_declare_plugin_end;
added
removed
sql/log.cc
