00001 /* Copyright (C) 2000-2003 MySQL AB 00002 00003 This program is free software; you can redistribute it and/or modify 00004 it under the terms of the GNU General Public License as published by 00005 the Free Software Foundation; either version 2 of the License, or 00006 (at your option) any later version. 00007 00008 This program is distributed in the hope that it will be useful, 00009 but WITHOUT ANY WARRANTY; without even the implied warranty of 00010 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the 00011 GNU General Public License for more details. 00012 00013 You should have received a copy of the GNU General Public License 00014 along with this program; if not, write to the Free Software 00015 Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA */ 00016 00017 00018 /* logging of commands */ 00019 /* TODO: Abort logging when we get an error in reading or writing log files */ 00020 00021 #include "mysql_priv.h" 00022 #include "sql_repl.h" 00023 #include "rpl_filter.h" 00024 00025 #include <my_dir.h> 00026 #include <stdarg.h> 00027 #include <m_ctype.h> // For test_if_number 00028 00029 #ifdef __NT__ 00030 #include "message.h" 00031 #endif 00032 00033 #include <mysql/plugin.h> 00034 00035 /* max size of the log message */ 00036 #define MAX_LOG_BUFFER_SIZE 1024 00037 #define MAX_USER_HOST_SIZE 512 00038 #define MAX_TIME_SIZE 32 00039 00040 LOGGER logger; 00041 00042 MYSQL_BIN_LOG mysql_bin_log; 00043 ulong sync_binlog_counter= 0; 00044 00045 static Muted_query_log_event invisible_commit; 00046 00047 static bool test_if_number(const char *str, 00048 long *res, bool allow_wildcards); 00049 static int binlog_init(); 00050 static int binlog_close_connection(THD *thd); 00051 static int binlog_savepoint_set(THD *thd, void *sv); 00052 static int binlog_savepoint_rollback(THD *thd, void *sv); 00053 static int binlog_commit(THD *thd, bool all); 00054 static int binlog_rollback(THD *thd, bool all); 00055 static int binlog_prepare(THD *thd, bool all); 00056 00057 sql_print_message_func sql_print_message_handlers[3] = 00058 { 00059 sql_print_information, 00060 sql_print_warning, 00061 sql_print_error 00062 }; 00063 00064 00065 char *make_default_log_name(char *buff,const char* log_ext) 00066 { 00067 strmake(buff, glob_hostname, FN_REFLEN-5); 00068 return fn_format(buff, buff, mysql_data_home, log_ext, 00069 MYF(MY_UNPACK_FILENAME|MY_APPEND_EXT)); 00070 } 00071 00072 /* 00073 This is a POD. Please keep it that way! 00074 00075 Don't add constructors, destructors, or virtual functions. 00076 */ 00077 struct binlog_trx_data { 00078 bool empty() const 00079 { 00080 #ifdef HAVE_ROW_BASED_REPLICATION 00081 return pending == NULL && my_b_tell(&trans_log) == 0; 00082 #else 00083 return my_b_tell(&trans_log) == 0; 00084 #endif 00085 } 00086 binlog_trx_data() {} 00087 IO_CACHE trans_log; // The transaction cache 00088 #ifdef HAVE_ROW_BASED_REPLICATION 00089 Rows_log_event *pending; // The pending binrows event 00090 #endif 00091 }; 00092 00093 handlerton binlog_hton; 00094 00095 /* 00096 Open log table of a given type (general or slow log) 00097 00098 SYNOPSIS 00099 open_log_table() 00100 00101 log_table_type type of the log table to open: QUERY_LOG_GENERAL 00102 or QUERY_LOG_SLOW 00103 00104 DESCRIPTION 00105 00106 The function opens a log table and marks it as such. Log tables are open 00107 during the whole time, while server is running. Except for the moments 00108 when they have to be reopened: during FLUSH LOGS and TRUNCATE. This 00109 function is invoked directly only once during startup. All subsequent 00110 calls happen through reopen_log_table(), which performs additional check. 00111 00112 RETURN 00113 FALSE - OK 00114 TRUE - error occured 00115 */ 00116 00117 bool Log_to_csv_event_handler::open_log_table(uint log_table_type) 00118 { 00119 THD *log_thd, *curr= current_thd; 00120 TABLE_LIST *table; 00121 bool error= FALSE; 00122 DBUG_ENTER("open_log_table"); 00123 00124 switch (log_table_type) { 00125 case QUERY_LOG_GENERAL: 00126 log_thd= general_log_thd; 00127 table= &general_log; 00128 /* clean up table before reuse/initial usage */ 00129 bzero((char*) table, sizeof(TABLE_LIST)); 00130 table->alias= table->table_name= (char*) "general_log"; 00131 table->table_name_length= 11; 00132 break; 00133 case QUERY_LOG_SLOW: 00134 log_thd= slow_log_thd; 00135 table= &slow_log; 00136 bzero((char*) table, sizeof(TABLE_LIST)); 00137 table->alias= table->table_name= (char*) "slow_log"; 00138 table->table_name_length= 8; 00139 break; 00140 default: 00141 DBUG_ASSERT(0); 00142 } 00143 00144 /* 00145 This way we check that appropriate log thd was created ok during 00146 initialization. We cannot check "is_log_tables_initialized" var, as 00147 the very initialization is not finished until this function is 00148 completed in the very first time. 00149 */ 00150 if (!log_thd) 00151 { 00152 DBUG_PRINT("error",("Cannot initialize log tables")); 00153 DBUG_RETURN(TRUE); 00154 } 00155 00156 /* 00157 Set THD's thread_stack. This is needed to perform stack overrun 00158 check, which is done by some routines (e.g. open_table()). 00159 In the case we are called by thread, which already has this parameter 00160 set, we use this value. Otherwise we do a wild guess. This won't help 00161 to correctly track the stack overrun in these exceptional cases (which 00162 could probably happen only during startup and shutdown) but at least 00163 lets us to pass asserts. 00164 The problem stems from the fact that logger THDs are not real threads. 00165 */ 00166 if (curr) 00167 log_thd->thread_stack= curr->thread_stack; 00168 else 00169 log_thd->thread_stack= (char*) &log_thd; 00170 00171 log_thd->store_globals(); 00172 00173 table->lock_type= TL_WRITE_CONCURRENT_INSERT; 00174 table->db= log_thd->db; 00175 table->db_length= log_thd->db_length; 00176 00177 if (simple_open_n_lock_tables(log_thd, table) || 00178 table->table->file->extra(HA_EXTRA_MARK_AS_LOG_TABLE) || 00179 table->table->file->ha_rnd_init(0)) 00180 error= TRUE; 00181 else 00182 { 00183 table->table->use_all_columns(); 00184 table->table->locked_by_logger= TRUE; 00185 } 00186 /* restore thread settings */ 00187 if (curr) 00188 curr->store_globals(); 00189 else 00190 { 00191 my_pthread_setspecific_ptr(THR_THD, 0); 00192 my_pthread_setspecific_ptr(THR_MALLOC, 0); 00193 } 00194 00195 DBUG_RETURN(error); 00196 } 00197 00198 00199 Log_to_csv_event_handler::Log_to_csv_event_handler() 00200 { 00201 /* init artificial THD's */ 00202 general_log_thd= new THD; 00203 /* logger thread always works with mysql database */ 00204 general_log_thd->db= my_strdup("mysql", MYF(0)); 00205 general_log_thd->db_length= 5; 00206 00207 slow_log_thd= new THD; 00208 /* logger thread always works with mysql database */ 00209 slow_log_thd->db= my_strdup("mysql", MYF(0));; 00210 slow_log_thd->db_length= 5; 00211 } 00212 00213 00214 Log_to_csv_event_handler::~Log_to_csv_event_handler() 00215 { 00216 /* now cleanup the tables */ 00217 if (general_log_thd) 00218 { 00219 delete general_log_thd; 00220 general_log_thd= NULL; 00221 } 00222 00223 if (slow_log_thd) 00224 { 00225 delete slow_log_thd; 00226 slow_log_thd= NULL; 00227 } 00228 } 00229 00230 00231 /* 00232 Reopen log table of a given type 00233 00234 SYNOPSIS 00235 reopen_log_table() 00236 00237 log_table_type type of the log table to open: QUERY_LOG_GENERAL 00238 or QUERY_LOG_SLOW 00239 00240 DESCRIPTION 00241 00242 The function is a wrapper around open_log_table(). It is used during 00243 FLUSH LOGS and TRUNCATE of the log tables (i.e. when we need to close 00244 and reopen them). The difference is in the check of the 00245 logger.is_log_tables_initialized var, which can't be done in 00246 open_log_table(), as it makes no sense during startup. 00247 00248 NOTE: this code assumes that we have logger mutex locked 00249 00250 RETURN 00251 FALSE - ok 00252 TRUE - open_log_table() returned an error 00253 */ 00254 00255 bool Log_to_csv_event_handler::reopen_log_table(uint log_table_type) 00256 { 00257 /* don't open the log table, if it wasn't enabled during startup */ 00258 if (!logger.is_log_tables_initialized) 00259 return FALSE; 00260 return open_log_table(log_table_type); 00261 } 00262 00263 void Log_to_csv_event_handler::cleanup() 00264 { 00265 if (opt_log) 00266 close_log_table(QUERY_LOG_GENERAL, FALSE); 00267 if (opt_slow_log) 00268 close_log_table(QUERY_LOG_SLOW, FALSE); 00269 logger.is_log_tables_initialized= FALSE; 00270 } 00271 00272 /* log event handlers */ 00273 00274 /* 00275 Log command to the general log table 00276 00277 SYNOPSIS 00278 log_general() 00279 00280 event_time command start timestamp 00281 user_host the pointer to the string with user@host info 00282 user_host_len length of the user_host string. this is computed once 00283 and passed to all general log event handlers 00284 thread_id Id of the thread, issued a query 00285 command_type the type of the command being logged 00286 command_type_len the length of the string above 00287 sql_text the very text of the query being executed 00288 sql_text_len the length of sql_text string 00289 00290 DESCRIPTION 00291 00292 Log given command to the general log table 00293 00294 RETURN 00295 FALSE - OK 00296 TRUE - error occured 00297 */ 00298 00299 bool Log_to_csv_event_handler:: 00300 log_general(time_t event_time, const char *user_host, 00301 uint user_host_len, int thread_id, 00302 const char *command_type, uint command_type_len, 00303 const char *sql_text, uint sql_text_len, 00304 CHARSET_INFO *client_cs) 00305 { 00306 TABLE *table= general_log.table; 00307 00308 /* below should never happen */ 00309 if (unlikely(!logger.is_log_tables_initialized)) 00310 return FALSE; 00311 00312 /* 00313 NOTE: we do not call restore_record() here, as all fields are 00314 filled by the Logger (=> no need to load default ones). 00315 */ 00316 00317 /* log table entries are not replicated at the moment */ 00318 tmp_disable_binlog(current_thd); 00319 00320 /* Set current time. Required for CURRENT_TIMESTAMP to work */ 00321 general_log_thd->start_time= event_time; 00322 00323 /* 00324 We do not set a value for table->field[0], as it will use 00325 default value (which is CURRENT_TIMESTAMP). 00326 */ 00327 00328 table->field[1]->store(user_host, user_host_len, client_cs); 00329 table->field[1]->set_notnull(); 00330 table->field[2]->store((longlong) thread_id, TRUE); 00331 table->field[2]->set_notnull(); 00332 table->field[3]->store((longlong) server_id, TRUE); 00333 table->field[3]->set_notnull(); 00334 table->field[4]->store(command_type, command_type_len, client_cs); 00335 table->field[4]->set_notnull(); 00336 table->field[5]->store(sql_text, sql_text_len, client_cs); 00337 table->field[5]->set_notnull(); 00338 table->file->ha_write_row(table->record[0]); 00339 00340 reenable_binlog(current_thd); 00341 00342 return FALSE; 00343 } 00344 00345 00346 /* 00347 Log a query to the slow log table 00348 00349 SYNOPSIS 00350 log_slow() 00351 thd THD of the query 00352 current_time current timestamp 00353 query_start_arg command start timestamp 00354 user_host the pointer to the string with user@host info 00355 user_host_len length of the user_host string. this is computed once 00356 and passed to all general log event handlers 00357 query_time Amount of time the query took to execute (in seconds) 00358 lock_time Amount of time the query was locked (in seconds) 00359 is_command The flag, which determines, whether the sql_text is a 00360 query or an administrator command (these are treated 00361 differently by the old logging routines) 00362 sql_text the very text of the query or administrator command 00363 processed 00364 sql_text_len the length of sql_text string 00365 00366 DESCRIPTION 00367 00368 Log a query to the slow log table 00369 00370 RETURN 00371 FALSE - OK 00372 TRUE - error occured 00373 */ 00374 00375 bool Log_to_csv_event_handler:: 00376 log_slow(THD *thd, time_t current_time, time_t query_start_arg, 00377 const char *user_host, uint user_host_len, 00378 longlong query_time, longlong lock_time, bool is_command, 00379 const char *sql_text, uint sql_text_len) 00380 { 00381 /* table variables */ 00382 TABLE *table= slow_log.table; 00383 CHARSET_INFO *client_cs= thd->variables.character_set_client; 00384 00385 DBUG_ENTER("log_slow"); 00386 00387 /* below should never happen */ 00388 if (unlikely(!logger.is_log_tables_initialized)) 00389 return FALSE; 00390 00391 /* log table entries are not replicated at the moment */ 00392 tmp_disable_binlog(current_thd); 00393 00394 /* 00395 Set start time for CURRENT_TIMESTAMP to the start of the query. 00396 This will be default value for the field[0] 00397 */ 00398 slow_log_thd->start_time= query_start_arg; 00399 restore_record(table, s->default_values); // Get empty record 00400 00401 /* 00402 We do not set a value for table->field[0], as it will use 00403 default value. 00404 */ 00405 00406 /* store the value */ 00407 table->field[1]->store(user_host, user_host_len, client_cs); 00408 00409 if (query_start_arg) 00410 { 00411 /* fill in query_time field */ 00412 table->field[2]->store(query_time, TRUE); 00413 /* lock_time */ 00414 table->field[3]->store(lock_time, TRUE); 00415 /* rows_sent */ 00416 table->field[4]->store((longlong) thd->sent_row_count, TRUE); 00417 /* rows_examined */ 00418 table->field[5]->store((longlong) thd->examined_row_count, TRUE); 00419 } 00420 else 00421 { 00422 table->field[2]->set_null(); 00423 table->field[3]->set_null(); 00424 table->field[4]->set_null(); 00425 table->field[5]->set_null(); 00426 } 00427 00428 /* fill database field */ 00429 if (thd->db) 00430 { 00431 table->field[6]->store(thd->db, thd->db_length, client_cs); 00432 table->field[6]->set_notnull(); 00433 } 00434 00435 if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt) 00436 { 00437 table->field[7]->store((longlong) 00438 thd->first_successful_insert_id_in_prev_stmt_for_binlog, TRUE); 00439 table->field[7]->set_notnull(); 00440 } 00441 00442 /* 00443 Set value if we do an insert on autoincrement column. Note that for 00444 some engines (those for which get_auto_increment() does not leave a 00445 table lock until the statement ends), this is just the first value and 00446 the next ones used may not be contiguous to it. 00447 */ 00448 if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0) 00449 { 00450 table->field[8]->store((longlong) 00451 thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum(), TRUE); 00452 table->field[8]->set_notnull(); 00453 } 00454 00455 table->field[9]->store((longlong) server_id, TRUE); 00456 table->field[9]->set_notnull(); 00457 00458 /* sql_text */ 00459 table->field[10]->store(sql_text,sql_text_len, client_cs); 00460 00461 /* write the row */ 00462 table->file->ha_write_row(table->record[0]); 00463 00464 reenable_binlog(current_thd); 00465 00466 DBUG_RETURN(0); 00467 } 00468 00469 bool Log_to_csv_event_handler:: 00470 log_error(enum loglevel level, const char *format, va_list args) 00471 { 00472 /* No log table is implemented */ 00473 DBUG_ASSERT(0); 00474 return FALSE; 00475 } 00476 00477 bool Log_to_file_event_handler:: 00478 log_error(enum loglevel level, const char *format, 00479 va_list args) 00480 { 00481 return vprint_msg_to_log(level, format, args); 00482 } 00483 00484 void Log_to_file_event_handler::init_pthread_objects() 00485 { 00486 mysql_log.init_pthread_objects(); 00487 mysql_slow_log.init_pthread_objects(); 00488 } 00489 00490 00491 /* Wrapper around MYSQL_LOG::write() for slow log */ 00492 00493 bool Log_to_file_event_handler:: 00494 log_slow(THD *thd, time_t current_time, time_t query_start_arg, 00495 const char *user_host, uint user_host_len, 00496 longlong query_time, longlong lock_time, bool is_command, 00497 const char *sql_text, uint sql_text_len) 00498 { 00499 return mysql_slow_log.write(thd, current_time, query_start_arg, 00500 user_host, user_host_len, 00501 query_time, lock_time, is_command, 00502 sql_text, sql_text_len); 00503 } 00504 00505 00506 /* 00507 Wrapper around MYSQL_LOG::write() for general log. We need it since we 00508 want all log event handlers to have the same signature. 00509 */ 00510 00511 bool Log_to_file_event_handler:: 00512 log_general(time_t event_time, const char *user_host, 00513 uint user_host_len, int thread_id, 00514 const char *command_type, uint command_type_len, 00515 const char *sql_text, uint sql_text_len, 00516 CHARSET_INFO *client_cs) 00517 { 00518 return mysql_log.write(event_time, user_host, user_host_len, 00519 thread_id, command_type, command_type_len, 00520 sql_text, sql_text_len); 00521 } 00522 00523 00524 bool Log_to_file_event_handler::init() 00525 { 00526 if (!is_initialized) 00527 { 00528 if (opt_slow_log) 00529 mysql_slow_log.open_slow_log(sys_var_slow_log_path.value); 00530 00531 if (opt_log) 00532 mysql_log.open_query_log(sys_var_general_log_path.value); 00533 00534 is_initialized= TRUE; 00535 } 00536 00537 return FALSE; 00538 } 00539 00540 00541 void Log_to_file_event_handler::cleanup() 00542 { 00543 mysql_log.cleanup(); 00544 mysql_slow_log.cleanup(); 00545 } 00546 00547 void Log_to_file_event_handler::flush() 00548 { 00549 /* reopen log files */ 00550 if (opt_log) 00551 mysql_log.reopen_file(); 00552 if (opt_slow_log) 00553 mysql_slow_log.reopen_file(); 00554 } 00555 00556 /* 00557 Log error with all enabled log event handlers 00558 00559 SYNOPSIS 00560 error_log_print() 00561 00562 level The level of the error significance: NOTE, 00563 WARNING or ERROR. 00564 format format string for the error message 00565 args list of arguments for the format string 00566 00567 RETURN 00568 FALSE - OK 00569 TRUE - error occured 00570 */ 00571 00572 bool LOGGER::error_log_print(enum loglevel level, const char *format, 00573 va_list args) 00574 { 00575 bool error= FALSE; 00576 Log_event_handler **current_handler= error_log_handler_list; 00577 00578 /* currently we don't need locking here as there is no error_log table */ 00579 while (*current_handler) 00580 error= (*current_handler++)->log_error(level, format, args) || error; 00581 00582 return error; 00583 } 00584 00585 00586 void LOGGER::cleanup_base() 00587 { 00588 DBUG_ASSERT(inited == 1); 00589 (void) pthread_mutex_destroy(&LOCK_logger); 00590 if (table_log_handler) 00591 { 00592 table_log_handler->cleanup(); 00593 delete table_log_handler; 00594 } 00595 if (file_log_handler) 00596 file_log_handler->cleanup(); 00597 } 00598 00599 00600 void LOGGER::cleanup_end() 00601 { 00602 DBUG_ASSERT(inited == 1); 00603 if (file_log_handler) 00604 delete file_log_handler; 00605 } 00606 00607 00608 void LOGGER::close_log_table(uint log_table_type, bool lock_in_use) 00609 { 00610 table_log_handler->close_log_table(log_table_type, lock_in_use); 00611 } 00612 00613 00614 /* 00615 Perform basic log initialization: create file-based log handler and 00616 init error log. 00617 */ 00618 void LOGGER::init_base() 00619 { 00620 DBUG_ASSERT(inited == 0); 00621 inited= 1; 00622 00623 /* 00624 Here we create file log handler. We don't do it for the table log handler 00625 here as it cannot be created so early. The reason is THD initialization, 00626 which depends on the system variables (parsed later). 00627 */ 00628 if (!file_log_handler) 00629 file_log_handler= new Log_to_file_event_handler; 00630 00631 /* by default we use traditional error log */ 00632 init_error_log(LOG_FILE); 00633 00634 file_log_handler->init_pthread_objects(); 00635 (void) pthread_mutex_init(&LOCK_logger, MY_MUTEX_INIT_SLOW); 00636 } 00637 00638 00639 void LOGGER::init_log_tables() 00640 { 00641 if (!table_log_handler) 00642 table_log_handler= new Log_to_csv_event_handler; 00643 00644 if (!is_log_tables_initialized && 00645 !table_log_handler->init() && !file_log_handler->init()) 00646 is_log_tables_initialized= TRUE; 00647 } 00648 00649 00650 bool LOGGER::reopen_log_table(uint log_table_type) 00651 { 00652 return table_log_handler->reopen_log_table(log_table_type); 00653 } 00654 00655 00656 bool LOGGER::flush_logs(THD *thd) 00657 { 00658 TABLE_LIST close_slow_log, close_general_log; 00659 00660 /* reopen log tables */ 00661 bzero((char*) &close_slow_log, sizeof(TABLE_LIST)); 00662 close_slow_log.alias= close_slow_log.table_name=(char*) "slow_log"; 00663 close_slow_log.table_name_length= 8; 00664 close_slow_log.db= (char*) "mysql"; 00665 close_slow_log.db_length= 5; 00666 00667 bzero((char*) &close_general_log, sizeof(TABLE_LIST)); 00668 close_general_log.alias= close_general_log.table_name=(char*) "general_log"; 00669 close_general_log.table_name_length= 11; 00670 close_general_log.db= (char*) "mysql"; 00671 close_general_log.db_length= 5; 00672 00673 /* lock tables, in the case they are enabled */ 00674 if (logger.is_log_tables_initialized) 00675 { 00676 /* 00677 This will lock and wait for all but the logger thread to release the 00678 tables. Then we could reopen log tables. Then release the name locks. 00679 00680 NOTE: in fact, the first parameter used in lock_and_wait_for_table_name() 00681 and table_log_handler->flush() could be any non-NULL THD, as the 00682 underlying code makes certain assumptions about this. 00683 Here we use one of the logger handler THD's. Simply because it 00684 seems appropriate. 00685 */ 00686 if (opt_slow_log) 00687 lock_and_wait_for_table_name(table_log_handler->general_log_thd, 00688 &close_slow_log); 00689 if (opt_log) 00690 lock_and_wait_for_table_name(table_log_handler->general_log_thd, 00691 &close_general_log); 00692 } 00693 00694 /* 00695 Deny others from logging to general and slow log, 00696 while reopening tables. 00697 */ 00698 logger.lock(); 00699 00700 /* reopen log files */ 00701 file_log_handler->flush(); 00702 00703 /* flush tables, in the case they are enabled */ 00704 if (logger.is_log_tables_initialized) 00705 table_log_handler->flush(table_log_handler->general_log_thd, 00706 &close_slow_log, &close_general_log); 00707 /* end of log flush */ 00708 logger.unlock(); 00709 return FALSE; 00710 } 00711 00712 00713 /* 00714 Log slow query with all enabled log event handlers 00715 00716 SYNOPSIS 00717 slow_log_print() 00718 00719 thd THD of the query being logged 00720 query The query being logged 00721 query_length The length of the query string 00722 query_start_arg Query start timestamp 00723 00724 RETURN 00725 FALSE - OK 00726 TRUE - error occured 00727 */ 00728 00729 bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length, 00730 time_t query_start_arg) 00731 { 00732 bool error= FALSE; 00733 Log_event_handler **current_handler= slow_log_handler_list; 00734 bool is_command= FALSE; 00735 char user_host_buff[MAX_USER_HOST_SIZE]; 00736 00737 my_time_t current_time; 00738 Security_context *sctx= thd->security_ctx; 00739 uint message_buff_len= 0, user_host_len= 0; 00740 longlong query_time= 0, lock_time= 0; 00741 00742 /* 00743 Print the message to the buffer if we have slow log enabled 00744 */ 00745 00746 if (*slow_log_handler_list) 00747 { 00748 current_time= time(NULL); 00749 00750 /* do not log slow queries from replication threads */ 00751 if (thd->slave_thread) 00752 return 0; 00753 00754 lock(); 00755 if (!opt_slow_log) 00756 { 00757 unlock(); 00758 return 0; 00759 } 00760 00761 /* fill in user_host value: the format is "%s[%s] @ %s [%s]" */ 00762 user_host_len= strxnmov(user_host_buff, MAX_USER_HOST_SIZE, 00763 sctx->priv_user ? sctx->priv_user : "", "[", 00764 sctx->user ? sctx->user : "", "] @ ", 00765 sctx->host ? sctx->host : "", " [", 00766 sctx->ip ? sctx->ip : "", "]", NullS) - 00767 user_host_buff; 00768 00769 if (query_start_arg) 00770 { 00771 query_time= (longlong) (current_time - query_start_arg); 00772 lock_time= (longlong) (thd->time_after_lock - query_start_arg); 00773 } 00774 00775 if (!query) 00776 { 00777 is_command= TRUE; 00778 query= command_name[thd->command].str; 00779 query_length= command_name[thd->command].length; 00780 } 00781 00782 while (*current_handler) 00783 error= (*current_handler++)->log_slow(thd, current_time, query_start_arg, 00784 user_host_buff, user_host_len, 00785 query_time, lock_time, is_command, 00786 query, query_length) || error; 00787 00788 unlock(); 00789 } 00790 return error; 00791 } 00792 00793 bool LOGGER::general_log_print(THD *thd, enum enum_server_command command, 00794 const char *format, va_list args) 00795 { 00796 bool error= FALSE; 00797 Log_event_handler **current_handler= general_log_handler_list; 00798 00799 /* 00800 Print the message to the buffer if we have at least one log event handler 00801 enabled and want to log this king of commands 00802 */ 00803 if (*general_log_handler_list && (what_to_log & (1L << (uint) command))) 00804 { 00805 char message_buff[MAX_LOG_BUFFER_SIZE]; 00806 char user_host_buff[MAX_USER_HOST_SIZE]; 00807 Security_context *sctx= thd->security_ctx; 00808 ulong id; 00809 uint message_buff_len= 0, user_host_len= 0; 00810 00811 if (thd) 00812 { /* Normal thread */ 00813 if ((thd->options & OPTION_LOG_OFF) 00814 #ifndef NO_EMBEDDED_ACCESS_CHECKS 00815 && (sctx->master_access & SUPER_ACL) 00816 #endif 00817 ) 00818 { 00819 return 0; /* No logging */ 00820 } 00821 id= thd->thread_id; 00822 } 00823 else 00824 id=0; /* Log from connect handler */ 00825 00826 lock(); 00827 if (!opt_log) 00828 { 00829 unlock(); 00830 return 0; 00831 } 00832 time_t current_time= time(NULL); 00833 00834 user_host_len= strxnmov(user_host_buff, MAX_USER_HOST_SIZE, 00835 sctx->priv_user ? sctx->priv_user : "", "[", 00836 sctx->user ? sctx->user : "", "] @ ", 00837 sctx->host ? sctx->host : "", " [", 00838 sctx->ip ? sctx->ip : "", "]", NullS) - 00839 user_host_buff; 00840 00841 /* prepare message */ 00842 if (format) 00843 message_buff_len= my_vsnprintf(message_buff, 00844 sizeof(message_buff), format, args); 00845 else 00846 message_buff[0]= '\0'; 00847 00848 while (*current_handler) 00849 error+= (*current_handler++)-> 00850 log_general(current_time, user_host_buff, 00851 user_host_len, id, 00852 command_name[(uint) command].str, 00853 command_name[(uint) command].length, 00854 message_buff, message_buff_len, 00855 thd->variables.character_set_client) || error; 00856 unlock(); 00857 } 00858 return error; 00859 } 00860 00861 void LOGGER::init_error_log(uint error_log_printer) 00862 { 00863 if (error_log_printer & LOG_NONE) 00864 { 00865 error_log_handler_list[0]= 0; 00866 return; 00867 } 00868 00869 switch (error_log_printer) { 00870 case LOG_FILE: 00871 error_log_handler_list[0]= file_log_handler; 00872 error_log_handler_list[1]= 0; 00873 break; 00874 /* these two are disabled for now */ 00875 case LOG_TABLE: 00876 DBUG_ASSERT(0); 00877 break; 00878 case LOG_TABLE|LOG_FILE: 00879 DBUG_ASSERT(0); 00880 break; 00881 } 00882 } 00883 00884 void LOGGER::init_slow_log(uint slow_log_printer) 00885 { 00886 if (slow_log_printer & LOG_NONE) 00887 { 00888 slow_log_handler_list[0]= 0; 00889 return; 00890 } 00891 00892 switch (slow_log_printer) { 00893 case LOG_FILE: 00894 slow_log_handler_list[0]= file_log_handler; 00895 slow_log_handler_list[1]= 0; 00896 break; 00897 case LOG_TABLE: 00898 slow_log_handler_list[0]= table_log_handler; 00899 slow_log_handler_list[1]= 0; 00900 break; 00901 case LOG_TABLE|LOG_FILE: 00902 slow_log_handler_list[0]= file_log_handler; 00903 slow_log_handler_list[1]= table_log_handler; 00904 slow_log_handler_list[2]= 0; 00905 break; 00906 } 00907 } 00908 00909 void LOGGER::init_general_log(uint general_log_printer) 00910 { 00911 if (general_log_printer & LOG_NONE) 00912 { 00913 general_log_handler_list[0]= 0; 00914 return; 00915 } 00916 00917 switch (general_log_printer) { 00918 case LOG_FILE: 00919 general_log_handler_list[0]= file_log_handler; 00920 general_log_handler_list[1]= 0; 00921 break; 00922 case LOG_TABLE: 00923 general_log_handler_list[0]= table_log_handler; 00924 general_log_handler_list[1]= 0; 00925 break; 00926 case LOG_TABLE|LOG_FILE: 00927 general_log_handler_list[0]= file_log_handler; 00928 general_log_handler_list[1]= table_log_handler; 00929 general_log_handler_list[2]= 0; 00930 break; 00931 } 00932 } 00933 00934 00935 bool LOGGER::activate_log_handler(THD* thd, uint log_type) 00936 { 00937 bool res= 0; 00938 lock(); 00939 switch (log_type) { 00940 case QUERY_LOG_SLOW: 00941 if (!opt_slow_log) 00942 { 00943 if ((res= reopen_log_table(log_type))) 00944 goto err; 00945 file_log_handler->get_mysql_slow_log()-> 00946 open_slow_log(sys_var_slow_log_path.value); 00947 init_slow_log(log_output_options); 00948 opt_slow_log= TRUE; 00949 } 00950 break; 00951 case QUERY_LOG_GENERAL: 00952 if (!opt_log) 00953 { 00954 if ((res= reopen_log_table(log_type))) 00955 goto err; 00956 file_log_handler->get_mysql_log()-> 00957 open_query_log(sys_var_general_log_path.value); 00958 init_general_log(log_output_options); 00959 opt_log= TRUE; 00960 } 00961 break; 00962 default: 00963 DBUG_ASSERT(0); 00964 } 00965 err: 00966 unlock(); 00967 return res; 00968 } 00969 00970 00971 void LOGGER::deactivate_log_handler(THD *thd, uint log_type) 00972 { 00973 TABLE_LIST *table_list; 00974 my_bool *tmp_opt= 0; 00975 MYSQL_LOG *file_log; 00976 THD *log_thd; 00977 00978 switch (log_type) { 00979 case QUERY_LOG_SLOW: 00980 table_list= &table_log_handler->slow_log; 00981 tmp_opt= &opt_slow_log; 00982 file_log= file_log_handler->get_mysql_slow_log(); 00983 log_thd= table_log_handler->slow_log_thd; 00984 break; 00985 case QUERY_LOG_GENERAL: 00986 table_list= &table_log_handler->general_log; 00987 tmp_opt= &opt_log; 00988 file_log= file_log_handler->get_mysql_log(); 00989 log_thd= table_log_handler->general_log_thd; 00990 break; 00991 default: 00992 DBUG_ASSERT(0); 00993 } 00994 00995 if (!(*tmp_opt)) 00996 return; 00997 00998 if (is_log_tables_initialized) 00999 lock_and_wait_for_table_name(log_thd, table_list); 01000 lock(); 01001 01002 if (is_log_tables_initialized) 01003 { 01004 VOID(pthread_mutex_lock(&LOCK_open)); 01005 close_log_table(log_type, TRUE); 01006 table_list->table= 0; 01007 query_cache_invalidate3(log_thd, table_list, 0); 01008 unlock_table_name(log_thd, table_list); 01009 VOID(pthread_mutex_unlock(&LOCK_open)); 01010 } 01011 file_log->close(0); 01012 *tmp_opt= FALSE; 01013 unlock(); 01014 } 01015 01016 01017 bool Log_to_csv_event_handler::flush(THD *thd, TABLE_LIST *close_slow_log, 01018 TABLE_LIST *close_general_log) 01019 { 01020 VOID(pthread_mutex_lock(&LOCK_open)); 01021 if (opt_log) 01022 { 01023 close_log_table(QUERY_LOG_GENERAL, TRUE); 01024 query_cache_invalidate3(thd, close_general_log, 0); 01025 unlock_table_name(thd, close_general_log); 01026 } 01027 if (opt_slow_log) 01028 { 01029 close_log_table(QUERY_LOG_SLOW, TRUE); 01030 query_cache_invalidate3(thd, close_slow_log, 0); 01031 unlock_table_name(thd, close_slow_log); 01032 } 01033 VOID(pthread_mutex_unlock(&LOCK_open)); 01034 /* 01035 we use | and not || here, to ensure that both reopen_log_table 01036 are called, even if the first one fails 01037 */ 01038 if ((opt_slow_log && reopen_log_table(QUERY_LOG_SLOW)) | 01039 (opt_log && reopen_log_table(QUERY_LOG_GENERAL))) 01040 return 1; 01041 return 0; 01042 } 01043 01044 /* the parameters are unused for the log tables */ 01045 bool Log_to_csv_event_handler::init() 01046 { 01047 /* 01048 we use | and not || here, to ensure that both open_log_table 01049 are called, even if the first one fails 01050 */ 01051 if ((opt_log && open_log_table(QUERY_LOG_GENERAL)) | 01052 (opt_slow_log && open_log_table(QUERY_LOG_SLOW))) 01053 return 1; 01054 return 0; 01055 } 01056 01057 int LOGGER::set_handlers(uint error_log_printer, 01058 uint slow_log_printer, 01059 uint general_log_printer) 01060 { 01061 /* error log table is not supported yet */ 01062 DBUG_ASSERT(error_log_printer < LOG_TABLE); 01063 01064 lock(); 01065 01066 if ((slow_log_printer & LOG_TABLE || general_log_printer & LOG_TABLE) && 01067 !is_log_tables_initialized) 01068 { 01069 slow_log_printer= (slow_log_printer & ~LOG_TABLE) | LOG_FILE; 01070 general_log_printer= (general_log_printer & ~LOG_TABLE) | LOG_FILE; 01071 01072 sql_print_error("Failed to initialize log tables. " 01073 "Falling back to the old-fashioned logs"); 01074 } 01075 01076 init_error_log(error_log_printer); 01077 init_slow_log(slow_log_printer); 01078 init_general_log(general_log_printer); 01079 01080 unlock(); 01081 01082 return 0; 01083 } 01084 01085 01086 /* 01087 Close log table of a given type (general or slow log) 01088 01089 SYNOPSIS 01090 close_log_table() 01091 01092 log_table_type type of the log table to close: QUERY_LOG_GENERAL 01093 or QUERY_LOG_SLOW 01094 lock_in_use Set to TRUE if the caller owns LOCK_open. FALSE otherwise. 01095 01096 DESCRIPTION 01097 01098 The function closes a log table. It is invoked (1) when we need to reopen 01099 log tables (e.g. FLUSH LOGS or TRUNCATE on the log table is being 01100 executed) or (2) during shutdown. 01101 */ 01102 01103 void Log_to_csv_event_handler:: 01104 close_log_table(uint log_table_type, bool lock_in_use) 01105 { 01106 THD *log_thd, *curr= current_thd; 01107 TABLE_LIST *table; 01108 01109 switch (log_table_type) { 01110 case QUERY_LOG_GENERAL: 01111 if (!logger.is_general_log_table_enabled()) 01112 return; /* do nothing */ 01113 log_thd= general_log_thd; 01114 table= &general_log; 01115 break; 01116 case QUERY_LOG_SLOW: 01117 if (!logger.is_slow_log_table_enabled()) 01118 return; /* do nothing */ 01119 log_thd= slow_log_thd; 01120 table= &slow_log; 01121 break; 01122 default: 01123 DBUG_ASSERT(0); 01124 } 01125 01126 /* 01127 Set thread stack start for the logger thread. See comment in 01128 open_log_table() for details. 01129 */ 01130 if (curr) 01131 log_thd->thread_stack= curr->thread_stack; 01132 else 01133 log_thd->thread_stack= (char*) &log_thd; 01134 01135 /* close the table */ 01136 log_thd->store_globals(); 01137 table->table->file->ha_rnd_end(); 01138 /* discard logger mark before unlock*/ 01139 table->table->locked_by_logger= FALSE; 01140 close_thread_tables(log_thd, lock_in_use); 01141 01142 if (curr) 01143 curr->store_globals(); 01144 else 01145 { 01146 my_pthread_setspecific_ptr(THR_THD, 0); 01147 my_pthread_setspecific_ptr(THR_MALLOC, 0); 01148 } 01149 } 01150 01151 01152 /* 01153 this function is mostly a placeholder. 01154 conceptually, binlog initialization (now mostly done in MYSQL_BIN_LOG::open) 01155 should be moved here. 01156 */ 01157 01158 int binlog_init() 01159 { 01160 01161 binlog_hton.state=opt_bin_log ? SHOW_OPTION_YES : SHOW_OPTION_NO; 01162 binlog_hton.db_type=DB_TYPE_BINLOG; 01163 binlog_hton.savepoint_offset= sizeof(my_off_t); 01164 binlog_hton.close_connection= binlog_close_connection; 01165 binlog_hton.savepoint_set= binlog_savepoint_set; 01166 binlog_hton.savepoint_rollback= binlog_savepoint_rollback; 01167 binlog_hton.commit= binlog_commit; 01168 binlog_hton.rollback= binlog_rollback; 01169 binlog_hton.prepare= binlog_prepare; 01170 binlog_hton.flags= HTON_NOT_USER_SELECTABLE | HTON_HIDDEN; 01171 return 0; 01172 } 01173 01174 static int binlog_close_connection(THD *thd) 01175 { 01176 binlog_trx_data *const trx_data= 01177 (binlog_trx_data*) thd->ha_data[binlog_hton.slot]; 01178 IO_CACHE *trans_log= &trx_data->trans_log; 01179 DBUG_ASSERT(mysql_bin_log.is_open() && trx_data->empty()); 01180 close_cached_file(trans_log); 01181 thd->ha_data[binlog_hton.slot]= 0; 01182 my_free((gptr)trx_data, MYF(0)); 01183 return 0; 01184 } 01185 01186 static int 01187 binlog_end_trans(THD *thd, binlog_trx_data *trx_data, Log_event *end_ev) 01188 { 01189 DBUG_ENTER("binlog_end_trans"); 01190 int error=0; 01191 IO_CACHE *trans_log= &trx_data->trans_log; 01192 01193 01194 /* NULL denotes ROLLBACK with nothing to replicate */ 01195 if (end_ev != NULL) 01196 { 01197 /* 01198 We can always end the statement when ending a transaction since 01199 transactions are not allowed inside stored functions. If they 01200 were, we would have to ensure that we're not ending a statement 01201 inside a stored function. 01202 */ 01203 #ifdef HAVE_ROW_BASED_REPLICATION 01204 thd->binlog_flush_pending_rows_event(TRUE); 01205 #endif 01206 error= mysql_bin_log.write(thd, trans_log, end_ev); 01207 } 01208 #ifdef HAVE_ROW_BASED_REPLICATION 01209 else 01210 { 01211 #ifdef HAVE_ROW_BASED_REPLICATION 01212 thd->binlog_delete_pending_rows_event(); 01213 #endif 01214 } 01215 01216 /* 01217 We need to step the table map version both after writing the 01218 entire transaction to the log file and after rolling back the 01219 transaction. 01220 01221 We need to step the table map version after writing the 01222 transaction cache to disk. In addition, we need to step the table 01223 map version on a rollback to ensure that a new table map event is 01224 generated instead of the one that was written to the thrown-away 01225 transaction cache. 01226 */ 01227 mysql_bin_log.update_table_map_version(); 01228 #endif 01229 01230 statistic_increment(binlog_cache_use, &LOCK_status); 01231 if (trans_log->disk_writes != 0) 01232 { 01233 statistic_increment(binlog_cache_disk_use, &LOCK_status); 01234 trans_log->disk_writes= 0; 01235 } 01236 reinit_io_cache(trans_log, WRITE_CACHE, (my_off_t) 0, 0, 1); // cannot fail 01237 trans_log->end_of_file= max_binlog_cache_size; 01238 DBUG_RETURN(error); 01239 } 01240 01241 static int binlog_prepare(THD *thd, bool all) 01242 { 01243 /* 01244 do nothing. 01245 just pretend we can do 2pc, so that MySQL won't 01246 switch to 1pc. 01247 real work will be done in MYSQL_BIN_LOG::log() 01248 */ 01249 return 0; 01250 } 01251 01252 static int binlog_commit(THD *thd, bool all) 01253 { 01254 DBUG_ENTER("binlog_commit"); 01255 binlog_trx_data *const trx_data= 01256 (binlog_trx_data*) thd->ha_data[binlog_hton.slot]; 01257 IO_CACHE *trans_log= &trx_data->trans_log; 01258 DBUG_ASSERT(mysql_bin_log.is_open() && 01259 (all || !(thd->options & (OPTION_NOT_AUTOCOMMIT | OPTION_BEGIN)))); 01260 01261 if (trx_data->empty()) 01262 { 01263 // we're here because trans_log was flushed in MYSQL_BIN_LOG::log() 01264 DBUG_RETURN(0); 01265 } 01266 if (all) 01267 { 01268 Query_log_event qev(thd, STRING_WITH_LEN("COMMIT"), TRUE, FALSE); 01269 qev.error_code= 0; // see comment in MYSQL_LOG::write(THD, IO_CACHE) 01270 DBUG_RETURN(binlog_end_trans(thd, trx_data, &qev)); 01271 } 01272 else 01273 DBUG_RETURN(binlog_end_trans(thd, trx_data, &invisible_commit)); 01274 } 01275 01276 static int binlog_rollback(THD *thd, bool all) 01277 { 01278 DBUG_ENTER("binlog_rollback"); 01279 int error=0; 01280 binlog_trx_data *const trx_data= 01281 (binlog_trx_data*) thd->ha_data[binlog_hton.slot]; 01282 IO_CACHE *trans_log= &trx_data->trans_log; 01283 /* 01284 First assert is guaranteed - see trans_register_ha() call below. 01285 The second must be true. If it is not, we're registering 01286 unnecessary, doing extra work. The cause should be found and eliminated 01287 */ 01288 DBUG_ASSERT(all || !(thd->options & (OPTION_NOT_AUTOCOMMIT | OPTION_BEGIN))); 01289 DBUG_ASSERT(mysql_bin_log.is_open() && !trx_data->empty()); 01290 /* 01291 Update the binary log with a BEGIN/ROLLBACK block if we have 01292 cached some queries and we updated some non-transactional 01293 table. Such cases should be rare (updating a 01294 non-transactional table inside a transaction...) 01295 */ 01296 if (unlikely(thd->options & (OPTION_STATUS_NO_TRANS_UPDATE | 01297 OPTION_KEEP_LOG))) 01298 { 01299 Query_log_event qev(thd, STRING_WITH_LEN("ROLLBACK"), TRUE, FALSE); 01300 qev.error_code= 0; // see comment in MYSQL_LOG::write(THD, IO_CACHE) 01301 error= binlog_end_trans(thd, trx_data, &qev); 01302 } 01303 else 01304 error= binlog_end_trans(thd, trx_data, 0); 01305 DBUG_RETURN(error); 01306 } 01307 01308 /* 01309 NOTE: how do we handle this (unlikely but legal) case: 01310 [transaction] + [update to non-trans table] + [rollback to savepoint] ? 01311 The problem occurs when a savepoint is before the update to the 01312 non-transactional table. Then when there's a rollback to the savepoint, if we 01313 simply truncate the binlog cache, we lose the part of the binlog cache where 01314 the update is. If we want to not lose it, we need to write the SAVEPOINT 01315 command and the ROLLBACK TO SAVEPOINT command to the binlog cache. The latter 01316 is easy: it's just write at the end of the binlog cache, but the former 01317 should be *inserted* to the place where the user called SAVEPOINT. The 01318 solution is that when the user calls SAVEPOINT, we write it to the binlog 01319 cache (so no need to later insert it). As transactions are never intermixed 01320 in the binary log (i.e. they are serialized), we won't have conflicts with 01321 savepoint names when using mysqlbinlog or in the slave SQL thread. 01322 Then when ROLLBACK TO SAVEPOINT is called, if we updated some 01323 non-transactional table, we don't truncate the binlog cache but instead write 01324 ROLLBACK TO SAVEPOINT to it; otherwise we truncate the binlog cache (which 01325 will chop the SAVEPOINT command from the binlog cache, which is good as in 01326 that case there is no need to have it in the binlog). 01327 */ 01328 01329 static int binlog_savepoint_set(THD *thd, void *sv) 01330 { 01331 DBUG_ENTER("binlog_savepoint_set"); 01332 binlog_trx_data *const trx_data= 01333 (binlog_trx_data*) thd->ha_data[binlog_hton.slot]; 01334 DBUG_ASSERT(mysql_bin_log.is_open() && my_b_tell(&trx_data->trans_log)); 01335 01336 *(my_off_t *)sv= my_b_tell(&trx_data->trans_log); 01337 /* Write it to the binary log */ 01338 01339 int const error= 01340 thd->binlog_query(THD::STMT_QUERY_TYPE, 01341 thd->query, thd->query_length, TRUE, FALSE); 01342 DBUG_RETURN(error); 01343 } 01344 01345 static int binlog_savepoint_rollback(THD *thd, void *sv) 01346 { 01347 DBUG_ENTER("binlog_savepoint_rollback"); 01348 binlog_trx_data *const trx_data= 01349 (binlog_trx_data*) thd->ha_data[binlog_hton.slot]; 01350 IO_CACHE *trans_log= &trx_data->trans_log; 01351 DBUG_ASSERT(mysql_bin_log.is_open() && my_b_tell(trans_log)); 01352 01353 /* 01354 Write ROLLBACK TO SAVEPOINT to the binlog cache if we have updated some 01355 non-transactional table. Otherwise, truncate the binlog cache starting 01356 from the SAVEPOINT command. 01357 */ 01358 if (unlikely(thd->options & 01359 (OPTION_STATUS_NO_TRANS_UPDATE | OPTION_KEEP_LOG))) 01360 { 01361 int const error= 01362 thd->binlog_query(THD::STMT_QUERY_TYPE, 01363 thd->query, thd->query_length, TRUE, FALSE); 01364 DBUG_RETURN(error); 01365 } 01366 reinit_io_cache(trans_log, WRITE_CACHE, *(my_off_t *)sv, 0, 0); 01367 DBUG_RETURN(0); 01368 } 01369 01370 int check_binlog_magic(IO_CACHE* log, const char** errmsg) 01371 { 01372 char magic[4]; 01373 DBUG_ASSERT(my_b_tell(log) == 0); 01374 01375 if (my_b_read(log, (byte*) magic, sizeof(magic))) 01376 { 01377 *errmsg = "I/O error reading the header from the binary log"; 01378 sql_print_error("%s, errno=%d, io cache code=%d", *errmsg, my_errno, 01379 log->error); 01380 return 1; 01381 } 01382 if (memcmp(magic, BINLOG_MAGIC, sizeof(magic))) 01383 { 01384 *errmsg = "Binlog has bad magic number; It's not a binary log file that can be used by this version of MySQL"; 01385 return 1; 01386 } 01387 return 0; 01388 } 01389 01390 File open_binlog(IO_CACHE *log, const char *log_file_name, const char **errmsg) 01391 { 01392 File file; 01393 DBUG_ENTER("open_binlog"); 01394 01395 if ((file = my_open(log_file_name, O_RDONLY | O_BINARY | O_SHARE, 01396 MYF(MY_WME))) < 0) 01397 { 01398 sql_print_error("Failed to open log (file '%s', errno %d)", 01399 log_file_name, my_errno); 01400 *errmsg = "Could not open log file"; 01401 goto err; 01402 } 01403 if (init_io_cache(log, file, IO_SIZE*2, READ_CACHE, 0, 0, 01404 MYF(MY_WME|MY_DONT_CHECK_FILESIZE))) 01405 { 01406 sql_print_error("Failed to create a cache on log (file '%s')", 01407 log_file_name); 01408 *errmsg = "Could not open log file"; 01409 goto err; 01410 } 01411 if (check_binlog_magic(log,errmsg)) 01412 goto err; 01413 DBUG_RETURN(file); 01414 01415 err: 01416 if (file >= 0) 01417 { 01418 my_close(file,MYF(0)); 01419 end_io_cache(log); 01420 } 01421 DBUG_RETURN(-1); 01422 } 01423 01424 #ifdef __NT__ 01425 static int eventSource = 0; 01426 01427 void setup_windows_event_source() 01428 { 01429 HKEY hRegKey= NULL; 01430 DWORD dwError= 0; 01431 TCHAR szPath[MAX_PATH]; 01432 DWORD dwTypes; 01433 01434 if (eventSource) // Ensure that we are only called once 01435 return; 01436 eventSource= 1; 01437 01438 // Create the event source registry key 01439 dwError= RegCreateKey(HKEY_LOCAL_MACHINE, 01440 "SYSTEM\\CurrentControlSet\\Services\\EventLog\\Application\\MySQL", 01441 &hRegKey); 01442 01443 /* Name of the PE module that contains the message resource */ 01444 GetModuleFileName(NULL, szPath, MAX_PATH); 01445 01446 /* Register EventMessageFile */ 01447 dwError = RegSetValueEx(hRegKey, "EventMessageFile", 0, REG_EXPAND_SZ, 01448 (PBYTE) szPath, strlen(szPath)+1); 01449 01450 /* Register supported event types */ 01451 dwTypes= (EVENTLOG_ERROR_TYPE | EVENTLOG_WARNING_TYPE | 01452 EVENTLOG_INFORMATION_TYPE); 01453 dwError= RegSetValueEx(hRegKey, "TypesSupported", 0, REG_DWORD, 01454 (LPBYTE) &dwTypes, sizeof dwTypes); 01455 01456 RegCloseKey(hRegKey); 01457 } 01458 01459 #endif /* __NT__ */ 01460 01461 01462 /**************************************************************************** 01463 ** Find a uniq filename for 'filename.#'. 01464 ** Set # to a number as low as possible 01465 ** returns != 0 if not possible to get uniq filename 01466 ****************************************************************************/ 01467 01468 static int find_uniq_filename(char *name) 01469 { 01470 long number; 01471 uint i; 01472 char buff[FN_REFLEN]; 01473 struct st_my_dir *dir_info; 01474 reg1 struct fileinfo *file_info; 01475 ulong max_found=0; 01476 01477 DBUG_ENTER("find_uniq_filename"); 01478 01479 uint length = dirname_part(buff,name); 01480 char *start = name + length; 01481 char *end = strend(start); 01482 01483 *end='.'; 01484 length= (uint) (end-start+1); 01485 01486 if (!(dir_info = my_dir(buff,MYF(MY_DONT_SORT)))) 01487 { // This shouldn't happen 01488 strmov(end,".1"); // use name+1 01489 DBUG_RETURN(0); 01490 } 01491 file_info= dir_info->dir_entry; 01492 for (i=dir_info->number_off_files ; i-- ; file_info++) 01493 { 01494 if (bcmp(file_info->name,start,length) == 0 && 01495 test_if_number(file_info->name+length, &number,0)) 01496 { 01497 set_if_bigger(max_found,(ulong) number); 01498 } 01499 } 01500 my_dirend(dir_info); 01501 01502 *end++='.'; 01503 sprintf(end,"%06ld",max_found+1); 01504 DBUG_RETURN(0); 01505 } 01506 01507 01508 void MYSQL_LOG::init(enum_log_type log_type_arg, 01509 enum cache_type io_cache_type_arg) 01510 { 01511 DBUG_ENTER("MYSQL_LOG::init"); 01512 log_type= log_type_arg; 01513 io_cache_type= io_cache_type_arg; 01514 DBUG_PRINT("info",("log_type: %d", log_type)); 01515 DBUG_VOID_RETURN; 01516 } 01517 01518 01519 /* 01520 Open a (new) log file. 01521 01522 SYNOPSIS 01523 open() 01524 01525 log_name The name of the log to open 01526 log_type_arg The type of the log. E.g. LOG_NORMAL 01527 new_name The new name for the logfile. This is only needed 01528 when the method is used to open the binlog file. 01529 io_cache_type_arg The type of the IO_CACHE to use for this log file 01530 01531 DESCRIPTION 01532 Open the logfile, init IO_CACHE and write startup messages 01533 (in case of general and slow query logs). 01534 01535 RETURN VALUES 01536 0 ok 01537 1 error 01538 */ 01539 01540 bool MYSQL_LOG::open(const char *log_name, enum_log_type log_type_arg, 01541 const char *new_name, enum cache_type io_cache_type_arg) 01542 { 01543 char buff[FN_REFLEN]; 01544 File file= -1; 01545 int open_flags= O_CREAT | O_BINARY; 01546 DBUG_ENTER("MYSQL_LOG::open"); 01547 DBUG_PRINT("enter", ("log_type: %d", (int) log_type_arg)); 01548 01549 write_error= 0; 01550 01551 init(log_type_arg, io_cache_type_arg); 01552 01553 if (!(name= my_strdup(log_name, MYF(MY_WME)))) 01554 { 01555 name= (char *)log_name; // for the error message 01556 goto err; 01557 } 01558 01559 if (new_name) 01560 strmov(log_file_name, new_name); 01561 else if (generate_new_name(log_file_name, name)) 01562 goto err; 01563 01564 if (io_cache_type == SEQ_READ_APPEND) 01565 open_flags |= O_RDWR | O_APPEND; 01566 else 01567 open_flags |= O_WRONLY | (log_type == LOG_BIN ? 0 : O_APPEND); 01568 01569 db[0]= 0; 01570 01571 if ((file= my_open(log_file_name, open_flags, 01572 MYF(MY_WME | ME_WAITTANG))) < 0 || 01573 init_io_cache(&log_file, file, IO_SIZE, io_cache_type, 01574 my_tell(file, MYF(MY_WME)), 0, 01575 MYF(MY_WME | MY_NABP | 01576 ((log_type == LOG_BIN) ? MY_WAIT_IF_FULL : 0)))) 01577 goto err; 01578 01579 if (log_type == LOG_NORMAL) 01580 { 01581 char *end; 01582 int len=my_snprintf(buff, sizeof(buff), "%s, Version: %s. " 01583 #ifdef EMBEDDED_LIBRARY 01584 "embedded library\n", my_progname, server_version 01585 #elif __NT__ 01586 "started with:\nTCP Port: %d, Named Pipe: %s\n", 01587 my_progname, server_version, mysqld_port, 01588 mysqld_unix_port 01589 #else 01590 "started with:\nTcp port: %d Unix socket: %s\n", 01591 my_progname, server_version, mysqld_port, 01592 mysqld_unix_port 01593 #endif 01594 ); 01595 end= strnmov(buff + len, "Time Id Command Argument\n", 01596 sizeof(buff) - len); 01597 if (my_b_write(&log_file, (byte*) buff, (uint) (end-buff)) || 01598 flush_io_cache(&log_file)) 01599 goto err; 01600 } 01601 01602 log_state= LOG_OPENED; 01603 DBUG_RETURN(0); 01604 01605 err: 01606 sql_print_error("Could not use %s for logging (error %d). \ 01607 Turning logging off for the whole duration of the MySQL server process. \ 01608 To turn it on again: fix the cause, \ 01609 shutdown the MySQL server and restart it.", name, errno); 01610 if (file >= 0) 01611 my_close(file, MYF(0)); 01612 end_io_cache(&log_file); 01613 safeFree(name); 01614 log_state= LOG_CLOSED; 01615 DBUG_RETURN(1); 01616 } 01617 01618 MYSQL_LOG::MYSQL_LOG() 01619 : name(0), log_type(LOG_UNKNOWN), log_state(LOG_CLOSED), write_error(FALSE), 01620 inited(FALSE) 01621 { 01622 /* 01623 We don't want to initialize LOCK_Log here as such initialization depends on 01624 safe_mutex (when using safe_mutex) which depends on MY_INIT(), which is 01625 called only in main(). Doing initialization here would make it happen 01626 before main(). 01627 */ 01628 bzero((char*) &log_file, sizeof(log_file)); 01629 } 01630 01631 void MYSQL_LOG::init_pthread_objects() 01632 { 01633 DBUG_ASSERT(inited == 0); 01634 inited= 1; 01635 (void) pthread_mutex_init(&LOCK_log, MY_MUTEX_INIT_SLOW); 01636 } 01637 01638 /* 01639 Close the log file 01640 01641 SYNOPSIS 01642 close() 01643 exiting Bitmask. For the slow and general logs the only used bit is 01644 LOG_CLOSE_TO_BE_OPENED. This is used if we intend to call 01645 open at once after close. 01646 01647 NOTES 01648 One can do an open on the object at once after doing a close. 01649 The internal structures are not freed until cleanup() is called 01650 */ 01651 01652 void MYSQL_LOG::close(uint exiting) 01653 { // One can't set log_type here! 01654 DBUG_ENTER("MYSQL_LOG::close"); 01655 DBUG_PRINT("enter",("exiting: %d", (int) exiting)); 01656 if (log_state == LOG_OPENED) 01657 { 01658 end_io_cache(&log_file); 01659 01660 if (my_sync(log_file.file, MYF(MY_WME)) && ! write_error) 01661 { 01662 write_error= 1; 01663 sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno); 01664 } 01665 01666 if (my_close(log_file.file, MYF(MY_WME)) && ! write_error) 01667 { 01668 write_error= 1; 01669 sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno); 01670 } 01671 } 01672 01673 log_state= (exiting & LOG_CLOSE_TO_BE_OPENED) ? LOG_TO_BE_OPENED : LOG_CLOSED; 01674 safeFree(name); 01675 DBUG_VOID_RETURN; 01676 } 01677 01678 /* this is called only once */ 01679 01680 void MYSQL_LOG::cleanup() 01681 { 01682 DBUG_ENTER("cleanup"); 01683 if (inited) 01684 { 01685 inited= 0; 01686 (void) pthread_mutex_destroy(&LOCK_log); 01687 close(0); 01688 } 01689 DBUG_VOID_RETURN; 01690 } 01691 01692 01693 int MYSQL_LOG::generate_new_name(char *new_name, const char *log_name) 01694 { 01695 fn_format(new_name, log_name, mysql_data_home, "", 4); 01696 if (log_type == LOG_BIN) 01697 { 01698 if (!fn_ext(log_name)[0]) 01699 { 01700 if (find_uniq_filename(new_name)) 01701 { 01702 sql_print_error(ER(ER_NO_UNIQUE_LOGFILE), log_name); 01703 return 1; 01704 } 01705 } 01706 } 01707 return 0; 01708 } 01709 01710 01711 /* 01712 Reopen the log file 01713 01714 SYNOPSIS 01715 reopen_file() 01716 01717 DESCRIPTION 01718 Reopen the log file. The method is used during FLUSH LOGS 01719 and locks LOCK_log mutex 01720 */ 01721 01722 01723 void MYSQL_QUERY_LOG::reopen_file() 01724 { 01725 char *save_name; 01726 01727 DBUG_ENTER("MYSQL_LOG::reopen_file"); 01728 if (!is_open()) 01729 { 01730 DBUG_PRINT("info",("log is closed")); 01731 DBUG_VOID_RETURN; 01732 } 01733 01734 pthread_mutex_lock(&LOCK_log); 01735 01736 save_name= name; 01737 name= 0; // Don't free name 01738 close(LOG_CLOSE_TO_BE_OPENED); 01739 01740 /* 01741 Note that at this point, log_state != LOG_CLOSED (important for is_open()). 01742 */ 01743 01744 open(save_name, log_type, 0, io_cache_type); 01745 my_free(save_name, MYF(0)); 01746 01747 pthread_mutex_unlock(&LOCK_log); 01748 01749 DBUG_VOID_RETURN; 01750 } 01751 01752 01753 /* 01754 Write a command to traditional general log file 01755 01756 SYNOPSIS 01757 write() 01758 01759 event_time command start timestamp 01760 user_host the pointer to the string with user@host info 01761 user_host_len length of the user_host string. this is computed once 01762 and passed to all general log event handlers 01763 thread_id Id of the thread, issued a query 01764 command_type the type of the command being logged 01765 command_type_len the length of the string above 01766 sql_text the very text of the query being executed 01767 sql_text_len the length of sql_text string 01768 01769 DESCRIPTION 01770 01771 Log given command to to normal (not rotable) log file 01772 01773 RETURN 01774 FASE - OK 01775 TRUE - error occured 01776 */ 01777 01778 bool MYSQL_QUERY_LOG::write(time_t event_time, const char *user_host, 01779 uint user_host_len, int thread_id, 01780 const char *command_type, uint command_type_len, 01781 const char *sql_text, uint sql_text_len) 01782 { 01783 char buff[32]; 01784 uint length= 0; 01785 char time_buff[MAX_TIME_SIZE]; 01786 struct tm start; 01787 uint time_buff_len= 0; 01788 01789 /* Test if someone closed between the is_open test and lock */ 01790 if (is_open()) 01791 { 01792 /* Note that my_b_write() assumes it knows the length for this */ 01793 if (event_time != last_time) 01794 { 01795 last_time= event_time; 01796 01797 localtime_r(&event_time, &start); 01798 01799 time_buff_len= my_snprintf(time_buff, MAX_TIME_SIZE, 01800 "%02d%02d%02d %2d:%02d:%02d", 01801 start.tm_year % 100, start.tm_mon + 1, 01802 start.tm_mday, start.tm_hour, 01803 start.tm_min, start.tm_sec); 01804 01805 if (my_b_write(&log_file, (byte*) &time_buff, time_buff_len)) 01806 goto err; 01807 } 01808 else 01809 if (my_b_write(&log_file, (byte*) "\t\t" ,2) < 0) 01810 goto err; 01811 01812 /* command_type, thread_id */ 01813 length= my_snprintf(buff, 32, "%5ld ", thread_id); 01814 01815 if (my_b_write(&log_file, (byte*) buff, length)) 01816 goto err; 01817 01818 if (my_b_write(&log_file, (byte*) command_type, command_type_len)) 01819 goto err; 01820 01821 if (my_b_write(&log_file, (byte*) "\t", 1)) 01822 goto err; 01823 01824 /* sql_text */ 01825 if (my_b_write(&log_file, (byte*) sql_text, sql_text_len)) 01826 goto err; 01827 01828 if (my_b_write(&log_file, (byte*) "\n", 1) || 01829 flush_io_cache(&log_file)) 01830 goto err; 01831 } 01832 01833 return FALSE; 01834 err: 01835 01836 if (!write_error) 01837 { 01838 write_error= 1; 01839 sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno); 01840 } 01841 return TRUE; 01842 } 01843 01844 01845 /* 01846 Log a query to the traditional slow log file 01847 01848 SYNOPSIS 01849 write() 01850 01851 thd THD of the query 01852 current_time current timestamp 01853 query_start_arg command start timestamp 01854 user_host the pointer to the string with user@host info 01855 user_host_len length of the user_host string. this is computed once 01856 and passed to all general log event handlers 01857 query_time Amount of time the query took to execute (in seconds) 01858 lock_time Amount of time the query was locked (in seconds) 01859 is_command The flag, which determines, whether the sql_text is a 01860 query or an administrator command. 01861 sql_text the very text of the query or administrator command 01862 processed 01863 sql_text_len the length of sql_text string 01864 01865 DESCRIPTION 01866 01867 Log a query to the slow log file. 01868 01869 RETURN 01870 FALSE - OK 01871 TRUE - error occured 01872 */ 01873 01874 bool MYSQL_QUERY_LOG::write(THD *thd, time_t current_time, 01875 time_t query_start_arg, const char *user_host, 01876 uint user_host_len, longlong query_time, 01877 longlong lock_time, bool is_command, 01878 const char *sql_text, uint sql_text_len) 01879 { 01880 bool error= 0; 01881 DBUG_ENTER("MYSQL_QUERY_LOG::write"); 01882 01883 if (!is_open()) 01884 DBUG_RETURN(0); 01885 01886 if (is_open()) 01887 { // Safety agains reopen 01888 int tmp_errno= 0; 01889 char buff[80], *end; 01890 uint buff_len; 01891 end= buff; 01892 01893 if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT)) 01894 { 01895 Security_context *sctx= thd->security_ctx; 01896 if (current_time != last_time) 01897 { 01898 last_time= current_time; 01899 struct tm start; 01900 localtime_r(¤t_time, &start); 01901 01902 buff_len= my_snprintf(buff, sizeof buff, 01903 "# Time: %02d%02d%02d %2d:%02d:%02d\n", 01904 start.tm_year % 100, start.tm_mon + 1, 01905 start.tm_mday, start.tm_hour, 01906 start.tm_min, start.tm_sec); 01907 01908 /* Note that my_b_write() assumes it knows the length for this */ 01909 if (my_b_write(&log_file, (byte*) buff, buff_len)) 01910 tmp_errno= errno; 01911 } 01912 if (my_b_printf(&log_file, "# User@Host: ", sizeof("# User@Host: ") - 1) 01913 != sizeof("# User@Host: ") - 1) 01914 tmp_errno= errno; 01915 if (my_b_printf(&log_file, user_host, user_host_len) != user_host_len) 01916 tmp_errno= errno; 01917 if (my_b_write(&log_file, (byte*) "\n", 1)) 01918 tmp_errno= errno; 01919 } 01920 /* For slow query log */ 01921 if (my_b_printf(&log_file, 01922 "# Query_time: %lu Lock_time: %lu" 01923 " Rows_sent: %lu Rows_examined: %lu\n", 01924 (ulong) query_time, (ulong) lock_time, 01925 (ulong) thd->sent_row_count, 01926 (ulong) thd->examined_row_count) == (uint) -1) 01927 tmp_errno= errno; 01928 if (thd->db && strcmp(thd->db, db)) 01929 { // Database changed 01930 if (my_b_printf(&log_file,"use %s;\n",thd->db) == (uint) -1) 01931 tmp_errno= errno; 01932 strmov(db,thd->db); 01933 } 01934 if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt) 01935 { 01936 end=strmov(end, ",last_insert_id="); 01937 end=longlong10_to_str((longlong) 01938 thd->first_successful_insert_id_in_prev_stmt_for_binlog, 01939 end, -10); 01940 } 01941 // Save value if we do an insert. 01942 if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0) 01943 { 01944 if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT)) 01945 { 01946 end=strmov(end,",insert_id="); 01947 end=longlong10_to_str((longlong) 01948 thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum(), 01949 end, -10); 01950 } 01951 } 01952 01953 /* 01954 This info used to show up randomly, depending on whether the query 01955 checked the query start time or not. now we always write current 01956 timestamp to the slow log 01957 */ 01958 end= strmov(end, ",timestamp="); 01959 end= int10_to_str((long) current_time, end, 10); 01960 01961 if (end != buff) 01962 { 01963 *end++=';'; 01964 *end='\n'; 01965 if (my_b_write(&log_file, (byte*) "SET ", 4) || 01966 my_b_write(&log_file, (byte*) buff + 1, (uint) (end-buff))) 01967 tmp_errno= errno; 01968 } 01969 if (is_command) 01970 { 01971 end= strxmov(buff, "# administrator command: ", NullS); 01972 buff_len= (ulong) (end - buff); 01973 my_b_write(&log_file, (byte*) buff, buff_len); 01974 } 01975 if (my_b_write(&log_file, (byte*) sql_text, sql_text_len) || 01976 my_b_write(&log_file, (byte*) ";\n",2) || 01977 flush_io_cache(&log_file)) 01978 tmp_errno= errno; 01979 if (tmp_errno) 01980 { 01981 error= 1; 01982 if (! write_error) 01983 { 01984 write_error= 1; 01985 sql_print_error(ER(ER_ERROR_ON_WRITE), name, error); 01986 } 01987 } 01988 } 01989 DBUG_RETURN(error); 01990 } 01991 01992 01993 const char *MYSQL_LOG::generate_name(const char *log_name, 01994 const char *suffix, 01995 bool strip_ext, char *buff) 01996 { 01997 if (!log_name || !log_name[0]) 01998 { 01999 /* 02000 TODO: The following should be using fn_format(); We just need to 02001 first change fn_format() to cut the file name if it's too long. 02002 */ 02003 strmake(buff, glob_hostname, FN_REFLEN - 5); 02004 strmov(fn_ext(buff), suffix); 02005 return (const char *)buff; 02006 } 02007 // get rid of extension if the log is binary to avoid problems 02008 if (strip_ext) 02009 { 02010 char *p= fn_ext(log_name); 02011 uint length= (uint) (p - log_name); 02012 strmake(buff, log_name, min(length, FN_REFLEN)); 02013 return (const char*)buff; 02014 } 02015 return log_name; 02016 } 02017 02018 02019 02020 MYSQL_BIN_LOG::MYSQL_BIN_LOG() 02021 :bytes_written(0), prepared_xids(0), file_id(1), open_count(1), 02022 need_start_event(TRUE), m_table_map_version(0), 02023 description_event_for_exec(0), description_event_for_queue(0) 02024 { 02025 /* 02026 We don't want to initialize locks here as such initialization depends on 02027 safe_mutex (when using safe_mutex) which depends on MY_INIT(), which is 02028 called only in main(). Doing initialization here would make it happen 02029 before main(). 02030 */ 02031 index_file_name[0] = 0; 02032 bzero((char*) &index_file, sizeof(index_file)); 02033 } 02034 02035 /* this is called only once */ 02036 02037 void MYSQL_BIN_LOG::cleanup() 02038 { 02039 DBUG_ENTER("cleanup"); 02040 if (inited) 02041 { 02042 inited= 0; 02043 close(LOG_CLOSE_INDEX|LOG_CLOSE_STOP_EVENT); 02044 delete description_event_for_queue; 02045 delete description_event_for_exec; 02046 (void) pthread_mutex_destroy(&LOCK_log); 02047 (void) pthread_mutex_destroy(&LOCK_index); 02048 (void) pthread_cond_destroy(&update_cond); 02049 } 02050 DBUG_VOID_RETURN; 02051 } 02052 02053 02054 /* Init binlog-specific vars */ 02055 void MYSQL_BIN_LOG::init(bool no_auto_events_arg, ulong max_size_arg) 02056 { 02057 DBUG_ENTER("MYSQL_BIN_LOG::init"); 02058 no_auto_events= no_auto_events_arg; 02059 max_size= max_size_arg; 02060 DBUG_PRINT("info",("max_size: %lu", max_size)); 02061 DBUG_VOID_RETURN; 02062 } 02063 02064 02065 void MYSQL_BIN_LOG::init_pthread_objects() 02066 { 02067 DBUG_ASSERT(inited == 0); 02068 inited= 1; 02069 (void) pthread_mutex_init(&LOCK_log, MY_MUTEX_INIT_SLOW); 02070 (void) pthread_mutex_init(&LOCK_index, MY_MUTEX_INIT_SLOW); 02071 (void) pthread_cond_init(&update_cond, 0); 02072 } 02073 02074 02075 bool MYSQL_BIN_LOG::open_index_file(const char *index_file_name_arg, 02076 const char *log_name) 02077 { 02078 File index_file_nr= -1; 02079 DBUG_ASSERT(!my_b_inited(&index_file)); 02080 02081 /* 02082 First open of this class instance 02083 Create an index file that will hold all file names uses for logging. 02084 Add new entries to the end of it. 02085 */ 02086 myf opt= MY_UNPACK_FILENAME; 02087 if (!index_file_name_arg) 02088 { 02089 index_file_name_arg= log_name; // Use same basename for index file 02090 opt= MY_UNPACK_FILENAME | MY_REPLACE_EXT; 02091 } 02092 fn_format(index_file_name, index_file_name_arg, mysql_data_home, 02093 ".index", opt); 02094 if ((index_file_nr= my_open(index_file_name, 02095 O_RDWR | O_CREAT | O_BINARY , 02096 MYF(MY_WME))) < 0 || 02097 my_sync(index_file_nr, MYF(MY_WME)) || 02098 init_io_cache(&index_file, index_file_nr, 02099 IO_SIZE, WRITE_CACHE, 02100 my_seek(index_file_nr,0L,MY_SEEK_END,MYF(0)), 02101 0, MYF(MY_WME | MY_WAIT_IF_FULL))) 02102 { 02103 if (index_file_nr >= 0) 02104 my_close(index_file_nr,MYF(0)); 02105 return TRUE; 02106 } 02107 return FALSE; 02108 } 02109 02110 02111 /* 02112 Open a (new) binlog file. 02113 02114 DESCRIPTION 02115 - Open the log file and the index file. Register the new 02116 file name in it 02117 - When calling this when the file is in use, you must have a locks 02118 on LOCK_log and LOCK_index. 02119 02120 RETURN VALUES 02121 0 ok 02122 1 error 02123 */ 02124 02125 bool MYSQL_BIN_LOG::open(const char *log_name, 02126 enum_log_type log_type_arg, 02127 const char *new_name, 02128 enum cache_type io_cache_type_arg, 02129 bool no_auto_events_arg, 02130 ulong max_size_arg, 02131 bool null_created_arg) 02132 { 02133 char buff[FN_REFLEN]; 02134 File file= -1; 02135 int open_flags = O_CREAT | O_BINARY; 02136 DBUG_ENTER("MYSQL_BIN_LOG::open"); 02137 DBUG_PRINT("enter",("log_type: %d",(int) log_type_arg)); 02138 02139 write_error=0; 02140 02141 /* open the main log file */ 02142 if (MYSQL_LOG::open(log_name, log_type_arg, new_name, io_cache_type_arg)) 02143 DBUG_RETURN(1); /* all warnings issued */ 02144 02145 init(no_auto_events_arg, max_size_arg); 02146 02147 open_count++; 02148 02149 DBUG_ASSERT(log_type == LOG_BIN); 02150 02151 { 02152 bool write_file_name_to_index_file=0; 02153 02154 if (!my_b_filelength(&log_file)) 02155 { 02156 /* 02157 The binary log file was empty (probably newly created) 02158 This is the normal case and happens when the user doesn't specify 02159 an extension for the binary log files. 02160 In this case we write a standard header to it. 02161 */ 02162 if (my_b_safe_write(&log_file, (byte*) BINLOG_MAGIC, 02163 BIN_LOG_HEADER_SIZE)) 02164 goto err; 02165 bytes_written+= BIN_LOG_HEADER_SIZE; 02166 write_file_name_to_index_file= 1; 02167 } 02168 02169 DBUG_ASSERT(my_b_inited(&index_file) != 0); 02170 reinit_io_cache(&index_file, WRITE_CACHE, 02171 my_b_filelength(&index_file), 0, 0); 02172 if (need_start_event && !no_auto_events) 02173 { 02174 /* 02175 In 4.x we set need_start_event=0 here, but in 5.0 we want a Start event 02176 even if this is not the very first binlog. 02177 */ 02178 Format_description_log_event s(BINLOG_VERSION); 02179 /* 02180 don't set LOG_EVENT_BINLOG_IN_USE_F for SEQ_READ_APPEND io_cache 02181 as we won't be able to reset it later 02182 */ 02183 if (io_cache_type == WRITE_CACHE) 02184 s.flags|= LOG_EVENT_BINLOG_IN_USE_F; 02185 if (!s.is_valid()) 02186 goto err; 02187 if (null_created_arg) 02188 s.created= 0; 02189 if (s.write(&log_file)) 02190 goto err; 02191 bytes_written+= s.data_written; 02192 } 02193 if (description_event_for_queue && 02194 description_event_for_queue->binlog_version>=4) 02195 { 02196 /* 02197 This is a relay log written to by the I/O slave thread. 02198 Write the event so that others can later know the format of this relay 02199 log. 02200 Note that this event is very close to the original event from the 02201 master (it has binlog version of the master, event types of the 02202 master), so this is suitable to parse the next relay log's event. It 02203 has been produced by 02204 Format_description_log_event::Format_description_log_event(char* buf,). 02205 Why don't we want to write the description_event_for_queue if this 02206 event is for format<4 (3.23 or 4.x): this is because in that case, the 02207 description_event_for_queue describes the data received from the 02208 master, but not the data written to the relay log (*conversion*), 02209 which is in format 4 (slave's). 02210 */ 02211 /* 02212 Set 'created' to 0, so that in next relay logs this event does not 02213 trigger cleaning actions on the slave in 02214 Format_description_log_event::exec_event(). 02215 */ 02216 description_event_for_queue->created= 0; 02217 /* Don't set log_pos in event header */ 02218 description_event_for_queue->artificial_event=1; 02219 02220 if (description_event_for_queue->write(&log_file)) 02221 goto err; 02222 bytes_written+= description_event_for_queue->data_written; 02223 } 02224 if (flush_io_cache(&log_file) || 02225 my_sync(log_file.file, MYF(MY_WME))) 02226 goto err; 02227 02228 if (write_file_name_to_index_file) 02229 { 02230 /* 02231 As this is a new log file, we write the file name to the index 02232 file. As every time we write to the index file, we sync it. 02233 */ 02234 if (my_b_write(&index_file, (byte*) log_file_name, 02235 strlen(log_file_name)) || 02236 my_b_write(&index_file, (byte*) "\n", 1) || 02237 flush_io_cache(&index_file) || 02238 my_sync(index_file.file, MYF(MY_WME))) 02239 goto err; 02240 } 02241 } 02242 log_state= LOG_OPENED; 02243 02244 DBUG_RETURN(0); 02245 02246 err: 02247 sql_print_error("Could not use %s for logging (error %d). \ 02248 Turning logging off for the whole duration of the MySQL server process. \ 02249 To turn it on again: fix the cause, \ 02250 shutdown the MySQL server and restart it.", name, errno); 02251 if (file >= 0) 02252 my_close(file,MYF(0)); 02253 end_io_cache(&log_file); 02254 end_io_cache(&index_file); 02255 safeFree(name); 02256 log_state= LOG_CLOSED; 02257 DBUG_RETURN(1); 02258 } 02259 02260 02261 int MYSQL_BIN_LOG::get_current_log(LOG_INFO* linfo) 02262 { 02263 pthread_mutex_lock(&LOCK_log); 02264 strmake(linfo->log_file_name, log_file_name, sizeof(linfo->log_file_name)-1); 02265 linfo->pos = my_b_tell(&log_file); 02266 pthread_mutex_unlock(&LOCK_log); 02267 return 0; 02268 } 02269 02270 02271 /* 02272 Move all data up in a file in an filename index file 02273 02274 SYNOPSIS 02275 copy_up_file_and_fill() 02276 index_file File to move 02277 offset Move everything from here to beginning 02278 02279 NOTE 02280 File will be truncated to be 'offset' shorter or filled up with 02281 newlines 02282 02283 IMPLEMENTATION 02284 We do the copy outside of the IO_CACHE as the cache buffers would just 02285 make things slower and more complicated. 02286 In most cases the copy loop should only do one read. 02287 02288 RETURN VALUES 02289 0 ok 02290 */ 02291 02292 static bool copy_up_file_and_fill(IO_CACHE *index_file, my_off_t offset) 02293 { 02294 int bytes_read; 02295 my_off_t init_offset= offset; 02296 File file= index_file->file; 02297 byte io_buf[IO_SIZE*2]; 02298 DBUG_ENTER("copy_up_file_and_fill"); 02299 02300 for (;; offset+= bytes_read) 02301 { 02302 (void) my_seek(file, offset, MY_SEEK_SET, MYF(0)); 02303 if ((bytes_read= (int) my_read(file, io_buf, sizeof(io_buf), MYF(MY_WME))) 02304 < 0) 02305 goto err; 02306 if (!bytes_read) 02307 break; // end of file 02308 (void) my_seek(file, offset-init_offset, MY_SEEK_SET, MYF(0)); 02309 if (my_write(file, (byte*) io_buf, bytes_read, MYF(MY_WME | MY_NABP))) 02310 goto err; 02311 } 02312 /* The following will either truncate the file or fill the end with \n' */ 02313 if (my_chsize(file, offset - init_offset, '\n', MYF(MY_WME)) || 02314 my_sync(file, MYF(MY_WME))) 02315 goto err; 02316 02317 /* Reset data in old index cache */ 02318 reinit_io_cache(index_file, READ_CACHE, (my_off_t) 0, 0, 1); 02319 DBUG_RETURN(0); 02320 02321 err: 02322 DBUG_RETURN(1); 02323 } 02324 02325 02326 /* 02327 Find the position in the log-index-file for the given log name 02328 02329 SYNOPSIS 02330 find_log_pos() 02331 linfo Store here the found log file name and position to 02332 the NEXT log file name in the index file. 02333 log_name Filename to find in the index file. 02334 Is a null pointer if we want to read the first entry 02335 need_lock Set this to 1 if the parent doesn't already have a 02336 lock on LOCK_index 02337 02338 NOTE 02339 On systems without the truncate function the file will end with one or 02340 more empty lines. These will be ignored when reading the file. 02341 02342 RETURN VALUES 02343 0 ok 02344 LOG_INFO_EOF End of log-index-file found 02345 LOG_INFO_IO Got IO error while reading file 02346 */ 02347 02348 int MYSQL_BIN_LOG::find_log_pos(LOG_INFO *linfo, const char *log_name, 02349 bool need_lock) 02350 { 02351 int error= 0; 02352 char *fname= linfo->log_file_name; 02353 uint log_name_len= log_name ? (uint) strlen(log_name) : 0; 02354 DBUG_ENTER("find_log_pos"); 02355 DBUG_PRINT("enter",("log_name: %s", log_name ? log_name : "NULL")); 02356 02357 /* 02358 Mutex needed because we need to make sure the file pointer does not 02359 move from under our feet 02360 */ 02361 if (need_lock) 02362 pthread_mutex_lock(&LOCK_index); 02363 safe_mutex_assert_owner(&LOCK_index); 02364 02365 /* As the file is flushed, we can't get an error here */ 02366 (void) reinit_io_cache(&index_file, READ_CACHE, (my_off_t) 0, 0, 0); 02367 02368 for (;;) 02369 { 02370 uint length; 02371 my_off_t offset= my_b_tell(&index_file); 02372 /* If we get 0 or 1 characters, this is the end of the file */ 02373 02374 if ((length= my_b_gets(&index_file, fname, FN_REFLEN)) <= 1) 02375 { 02376 /* Did not find the given entry; Return not found or error */ 02377 error= !index_file.error ? LOG_INFO_EOF : LOG_INFO_IO; 02378 break; 02379 } 02380 02381 // if the log entry matches, null string matching anything 02382 if (!log_name || 02383 (log_name_len == length-1 && fname[log_name_len] == '\n' && 02384 !memcmp(fname, log_name, log_name_len))) 02385 { 02386 DBUG_PRINT("info",("Found log file entry")); 02387 fname[length-1]=0; // remove last \n 02388 linfo->index_file_start_offset= offset; 02389 linfo->index_file_offset = my_b_tell(&index_file); 02390 break; 02391 } 02392 } 02393 02394 if (need_lock) 02395 pthread_mutex_unlock(&LOCK_index); 02396 DBUG_RETURN(error); 02397 } 02398 02399 02400 /* 02401 Find the position in the log-index-file for the given log name 02402 02403 SYNOPSIS 02404 find_next_log() 02405 linfo Store here the next log file name and position to 02406 the file name after that. 02407 need_lock Set this to 1 if the parent doesn't already have a 02408 lock on LOCK_index 02409 02410 NOTE 02411 - Before calling this function, one has to call find_log_pos() 02412 to set up 'linfo' 02413 - Mutex needed because we need to make sure the file pointer does not move 02414 from under our feet 02415 02416 RETURN VALUES 02417 0 ok 02418 LOG_INFO_EOF End of log-index-file found 02419 LOG_INFO_IO Got IO error while reading file 02420 */ 02421 02422 int MYSQL_BIN_LOG::find_next_log(LOG_INFO* linfo, bool need_lock) 02423 { 02424 int error= 0; 02425 uint length; 02426 char *fname= linfo->log_file_name; 02427 02428 if (need_lock) 02429 pthread_mutex_lock(&LOCK_index); 02430 safe_mutex_assert_owner(&LOCK_index); 02431 02432 /* As the file is flushed, we can't get an error here */ 02433 (void) reinit_io_cache(&index_file, READ_CACHE, linfo->index_file_offset, 0, 02434 0); 02435 02436 linfo->index_file_start_offset= linfo->index_file_offset; 02437 if ((length=my_b_gets(&index_file, fname, FN_REFLEN)) <= 1) 02438 { 02439 error = !index_file.error ? LOG_INFO_EOF : LOG_INFO_IO; 02440 goto err; 02441 } 02442 fname[length-1]=0; // kill \n 02443 linfo->index_file_offset = my_b_tell(&index_file); 02444 02445 err: 02446 if (need_lock) 02447 pthread_mutex_unlock(&LOCK_index); 02448 return error; 02449 } 02450 02451 02452 /* 02453 Delete all logs refered to in the index file 02454 Start writing to a new log file. The new index file will only contain 02455 this file. 02456 02457 SYNOPSIS 02458 reset_logs() 02459 thd Thread 02460 02461 NOTE 02462 If not called from slave thread, write start event to new log 02463 02464 02465 RETURN VALUES 02466 0 ok 02467 1 error 02468 */ 02469 02470 bool MYSQL_BIN_LOG::reset_logs(THD* thd) 02471 { 02472 LOG_INFO linfo; 02473 bool error=0; 02474 const char* save_name; 02475 DBUG_ENTER("reset_logs"); 02476 02477 ha_reset_logs(thd); 02478 /* 02479 We need to get both locks to be sure that no one is trying to 02480 write to the index log file. 02481 */ 02482 pthread_mutex_lock(&LOCK_log); 02483 pthread_mutex_lock(&LOCK_index); 02484 02485 /* 02486 The following mutex is needed to ensure that no threads call 02487 'delete thd' as we would then risk missing a 'rollback' from this 02488 thread. If the transaction involved MyISAM tables, it should go 02489 into binlog even on rollback. 02490 */ 02491 (void) pthread_mutex_lock(&LOCK_thread_count); 02492 02493 /* Save variables so that we can reopen the log */ 02494 save_name=name; 02495 name=0; // Protect against free 02496 close(LOG_CLOSE_TO_BE_OPENED); 02497 02498 /* First delete all old log files */ 02499 02500 if (find_log_pos(&linfo, NullS, 0)) 02501 { 02502 error=1; 02503 goto err; 02504 } 02505 02506 for (;;) 02507 { 02508 my_delete_allow_opened(linfo.log_file_name, MYF(MY_WME)); 02509 if (find_next_log(&linfo, 0)) 02510 break; 02511 } 02512 02513 /* Start logging with a new file */ 02514 close(LOG_CLOSE_INDEX); 02515 my_delete_allow_opened(index_file_name, MYF(MY_WME)); // Reset (open will update) 02516 if (!thd->slave_thread) 02517 need_start_event=1; 02518 if (!open_index_file(index_file_name, 0)) 02519 open(save_name, log_type, 0, io_cache_type, no_auto_events, max_size, 0); 02520 my_free((gptr) save_name, MYF(0)); 02521 02522 err: 02523 (void) pthread_mutex_unlock(&LOCK_thread_count); 02524 pthread_mutex_unlock(&LOCK_index); 02525 pthread_mutex_unlock(&LOCK_log); 02526 DBUG_RETURN(error); 02527 } 02528 02529 02530 /* 02531 Delete relay log files prior to rli->group_relay_log_name 02532 (i.e. all logs which are not involved in a non-finished group 02533 (transaction)), remove them from the index file and start on next relay log. 02534 02535 SYNOPSIS 02536 purge_first_log() 02537 rli Relay log information 02538 included If false, all relay logs that are strictly before 02539 rli->group_relay_log_name are deleted ; if true, the latter is 02540 deleted too (i.e. all relay logs 02541 read by the SQL slave thread are deleted). 02542 02543 NOTE 02544 - This is only called from the slave-execute thread when it has read 02545 all commands from a relay log and want to switch to a new relay log. 02546 - When this happens, we can be in an active transaction as 02547 a transaction can span over two relay logs 02548 (although it is always written as a single block to the master's binary 02549 log, hence cannot span over two master's binary logs). 02550 02551 IMPLEMENTATION 02552 - Protects index file with LOCK_index 02553 - Delete relevant relay log files 02554 - Copy all file names after these ones to the front of the index file 02555 - If the OS has truncate, truncate the file, else fill it with \n' 02556 - Read the next file name from the index file and store in rli->linfo 02557 02558 RETURN VALUES 02559 0 ok 02560 LOG_INFO_EOF End of log-index-file found 02561 LOG_INFO_SEEK Could not allocate IO cache 02562 LOG_INFO_IO Got IO error while reading file 02563 */ 02564 02565 #ifdef HAVE_REPLICATION 02566 02567 int MYSQL_BIN_LOG::purge_first_log(struct st_relay_log_info* rli, bool included) 02568 { 02569 int error; 02570 DBUG_ENTER("purge_first_log"); 02571 02572 DBUG_ASSERT(is_open()); 02573 DBUG_ASSERT(rli->slave_running == 1); 02574 DBUG_ASSERT(!strcmp(rli->linfo.log_file_name,rli->event_relay_log_name)); 02575 02576 pthread_mutex_lock(&LOCK_index); 02577 pthread_mutex_lock(&rli->log_space_lock); 02578 rli->relay_log.purge_logs(rli->group_relay_log_name, included, 02579 0, 0, &rli->log_space_total); 02580 // Tell the I/O thread to take the relay_log_space_limit into account 02581 rli->ignore_log_space_limit= 0; 02582 pthread_mutex_unlock(&rli->log_space_lock); 02583 02584 /* 02585 Ok to broadcast after the critical region as there is no risk of 02586 the mutex being destroyed by this thread later - this helps save 02587 context switches 02588 */ 02589 pthread_cond_broadcast(&rli->log_space_cond); 02590 02591 /* 02592 Read the next log file name from the index file and pass it back to 02593 the caller 02594 If included is true, we want the first relay log; 02595 otherwise we want the one after event_relay_log_name. 02596 */ 02597 if ((included && (error=find_log_pos(&rli->linfo, NullS, 0))) || 02598 (!included && 02599 ((error=find_log_pos(&rli->linfo, rli->event_relay_log_name, 0)) || 02600 (error=find_next_log(&rli->linfo, 0))))) 02601 { 02602 char buff[22]; 02603 sql_print_error("next log error: %d offset: %s log: %s included: %d", 02604 error, 02605 llstr(rli->linfo.index_file_offset,buff), 02606 rli->group_relay_log_name, 02607 included); 02608 goto err; 02609 } 02610 02611 /* 02612 Reset rli's coordinates to the current log. 02613 */ 02614 rli->event_relay_log_pos= BIN_LOG_HEADER_SIZE; 02615 strmake(rli->event_relay_log_name,rli->linfo.log_file_name, 02616 sizeof(rli->event_relay_log_name)-1); 02617 02618 /* 02619 If we removed the rli->group_relay_log_name file, 02620 we must update the rli->group* coordinates, otherwise do not touch it as the 02621 group's execution is not finished (e.g. COMMIT not executed) 02622 */ 02623 if (included) 02624 { 02625 rli->group_relay_log_pos = BIN_LOG_HEADER_SIZE; 02626 strmake(rli->group_relay_log_name,rli->linfo.log_file_name, 02627 sizeof(rli->group_relay_log_name)-1); 02628 rli->notify_group_relay_log_name_update(); 02629 } 02630 02631 /* Store where we are in the new file for the execution thread */ 02632 flush_relay_log_info(rli); 02633 02634 err: 02635 pthread_mutex_unlock(&LOCK_index); 02636 DBUG_RETURN(error); 02637 } 02638 02639 /* 02640 Update log index_file 02641 */ 02642 02643 int MYSQL_BIN_LOG::update_log_index(LOG_INFO* log_info, bool need_update_threads) 02644 { 02645 if (copy_up_file_and_fill(&index_file, log_info->index_file_start_offset)) 02646 return LOG_INFO_IO; 02647 02648 // now update offsets in index file for running threads 02649 if (need_update_threads) 02650 adjust_linfo_offsets(log_info->index_file_start_offset); 02651 return 0; 02652 } 02653 02654 /* 02655 Remove all logs before the given log from disk and from the index file. 02656 02657 SYNOPSIS 02658 purge_logs() 02659 to_log Delete all log file name before this file. 02660 included If true, to_log is deleted too. 02661 need_mutex 02662 need_update_threads If we want to update the log coordinates of 02663 all threads. False for relay logs, true otherwise. 02664 freed_log_space If not null, decrement this variable of 02665 the amount of log space freed 02666 02667 NOTES 02668 If any of the logs before the deleted one is in use, 02669 only purge logs up to this one. 02670 02671 RETURN VALUES 02672 0 ok 02673 LOG_INFO_EOF to_log not found 02674 */ 02675 02676 int MYSQL_BIN_LOG::purge_logs(const char *to_log, 02677 bool included, 02678 bool need_mutex, 02679 bool need_update_threads, 02680 ulonglong *decrease_log_space) 02681 { 02682 int error; 02683 bool exit_loop= 0; 02684 LOG_INFO log_info; 02685 DBUG_ENTER("purge_logs"); 02686 DBUG_PRINT("info",("to_log= %s",to_log)); 02687 02688 if (need_mutex) 02689 pthread_mutex_lock(&LOCK_index); 02690 if ((error=find_log_pos(&log_info, to_log, 0 /*no mutex*/))) 02691 goto err; 02692 02693 /* 02694 File name exists in index file; delete until we find this file 02695 or a file that is used. 02696 */ 02697 if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/))) 02698 goto err; 02699 while ((strcmp(to_log,log_info.log_file_name) || (exit_loop=included)) && 02700 !log_in_use(log_info.log_file_name)) 02701 { 02702 ulong file_size= 0; 02703 if (decrease_log_space) //stat the file we want to delete 02704 { 02705 MY_STAT s; 02706 02707 /* 02708 If we could not stat, we can't know the amount 02709 of space that deletion will free. In most cases, 02710 deletion won't work either, so it's not a problem. 02711 */ 02712 if (my_stat(log_info.log_file_name,&s,MYF(0))) 02713 file_size= s.st_size; 02714 else 02715 sql_print_information("Failed to execute my_stat on file '%s'", 02716 log_info.log_file_name); 02717 } 02718 /* 02719 It's not fatal if we can't delete a log file ; 02720 if we could delete it, take its size into account 02721 */ 02722 DBUG_PRINT("info",("purging %s",log_info.log_file_name)); 02723 if (!my_delete(log_info.log_file_name, MYF(0)) && decrease_log_space) 02724 *decrease_log_space-= file_size; 02725 02726 ha_binlog_index_purge_file(current_thd, log_info.log_file_name); 02727 02728 if (find_next_log(&log_info, 0) || exit_loop) 02729 break; 02730 } 02731 02732 /* 02733 If we get killed -9 here, the sysadmin would have to edit 02734 the log index file after restart - otherwise, this should be safe 02735 */ 02736 error= update_log_index(&log_info, need_update_threads); 02737 02738 err: 02739 if (need_mutex) 02740 pthread_mutex_unlock(&LOCK_index); 02741 DBUG_RETURN(error); 02742 } 02743 02744 /* 02745 Remove all logs before the given file date from disk and from the 02746 index file. 02747 02748 SYNOPSIS 02749 purge_logs_before_date() 02750 thd Thread pointer 02751 before_date Delete all log files before given date. 02752 02753 NOTES 02754 If any of the logs before the deleted one is in use, 02755 only purge logs up to this one. 02756 02757 RETURN VALUES 02758 0 ok 02759 LOG_INFO_PURGE_NO_ROTATE Binary file that can't be rotated 02760 */ 02761 02762 int MYSQL_BIN_LOG::purge_logs_before_date(time_t purge_time) 02763 { 02764 int error; 02765 LOG_INFO log_info; 02766 MY_STAT stat_area; 02767 02768 DBUG_ENTER("purge_logs_before_date"); 02769 02770 pthread_mutex_lock(&LOCK_index); 02771 02772 /* 02773 Delete until we find curren file 02774 or a file that is used or a file 02775 that is older than purge_time. 02776 */ 02777 if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/))) 02778 goto err; 02779 02780 while (strcmp(log_file_name, log_info.log_file_name) && 02781 !log_in_use(log_info.log_file_name)) 02782 { 02783 /* It's not fatal even if we can't delete a log file */ 02784 if (!my_stat(log_info.log_file_name, &stat_area, MYF(0)) || 02785 stat_area.st_mtime >= purge_time) 02786 break; 02787 my_delete(log_info.log_file_name, MYF(0)); 02788 02789 ha_binlog_index_purge_file(current_thd, log_info.log_file_name); 02790 02791 if (find_next_log(&log_info, 0)) 02792 break; 02793 } 02794 02795 /* 02796 If we get killed -9 here, the sysadmin would have to edit 02797 the log index file after restart - otherwise, this should be safe 02798 */ 02799 error= update_log_index(&log_info, 1); 02800 02801 err: 02802 pthread_mutex_unlock(&LOCK_index); 02803 DBUG_RETURN(error); 02804 } 02805 02806 02807 #endif /* HAVE_REPLICATION */ 02808 02809 02810 /* 02811 Create a new log file name 02812 02813 SYNOPSIS 02814 make_log_name() 02815 buf buf of at least FN_REFLEN where new name is stored 02816 02817 NOTE 02818 If file name will be longer then FN_REFLEN it will be truncated 02819 */ 02820 02821 void MYSQL_BIN_LOG::make_log_name(char* buf, const char* log_ident) 02822 { 02823 uint dir_len = dirname_length(log_file_name); 02824 if (dir_len > FN_REFLEN) 02825 dir_len=FN_REFLEN-1; 02826 strnmov(buf, log_file_name, dir_len); 02827 strmake(buf+dir_len, log_ident, FN_REFLEN - dir_len); 02828 } 02829 02830 02831 /* 02832 Check if we are writing/reading to the given log file 02833 */ 02834 02835 bool MYSQL_BIN_LOG::is_active(const char *log_file_name_arg) 02836 { 02837 return !strcmp(log_file_name, log_file_name_arg); 02838 } 02839 02840 02841 /* 02842 Wrappers around new_file_impl to avoid using argument 02843 to control locking. The argument 1) less readable 2) breaks 02844 incapsulation 3) allows external access to the class without 02845 a lock (which is not possible with private new_file_without_locking 02846 method). 02847 */ 02848 02849 void MYSQL_BIN_LOG::new_file() 02850 { 02851 new_file_impl(1); 02852 } 02853 02854 02855 void MYSQL_BIN_LOG::new_file_without_locking() 02856 { 02857 new_file_impl(0); 02858 } 02859 02860 02861 /* 02862 Start writing to a new log file or reopen the old file 02863 02864 SYNOPSIS 02865 new_file_impl() 02866 need_lock Set to 1 if caller has not locked LOCK_log 02867 02868 NOTE 02869 The new file name is stored last in the index file 02870 */ 02871 02872 void MYSQL_BIN_LOG::new_file_impl(bool need_lock) 02873 { 02874 char new_name[FN_REFLEN], *new_name_ptr, *old_name; 02875 02876 DBUG_ENTER("MYSQL_BIN_LOG::new_file_impl"); 02877 if (!is_open()) 02878 { 02879 DBUG_PRINT("info",("log is closed")); 02880 DBUG_VOID_RETURN; 02881 } 02882 02883 if (need_lock) 02884 pthread_mutex_lock(&LOCK_log); 02885 pthread_mutex_lock(&LOCK_index); 02886 02887 safe_mutex_assert_owner(&LOCK_log); 02888 safe_mutex_assert_owner(&LOCK_index); 02889 02890 /* 02891 if binlog is used as tc log, be sure all xids are "unlogged", 02892 so that on recover we only need to scan one - latest - binlog file 02893 for prepared xids. As this is expected to be a rare event, 02894 simple wait strategy is enough. We're locking LOCK_log to be sure no 02895 new Xid_log_event's are added to the log (and prepared_xids is not 02896 increased), and waiting on COND_prep_xids for late threads to 02897 catch up. 02898 */ 02899 if (prepared_xids) 02900 { 02901 tc_log_page_waits++; 02902 pthread_mutex_lock(&LOCK_prep_xids); 02903 while (prepared_xids) 02904 pthread_cond_wait(&COND_prep_xids, &LOCK_prep_xids); 02905 pthread_mutex_unlock(&LOCK_prep_xids); 02906 } 02907 02908 /* Reuse old name if not binlog and not update log */ 02909 new_name_ptr= name; 02910 02911 /* 02912 If user hasn't specified an extension, generate a new log name 02913 We have to do this here and not in open as we want to store the 02914 new file name in the current binary log file. 02915 */ 02916 if (generate_new_name(new_name, name)) 02917 goto end; 02918 new_name_ptr=new_name; 02919 02920 if (log_type == LOG_BIN) 02921 { 02922 if (!no_auto_events) 02923 { 02924 /* 02925 We log the whole file name for log file as the user may decide 02926 to change base names at some point. 02927 */ 02928 THD *thd = current_thd; /* may be 0 if we are reacting to SIGHUP */ 02929 Rotate_log_event r(new_name+dirname_length(new_name), 02930 0, LOG_EVENT_OFFSET, 0); 02931 r.write(&log_file); 02932 bytes_written += r.data_written; 02933 } 02934 /* 02935 Update needs to be signalled even if there is no rotate event 02936 log rotation should give the waiting thread a signal to 02937 discover EOF and move on to the next log. 02938 */ 02939 signal_update(); 02940 } 02941 old_name=name; 02942 name=0; // Don't free name 02943 close(LOG_CLOSE_TO_BE_OPENED); 02944 02945 /* 02946 Note that at this point, log_state != LOG_CLOSED (important for is_open()). 02947 */ 02948 02949 /* 02950 new_file() is only used for rotation (in FLUSH LOGS or because size > 02951 max_binlog_size or max_relay_log_size). 02952 If this is a binary log, the Format_description_log_event at the beginning of 02953 the new file should have created=0 (to distinguish with the 02954 Format_description_log_event written at server startup, which should 02955 trigger temp tables deletion on slaves. 02956 */ 02957 02958 open(old_name, log_type, new_name_ptr, 02959 io_cache_type, no_auto_events, max_size, 1); 02960 my_free(old_name,MYF(0)); 02961 02962 end: 02963 if (need_lock) 02964 pthread_mutex_unlock(&LOCK_log); 02965 pthread_mutex_unlock(&LOCK_index); 02966 02967 DBUG_VOID_RETURN; 02968 } 02969 02970 02971 bool MYSQL_BIN_LOG::append(Log_event* ev) 02972 { 02973 bool error = 0; 02974 pthread_mutex_lock(&LOCK_log); 02975 DBUG_ENTER("MYSQL_BIN_LOG::append"); 02976 02977 DBUG_ASSERT(log_file.type == SEQ_READ_APPEND); 02978 /* 02979 Log_event::write() is smart enough to use my_b_write() or 02980 my_b_append() depending on the kind of cache we have. 02981 */ 02982 if (ev->write(&log_file)) 02983 { 02984 error=1; 02985 goto err; 02986 } 02987 bytes_written+= ev->data_written; 02988 DBUG_PRINT("info",("max_size: %lu",max_size)); 02989 if ((uint) my_b_append_tell(&log_file) > max_size) 02990 new_file_without_locking(); 02991 02992 err: 02993 pthread_mutex_unlock(&LOCK_log); 02994 signal_update(); // Safe as we don't call close 02995 DBUG_RETURN(error); 02996 } 02997 02998 02999 bool MYSQL_BIN_LOG::appendv(const char* buf, uint len,...) 03000 { 03001 bool error= 0; 03002 DBUG_ENTER("MYSQL_BIN_LOG::appendv"); 03003 va_list(args); 03004 va_start(args,len); 03005 03006 DBUG_ASSERT(log_file.type == SEQ_READ_APPEND); 03007 03008 safe_mutex_assert_owner(&LOCK_log); 03009 do 03010 { 03011 if (my_b_append(&log_file,(byte*) buf,len)) 03012 { 03013 error= 1; 03014 goto err; 03015 } 03016 bytes_written += len; 03017 } while ((buf=va_arg(args,const char*)) && (len=va_arg(args,uint))); 03018 DBUG_PRINT("info",("max_size: %lu",max_size)); 03019 if ((uint) my_b_append_tell(&log_file) > max_size) 03020 new_file_without_locking(); 03021 03022 err: 03023 if (!error) 03024 signal_update(); 03025 DBUG_RETURN(error); 03026 } 03027 03028 03029 bool MYSQL_BIN_LOG::flush_and_sync() 03030 { 03031 int err=0, fd=log_file.file; 03032 safe_mutex_assert_owner(&LOCK_log); 03033 if (flush_io_cache(&log_file)) 03034 return 1; 03035 if (++sync_binlog_counter >= sync_binlog_period && sync_binlog_period) 03036 { 03037 sync_binlog_counter= 0; 03038 err=my_sync(fd, MYF(MY_WME)); 03039 } 03040 return err; 03041 } 03042 03043 void MYSQL_BIN_LOG::start_union_events(THD *thd) 03044 { 03045 DBUG_ASSERT(!thd->binlog_evt_union.do_union); 03046 thd->binlog_evt_union.do_union= TRUE; 03047 thd->binlog_evt_union.unioned_events= FALSE; 03048 thd->binlog_evt_union.unioned_events_trans= FALSE; 03049 thd->binlog_evt_union.first_query_id= thd->query_id; 03050 } 03051 03052 void MYSQL_BIN_LOG::stop_union_events(THD *thd) 03053 { 03054 DBUG_ASSERT(thd->binlog_evt_union.do_union); 03055 thd->binlog_evt_union.do_union= FALSE; 03056 } 03057 03058 bool MYSQL_BIN_LOG::is_query_in_union(THD *thd, query_id_t query_id_param) 03059 { 03060 return (thd->binlog_evt_union.do_union && 03061 query_id_param >= thd->binlog_evt_union.first_query_id); 03062 } 03063 03064 03065 /* 03066 These functions are placed in this file since they need access to 03067 binlog_hton, which has internal linkage. 03068 */ 03069 03070 int THD::binlog_setup_trx_data() 03071 { 03072 DBUG_ENTER("THD::binlog_setup_trx_data"); 03073 binlog_trx_data *trx_data= 03074 (binlog_trx_data*) ha_data[binlog_hton.slot]; 03075 03076 if (trx_data) 03077 DBUG_RETURN(0); // Already set up 03078 03079 ha_data[binlog_hton.slot]= trx_data= 03080 (binlog_trx_data*) my_malloc(sizeof(binlog_trx_data), MYF(MY_ZEROFILL)); 03081 if (!trx_data || 03082 open_cached_file(&trx_data->trans_log, mysql_tmpdir, 03083 LOG_PREFIX, binlog_cache_size, MYF(MY_WME))) 03084 { 03085 my_free((gptr)trx_data, MYF(MY_ALLOW_ZERO_PTR)); 03086 ha_data[binlog_hton.slot]= 0; 03087 DBUG_RETURN(1); // Didn't manage to set it up 03088 } 03089 trx_data->trans_log.end_of_file= max_binlog_cache_size; 03090 DBUG_RETURN(0); 03091 } 03092 03093 /* 03094 Write a table map to the binary log. 03095 03096 This function is called from ha_external_lock() after the storage 03097 engine has registered for the transaction. 03098 */ 03099 03100 #ifdef HAVE_ROW_BASED_REPLICATION 03101 int THD::binlog_write_table_map(TABLE *table, bool is_trans) 03102 { 03103 int error; 03104 DBUG_ENTER("THD::binlog_write_table_map"); 03105 DBUG_PRINT("enter", ("table: %0xlx (%s: #%u)", 03106 (long) table, table->s->table_name, 03107 table->s->table_map_id)); 03108 03109 /* Pre-conditions */ 03110 DBUG_ASSERT(current_stmt_binlog_row_based && mysql_bin_log.is_open()); 03111 DBUG_ASSERT(table->s->table_map_id != ULONG_MAX); 03112 03113 Table_map_log_event::flag_set const 03114 flags= Table_map_log_event::TM_NO_FLAGS; 03115 03116 Table_map_log_event 03117 the_event(this, table, table->s->table_map_id, is_trans, flags); 03118 03119 if (is_trans) 03120 trans_register_ha(this, 03121 (options & (OPTION_NOT_AUTOCOMMIT | OPTION_BEGIN)) != 0, 03122 &binlog_hton); 03123 03124 if ((error= mysql_bin_log.write(&the_event))) 03125 DBUG_RETURN(error); 03126 03127 binlog_table_maps++; 03128 table->s->table_map_version= mysql_bin_log.table_map_version(); 03129 DBUG_RETURN(0); 03130 } 03131 03132 Rows_log_event* 03133 THD::binlog_get_pending_rows_event() const 03134 { 03135 binlog_trx_data *const trx_data= 03136 (binlog_trx_data*) ha_data[binlog_hton.slot]; 03137 /* 03138 This is less than ideal, but here's the story: If there is no 03139 trx_data, prepare_pending_rows_event() has never been called 03140 (since the trx_data is set up there). In that case, we just return 03141 NULL. 03142 */ 03143 return trx_data ? trx_data->pending : NULL; 03144 } 03145 03146 void 03147 THD::binlog_set_pending_rows_event(Rows_log_event* ev) 03148 { 03149 if (ha_data[binlog_hton.slot] == NULL) 03150 binlog_setup_trx_data(); 03151 03152 binlog_trx_data *const trx_data= 03153 (binlog_trx_data*) ha_data[binlog_hton.slot]; 03154 03155 DBUG_ASSERT(trx_data); 03156 trx_data->pending= ev; 03157 } 03158 03159 03160 /* 03161 Moves the last bunch of rows from the pending Rows event to the binlog 03162 (either cached binlog if transaction, or disk binlog). Sets a new pending 03163 event. 03164 */ 03165 int MYSQL_BIN_LOG:: 03166 flush_and_set_pending_rows_event(THD *thd, Rows_log_event* event) 03167 { 03168 DBUG_ENTER("MYSQL_BIN_LOG::flush_and_set_pending_rows_event(event)"); 03169 DBUG_ASSERT(thd->current_stmt_binlog_row_based && mysql_bin_log.is_open()); 03170 DBUG_PRINT("enter", ("event=%p", event)); 03171 03172 int error= 0; 03173 03174 binlog_trx_data *const trx_data= 03175 (binlog_trx_data*) thd->ha_data[binlog_hton.slot]; 03176 03177 DBUG_ASSERT(trx_data); 03178 03179 DBUG_PRINT("info", ("trx_data->pending=%p", trx_data->pending)); 03180 03181 if (Rows_log_event* pending= trx_data->pending) 03182 { 03183 IO_CACHE *file= &log_file; 03184 03185 /* 03186 Decide if we should write to the log file directly or to the 03187 transaction log. 03188 */ 03189 if (pending->get_cache_stmt() || my_b_tell(&trx_data->trans_log)) 03190 file= &trx_data->trans_log; 03191 03192 /* 03193 If we are writing to the log file directly, we could avoid 03194 locking the log. This does not work since we need to step the 03195 m_table_map_version below, and that change has to be protected 03196 by the LOCK_log mutex. 03197 */ 03198 pthread_mutex_lock(&LOCK_log); 03199 03200 /* 03201 Write pending event to log file or transaction cache 03202 */ 03203 if (pending->write(file)) 03204 { 03205 pthread_mutex_unlock(&LOCK_log); 03206 DBUG_RETURN(1); 03207 } 03208 03209 /* 03210 We step the table map version if we are writing an event 03211 representing the end of a statement. We do this regardless of 03212 wheather we write to the transaction cache or to directly to the 03213 file. 03214 03215 In an ideal world, we could avoid stepping the table map version 03216 if we were writing to a transaction cache, since we could then 03217 reuse the table map that was written earlier in the transaction 03218 cache. This does not work since STMT_END_F implies closing all 03219 table mappings on the slave side. 03220 03221 TODO: Find a solution so that table maps does not have to be 03222 written several times within a transaction. 03223 */ 03224 if (pending->get_flags(Rows_log_event::STMT_END_F)) 03225 ++m_table_map_version; 03226 03227 delete pending; 03228 03229 if (file == &log_file) 03230 { 03231 error= flush_and_sync(); 03232 if (!error) 03233 { 03234 signal_update(); 03235 rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED); 03236 } 03237 } 03238 03239 pthread_mutex_unlock(&LOCK_log); 03240 } 03241 03242 thd->binlog_set_pending_rows_event(event); 03243 03244 DBUG_RETURN(error); 03245 } 03246 #endif /*HAVE_ROW_BASED_REPLICATION*/ 03247 03248 /* 03249 Write an event to the binary log 03250 */ 03251 03252 bool MYSQL_BIN_LOG::write(Log_event *event_info) 03253 { 03254 THD *thd= event_info->thd; 03255 bool error= 1; 03256 DBUG_ENTER("MYSQL_BIN_LOG::write(Log_event *)"); 03257 03258 if (thd->binlog_evt_union.do_union) 03259 { 03260 /* 03261 In Stored function; Remember that function call caused an update. 03262 We will log the function call to the binary log on function exit 03263 */ 03264 thd->binlog_evt_union.unioned_events= TRUE; 03265 thd->binlog_evt_union.unioned_events_trans |= event_info->cache_stmt; 03266 DBUG_RETURN(0); 03267 } 03268 03269 /* 03270 Flush the pending rows event to the transaction cache or to the 03271 log file. Since this function potentially aquire the LOCK_log 03272 mutex, we do this before aquiring the LOCK_log mutex in this 03273 function. 03274 03275 We only end the statement if we are in a top-level statement. If 03276 we are inside a stored function, we do not end the statement since 03277 this will close all tables on the slave. 03278 */ 03279 #ifdef HAVE_ROW_BASED_REPLICATION 03280 bool const end_stmt= 03281 thd->prelocked_mode && thd->lex->requires_prelocking(); 03282 thd->binlog_flush_pending_rows_event(end_stmt); 03283 #endif /*HAVE_ROW_BASED_REPLICATION*/ 03284 03285 pthread_mutex_lock(&LOCK_log); 03286 03287 /* 03288 In most cases this is only called if 'is_open()' is true; in fact this is 03289 mostly called if is_open() *was* true a few instructions before, but it 03290 could have changed since. 03291 */ 03292 if (likely(is_open())) 03293 { 03294 const char *local_db= event_info->get_db(); 03295 IO_CACHE *file= &log_file; 03296 #ifdef HAVE_REPLICATION 03297 /* 03298 In the future we need to add to the following if tests like 03299 "do the involved tables match (to be implemented) 03300 binlog_[wild_]{do|ignore}_table?" (WL#1049)" 03301 */ 03302 if ((thd && !(thd->options & OPTION_BIN_LOG)) || 03303 (!binlog_filter->db_ok(local_db))) 03304 { 03305 VOID(pthread_mutex_unlock(&LOCK_log)); 03306 DBUG_PRINT("info",("OPTION_BIN_LOG is %s, db_ok('%s') == %d", 03307 (thd->options & OPTION_BIN_LOG) ? "set" : "clear", 03308 local_db, binlog_filter->db_ok(local_db))); 03309 DBUG_RETURN(0); 03310 } 03311 #endif /* HAVE_REPLICATION */ 03312 03313 #if defined(USING_TRANSACTIONS) && defined(HAVE_ROW_BASED_REPLICATION) 03314 /* 03315 Should we write to the binlog cache or to the binlog on disk? 03316 Write to the binlog cache if: 03317 - it is already not empty (meaning we're in a transaction; note that the 03318 present event could be about a non-transactional table, but still we need 03319 to write to the binlog cache in that case to handle updates to mixed 03320 trans/non-trans table types the best possible in binlogging) 03321 - or if the event asks for it (cache_stmt == TRUE). 03322 */ 03323 if (opt_using_transactions && thd) 03324 { 03325 if (thd->binlog_setup_trx_data()) 03326 goto err; 03327 03328 binlog_trx_data *const trx_data= 03329 (binlog_trx_data*) thd->ha_data[binlog_hton.slot]; 03330 IO_CACHE *trans_log= &trx_data->trans_log; 03331 bool trans_log_in_use= my_b_tell(trans_log) != 0; 03332 if (event_info->get_cache_stmt() && !trans_log_in_use) 03333 trans_register_ha(thd, 03334 (thd->options & 03335 (OPTION_NOT_AUTOCOMMIT | OPTION_BEGIN)) != 0, 03336 &binlog_hton); 03337 if (event_info->get_cache_stmt() || trans_log_in_use) 03338 { 03339 DBUG_PRINT("info", ("Using trans_log")); 03340 file= trans_log; 03341 } 03342 /* 03343 TODO as Mats suggested, for all the cases above where we write to 03344 trans_log, it sounds unnecessary to lock LOCK_log. We should rather 03345 test first if we want to write to trans_log, and if not, lock 03346 LOCK_log. 03347 */ 03348 } 03349 #endif /* USING_TRANSACTIONS && HAVE_ROW_BASED_REPLICATION */ 03350 DBUG_PRINT("info",("event type: %d",event_info->get_type_code())); 03351 03352 /* 03353 No check for auto events flag here - this write method should 03354 never be called if auto-events are enabled 03355 */ 03356 03357 /* 03358 1. Write first log events which describe the 'run environment' 03359 of the SQL command 03360 */ 03361 03362 /* 03363 If row-based binlogging, Insert_id, Rand and other kind of "setting 03364 context" events are not needed. 03365 */ 03366 if (thd) 03367 { 03368 if (!thd->current_stmt_binlog_row_based) 03369 { 03370 if (thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt) 03371 { 03372 Intvar_log_event e(thd,(uchar) LAST_INSERT_ID_EVENT, 03373 thd->first_successful_insert_id_in_prev_stmt_for_binlog); 03374 if (e.write(file)) 03375 goto err; 03376 } 03377 if (thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements() > 0) 03378 { 03379 DBUG_PRINT("info",("number of auto_inc intervals: %lu", 03380 thd->auto_inc_intervals_in_cur_stmt_for_binlog.nb_elements())); 03381 /* 03382 If the auto_increment was second in a table's index (possible with 03383 MyISAM or BDB) (table->next_number_key_offset != 0), such event is 03384 in fact not necessary. We could avoid logging it. 03385 */ 03386 Intvar_log_event e(thd,(uchar) INSERT_ID_EVENT, 03387 thd->auto_inc_intervals_in_cur_stmt_for_binlog.minimum()); 03388 if (e.write(file)) 03389 goto err; 03390 } 03391 if (thd->rand_used) 03392 { 03393 Rand_log_event e(thd,thd->rand_saved_seed1,thd->rand_saved_seed2); 03394 if (e.write(file)) 03395 goto err; 03396 } 03397 if (thd->user_var_events.elements) 03398 { 03399 for (uint i= 0; i < thd->user_var_events.elements; i++) 03400 { 03401 BINLOG_USER_VAR_EVENT *user_var_event; 03402 get_dynamic(&thd->user_var_events,(gptr) &user_var_event, i); 03403 User_var_log_event e(thd, user_var_event->user_var_event->name.str, 03404 user_var_event->user_var_event->name.length, 03405 user_var_event->value, 03406 user_var_event->length, 03407 user_var_event->type, 03408 user_var_event->charset_number); 03409 if (e.write(file)) 03410 goto err; 03411 } 03412 } 03413 } 03414 /* Forget those values, for next binlogger: */ 03415 thd->stmt_depends_on_first_successful_insert_id_in_prev_stmt= 0; 03416 thd->auto_inc_intervals_in_cur_stmt_for_binlog.empty(); 03417 } 03418 03419 /* 03420 Write the SQL command 03421 */ 03422 03423 if (event_info->write(file)) 03424 goto err; 03425 03426 if (file == &log_file) // we are writing to the real log (disk) 03427 { 03428 if (flush_and_sync()) 03429 goto err; 03430 signal_update(); 03431 rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED); 03432 } 03433 error=0; 03434 03435 err: 03436 if (error) 03437 { 03438 if (my_errno == EFBIG) 03439 my_message(ER_TRANS_CACHE_FULL, ER(ER_TRANS_CACHE_FULL), MYF(0)); 03440 else 03441 my_error(ER_ERROR_ON_WRITE, MYF(0), name, errno); 03442 write_error=1; 03443 } 03444 } 03445 03446 if (event_info->flags & LOG_EVENT_UPDATE_TABLE_MAP_VERSION_F) 03447 ++m_table_map_version; 03448 03449 pthread_mutex_unlock(&LOCK_log); 03450 DBUG_RETURN(error); 03451 } 03452 03453 03454 int error_log_print(enum loglevel level, const char *format, 03455 va_list args) 03456 { 03457 return logger.error_log_print(level, format, args); 03458 } 03459 03460 03461 bool slow_log_print(THD *thd, const char *query, uint query_length, 03462 time_t query_start_arg) 03463 { 03464 return logger.slow_log_print(thd, query, query_length, query_start_arg); 03465 } 03466 03467 03468 bool general_log_print(THD *thd, enum enum_server_command command, 03469 const char *format, ...) 03470 { 03471 va_list args; 03472 uint error= 0; 03473 03474 va_start(args, format); 03475 error= logger.general_log_print(thd, command, format, args); 03476 va_end(args); 03477 03478 return error; 03479 } 03480 03481 void MYSQL_BIN_LOG::rotate_and_purge(uint flags) 03482 { 03483 if (!(flags & RP_LOCK_LOG_IS_ALREADY_LOCKED)) 03484 pthread_mutex_lock(&LOCK_log); 03485 if ((flags & RP_FORCE_ROTATE) || 03486 (my_b_tell(&log_file) >= (my_off_t) max_size)) 03487 { 03488 new_file_without_locking(); 03489 #ifdef HAVE_REPLICATION 03490 if (expire_logs_days) 03491 { 03492 long purge_time= time(0) - expire_logs_days*24*60*60; 03493 if (purge_time >= 0) 03494 purge_logs_before_date(purge_time); 03495 } 03496 #endif 03497 } 03498 if (!(flags & RP_LOCK_LOG_IS_ALREADY_LOCKED)) 03499 pthread_mutex_unlock(&LOCK_log); 03500 } 03501 03502 uint MYSQL_BIN_LOG::next_file_id() 03503 { 03504 uint res; 03505 pthread_mutex_lock(&LOCK_log); 03506 res = file_id++; 03507 pthread_mutex_unlock(&LOCK_log); 03508 return res; 03509 } 03510 03511 03512 /* 03513 Write a cached log entry to the binary log 03514 03515 SYNOPSIS 03516 write() 03517 thd 03518 cache The cache to copy to the binlog 03519 03520 NOTE 03521 - We only come here if there is something in the cache. 03522 - The thing in the cache is always a complete transaction 03523 - 'cache' needs to be reinitialized after this functions returns. 03524 03525 IMPLEMENTATION 03526 - To support transaction over replication, we wrap the transaction 03527 with BEGIN/COMMIT or BEGIN/ROLLBACK in the binary log. 03528 We want to write a BEGIN/ROLLBACK block when a non-transactional table 03529 was updated in a transaction which was rolled back. This is to ensure 03530 that the same updates are run on the slave. 03531 */ 03532 03533 bool MYSQL_BIN_LOG::write(THD *thd, IO_CACHE *cache, Log_event *commit_event) 03534 { 03535 DBUG_ENTER("MYSQL_BIN_LOG::write(THD *, IO_CACHE *, Log_event *)"); 03536 VOID(pthread_mutex_lock(&LOCK_log)); 03537 03538 /* NULL would represent nothing to replicate after ROLLBACK */ 03539 DBUG_ASSERT(commit_event != NULL); 03540 03541 if (likely(is_open())) // Should always be true 03542 { 03543 uint length; 03544 03545 /* 03546 Log "BEGIN" at the beginning of the transaction. 03547 which may contain more than 1 SQL statement. 03548 */ 03549 if (thd->options & (OPTION_NOT_AUTOCOMMIT | OPTION_BEGIN)) 03550 { 03551 Query_log_event qinfo(thd, STRING_WITH_LEN("BEGIN"), TRUE, FALSE); 03552 /* 03553 Imagine this is rollback due to net timeout, after all statements of 03554 the transaction succeeded. Then we want a zero-error code in BEGIN. 03555 In other words, if there was a really serious error code it's already 03556 in the statement's events, there is no need to put it also in this 03557 internally generated event, and as this event is generated late it 03558 would lead to false alarms. 03559 This is safer than thd->clear_error() against kills at shutdown. 03560 */ 03561 qinfo.error_code= 0; 03562 /* 03563 Now this Query_log_event has artificial log_pos 0. It must be adjusted 03564 to reflect the real position in the log. Not doing it would confuse the 03565 slave: it would prevent this one from knowing where he is in the 03566 master's binlog, which would result in wrong positions being shown to 03567 the user, MASTER_POS_WAIT undue waiting etc. 03568 */ 03569 if (qinfo.write(&log_file)) 03570 goto err; 03571 } 03572 /* Read from the file used to cache the queries .*/ 03573 if (reinit_io_cache(cache, READ_CACHE, 0, 0, 0)) 03574 goto err; 03575 length=my_b_bytes_in_cache(cache); 03576 DBUG_EXECUTE_IF("half_binlogged_transaction", length-=100;); 03577 do 03578 { 03579 /* Write data to the binary log file */ 03580 if (my_b_write(&log_file, cache->read_pos, length)) 03581 goto err; 03582 cache->read_pos=cache->read_end; // Mark buffer used up 03583 DBUG_EXECUTE_IF("half_binlogged_transaction", goto DBUG_skip_commit;); 03584 } while ((length=my_b_fill(cache))); 03585 03586 if (commit_event->write(&log_file)) 03587 goto err; 03588 #ifndef DBUG_OFF 03589 DBUG_skip_commit: 03590 #endif 03591 if (flush_and_sync()) 03592 goto err; 03593 DBUG_EXECUTE_IF("half_binlogged_transaction", abort();); 03594 if (cache->error) // Error on read 03595 { 03596 sql_print_error(ER(ER_ERROR_ON_READ), cache->file_name, errno); 03597 write_error=1; // Don't give more errors 03598 goto err; 03599 } 03600 signal_update(); 03601 /* 03602 if commit_event is Xid_log_event, increase the number of 03603 prepared_xids (it's decreasd in ::unlog()). Binlog cannot be rotated 03604 if there're prepared xids in it - see the comment in new_file() for 03605 an explanation. 03606 If the commit_event is not Xid_log_event (then it's a Query_log_event) 03607 rotate binlog, if necessary. 03608 */ 03609 if (commit_event->get_type_code() == XID_EVENT) 03610 { 03611 pthread_mutex_lock(&LOCK_prep_xids); 03612 prepared_xids++; 03613 pthread_mutex_unlock(&LOCK_prep_xids); 03614 } 03615 else 03616 rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED); 03617 } 03618 VOID(pthread_mutex_unlock(&LOCK_log)); 03619 03620 DBUG_RETURN(0); 03621 03622 err: 03623 if (!write_error) 03624 { 03625 write_error= 1; 03626 sql_print_error(ER(ER_ERROR_ON_WRITE), name, errno); 03627 } 03628 VOID(pthread_mutex_unlock(&LOCK_log)); 03629 DBUG_RETURN(1); 03630 } 03631 03632 03633 /* 03634 Wait until we get a signal that the binary log has been updated 03635 03636 SYNOPSIS 03637 wait_for_update() 03638 thd Thread variable 03639 is_slave If 0, the caller is the Binlog_dump thread from master; 03640 if 1, the caller is the SQL thread from the slave. This 03641 influences only thd->proc_info. 03642 03643 NOTES 03644 One must have a lock on LOCK_log before calling this function. 03645 This lock will be released before return! That's required by 03646 THD::enter_cond() (see NOTES in sql_class.h). 03647 */ 03648 03649 void MYSQL_BIN_LOG::wait_for_update(THD* thd, bool is_slave) 03650 { 03651 const char *old_msg; 03652 DBUG_ENTER("wait_for_update"); 03653 03654 old_msg= thd->enter_cond(&update_cond, &LOCK_log, 03655 is_slave ? 03656 "Has read all relay log; waiting for the slave I/O " 03657 "thread to update it" : 03658 "Has sent all binlog to slave; waiting for binlog " 03659 "to be updated"); 03660 pthread_cond_wait(&update_cond, &LOCK_log); 03661 thd->exit_cond(old_msg); 03662 DBUG_VOID_RETURN; 03663 } 03664 03665 03666 /* 03667 Close the log file 03668 03669 SYNOPSIS 03670 close() 03671 exiting Bitmask for one or more of the following bits: 03672 LOG_CLOSE_INDEX if we should close the index file 03673 LOG_CLOSE_TO_BE_OPENED if we intend to call open 03674 at once after close. 03675 LOG_CLOSE_STOP_EVENT write a 'stop' event to the log 03676 03677 NOTES 03678 One can do an open on the object at once after doing a close. 03679 The internal structures are not freed until cleanup() is called 03680 */ 03681 03682 void MYSQL_BIN_LOG::close(uint exiting) 03683 { // One can't set log_type here! 03684 DBUG_ENTER("MYSQL_BIN_LOG::close"); 03685 DBUG_PRINT("enter",("exiting: %d", (int) exiting)); 03686 if (log_state == LOG_OPENED) 03687 { 03688 #ifdef HAVE_REPLICATION 03689 if (log_type == LOG_BIN && !no_auto_events && 03690 (exiting & LOG_CLOSE_STOP_EVENT)) 03691 { 03692 Stop_log_event s; 03693 s.write(&log_file); 03694 bytes_written+= s.data_written; 03695 signal_update(); 03696 } 03697 #endif /* HAVE_REPLICATION */ 03698 03699 /* don't pwrite in a file opened with O_APPEND - it doesn't work */ 03700 if (log_file.type == WRITE_CACHE && log_type == LOG_BIN) 03701 { 03702 my_off_t offset= BIN_LOG_HEADER_SIZE + FLAGS_OFFSET; 03703 byte flags=0; // clearing LOG_EVENT_BINLOG_IN_USE_F 03704 my_pwrite(log_file.file, &flags, 1, offset, MYF(0)); 03705 } 03706 03707 /* this will cleanup IO_CACHE, sync and close the file */ 03708 MYSQL_LOG::close(exiting); 03709 } 03710 03711 /* 03712 The following test is needed even if is_open() is not set, as we may have 03713 called a not complete close earlier and the index file is still open. 03714 */ 03715 03716 if ((exiting & LOG_CLOSE_INDEX) && my_b_inited(&index_file)) 03717 { 03718 end_io_cache(&index_file); 03719 if (my_close(index_file.file, MYF(0)) < 0 && ! write_error) 03720 { 03721 write_error= 1; 03722 sql_print_error(ER(ER_ERROR_ON_WRITE), index_file_name, errno); 03723 } 03724 } 03725 log_state= (exiting & LOG_CLOSE_TO_BE_OPENED) ? LOG_TO_BE_OPENED : LOG_CLOSED; 03726 safeFree(name); 03727 DBUG_VOID_RETURN; 03728 } 03729 03730 03731 void MYSQL_BIN_LOG::set_max_size(ulong max_size_arg) 03732 { 03733 /* 03734 We need to take locks, otherwise this may happen: 03735 new_file() is called, calls open(old_max_size), then before open() starts, 03736 set_max_size() sets max_size to max_size_arg, then open() starts and 03737 uses the old_max_size argument, so max_size_arg has been overwritten and 03738 it's like if the SET command was never run. 03739 */ 03740 DBUG_ENTER("MYSQL_BIN_LOG::set_max_size"); 03741 pthread_mutex_lock(&LOCK_log); 03742 if (is_open()) 03743 max_size= max_size_arg; 03744 pthread_mutex_unlock(&LOCK_log); 03745 DBUG_VOID_RETURN; 03746 } 03747 03748 03749 /* 03750 Check if a string is a valid number 03751 03752 SYNOPSIS 03753 test_if_number() 03754 str String to test 03755 res Store value here 03756 allow_wildcards Set to 1 if we should ignore '%' and '_' 03757 03758 NOTE 03759 For the moment the allow_wildcards argument is not used 03760 Should be move to some other file. 03761 03762 RETURN VALUES 03763 1 String is a number 03764 0 Error 03765 */ 03766 03767 static bool test_if_number(register const char *str, 03768 long *res, bool allow_wildcards) 03769 { 03770 reg2 int flag; 03771 const char *start; 03772 DBUG_ENTER("test_if_number"); 03773 03774 flag=0; start=str; 03775 while (*str++ == ' ') ; 03776 if (*--str == '-' || *str == '+') 03777 str++; 03778 while (my_isdigit(files_charset_info,*str) || 03779 (allow_wildcards && (*str == wild_many || *str == wild_one))) 03780 { 03781 flag=1; 03782 str++; 03783 } 03784 if (*str == '.') 03785 { 03786 for (str++ ; 03787 my_isdigit(files_charset_info,*str) || 03788 (allow_wildcards && (*str == wild_many || *str == wild_one)) ; 03789 str++, flag=1) ; 03790 } 03791 if (*str != 0 || flag == 0) 03792 DBUG_RETURN(0); 03793 if (res) 03794 *res=atol(start); 03795 DBUG_RETURN(1); /* Number ok */ 03796 } /* test_if_number */ 03797 03798 03799 void print_buffer_to_file(enum loglevel level, const char *buffer) 03800 { 03801 time_t skr; 03802 struct tm tm_tmp; 03803 struct tm *start; 03804 DBUG_ENTER("print_buffer_to_file"); 03805 DBUG_PRINT("enter",("buffer: %s", buffer)); 03806 03807 VOID(pthread_mutex_lock(&LOCK_error_log)); 03808 03809 skr=time(NULL); 03810 localtime_r(&skr, &tm_tmp); 03811 start=&tm_tmp; 03812 03813 fprintf(stderr, "%02d%02d%02d %2d:%02d:%02d [%s] %s\n", 03814 start->tm_year % 100, 03815 start->tm_mon+1, 03816 start->tm_mday, 03817 start->tm_hour, 03818 start->tm_min, 03819 start->tm_sec, 03820 (level == ERROR_LEVEL ? "ERROR" : level == WARNING_LEVEL ? 03821 "Warning" : "Note"), 03822 buffer); 03823 03824 fflush(stderr); 03825 03826 VOID(pthread_mutex_unlock(&LOCK_error_log)); 03827 DBUG_VOID_RETURN; 03828 } 03829 03830 03831 void sql_perror(const char *message) 03832 { 03833 #ifdef HAVE_STRERROR 03834 sql_print_error("%s: %s",message, strerror(errno)); 03835 #else 03836 perror(message); 03837 #endif 03838 } 03839 03840 03841 bool flush_error_log() 03842 { 03843 bool result=0; 03844 if (opt_error_log) 03845 { 03846 char err_renamed[FN_REFLEN], *end; 03847 end= strmake(err_renamed,log_error_file,FN_REFLEN-4); 03848 strmov(end, "-old"); 03849 VOID(pthread_mutex_lock(&LOCK_error_log)); 03850 #ifdef __WIN__ 03851 char err_temp[FN_REFLEN+4]; 03852 /* 03853 On Windows is necessary a temporary file for to rename 03854 the current error file. 03855 */ 03856 strxmov(err_temp, err_renamed,"-tmp",NullS); 03857 (void) my_delete(err_temp, MYF(0)); 03858 if (freopen(err_temp,"a+",stdout)) 03859 { 03860 freopen(err_temp,"a+",stderr); 03861 (void) my_delete(err_renamed, MYF(0)); 03862 my_rename(log_error_file,err_renamed,MYF(0)); 03863 if (freopen(log_error_file,"a+",stdout)) 03864 freopen(log_error_file,"a+",stderr); 03865 int fd, bytes; 03866 char buf[IO_SIZE]; 03867 if ((fd = my_open(err_temp, O_RDONLY, MYF(0))) >= 0) 03868 { 03869 while ((bytes = (int) my_read(fd, (byte*) buf, IO_SIZE, MYF(0))) > 0) 03870 my_fwrite(stderr, (byte*) buf, bytes, MYF(0)); 03871 my_close(fd, MYF(0)); 03872 } 03873 (void) my_delete(err_temp, MYF(0)); 03874 } 03875 else 03876 result= 1; 03877 #else 03878 my_rename(log_error_file,err_renamed,MYF(0)); 03879 if (freopen(log_error_file,"a+",stdout)) 03880 freopen(log_error_file,"a+",stderr); 03881 else 03882 result= 1; 03883 #endif 03884 VOID(pthread_mutex_unlock(&LOCK_error_log)); 03885 } 03886 return result; 03887 } 03888 03889 void MYSQL_BIN_LOG::signal_update() 03890 { 03891 DBUG_ENTER("MYSQL_BIN_LOG::signal_update"); 03892 pthread_cond_broadcast(&update_cond); 03893 DBUG_VOID_RETURN; 03894 } 03895 03896 #ifdef __NT__ 03897 void print_buffer_to_nt_eventlog(enum loglevel level, char *buff, 03898 uint length, int buffLen) 03899 { 03900 HANDLE event; 03901 char *buffptr; 03902 LPCSTR *buffmsgptr; 03903 DBUG_ENTER("print_buffer_to_nt_eventlog"); 03904 03905 buffptr= buff; 03906 if (length > (uint)(buffLen-5)) 03907 { 03908 char *newBuff= new char[length + 5]; 03909 strcpy(newBuff, buff); 03910 buffptr= newBuff; 03911 } 03912 strmov(buffptr+length, "\r\n\r\n"); 03913 buffmsgptr= (LPCSTR*) &buffptr; // Keep windows happy 03914 03915 setup_windows_event_source(); 03916 if ((event= RegisterEventSource(NULL,"MySQL"))) 03917 { 03918 switch (level) { 03919 case ERROR_LEVEL: 03920 ReportEvent(event, EVENTLOG_ERROR_TYPE, 0, MSG_DEFAULT, NULL, 1, 0, 03921 buffmsgptr, NULL); 03922 break; 03923 case WARNING_LEVEL: 03924 ReportEvent(event, EVENTLOG_WARNING_TYPE, 0, MSG_DEFAULT, NULL, 1, 0, 03925 buffmsgptr, NULL); 03926 break; 03927 case INFORMATION_LEVEL: 03928 ReportEvent(event, EVENTLOG_INFORMATION_TYPE, 0, MSG_DEFAULT, NULL, 1, 03929 0, buffmsgptr, NULL); 03930 break; 03931 } 03932 DeregisterEventSource(event); 03933 } 03934 03935 /* if we created a string buffer, then delete it */ 03936 if (buffptr != buff) 03937 delete[] buffptr; 03938 03939 DBUG_VOID_RETURN; 03940 } 03941 #endif /* __NT__ */ 03942 03943 03944 /* 03945 Prints a printf style message to the error log and, under NT, to the 03946 Windows event log. 03947 03948 SYNOPSIS 03949 vprint_msg_to_log() 03950 event_type Type of event to write (Error, Warning, or Info) 03951 format Printf style format of message 03952 args va_list list of arguments for the message 03953 03954 NOTE 03955 03956 IMPLEMENTATION 03957 This function prints the message into a buffer and then sends that buffer 03958 to other functions to write that message to other logging sources. 03959 03960 RETURN VALUES 03961 The function always returns 0. The return value is present in the 03962 signature to be compatible with other logging routines, which could 03963 return an error (e.g. logging to the log tables) 03964 */ 03965 03966 int vprint_msg_to_log(enum loglevel level, const char *format, va_list args) 03967 { 03968 char buff[1024]; 03969 uint length; 03970 DBUG_ENTER("vprint_msg_to_log"); 03971 03972 /* "- 5" is because of print_buffer_to_nt_eventlog() */ 03973 length= my_vsnprintf(buff, sizeof(buff) - 5, format, args); 03974 print_buffer_to_file(level, buff); 03975 03976 #ifdef __NT__ 03977 print_buffer_to_nt_eventlog(level, buff, length, sizeof(buff)); 03978 #endif 03979 03980 DBUG_RETURN(0); 03981 } 03982 03983 03984 void sql_print_error(const char *format, ...) 03985 { 03986 va_list args; 03987 DBUG_ENTER("sql_print_error"); 03988 03989 va_start(args, format); 03990 error_log_print(ERROR_LEVEL, format, args); 03991 va_end(args); 03992 03993 DBUG_VOID_RETURN; 03994 } 03995 03996 03997 void sql_print_warning(const char *format, ...) 03998 { 03999 va_list args; 04000 DBUG_ENTER("sql_print_warning"); 04001 04002 va_start(args, format); 04003 error_log_print(WARNING_LEVEL, format, args); 04004 va_end(args); 04005 04006 DBUG_VOID_RETURN; 04007 } 04008 04009 04010 void sql_print_information(const char *format, ...) 04011 { 04012 va_list args; 04013 DBUG_ENTER("sql_print_information"); 04014 04015 va_start(args, format); 04016 error_log_print(INFORMATION_LEVEL, format, args); 04017 va_end(args); 04018 04019 DBUG_VOID_RETURN; 04020 } 04021 04022 04023 /********* transaction coordinator log for 2pc - mmap() based solution *******/ 04024 04025 /* 04026 the log consists of a file, mmapped to a memory. 04027 file is divided on pages of tc_log_page_size size. 04028 (usable size of the first page is smaller because of log header) 04029 there's PAGE control structure for each page 04030 each page (or rather PAGE control structure) can be in one of three 04031 states - active, syncing, pool. 04032 there could be only one page in active or syncing states, 04033 but many in pool - pool is fifo queue. 04034 usual lifecycle of a page is pool->active->syncing->pool 04035 "active" page - is a page where new xid's are logged. 04036 the page stays active as long as syncing slot is taken. 04037 "syncing" page is being synced to disk. no new xid can be added to it. 04038 when the sync is done the page is moved to a pool and an active page 04039 becomes "syncing". 04040 04041 the result of such an architecture is a natural "commit grouping" - 04042 If commits are coming faster than the system can sync, they do not 04043 stall. Instead, all commit that came since the last sync are 04044 logged to the same page, and they all are synced with the next - 04045 one - sync. Thus, thought individual commits are delayed, throughput 04046 is not decreasing. 04047 04048 when a xid is added to an active page, the thread of this xid waits 04049 for a page's condition until the page is synced. when syncing slot 04050 becomes vacant one of these waiters is awaken to take care of syncing. 04051 it syncs the page and signals all waiters that the page is synced. 04052 PAGE::waiters is used to count these waiters, and a page may never 04053 become active again until waiters==0 (that is all waiters from the 04054 previous sync have noticed the sync was completed) 04055 04056 note, that the page becomes "dirty" and has to be synced only when a 04057 new xid is added into it. Removing a xid from a page does not make it 04058 dirty - we don't sync removals to disk. 04059 */ 04060 04061 ulong tc_log_page_waits= 0; 04062 04063 #ifdef HAVE_MMAP 04064 04065 #define TC_LOG_HEADER_SIZE (sizeof(tc_log_magic)+1) 04066 04067 static const char tc_log_magic[]={(char) 254, 0x23, 0x05, 0x74}; 04068 04069 ulong opt_tc_log_size= TC_LOG_MIN_SIZE; 04070 ulong tc_log_max_pages_used=0, tc_log_page_size=0, tc_log_cur_pages_used=0; 04071 04072 int TC_LOG_MMAP::open(const char *opt_name) 04073 { 04074 uint i; 04075 bool crashed=FALSE; 04076 PAGE *pg; 04077 04078 DBUG_ASSERT(total_ha_2pc > 1); 04079 DBUG_ASSERT(opt_name && opt_name[0]); 04080 04081 tc_log_page_size= my_getpagesize(); 04082 DBUG_ASSERT(TC_LOG_PAGE_SIZE % tc_log_page_size == 0); 04083 04084 fn_format(logname,opt_name,mysql_data_home,"",MY_UNPACK_FILENAME); 04085 if ((fd= my_open(logname, O_RDWR, MYF(0))) < 0) 04086 { 04087 if (my_errno != ENOENT) 04088 goto err; 04089 if (using_heuristic_recover()) 04090 return 1; 04091 if ((fd= my_create(logname, O_RDWR, 0, MYF(MY_WME))) < 0) 04092 goto err; 04093 inited=1; 04094 file_length= opt_tc_log_size; 04095 if (my_chsize(fd, file_length, 0, MYF(MY_WME))) 04096 goto err; 04097 } 04098 else 04099 { 04100 inited= 1; 04101 crashed= TRUE; 04102 sql_print_information("Recovering after a crash using %s", opt_name); 04103 if (tc_heuristic_recover) 04104 { 04105 sql_print_error("Cannot perform automatic crash recovery when " 04106 "--tc-heuristic-recover is used"); 04107 goto err; 04108 } 04109 file_length= my_seek(fd, 0L, MY_SEEK_END, MYF(MY_WME+MY_FAE)); 04110 if (file_length == MY_FILEPOS_ERROR || file_length % tc_log_page_size) 04111 goto err; 04112 } 04113 04114 data= (uchar *)my_mmap(0, (size_t)file_length, PROT_READ|PROT_WRITE, 04115 MAP_NOSYNC|MAP_SHARED, fd, 0); 04116 if (data == MAP_FAILED) 04117 { 04118 my_errno=errno; 04119 goto err; 04120 } 04121 inited=2; 04122 04123 npages=(uint)file_length/tc_log_page_size; 04124 DBUG_ASSERT(npages >= 3); // to guarantee non-empty pool 04125 if (!(pages=(PAGE *)my_malloc(npages*sizeof(PAGE), MYF(MY_WME|MY_ZEROFILL)))) 04126 goto err; 04127 inited=3; 04128 for (pg=pages, i=0; i < npages; i++, pg++) 04129 { 04130 pg->next=pg+1; 04131 pg->waiters=0; 04132 pg->state=POOL; 04133 pthread_mutex_init(&pg->lock, MY_MUTEX_INIT_FAST); 04134 pthread_cond_init (&pg->cond, 0); 04135 pg->start=(my_xid *)(data + i*tc_log_page_size); 04136 pg->end=(my_xid *)(pg->start + tc_log_page_size); 04137 pg->size=pg->free=tc_log_page_size/sizeof(my_xid); 04138 } 04139 pages[0].size=pages[0].free= 04140 (tc_log_page_size-TC_LOG_HEADER_SIZE)/sizeof(my_xid); 04141 pages[0].start=pages[0].end-pages[0].size; 04142 pages[npages-1].next=0; 04143 inited=4; 04144 04145 if (crashed && recover()) 04146 goto err; 04147 04148 memcpy(data, tc_log_magic, sizeof(tc_log_magic)); 04149 data[sizeof(tc_log_magic)]= (uchar)total_ha_2pc; 04150 my_msync(fd, data, tc_log_page_size, MS_SYNC); 04151 inited=5; 04152 04153 pthread_mutex_init(&LOCK_sync, MY_MUTEX_INIT_FAST); 04154 pthread_mutex_init(&LOCK_active, MY_MUTEX_INIT_FAST); 04155 pthread_mutex_init(&LOCK_pool, MY_MUTEX_INIT_FAST); 04156 pthread_cond_init(&COND_active, 0); 04157 pthread_cond_init(&COND_pool, 0); 04158 04159 inited=6; 04160 04161 syncing= 0; 04162 active=pages; 04163 pool=pages+1; 04164 pool_last=pages+npages-1; 04165 04166 return 0; 04167 04168 err: 04169 close(); 04170 return 1; 04171 } 04172 04173 /* 04174 there is no active page, let's got one from the pool 04175 04176 two strategies here: 04177 1. take the first from the pool 04178 2. if there're waiters - take the one with the most free space 04179 04180 TODO page merging. try to allocate adjacent page first, 04181 so that they can be flushed both in one sync 04182 */ 04183 void TC_LOG_MMAP::get_active_from_pool() 04184 { 04185 PAGE **p, **best_p=0; 04186 int best_free; 04187 04188 if (syncing) 04189 pthread_mutex_lock(&LOCK_pool); 04190 04191 do 04192 { 04193 best_p= p= &pool; 04194 if ((*p)->waiters == 0) // can the first page be used ? 04195 break; // yes - take it. 04196 04197 best_free=0; // no - trying second strategy 04198 for (p=&(*p)->next; *p; p=&(*p)->next) 04199 { 04200 if ((*p)->waiters == 0 && (*p)->free > best_free) 04201 { 04202 best_free=(*p)->free; 04203 best_p=p; 04204 } 04205 } 04206 } 04207 while ((*best_p == 0 || best_free == 0) && overflow()); 04208 04209 active=*best_p; 04210 if (active->free == active->size) // we've chosen an empty page 04211 { 04212 tc_log_cur_pages_used++; 04213 set_if_bigger(tc_log_max_pages_used, tc_log_cur_pages_used); 04214 } 04215 04216 if ((*best_p)->next) // unlink the page from the pool 04217 *best_p=(*best_p)->next; 04218 else 04219 pool_last=*best_p; 04220 04221 if (syncing) 04222 pthread_mutex_unlock(&LOCK_pool); 04223 } 04224 04225 int TC_LOG_MMAP::overflow() 04226 { 04227 /* 04228 simple overflow handling - just wait 04229 TODO perhaps, increase log size ? 04230 let's check the behaviour of tc_log_page_waits first 04231 */ 04232 tc_log_page_waits++; 04233 pthread_cond_wait(&COND_pool, &LOCK_pool); 04234 return 1; // always return 1 04235 } 04236 04237 /* 04238 all access to active page is serialized but it's not a problem, as 04239 we're assuming that fsync() will be a main bottleneck. 04240 That is, parallelizing writes to log pages we'll decrease number of 04241 threads waiting for a page, but then all these threads will be waiting 04242 for a fsync() anyway 04243 04244 RETURN 04245 0 - error 04246 otherwise - "cookie", a number that will be passed as an argument 04247 to unlog() call. tc_log can define it any way it wants, 04248 and use for whatever purposes. TC_LOG_MMAP sets it 04249 to the position in memory where xid was logged to. 04250 */ 04251 04252 int TC_LOG_MMAP::log(THD *thd, my_xid xid) 04253 { 04254 int err; 04255 PAGE *p; 04256 ulong cookie; 04257 04258 pthread_mutex_lock(&LOCK_active); 04259 04260 /* 04261 if active page is full - just wait... 04262 frankly speaking, active->free here accessed outside of mutex 04263 protection, but it's safe, because it only means we may miss an 04264 unlog() for the active page, and we're not waiting for it here - 04265 unlog() does not signal COND_active. 04266 */ 04267 while (unlikely(active && active->free == 0)) 04268 pthread_cond_wait(&COND_active, &LOCK_active); 04269 04270 /* no active page ? take one from the pool */ 04271 if (active == 0) 04272 get_active_from_pool(); 04273 04274 p=active; 04275 pthread_mutex_lock(&p->lock); 04276 04277 /* searching for an empty slot */ 04278 while (*p->ptr) 04279 { 04280 p->ptr++; 04281 DBUG_ASSERT(p->ptr < p->end); // because p->free > 0 04282 } 04283 04284 /* found! store xid there and mark the page dirty */ 04285 cookie= (ulong)((uchar *)p->ptr - data); // can never be zero 04286 *p->ptr++= xid; 04287 p->free--; 04288 p->state= DIRTY; 04289 04290 /* to sync or not to sync - this is the question */ 04291 pthread_mutex_unlock(&LOCK_active); 04292 pthread_mutex_lock(&LOCK_sync); 04293 pthread_mutex_unlock(&p->lock); 04294 04295 if (syncing) 04296 { // somebody's syncing. let's wait 04297 p->waiters++; 04298 /* 04299 note - it must be while (), not do ... while () here 04300 as p->state may be not DIRTY when we come here 04301 */ 04302 while (p->state == DIRTY && syncing) 04303 pthread_cond_wait(&p->cond, &LOCK_sync); 04304 p->waiters--; 04305 err= p->state == ERROR; 04306 if (p->state != DIRTY) // page was synced 04307 { 04308 if (p->waiters == 0) 04309 pthread_cond_signal(&COND_pool); // in case somebody's waiting 04310 pthread_mutex_unlock(&LOCK_sync); 04311 goto done; // we're done 04312 } 04313 } // page was not synced! do it now 04314 DBUG_ASSERT(active == p && syncing == 0); 04315 pthread_mutex_lock(&LOCK_active); 04316 syncing=p; // place is vacant - take it 04317 active=0; // page is not active anymore 04318 pthread_cond_broadcast(&COND_active); // in case somebody's waiting 04319 pthread_mutex_unlock(&LOCK_active); 04320 pthread_mutex_unlock(&LOCK_sync); 04321 err= sync(); 04322 04323 done: 04324 return err ? 0 : cookie; 04325 } 04326 04327 int TC_LOG_MMAP::sync() 04328 { 04329 int err; 04330 04331 DBUG_ASSERT(syncing != active); 04332 04333 /* 04334 sit down and relax - this can take a while... 04335 note - no locks are held at this point 04336 */ 04337 err= my_msync(fd, syncing->start, 1, MS_SYNC); 04338 04339 /* page is synced. let's move it to the pool */ 04340 pthread_mutex_lock(&LOCK_pool); 04341 pool_last->next=syncing; 04342 pool_last=syncing; 04343 syncing->next=0; 04344 syncing->state= err ? ERROR : POOL; 04345 pthread_cond_broadcast(&syncing->cond); // signal "sync done" 04346 pthread_cond_signal(&COND_pool); // in case somebody's waiting 04347 pthread_mutex_unlock(&LOCK_pool); 04348 04349 /* marking 'syncing' slot free */ 04350 pthread_mutex_lock(&LOCK_sync); 04351 syncing=0; 04352 pthread_cond_signal(&active->cond); // wake up a new syncer 04353 pthread_mutex_unlock(&LOCK_sync); 04354 return err; 04355 } 04356 04357 /* 04358 erase xid from the page, update page free space counters/pointers. 04359 cookie points directly to the memory where xid was logged 04360 */ 04361 void TC_LOG_MMAP::unlog(ulong cookie, my_xid xid) 04362 { 04363 PAGE *p=pages+(cookie/tc_log_page_size); 04364 my_xid *x=(my_xid *)(data+cookie); 04365 04366 DBUG_ASSERT(*x == xid); 04367 DBUG_ASSERT(x >= p->start && x < p->end); 04368 *x=0; 04369 04370 pthread_mutex_lock(&p->lock); 04371 p->free++; 04372 DBUG_ASSERT(p->free <= p->size); 04373 set_if_smaller(p->ptr, x); 04374 if (p->free == p->size) // the page is completely empty 04375 statistic_decrement(tc_log_cur_pages_used, &LOCK_status); 04376 if (p->waiters == 0) // the page is in pool and ready to rock 04377 pthread_cond_signal(&COND_pool); // ping ... for overflow() 04378 pthread_mutex_unlock(&p->lock); 04379 } 04380 04381 void TC_LOG_MMAP::close() 04382 { 04383 uint i; 04384 switch (inited) { 04385 case 6: 04386 pthread_mutex_destroy(&LOCK_sync); 04387 pthread_mutex_destroy(&LOCK_active); 04388 pthread_mutex_destroy(&LOCK_pool); 04389 pthread_cond_destroy(&COND_pool); 04390 case 5: 04391 data[0]='A'; // garble the first (signature) byte, in case my_delete fails 04392 case 4: 04393 for (i=0; i < npages; i++) 04394 { 04395 if (pages[i].ptr == 0) 04396 break; 04397 pthread_mutex_destroy(&pages[i].lock); 04398 pthread_cond_destroy(&pages[i].cond); 04399 } 04400 case 3: 04401 my_free((gptr)pages, MYF(0)); 04402 case 2: 04403 my_munmap((byte*)data, (size_t)file_length); 04404 case 1: 04405 my_close(fd, MYF(0)); 04406 } 04407 if (inited>=5) // cannot do in the switch because of Windows 04408 my_delete(logname, MYF(MY_WME)); 04409 inited=0; 04410 } 04411 04412 int TC_LOG_MMAP::recover() 04413 { 04414 HASH xids; 04415 PAGE *p=pages, *end_p=pages+npages; 04416 04417 if (memcmp(data, tc_log_magic, sizeof(tc_log_magic))) 04418 { 04419 sql_print_error("Bad magic header in tc log"); 04420 goto err1; 04421 } 04422 04423 /* 04424 the first byte after magic signature is set to current 04425 number of storage engines on startup 04426 */ 04427 if (data[sizeof(tc_log_magic)] != total_ha_2pc) 04428 { 04429 sql_print_error("Recovery failed! You must enable " 04430 "exactly %d storage engines that support " 04431 "two-phase commit protocol", 04432 data[sizeof(tc_log_magic)]); 04433 goto err1; 04434 } 04435 04436 if (hash_init(&xids, &my_charset_bin, tc_log_page_size/3, 0, 04437 sizeof(my_xid), 0, 0, MYF(0))) 04438 goto err1; 04439 04440 for ( ; p < end_p ; p++) 04441 { 04442 for (my_xid *x=p->start; x < p->end; x++) 04443 if (*x && my_hash_insert(&xids, (byte *)x)) 04444 goto err2; // OOM 04445 } 04446 04447 if (ha_recover(&xids)) 04448 goto err2; 04449 04450 hash_free(&xids); 04451 bzero(data, (size_t)file_length); 04452 return 0; 04453 04454 err2: 04455 hash_free(&xids); 04456 err1: 04457 sql_print_error("Crash recovery failed. Either correct the problem " 04458 "(if it's, for example, out of memory error) and restart, " 04459 "or delete tc log and start mysqld with " 04460 "--tc-heuristic-recover={commit|rollback}"); 04461 return 1; 04462 } 04463 #endif 04464 04465 TC_LOG *tc_log; 04466 TC_LOG_DUMMY tc_log_dummy; 04467 TC_LOG_MMAP tc_log_mmap; 04468 04469 /* 04470 Perform heuristic recovery, if --tc-heuristic-recover was used 04471 04472 RETURN VALUE 04473 0 no heuristic recovery was requested 04474 1 heuristic recovery was performed 04475 04476 NOTE 04477 no matter whether heuristic recovery was successful or not 04478 mysqld must exit. So, return value is the same in both cases. 04479 */ 04480 04481 int TC_LOG::using_heuristic_recover() 04482 { 04483 if (!tc_heuristic_recover) 04484 return 0; 04485 04486 sql_print_information("Heuristic crash recovery mode"); 04487 if (ha_recover(0)) 04488 sql_print_error("Heuristic crash recovery failed"); 04489 sql_print_information("Please restart mysqld without --tc-heuristic-recover"); 04490 return 1; 04491 } 04492 04493 /****** transaction coordinator log for 2pc - binlog() based solution ******/ 04494 #define TC_LOG_BINLOG MYSQL_BIN_LOG 04495 04496 /* 04497 TODO keep in-memory list of prepared transactions 04498 (add to list in log(), remove on unlog()) 04499 and copy it to the new binlog if rotated 04500 but let's check the behaviour of tc_log_page_waits first! 04501 */ 04502 04503 int TC_LOG_BINLOG::open(const char *opt_name) 04504 { 04505 LOG_INFO log_info; 04506 int error= 1; 04507 04508 DBUG_ASSERT(total_ha_2pc > 1); 04509 DBUG_ASSERT(opt_name && opt_name[0]); 04510 04511 pthread_mutex_init(&LOCK_prep_xids, MY_MUTEX_INIT_FAST); 04512 pthread_cond_init (&COND_prep_xids, 0); 04513 04514 if (!my_b_inited(&index_file)) 04515 { 04516 /* There was a failure to open the index file, can't open the binlog */ 04517 cleanup(); 04518 return 1; 04519 } 04520 04521 if (using_heuristic_recover()) 04522 { 04523 /* generate a new binlog to mask a corrupted one */ 04524 open(opt_name, LOG_BIN, 0, WRITE_CACHE, 0, max_binlog_size, 0); 04525 cleanup(); 04526 return 1; 04527 } 04528 04529 if ((error= find_log_pos(&log_info, NullS, 1))) 04530 { 04531 if (error != LOG_INFO_EOF) 04532 sql_print_error("find_log_pos() failed (error: %d)", error); 04533 else 04534 error= 0; 04535 goto err; 04536 } 04537 04538 { 04539 const char *errmsg; 04540 IO_CACHE log; 04541 File file; 04542 Log_event *ev=0; 04543 Format_description_log_event fdle(BINLOG_VERSION); 04544 char log_name[FN_REFLEN]; 04545 04546 if (! fdle.is_valid()) 04547 goto err; 04548 04549 do 04550 { 04551 strmake(log_name, log_info.log_file_name, sizeof(log_name)-1); 04552 } while (!(error= find_next_log(&log_info, 1))); 04553 04554 if (error != LOG_INFO_EOF) 04555 { 04556 sql_print_error("find_log_pos() failed (error: %d)", error); 04557 goto err; 04558 } 04559 04560 if ((file= open_binlog(&log, log_name, &errmsg)) < 0) 04561 { 04562 sql_print_error("%s", errmsg); 04563 goto err; 04564 } 04565 04566 if ((ev= Log_event::read_log_event(&log, 0, &fdle)) && 04567 ev->get_type_code() == FORMAT_DESCRIPTION_EVENT && 04568 ev->flags & LOG_EVENT_BINLOG_IN_USE_F) 04569 { 04570 sql_print_information("Recovering after a crash using %s", opt_name); 04571 error= recover(&log, (Format_description_log_event *)ev); 04572 } 04573 else 04574 error=0; 04575 04576 delete ev; 04577 end_io_cache(&log); 04578 my_close(file, MYF(MY_WME)); 04579 04580 if (error) 04581 goto err; 04582 } 04583 04584 err: 04585 return error; 04586 } 04587 04588 /* this is called on shutdown, after ha_panic */ 04589 void TC_LOG_BINLOG::close() 04590 { 04591 DBUG_ASSERT(prepared_xids==0); 04592 pthread_mutex_destroy(&LOCK_prep_xids); 04593 pthread_cond_destroy (&COND_prep_xids); 04594 } 04595 04596 /* 04597 TODO group commit 04598 04599 RETURN 04600 0 - error 04601 1 - success 04602 */ 04603 int TC_LOG_BINLOG::log(THD *thd, my_xid xid) 04604 { 04605 DBUG_ENTER("TC_LOG_BINLOG::log"); 04606 Xid_log_event xle(thd, xid); 04607 binlog_trx_data *trx_data= 04608 (binlog_trx_data*) thd->ha_data[binlog_hton.slot]; 04609 DBUG_RETURN(!binlog_end_trans(thd, trx_data, &xle)); // invert return value 04610 } 04611 04612 void TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid) 04613 { 04614 pthread_mutex_lock(&LOCK_prep_xids); 04615 if (--prepared_xids == 0) 04616 pthread_cond_signal(&COND_prep_xids); 04617 pthread_mutex_unlock(&LOCK_prep_xids); 04618 rotate_and_purge(0); // as ::write() did not rotate 04619 } 04620 04621 int TC_LOG_BINLOG::recover(IO_CACHE *log, Format_description_log_event *fdle) 04622 { 04623 Log_event *ev; 04624 HASH xids; 04625 MEM_ROOT mem_root; 04626 04627 if (! fdle->is_valid() || 04628 hash_init(&xids, &my_charset_bin, TC_LOG_PAGE_SIZE/3, 0, 04629 sizeof(my_xid), 0, 0, MYF(0))) 04630 goto err1; 04631 04632 init_alloc_root(&mem_root, TC_LOG_PAGE_SIZE, TC_LOG_PAGE_SIZE); 04633 04634 fdle->flags&= ~LOG_EVENT_BINLOG_IN_USE_F; // abort on the first error 04635 04636 while ((ev= Log_event::read_log_event(log,0,fdle)) && ev->is_valid()) 04637 { 04638 if (ev->get_type_code() == XID_EVENT) 04639 { 04640 Xid_log_event *xev=(Xid_log_event *)ev; 04641 byte *x=(byte *)memdup_root(&mem_root, (char *)& xev->xid, 04642 sizeof(xev->xid)); 04643 if (! x) 04644 goto err2; 04645 my_hash_insert(&xids, x); 04646 } 04647 delete ev; 04648 } 04649 04650 if (ha_recover(&xids)) 04651 goto err2; 04652 04653 free_root(&mem_root, MYF(0)); 04654 hash_free(&xids); 04655 return 0; 04656 04657 err2: 04658 free_root(&mem_root, MYF(0)); 04659 hash_free(&xids); 04660 err1: 04661 sql_print_error("Crash recovery failed. Either correct the problem " 04662 "(if it's, for example, out of memory error) and restart, " 04663 "or delete (or rename) binary log and start mysqld with " 04664 "--tc-heuristic-recover={commit|rollback}"); 04665 return 1; 04666 } 04667 04668 struct st_mysql_storage_engine binlog_storage_engine= 04669 { MYSQL_HANDLERTON_INTERFACE_VERSION, &binlog_hton }; 04670 04671 mysql_declare_plugin(binlog) 04672 { 04673 MYSQL_STORAGE_ENGINE_PLUGIN, 04674 &binlog_storage_engine, 04675 "binlog", 04676 "MySQL AB", 04677 "This is a pseudo storage engine to represent the binlog in a transaction", 04678 binlog_init, /* Plugin Init */ 04679 NULL, /* Plugin Deinit */ 04680 0x0100 /* 1.0 */, 04681 0 04682 } 04683 mysql_declare_plugin_end;
1.4.7

