diff options
Diffstat (limited to 'sql/log.cc')
| -rw-r--r-- | sql/log.cc | 721 |
1 files changed, 454 insertions, 267 deletions
diff --git a/sql/log.cc b/sql/log.cc index a9452ed1c26..e3d42a41e10 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -1,4 +1,4 @@ -/* Copyright 2000-2008 MySQL AB, 2008-2009 Sun Microsystems, Inc. +/* Copyright (c) 2000, 2011, Oracle and/or its affiliates. All rights reserved. This program is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License as published by @@ -210,11 +210,11 @@ class binlog_cache_data { public: binlog_cache_data(): m_pending(0), before_stmt_pos(MY_OFF_T_UNDEF), - incident(FALSE), changes_to_non_trans_temp_table_flag(FALSE) - { - cache_log.end_of_file= max_binlog_cache_size; - } - + incident(FALSE), changes_to_non_trans_temp_table_flag(FALSE), + saved_max_binlog_cache_size(0), ptr_binlog_cache_use(0), + ptr_binlog_cache_disk_use(0) + { } + ~binlog_cache_data() { DBUG_ASSERT(empty()); @@ -258,11 +258,19 @@ public: void reset() { + compute_statistics(); truncate(0); changes_to_non_trans_temp_table_flag= FALSE; incident= FALSE; before_stmt_pos= MY_OFF_T_UNDEF; - cache_log.end_of_file= max_binlog_cache_size; + /* + The truncate function calls reinit_io_cache that calls my_b_flush_io_cache + which may increase disk_writes. This breaks the disk_writes use by the + binary log which aims to compute the ratio between in-memory cache usage + and disk cache usage. To avoid this undesirable behavior, we reset the + variable after truncating the cache. + */ + cache_log.disk_writes= 0; DBUG_ASSERT(empty()); } @@ -293,6 +301,36 @@ public: before_stmt_pos= MY_OFF_T_UNDEF; } + void set_binlog_cache_info(ulong param_max_binlog_cache_size, + ulong *param_ptr_binlog_cache_use, + ulong *param_ptr_binlog_cache_disk_use) + { + /* + The assertions guarantee that the set_binlog_cache_info is + called just once and information passed as parameters are + never zero. + + This is done while calling the constructor binlog_cache_mngr. + We cannot set informaton in the constructor binlog_cache_data + because the space for binlog_cache_mngr is allocated through + a placement new. + + In the future, we can refactor this and change it to avoid + the set_binlog_info. + */ + DBUG_ASSERT(saved_max_binlog_cache_size == 0 && + param_max_binlog_cache_size != 0 && + ptr_binlog_cache_use == 0 && + param_ptr_binlog_cache_use != 0 && + ptr_binlog_cache_disk_use == 0 && + param_ptr_binlog_cache_disk_use != 0); + + saved_max_binlog_cache_size= param_max_binlog_cache_size; + ptr_binlog_cache_use= param_ptr_binlog_cache_use; + ptr_binlog_cache_disk_use= param_ptr_binlog_cache_disk_use; + cache_log.end_of_file= saved_max_binlog_cache_size; + } + /* Cache to store data before copying it to the binary log. */ @@ -322,6 +360,40 @@ private: */ bool changes_to_non_trans_temp_table_flag; + /** + This function computes binlog cache and disk usage. + */ + void compute_statistics() + { + if (!empty()) + { + statistic_increment(*ptr_binlog_cache_use, &LOCK_status); + if (cache_log.disk_writes != 0) + statistic_increment(*ptr_binlog_cache_disk_use, &LOCK_status); + } + } + + /* + Stores the values of maximum size of the cache allowed when this cache + is configured. This corresponds to either + . max_binlog_cache_size or max_binlog_stmt_cache_size. + */ + ulong saved_max_binlog_cache_size; + + /* + Stores a pointer to the status variable that keeps track of the in-memory + cache usage. This corresponds to either + . binlog_cache_use or binlog_stmt_cache_use. + */ + ulong *ptr_binlog_cache_use; + + /* + Stores a pointer to the status variable that keeps track of the disk + cache usage. This corresponds to either + . binlog_cache_disk_use or binlog_stmt_cache_disk_use. + */ + ulong *ptr_binlog_cache_disk_use; + /* It truncates the cache to a certain position. This includes deleting the pending event. @@ -335,7 +407,7 @@ private: set_pending(0); } reinit_io_cache(&cache_log, WRITE_CACHE, pos, 0, 0); - cache_log.end_of_file= max_binlog_cache_size; + cache_log.end_of_file= saved_max_binlog_cache_size; } binlog_cache_data& operator=(const binlog_cache_data& info); @@ -344,7 +416,20 @@ private: class binlog_cache_mngr { public: - binlog_cache_mngr() {} + binlog_cache_mngr(ulong param_max_binlog_stmt_cache_size, + ulong param_max_binlog_cache_size, + ulong *param_ptr_binlog_stmt_cache_use, + ulong *param_ptr_binlog_stmt_cache_disk_use, + ulong *param_ptr_binlog_cache_use, + ulong *param_ptr_binlog_cache_disk_use) + { + stmt_cache.set_binlog_cache_info(param_max_binlog_stmt_cache_size, + param_ptr_binlog_stmt_cache_use, + param_ptr_binlog_stmt_cache_disk_use); + trx_cache.set_binlog_cache_info(param_max_binlog_cache_size, + param_ptr_binlog_cache_use, + param_ptr_binlog_cache_disk_use); + } void reset_cache(binlog_cache_data* cache_data) { @@ -1374,7 +1459,7 @@ void LOGGER::deactivate_log_handler(THD *thd, uint log_type) file_log= file_log_handler->get_mysql_log(); break; default: - assert(0); // Impossible + MY_ASSERT_UNREACHABLE(); } if (!(*tmp_opt)) @@ -1518,57 +1603,122 @@ static int binlog_close_connection(handlerton *hton, THD *thd) } /** - This function flushes a transactional cache upon commit/rollback. + This function flushes a cache upon commit/rollback. - @param thd The thread whose transaction should be flushed - @param cache_mngr Pointer to the cache data to be flushed - @param end_ev The end event either commit/rollback. + @param thd The thread whose transaction should be flushed + @param cache_data Pointer to the cache + @param end_ev The end event either commit/rollback + @param is_transactional The type of the cache: transactional or + non-transactional @return - nonzero if an error pops up when flushing the transactional cache. + nonzero if an error pops up when flushing the cache. */ -static int -binlog_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr, - Log_event *end_ev) +static inline int +binlog_flush_cache(THD *thd, binlog_cache_data* cache_data, Log_event *end_evt, + bool is_transactional) { - DBUG_ENTER("binlog_flush_trx_cache"); - int error=0; - IO_CACHE *cache_log= &cache_mngr->trx_cache.cache_log; - - /* - This function handles transactional changes and as such - this flag equals to true. - */ - bool const is_transactional= TRUE; - - if (thd->binlog_flush_pending_rows_event(TRUE, is_transactional)) - DBUG_RETURN(1); - /* - Doing a commit or a rollback including non-transactional tables, - i.e., ending a transaction where we might write the transaction - cache to the binary log. - - We can always end the statement when ending a transaction since - transactions are not allowed inside stored functions. If they - were, we would have to ensure that we're not ending a statement - inside a stored function. - */ - error= mysql_bin_log.write(thd, &cache_mngr->trx_cache.cache_log, end_ev, - cache_mngr->trx_cache.has_incident()); - cache_mngr->reset_cache(&cache_mngr->trx_cache); + DBUG_ENTER("binlog_flush_cache"); + int error= 0; - statistic_increment(binlog_cache_use, &LOCK_status); - if (cache_log->disk_writes != 0) + if (!cache_data->empty()) { - statistic_increment(binlog_cache_disk_use, &LOCK_status); - cache_log->disk_writes= 0; + if (thd->binlog_flush_pending_rows_event(TRUE, is_transactional)) + DBUG_RETURN(1); + /* + Doing a commit or a rollback including non-transactional tables, + i.e., ending a transaction where we might write the transaction + cache to the binary log. + + We can always end the statement when ending a transaction since + transactions are not allowed inside stored functions. If they + were, we would have to ensure that we're not ending a statement + inside a stored function. + */ + error= mysql_bin_log.write(thd, &cache_data->cache_log, end_evt, + cache_data->has_incident()); } + cache_data->reset(); - DBUG_ASSERT(cache_mngr->trx_cache.empty()); + DBUG_ASSERT(cache_data->empty()); DBUG_RETURN(error); } /** + This function flushes the stmt-cache upon commit. + + @param thd The thread whose transaction should be flushed + @param cache_mngr Pointer to the cache manager + + @return + nonzero if an error pops up when flushing the cache. +*/ +static inline int +binlog_commit_flush_stmt_cache(THD *thd, + binlog_cache_mngr *cache_mngr) +{ + Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"), + FALSE, FALSE, TRUE, 0); + return (binlog_flush_cache(thd, &cache_mngr->stmt_cache, &end_evt, + FALSE)); +} + +/** + This function flushes the trx-cache upon commit. + + @param thd The thread whose transaction should be flushed + @param cache_mngr Pointer to the cache manager + + @return + nonzero if an error pops up when flushing the cache. +*/ +static inline int +binlog_commit_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr) +{ + Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"), + TRUE, FALSE, TRUE, 0); + return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt, + TRUE)); +} + +/** + This function flushes the trx-cache upon rollback. + + @param thd The thread whose transaction should be flushed + @param cache_mngr Pointer to the cache manager + + @return + nonzero if an error pops up when flushing the cache. +*/ +static inline int +binlog_rollback_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr) +{ + Query_log_event end_evt(thd, STRING_WITH_LEN("ROLLBACK"), + TRUE, FALSE, TRUE, 0); + return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt, + TRUE)); +} + +/** + This function flushes the trx-cache upon commit. + + @param thd The thread whose transaction should be flushed + @param cache_mngr Pointer to the cache manager + @param xid Transaction Id + + @return + nonzero if an error pops up when flushing the cache. +*/ +static inline int +binlog_commit_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr, + my_xid xid) +{ + Xid_log_event end_evt(thd, xid); + return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt, + TRUE)); +} + +/** This function truncates the transactional cache upon committing or rolling back either a transaction or a statement. @@ -1591,23 +1741,24 @@ binlog_truncate_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr, bool all) */ bool const is_transactional= TRUE; - DBUG_PRINT("info", ("thd->options={ %s%s}, transaction: %s", + DBUG_PRINT("info", ("thd->options={ %s %s}, transaction: %s", FLAGSTR(thd->variables.option_bits, OPTION_NOT_AUTOCOMMIT), FLAGSTR(thd->variables.option_bits, OPTION_BEGIN), all ? "all" : "stmt")); + + thd->binlog_remove_pending_rows_event(TRUE, is_transactional); /* If rolling back an entire transaction or a single statement not inside a transaction, we reset the transaction cache. */ - thd->binlog_remove_pending_rows_event(TRUE, is_transactional); if (ending_trans(thd, all)) { if (cache_mngr->trx_cache.has_incident()) error= mysql_bin_log.write_incident(thd, TRUE); - cache_mngr->reset_cache(&cache_mngr->trx_cache); - thd->clear_binlog_table_maps(); + + cache_mngr->reset_cache(&cache_mngr->trx_cache); } /* If rolling back a statement in a transaction, we truncate the @@ -1632,51 +1783,6 @@ static int binlog_prepare(handlerton *hton, THD *thd, bool all) } /** - This function flushes the non-transactional to the binary log upon - committing or rolling back a statement. - - @param thd The thread whose transaction should be flushed - @param cache_mngr Pointer to the cache data to be flushed - - @return - nonzero if an error pops up when flushing the non-transactional cache. -*/ -static int -binlog_flush_stmt_cache(THD *thd, binlog_cache_mngr *cache_mngr) -{ - int error= 0; - DBUG_ENTER("binlog_flush_stmt_cache"); - /* - If we are flushing the statement cache, it means that the changes get - through otherwise the cache is empty and this routine should not be called. - */ - DBUG_ASSERT(cache_mngr->stmt_cache.has_incident() == FALSE); - /* - This function handles non-transactional changes and as such this flag equals - to false. - */ - bool const is_transactional= FALSE; - IO_CACHE *cache_log= &cache_mngr->stmt_cache.cache_log; - - if (thd->binlog_flush_pending_rows_event(TRUE, is_transactional)) - DBUG_RETURN(1); - - Query_log_event qev(thd, STRING_WITH_LEN("COMMIT"), TRUE, FALSE, TRUE, 0); - if ((error= mysql_bin_log.write(thd, cache_log, &qev, - cache_mngr->stmt_cache.has_incident()))) - DBUG_RETURN(error); - cache_mngr->reset_cache(&cache_mngr->stmt_cache); - - statistic_increment(binlog_cache_use, &LOCK_status); - if (cache_log->disk_writes != 0) - { - statistic_increment(binlog_cache_disk_use, &LOCK_status); - cache_log->disk_writes= 0; - } - DBUG_RETURN(error); -} - -/** This function is called once after each statement. It has the responsibility to flush the caches to the binary log on commits. @@ -1704,7 +1810,7 @@ static int binlog_commit(handlerton *hton, THD *thd, bool all) if (!cache_mngr->stmt_cache.empty()) { - binlog_flush_stmt_cache(thd, cache_mngr); + error= binlog_commit_flush_stmt_cache(thd, cache_mngr); } if (cache_mngr->trx_cache.empty()) @@ -1713,7 +1819,7 @@ static int binlog_commit(handlerton *hton, THD *thd, bool all) we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid() */ cache_mngr->reset_cache(&cache_mngr->trx_cache); - DBUG_RETURN(0); + DBUG_RETURN(error); } /* @@ -1722,17 +1828,15 @@ static int binlog_commit(handlerton *hton, THD *thd, bool all) - We are in a transaction and a full transaction is committed. Otherwise, we accumulate the changes. */ - if (ending_trans(thd, all)) - { - Query_log_event qev(thd, STRING_WITH_LEN("COMMIT"), TRUE, FALSE, TRUE, 0); - error= binlog_flush_trx_cache(thd, cache_mngr, &qev); - } + if (!error && ending_trans(thd, all)) + error= binlog_commit_flush_trx_cache(thd, cache_mngr); /* This is part of the stmt rollback. */ if (!all) cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF); + DBUG_RETURN(error); } @@ -1749,7 +1853,7 @@ static int binlog_commit(handlerton *hton, THD *thd, bool all) static int binlog_rollback(handlerton *hton, THD *thd, bool all) { DBUG_ENTER("binlog_rollback"); - int error=0; + int error= 0; binlog_cache_mngr *const cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton); @@ -1769,16 +1873,16 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all) } else if (!cache_mngr->stmt_cache.empty()) { - binlog_flush_stmt_cache(thd, cache_mngr); + error= binlog_commit_flush_stmt_cache(thd, cache_mngr); } if (cache_mngr->trx_cache.empty()) { - /* + /* we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid() */ cache_mngr->reset_cache(&cache_mngr->trx_cache); - DBUG_RETURN(0); + DBUG_RETURN(error); } if (mysql_bin_log.check_write_error(thd)) @@ -1794,9 +1898,9 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all) We reach this point if the effect of a statement did not properly get into a cache and need to be rolled back. */ - error= binlog_truncate_trx_cache(thd, cache_mngr, all); + error |= binlog_truncate_trx_cache(thd, cache_mngr, all); } - else + else if (!error) { /* We flush the cache wrapped in a beging/rollback if: @@ -1808,7 +1912,6 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all) . the format is MIXED, non-trans table was updated and aborting a single statement transaction; */ - if (ending_trans(thd, all) && ((thd->variables.option_bits & OPTION_KEEP_LOG) || (trans_has_updated_non_trans_table(thd) && @@ -1818,10 +1921,7 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all) (trans_has_updated_non_trans_table(thd) && ending_single_stmt_trans(thd,all) && thd->variables.binlog_format == BINLOG_FORMAT_MIXED))) - { - Query_log_event qev(thd, STRING_WITH_LEN("ROLLBACK"), TRUE, FALSE, TRUE, 0); - error= binlog_flush_trx_cache(thd, cache_mngr, &qev); - } + error= binlog_rollback_flush_trx_cache(thd, cache_mngr); /* Truncate the cache if: . aborting a single or multi-statement transaction or; @@ -1844,11 +1944,12 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all) This is part of the stmt rollback. */ if (!all) - cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF); + cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF); + DBUG_RETURN(error); } -void MYSQL_BIN_LOG::set_write_error(THD *thd) +void MYSQL_BIN_LOG::set_write_error(THD *thd, bool is_transactional) { DBUG_ENTER("MYSQL_BIN_LOG::set_write_error"); @@ -1858,9 +1959,20 @@ void MYSQL_BIN_LOG::set_write_error(THD *thd) DBUG_VOID_RETURN; if (my_errno == EFBIG) - my_message(ER_TRANS_CACHE_FULL, ER(ER_TRANS_CACHE_FULL), MYF(MY_WME)); + { + if (is_transactional) + { + my_message(ER_TRANS_CACHE_FULL, ER(ER_TRANS_CACHE_FULL), MYF(MY_WME)); + } + else + { + my_message(ER_STMT_CACHE_FULL, ER(ER_STMT_CACHE_FULL), MYF(MY_WME)); + } + } else + { my_error(ER_ERROR_ON_WRITE, MYF(MY_WME), name, errno); + } DBUG_VOID_RETURN; } @@ -1877,6 +1989,7 @@ bool MYSQL_BIN_LOG::check_write_error(THD *thd) switch (thd->stmt_da->sql_errno()) { case ER_TRANS_CACHE_FULL: + case ER_STMT_CACHE_FULL: case ER_ERROR_ON_WRITE: case ER_BINLOG_LOGGING_IMPOSSIBLE: checked= TRUE; @@ -2085,7 +2198,8 @@ static int find_uniq_filename(char *name) *end='.'; length= (size_t) (end - start + 1); - if (!(dir_info= my_dir(buff,MYF(MY_DONT_SORT)))) + if ((DBUG_EVALUATE_IF("error_unique_log_filename", 1, + !(dir_info= my_dir(buff,MYF(MY_DONT_SORT)))))) { // This shouldn't happen strmov(end,".1"); // use name+1 DBUG_RETURN(1); @@ -2112,7 +2226,11 @@ updating the index files.", max_found); } next= max_found + 1; - sprintf(ext_buf, "%06lu", next); + if (sprintf(ext_buf, "%06lu", next)<0) + { + error= 1; + goto end; + } *end++='.'; /* @@ -2129,7 +2247,11 @@ index files.", name, ext_buf, (strlen(ext_buf) + (end - name))); goto end; } - sprintf(end, "%06lu", next); + if (sprintf(end, "%06lu", next)<0) + { + error= 1; + goto end; + } /* print warning if reaching the end of available extensions. */ if ((next > (MAX_LOG_UNIQUE_FN_EXT - LOG_WARN_UNIQUE_FN_EXT_LEFT))) @@ -2190,7 +2312,11 @@ bool MYSQL_LOG::init_and_set_log_file_name(const char *log_name, 1 error */ -bool MYSQL_LOG::open(const char *log_name, enum_log_type log_type_arg, +bool MYSQL_LOG::open( +#ifdef HAVE_PSI_INTERFACE + PSI_file_key log_file_key, +#endif + const char *log_name, enum_log_type log_type_arg, const char *new_name, enum cache_type io_cache_type_arg) { char buff[FN_REFLEN]; @@ -2218,7 +2344,12 @@ bool MYSQL_LOG::open(const char *log_name, enum_log_type log_type_arg, db[0]= 0; - if ((file= mysql_file_open(key_file_MYSQL_LOG, +#ifdef HAVE_PSI_INTERFACE + /* Keep the key for reopen */ + m_log_file_key= log_file_key; +#endif + + if ((file= mysql_file_open(log_file_key, log_file_name, open_flags, MYF(MY_WME | ME_WAITTANG))) < 0 || init_io_cache(&log_file, file, IO_SIZE, io_cache_type, @@ -2353,13 +2484,8 @@ int MYSQL_LOG::generate_new_name(char *new_name, const char *log_name) { if (find_uniq_filename(new_name)) { - /* - This should be treated as error once propagation of error further - up in the stack gets proper handling. - */ - push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN, - ER_NO_UNIQUE_LOGFILE, ER(ER_NO_UNIQUE_LOGFILE), - log_name); + my_printf_error(ER_NO_UNIQUE_LOGFILE, ER(ER_NO_UNIQUE_LOGFILE), + MYF(ME_FATALERROR), log_name); sql_print_error(ER(ER_NO_UNIQUE_LOGFILE), log_name); return 1; } @@ -2402,7 +2528,11 @@ void MYSQL_QUERY_LOG::reopen_file() Note that at this point, log_state != LOG_CLOSED (important for is_open()). */ - open(save_name, log_type, 0, io_cache_type); + open( +#ifdef HAVE_PSI_INTERFACE + m_log_file_key, +#endif + save_name, log_type, 0, io_cache_type); my_free(save_name); mysql_mutex_unlock(&LOCK_log); @@ -2764,11 +2894,9 @@ void MYSQL_BIN_LOG::init(bool no_auto_events_arg, ulong max_size_arg) void MYSQL_BIN_LOG::init_pthread_objects() { - DBUG_ASSERT(inited == 0); - inited= 1; - mysql_mutex_init(key_LOG_LOCK_log, &LOCK_log, MY_MUTEX_INIT_SLOW); - mysql_mutex_init(key_BINLOG_LOCK_index, &LOCK_index, MY_MUTEX_INIT_SLOW); - mysql_cond_init(key_BINLOG_update_cond, &update_cond, 0); + MYSQL_LOG::init_pthread_objects(); + mysql_mutex_init(m_key_LOCK_index, &LOCK_index, MY_MUTEX_INIT_SLOW); + mysql_cond_init(m_key_update_cond, &update_cond, 0); } @@ -2791,7 +2919,7 @@ bool MYSQL_BIN_LOG::open_index_file(const char *index_file_name_arg, } fn_format(index_file_name, index_file_name_arg, mysql_data_home, ".index", opt); - if ((index_file_nr= mysql_file_open(key_file_binlog_index, + if ((index_file_nr= mysql_file_open(m_key_file_log_index, index_file_name, O_RDWR | O_CREAT | O_BINARY, MYF(MY_WME))) < 0 || @@ -2879,17 +3007,37 @@ bool MYSQL_BIN_LOG::open(const char *log_name, sync_purge_index_file() || DBUG_EVALUATE_IF("fault_injection_registering_index", 1, 0)) { + /** + TODO: although this was introduced to appease valgrind + when injecting emulated faults using fault_injection_registering_index + it may be good to consider what actually happens when + open_purge_index_file succeeds but register or sync fails. + + Perhaps we might need the code below in MYSQL_LOG_BIN::cleanup + for "real life" purposes as well? + */ + DBUG_EXECUTE_IF("fault_injection_registering_index", { + if (my_b_inited(&purge_index_file)) + { + end_io_cache(&purge_index_file); + my_close(purge_index_file.file, MYF(0)); + } + }); + sql_print_error("MSYQL_BIN_LOG::open failed to sync the index file."); DBUG_RETURN(1); } - DBUG_EXECUTE_IF("crash_create_non_critical_before_update_index", DBUG_ABORT();); + DBUG_EXECUTE_IF("crash_create_non_critical_before_update_index", DBUG_SUICIDE();); #endif write_error= 0; /* open the main log file */ - if (MYSQL_LOG::open(log_name, log_type_arg, new_name, - io_cache_type_arg)) + if (MYSQL_LOG::open( +#ifdef HAVE_PSI_INTERFACE + m_key_file_log, +#endif + log_name, log_type_arg, new_name, io_cache_type_arg)) { #ifdef HAVE_REPLICATION close_purge_index_file(); @@ -2979,7 +3127,7 @@ bool MYSQL_BIN_LOG::open(const char *log_name, if (write_file_name_to_index_file) { #ifdef HAVE_REPLICATION - DBUG_EXECUTE_IF("crash_create_critical_before_update_index", DBUG_ABORT();); + DBUG_EXECUTE_IF("crash_create_critical_before_update_index", DBUG_SUICIDE();); #endif DBUG_ASSERT(my_b_inited(&index_file) != 0); @@ -2998,7 +3146,7 @@ bool MYSQL_BIN_LOG::open(const char *log_name, goto err; #ifdef HAVE_REPLICATION - DBUG_EXECUTE_IF("crash_create_after_update_index", DBUG_ABORT();); + DBUG_EXECUTE_IF("crash_create_after_update_index", DBUG_SUICIDE();); #endif } } @@ -3257,12 +3405,6 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd) DBUG_ENTER("reset_logs"); ha_reset_logs(thd); - /* - We need to get both locks to be sure that no one is trying to - write to the index log file. - */ - mysql_mutex_lock(&LOCK_log); - mysql_mutex_lock(&LOCK_index); /* The following mutex is needed to ensure that no threads call @@ -3272,6 +3414,13 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd) */ mysql_mutex_lock(&LOCK_thread_count); + /* + We need to get both locks to be sure that no one is trying to + write to the index log file. + */ + mysql_mutex_lock(&LOCK_log); + mysql_mutex_lock(&LOCK_index); + /* Save variables so that we can reopen the log */ save_name=name; name=0; // Protect against free @@ -3328,7 +3477,7 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd) } /* Start logging with a new file */ - close(LOG_CLOSE_INDEX); + close(LOG_CLOSE_INDEX | LOG_CLOSE_TO_BE_OPENED); if ((error= my_delete_allow_opened(index_file_name, MYF(0)))) // Reset (open will update) { if (my_errno == ENOENT) @@ -3357,7 +3506,8 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd) if (!thd->slave_thread) need_start_event=1; if (!open_index_file(index_file_name, 0, FALSE)) - open(save_name, log_type, 0, io_cache_type, no_auto_events, max_size, 0, FALSE); + if ((error= open(save_name, log_type, 0, io_cache_type, no_auto_events, max_size, 0, FALSE))) + goto err; my_free((void *) save_name); err: @@ -3461,7 +3611,7 @@ int MYSQL_BIN_LOG::purge_first_log(Relay_log_info* rli, bool included) /* Store where we are in the new file for the execution thread */ flush_relay_log_info(rli); - DBUG_EXECUTE_IF("crash_before_purge_logs", DBUG_ABORT();); + DBUG_EXECUTE_IF("crash_before_purge_logs", DBUG_SUICIDE();); mysql_mutex_lock(&rli->log_space_lock); rli->relay_log.purge_logs(to_purge_if_included, included, @@ -3589,7 +3739,7 @@ int MYSQL_BIN_LOG::purge_logs(const char *to_log, break; } - DBUG_EXECUTE_IF("crash_purge_before_update_index", DBUG_ABORT();); + DBUG_EXECUTE_IF("crash_purge_before_update_index", DBUG_SUICIDE();); if ((error= sync_purge_index_file())) { @@ -3604,7 +3754,7 @@ int MYSQL_BIN_LOG::purge_logs(const char *to_log, goto err; } - DBUG_EXECUTE_IF("crash_purge_critical_after_update_index", DBUG_ABORT();); + DBUG_EXECUTE_IF("crash_purge_critical_after_update_index", DBUG_SUICIDE();); err: /* Read each entry from purge_index_file and delete the file. */ @@ -3614,7 +3764,7 @@ err: " that would be purged."); close_purge_index_file(); - DBUG_EXECUTE_IF("crash_purge_non_critical_after_update_index", DBUG_ABORT();); + DBUG_EXECUTE_IF("crash_purge_non_critical_after_update_index", DBUG_SUICIDE();); if (need_mutex) mysql_mutex_unlock(&LOCK_index); @@ -3756,7 +3906,7 @@ int MYSQL_BIN_LOG::purge_index_entry(THD *thd, ulonglong *decrease_log_space, /* Get rid of the trailing '\n' */ log_info.log_file_name[length-1]= 0; - if (!mysql_file_stat(key_file_binlog, log_info.log_file_name, &s, MYF(0))) + if (!mysql_file_stat(m_key_file_log, log_info.log_file_name, &s, MYF(0))) { if (my_errno == ENOENT) { @@ -3931,7 +4081,7 @@ int MYSQL_BIN_LOG::purge_logs_before_date(time_t purge_time) !is_active(log_info.log_file_name) && !log_in_use(log_info.log_file_name)) { - if (!mysql_file_stat(key_file_binlog, + if (!mysql_file_stat(m_key_file_log, log_info.log_file_name, &stat_area, MYF(0))) { if (my_errno == ENOENT) @@ -4022,17 +4172,23 @@ bool MYSQL_BIN_LOG::is_active(const char *log_file_name_arg) incapsulation 3) allows external access to the class without a lock (which is not possible with private new_file_without_locking method). + + @retval + nonzero - error */ -void MYSQL_BIN_LOG::new_file() +int MYSQL_BIN_LOG::new_file() { - new_file_impl(1); + return new_file_impl(1); } - -void MYSQL_BIN_LOG::new_file_without_locking() +/* + @retval + nonzero - error + */ +int MYSQL_BIN_LOG::new_file_without_locking() { - new_file_impl(0); + return new_file_impl(0); } @@ -4041,19 +4197,23 @@ void MYSQL_BIN_LOG::new_file_without_locking() @param need_lock Set to 1 if caller has not locked LOCK_log + @retval + nonzero - error + @note The new file name is stored last in the index file */ -void MYSQL_BIN_LOG::new_file_impl(bool need_lock) +int MYSQL_BIN_LOG::new_file_impl(bool need_lock) { - char new_name[FN_REFLEN], *new_name_ptr, *old_name; + int error= 0, close_on_error= FALSE; + char new_name[FN_REFLEN], *new_name_ptr, *old_name, *file_to_open; DBUG_ENTER("MYSQL_BIN_LOG::new_file_impl"); if (!is_open()) { DBUG_PRINT("info",("log is closed")); - DBUG_VOID_RETURN; + DBUG_RETURN(error); } if (need_lock) @@ -4091,7 +4251,7 @@ void MYSQL_BIN_LOG::new_file_impl(bool need_lock) We have to do this here and not in open as we want to store the new file name in the current binary log file. */ - if (generate_new_name(new_name, name)) + if ((error= generate_new_name(new_name, name))) goto end; new_name_ptr=new_name; @@ -4105,7 +4265,14 @@ void MYSQL_BIN_LOG::new_file_impl(bool need_lock) */ Rotate_log_event r(new_name+dirname_length(new_name), 0, LOG_EVENT_OFFSET, is_relay_log ? Rotate_log_event::RELAY_LOG : 0); - r.write(&log_file); + if(DBUG_EVALUATE_IF("fault_injection_new_file_rotate_event", (error=close_on_error=TRUE), FALSE) || + (error= r.write(&log_file))) + { + DBUG_EXECUTE_IF("fault_injection_new_file_rotate_event", errno=2;); + close_on_error= TRUE; + my_printf_error(ER_ERROR_ON_WRITE, ER(ER_CANT_OPEN_FILE), MYF(ME_FATALERROR), name, errno); + goto end; + } bytes_written += r.data_written; } /* @@ -4133,17 +4300,56 @@ void MYSQL_BIN_LOG::new_file_impl(bool need_lock) */ /* reopen index binlog file, BUG#34582 */ - if (!open_index_file(index_file_name, 0, FALSE)) - open(old_name, log_type, new_name_ptr, - io_cache_type, no_auto_events, max_size, 1, FALSE); + file_to_open= index_file_name; + error= open_index_file(index_file_name, 0, FALSE); + if (!error) + { + /* reopen the binary log file. */ + file_to_open= new_name_ptr; + error= open(old_name, log_type, new_name_ptr, io_cache_type, + no_auto_events, max_size, 1, FALSE); + } + + /* handle reopening errors */ + if (error) + { + my_printf_error(ER_CANT_OPEN_FILE, ER(ER_CANT_OPEN_FILE), + MYF(ME_FATALERROR), file_to_open, error); + close_on_error= TRUE; + } + my_free(old_name); end: + + if (error && close_on_error /* rotate or reopen failed */) + { + /* + Close whatever was left opened. + + We are keeping the behavior as it exists today, ie, + we disable logging and move on (see: BUG#51014). + + TODO: as part of WL#1790 consider other approaches: + - kill mysql (safety); + - try multiple locations for opening a log file; + - switch server to protected/readonly mode + - ... + */ + close(LOG_CLOSE_INDEX); + sql_print_error("Could not open %s for logging (error %d). " + "Turning logging off for the whole duration " + "of the MySQL server process. To turn it on " + "again: fix the cause, shutdown the MySQL " + "server and restart it.", + new_name_ptr, errno); + } + if (need_lock) mysql_mutex_unlock(&LOCK_log); mysql_mutex_unlock(&LOCK_index); - DBUG_VOID_RETURN; + DBUG_RETURN(error); } @@ -4168,8 +4374,7 @@ bool MYSQL_BIN_LOG::append(Log_event* ev) if (flush_and_sync(0)) goto err; if ((uint) my_b_append_tell(&log_file) > max_size) - new_file_without_locking(); - + error= new_file_without_locking(); err: mysql_mutex_unlock(&LOCK_log); signal_update(); // Safe as we don't call close @@ -4200,8 +4405,7 @@ bool MYSQL_BIN_LOG::appendv(const char* buf, uint len,...) if (flush_and_sync(0)) goto err; if ((uint) my_b_append_tell(&log_file) > max_size) - new_file_without_locking(); - + error= new_file_without_locking(); err: if (!error) signal_update(); @@ -4390,7 +4594,7 @@ int THD::binlog_setup_trx_data() cache_mngr= (binlog_cache_mngr*) my_malloc(sizeof(binlog_cache_mngr), MYF(MY_ZEROFILL)); if (!cache_mngr || open_cached_file(&cache_mngr->stmt_cache.cache_log, mysql_tmpdir, - LOG_PREFIX, binlog_cache_size, MYF(MY_WME)) || + LOG_PREFIX, binlog_stmt_cache_size, MYF(MY_WME)) || open_cached_file(&cache_mngr->trx_cache.cache_log, mysql_tmpdir, LOG_PREFIX, binlog_cache_size, MYF(MY_WME))) { @@ -4399,8 +4603,13 @@ int THD::binlog_setup_trx_data() } thd_set_ha_data(this, binlog_hton, cache_mngr); - cache_mngr= new (thd_get_ha_data(this, binlog_hton)) binlog_cache_mngr; - + cache_mngr= new (thd_get_ha_data(this, binlog_hton)) + binlog_cache_mngr(max_binlog_stmt_cache_size, + max_binlog_cache_size, + &binlog_stmt_cache_use, + &binlog_stmt_cache_disk_use, + &binlog_cache_use, + &binlog_cache_disk_use); DBUG_RETURN(0); } @@ -4652,7 +4861,7 @@ MYSQL_BIN_LOG::flush_and_set_pending_rows_event(THD *thd, */ if (pending->write(file)) { - set_write_error(thd); + set_write_error(thd, is_transactional); if (check_write_error(thd) && cache_data && stmt_has_updated_non_trans_table(thd)) cache_data->set_incident(); @@ -4677,6 +4886,7 @@ bool MYSQL_BIN_LOG::write(Log_event *event_info) bool error= 1; DBUG_ENTER("MYSQL_BIN_LOG::write(Log_event *)"); binlog_cache_data *cache_data= 0; + bool is_trans_cache= FALSE; if (thd->binlog_evt_union.do_union) { @@ -4739,7 +4949,7 @@ bool MYSQL_BIN_LOG::write(Log_event *event_info) binlog_cache_mngr *const cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton); - bool is_trans_cache= use_trans_cache(thd, event_info->use_trans_cache()); + is_trans_cache= use_trans_cache(thd, event_info->use_trans_cache()); file= cache_mngr->get_binlog_cache_log(is_trans_cache); cache_data= cache_mngr->get_binlog_cache_data(is_trans_cache); @@ -4819,7 +5029,6 @@ bool MYSQL_BIN_LOG::write(Log_event *event_info) goto err; error= 0; - err: if (event_info->use_direct_logging()) { @@ -4848,7 +5057,7 @@ unlock: if (error) { - set_write_error(thd); + set_write_error(thd, is_trans_cache); if (check_write_error(thd) && cache_data && stmt_has_updated_non_trans_table(thd)) cache_data->set_incident(); @@ -4928,8 +5137,19 @@ bool general_log_write(THD *thd, enum enum_server_command command, return FALSE; } -void MYSQL_BIN_LOG::rotate_and_purge(uint flags) +/** + @note + If rotation fails, for instance the server was unable + to create a new log file, we still try to write an + incident event to the current log. + + @retval + nonzero - error +*/ +int MYSQL_BIN_LOG::rotate_and_purge(uint flags) { + int error= 0; + DBUG_ENTER("MYSQL_BIN_LOG::rotate_and_purge"); #ifdef HAVE_REPLICATION bool check_purge= false; #endif @@ -4938,26 +5158,38 @@ void MYSQL_BIN_LOG::rotate_and_purge(uint flags) if ((flags & RP_FORCE_ROTATE) || (my_b_tell(&log_file) >= (my_off_t) max_size)) { - new_file_without_locking(); + if ((error= new_file_without_locking())) + /** + Be conservative... There are possible lost events (eg, + failing to log the Execute_load_query_log_event + on a LOAD DATA while using a non-transactional + table)! + + We give it a shot and try to write an incident event anyway + to the current log. + */ + if (!write_incident(current_thd, FALSE)) + flush_and_sync(0); + #ifdef HAVE_REPLICATION check_purge= true; #endif } if (!(flags & RP_LOCK_LOG_IS_ALREADY_LOCKED)) mysql_mutex_unlock(&LOCK_log); - #ifdef HAVE_REPLICATION /* NOTE: Run purge_logs wo/ holding LOCK_log as it otherwise will deadlock in ndbcluster_binlog_index_purge_file */ - if (check_purge && expire_logs_days) + if (!error && check_purge && expire_logs_days) { time_t purge_time= my_time(0) - expire_logs_days*24*60*60; if (purge_time >= 0) purge_logs_before_date(purge_time); } #endif + DBUG_RETURN(error); } uint MYSQL_BIN_LOG::next_file_id() @@ -5148,6 +5380,10 @@ bool MYSQL_BIN_LOG::write_incident(THD *thd, bool lock) { uint error= 0; DBUG_ENTER("MYSQL_BIN_LOG::write_incident"); + + if (!is_open()) + DBUG_RETURN(error); + LEX_STRING const write_error_msg= { C_STRING_WITH_LEN("error writing to the binary log") }; Incident incident= INCIDENT_LOST_EVENTS; @@ -5161,7 +5397,7 @@ bool MYSQL_BIN_LOG::write_incident(THD *thd, bool lock) if (!error && !(error= flush_and_sync(0))) { signal_update(); - rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED); + error= rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED); } mysql_mutex_unlock(&LOCK_log); } @@ -5225,7 +5461,7 @@ bool MYSQL_BIN_LOG::write(THD *thd, IO_CACHE *cache, Log_event *commit_event, DBUG_PRINT("info", ("error writing binlog cache: %d", write_error)); DBUG_PRINT("info", ("crashing before writing xid")); - DBUG_ABORT(); + DBUG_SUICIDE(); }); if ((write_error= write_cache(thd, cache, FALSE, FALSE))) @@ -5245,7 +5481,7 @@ bool MYSQL_BIN_LOG::write(THD *thd, IO_CACHE *cache, Log_event *commit_event, bool synced= 0; if (flush_and_sync(&synced)) goto err; - DBUG_EXECUTE_IF("half_binlogged_transaction", DBUG_ABORT();); + DBUG_EXECUTE_IF("half_binlogged_transaction", DBUG_SUICIDE();); if (cache->error) // Error on read { sql_print_error(ER(ER_ERROR_ON_READ), cache->file_name, errno); @@ -5279,7 +5515,8 @@ bool MYSQL_BIN_LOG::write(THD *thd, IO_CACHE *cache, Log_event *commit_event, mysql_mutex_unlock(&LOCK_prep_xids); } else - rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED); + if (rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED)) + goto err; } mysql_mutex_unlock(&LOCK_log); @@ -5501,80 +5738,26 @@ void sql_perror(const char *message) } -#ifdef __WIN__ +/* + Change the file associated with two output streams. Used to + redirect stdout and stderr to a file. The streams are reopened + only for appending (writing at end of file). +*/ extern "C" my_bool reopen_fstreams(const char *filename, FILE *outstream, FILE *errstream) { - int handle_fd; - int err_fd, out_fd; - HANDLE osfh; - - DBUG_ASSERT(filename && errstream); - - // Services don't have stdout/stderr on Windows, so _fileno returns -1. - err_fd= _fileno(errstream); - if (err_fd < 0) - { - if (!freopen(filename, "a+", errstream)) - return TRUE; - - setbuf(errstream, NULL); - err_fd= _fileno(errstream); - } - - if (outstream) - { - out_fd= _fileno(outstream); - if (out_fd < 0) - { - if (!freopen(filename, "a+", outstream)) - return TRUE; - out_fd= _fileno(outstream); - } - } - - if ((osfh= CreateFile(filename, GENERIC_READ | GENERIC_WRITE, - FILE_SHARE_READ | FILE_SHARE_WRITE | - FILE_SHARE_DELETE, NULL, - OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, - NULL)) == INVALID_HANDLE_VALUE) - return TRUE; - - if ((handle_fd= _open_osfhandle((intptr_t)osfh, - _O_APPEND | _O_TEXT)) == -1) - { - CloseHandle(osfh); - return TRUE; - } - - if (_dup2(handle_fd, err_fd) < 0) - { - CloseHandle(osfh); - return TRUE; - } - - if (outstream && _dup2(handle_fd, out_fd) < 0) - { - CloseHandle(osfh); + if (outstream && !my_freopen(filename, "a", outstream)) return TRUE; - } - _close(handle_fd); - return FALSE; -} -#else -extern "C" my_bool reopen_fstreams(const char *filename, - FILE *outstream, FILE *errstream) -{ - if (outstream && !freopen(filename, "a+", outstream)) + if (errstream && !my_freopen(filename, "a", errstream)) return TRUE; - if (errstream && !freopen(filename, "a+", errstream)) - return TRUE; + /* The error stream must be unbuffered. */ + if (errstream) + setbuf(errstream, NULL); return FALSE; } -#endif /* @@ -5865,7 +6048,7 @@ int TC_LOG_MMAP::open(const char *opt_name) { pg->next=pg+1; pg->waiters=0; - pg->state=POOL; + pg->state=PS_POOL; mysql_mutex_init(key_PAGE_lock, &pg->lock, MY_MUTEX_INIT_FAST); mysql_cond_init(key_PAGE_cond, &pg->cond, 0); pg->ptr= pg->start=(my_xid *)(data + i*tc_log_page_size); @@ -6047,7 +6230,7 @@ int TC_LOG_MMAP::log_xid(THD *thd, my_xid xid) cookie= (ulong)((uchar *)p->ptr - data); // can never be zero *p->ptr++= xid; p->free--; - p->state= DIRTY; + p->state= PS_DIRTY; mysql_mutex_unlock(&p->lock); mysql_mutex_lock(&LOCK_sync); @@ -6058,7 +6241,7 @@ int TC_LOG_MMAP::log_xid(THD *thd, my_xid xid) p->waiters++; for (;;) { - int not_dirty = p->state != DIRTY; + int not_dirty = p->state != PS_DIRTY; mysql_mutex_unlock(&p->lock); if (not_dirty || !syncing) break; @@ -6066,8 +6249,8 @@ int TC_LOG_MMAP::log_xid(THD *thd, my_xid xid) mysql_mutex_lock(&p->lock); } p->waiters--; - err= p->state == ERROR; - if (p->state != DIRTY) // page was synced + err= p->state == PS_ERROR; + if (p->state != PS_DIRTY) // page was synced { mysql_mutex_unlock(&LOCK_sync); if (p->waiters == 0) @@ -6116,7 +6299,7 @@ int TC_LOG_MMAP::sync() pool_last->next=syncing; pool_last=syncing; syncing->next=0; - syncing->state= err ? ERROR : POOL; + syncing->state= err ? PS_ERROR : PS_POOL; mysql_cond_signal(&COND_pool); // in case somebody's waiting mysql_mutex_unlock(&LOCK_pool); @@ -6143,7 +6326,7 @@ int TC_LOG_MMAP::sync() cookie points directly to the memory where xid was logged. */ -void TC_LOG_MMAP::unlog(ulong cookie, my_xid xid) +int TC_LOG_MMAP::unlog(ulong cookie, my_xid xid) { PAGE *p=pages+(cookie/tc_log_page_size); my_xid *x=(my_xid *)(data+cookie); @@ -6161,6 +6344,7 @@ void TC_LOG_MMAP::unlog(ulong cookie, my_xid xid) if (p->waiters == 0) // the page is in pool and ready to rock mysql_cond_signal(&COND_pool); // ping ... for overflow() mysql_mutex_unlock(&p->lock); + return 0; } void TC_LOG_MMAP::close() @@ -6393,27 +6577,30 @@ void TC_LOG_BINLOG::close() int TC_LOG_BINLOG::log_xid(THD *thd, my_xid xid) { DBUG_ENTER("TC_LOG_BINLOG::log"); - Xid_log_event xle(thd, xid); binlog_cache_mngr *cache_mngr= (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton); /* We always commit the entire transaction when writing an XID. Also note that the return value is inverted. */ - DBUG_RETURN(!binlog_flush_stmt_cache(thd, cache_mngr) && - !binlog_flush_trx_cache(thd, cache_mngr, &xle)); + DBUG_RETURN(!binlog_commit_flush_stmt_cache(thd, cache_mngr) && + !binlog_commit_flush_trx_cache(thd, cache_mngr, xid)); } -void TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid) +int TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid) { + DBUG_ENTER("TC_LOG_BINLOG::unlog"); mysql_mutex_lock(&LOCK_prep_xids); - DBUG_ASSERT(prepared_xids > 0); - if (--prepared_xids == 0) { + // prepared_xids can be 0 if the transaction had ignorable errors. + DBUG_ASSERT(prepared_xids >= 0); + if (prepared_xids > 0) + prepared_xids--; + if (prepared_xids == 0) { DBUG_PRINT("info", ("prepared_xids=%lu", prepared_xids)); mysql_cond_signal(&COND_prep_xids); } mysql_mutex_unlock(&LOCK_prep_xids); - rotate_and_purge(0); // as ::write() did not rotate + DBUG_RETURN(rotate_and_purge(0)); // as ::write() did not rotate } int TC_LOG_BINLOG::recover(IO_CACHE *log, Format_description_log_event *fdle) |