- developers - lists.mariadb.org

Re: [Maria-developers] MDEV-181: XID crash recovery across binlog boundaries
by Sergei Golubchik 12 Jun '12

12 Jun '12

Hi, Kristian! Here's my review. Only few comments and questions, see below. On May 14, Kristian Nielsen wrote: > At http://bazaar.launchpad.net/~maria-captains/maria/5.5 > > ------------------------------------------------------------ > revno: 3372 > revision-id: knielsen(a)knielsen-hq.org-20120514095140-n685kn0n4vtronn5 > timestamp: Mon 2012-05-14 11:51:40 +0200 > message: > MDEV-181: XID crash recovery across binlog boundaries > === added file 'mysql-test/suite/binlog/t/binlog_xa_recover.test' > --- mysql-test/suite/binlog/t/binlog_xa_recover.test 1970-01-01 00:00:00 +0000 > +++ mysql-test/suite/binlog/t/binlog_xa_recover.test 2012-05-14 09:51:40 +0000 > @@ -0,0 +1,172 @@ > +--source include/have_innodb.inc > +--source include/have_debug.inc > +--source include/have_debug_sync.inc > +--source include/have_binlog_format_row.inc > + > +SET GLOBAL max_binlog_size= 4096; > + > +CREATE TABLE t1 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb; > +CREATE TABLE t2 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Myisam; > + > +# Transactions are not guaranteed stored durably on disk in the engine until > +# they are fsync()ed, which normally happens during commit(). But there is no > +# guarantee that they will _not_ be durable, in particular loosing results > +# of a write(2) system call normally requires a kernel crash (as opposed to > +# just mysqld crash), which is inconvenient to do in a test suite. > +# So instead we do an error insert to prevent commit_ordered() from being > +# called in the engine - so nothing will be written to disk at all, and crash > +# recovery is sure to be needed. Are these assumptions reasonable? You seem to assume that without commit_ordered the engine will still work normally. but simply won't write changes to disk. Is it always the case? > +SET @@global.debug_dbug='+d,skip_commit_ordered'; I don't see where you restore the old value of debug_dbug > + > +INSERT INTO t1 VALUES (0, REPEAT("x", 4100)); how comes this insert is not affected by skip_commit_ordered ? > + > +# Now start a bunch of transactions that span multiple binlog > +# files. Leave then in the state prepared-but-not-committed in the engine > +# and crash the server. Check that crash recovery is able to recover all > +# of them. > + > +connect(con1,localhost,root,,); > +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con1_ready WAIT_FOR _ever"; > +send INSERT INTO t1 VALUES (1, REPEAT("x", 4100)); > + > +connection default; > +SET DEBUG_SYNC= "now WAIT_FOR con1_ready"; > +INSERT INTO t2 VALUES (1, "force binlog rotation"); > + > +connect(con2,localhost,root,,); > +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con2_ready WAIT_FOR _ever"; > +send INSERT INTO t1 VALUES (2, NULL); > + > +connection default; > +SET DEBUG_SYNC= "now WAIT_FOR con2_ready"; > + > +connect(con3,localhost,root,,); > +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con3_ready WAIT_FOR _ever"; > +send INSERT INTO t1 VALUES (3, REPEAT("x", 4100)); > +connection default; > +SET DEBUG_SYNC= "now WAIT_FOR con3_ready"; > +INSERT INTO t2 VALUES (2, "force binlog rotation"); > +# So we won't get warnings about t2 being crashed. > +FLUSH TABLES t2; > + > +# Check that everything is committed in binary log. > +--source include/show_binary_logs.inc > +--let $binlog_file= master-bin.000001 > +--let $binlog_start= 4 > +--source include/show_binlog_events.inc > +--let $binlog_file= master-bin.000002 > +--source include/show_binlog_events.inc > +--let $binlog_file= master-bin.000003 > +--source include/show_binlog_events.inc > +--let $binlog_file= master-bin.000004 > +--source include/show_binlog_events.inc > + > +# Check that transactions really are not yet committed in engine. > +# (This works because of debug_dbug='+d,skip_commit_ordered'). > +--echo We should see only one entry here, a=0: > +SELECT a FROM t1 ORDER BY a; > + > + > +# Check that server will not purge too much. > +PURGE BINARY LOGS TO "master-bin.000004"; > +--source include/show_binary_logs.inc > + > +# Now crash the server with one more transaction in prepared state. > +system echo wait-binlog_xa_recover.test >> $MYSQLTEST_VARDIR/tmp/mysqld.1.expect; better use --write_file directive > +SET SESSION debug_dbug="+d,crash_commit_after_log"; > +--error 2006,2013 > +INSERT INTO t1 VALUES (4, NULL); > + > +system echo restart-group_commit_binlog_pos.test >> $MYSQLTEST_VARDIR/tmp/mysqld.1.expect; same > + > +connection default; > +--enable_reconnect > +--source include/wait_until_connected_again.inc > + > +# Check that all transactions are recovered. > +SELECT a FROM t1 ORDER BY a; > + > + > +--echo *** Test that RESET MASTER waits for pending XIDs to be unlogged. Ah, good point > + > +SET @old_max_binlog_size= @@global.max_binlog_size; > +SET GLOBAL max_binlog_size= 4096; > +# con10 will hang with a pending XID, blocking RESET MASTER. > +connect(con10,localhost,root,,); > +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con10_ready WAIT_FOR con10_go"; > +send INSERT INTO t1 VALUES (10, NULL); > + > +connection default; > +SET DEBUG_SYNC= "now WAIT_FOR con10_ready"; > +# Let's add a few binlog rotations just for good measure. > +INSERT INTO t2 VALUES (10, REPEAT("x", 4100)); > +INSERT INTO t2 VALUES (11, REPEAT("x", 4100)); > +--source include/show_binary_logs.inc > +SET DEBUG_SYNC= "execute_command_after_close_tables SIGNAL reset_master_done"; > +send RESET MASTER; > + > +connect(con11,localhost,root,,); > +--echo This will timeout, as RESET MASTER is blocked > +SET DEBUG_SYNC= "now WAIT_FOR reset_master_done TIMEOUT 1"; > +# Wake up transaction to allow RESET MASTER to complete. > +SET DEBUG_SYNC= "now SIGNAL con10_go"; > + > +connection con10; > +reap; > + > +connection default; > +reap; > +--source include/show_binary_logs.inc > + > + > +--echo *** Test that binlog N is active, and last pending trx in (N-1) is > +--echo unlogged while there is still a pending trx in (N-2). > + > +connection con10; > +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con10_ready WAIT_FOR con10_continue"; > +send INSERT INTO t1 VALUES (20, REPEAT("x", 4100)); > + > +connection default; > +SET DEBUG_SYNC= "now WAIT_FOR con10_ready"; > +INSERT INTO t2 VALUES (3, "force binlog rotation"); > + > +connection con11; > +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con11_ready WAIT_FOR con11_continue"; > +send INSERT INTO t1 VALUES (21, REPEAT("x", 4100)); > + > +connection default; > +SET DEBUG_SYNC= "now WAIT_FOR con11_ready"; > +INSERT INTO t2 VALUES (4, "force binlog rotation"); > +--source include/show_binary_logs.inc > +--let $binlog_file= master-bin.000001 > +--source include/show_binlog_events.inc > +--let $binlog_file= master-bin.000002 > +--source include/show_binlog_events.inc > +--let $binlog_file= master-bin.000003 > +--source include/show_binlog_events.inc > + > +SET DEBUG_SYNC= "now SIGNAL con11_continue"; > + > +connection con11; > +reap; > + > +connection default; > +--echo con10 is still pending, no new binlog checkpoint should have been logged. > +--let $binlog_file= master-bin.000003 > +--source include/show_binlog_events.inc > + > +SET DEBUG_SYNC= "now SIGNAL con10_continue"; > + > +connection con10; > +reap; > + > +connection default; > +--echo No XIDs are pending, a new binlog checkpoint should have been logged. Could you also test recovery with multiple checkpoints in a binlog? E.g. binlog, like the above, then crash, and see that it uses the *last* checkpoint in the binlog. > +--let $binlog_file= master-bin.000003 > +--source include/show_binlog_events.inc > + > + > +# Cleanup > +connection default; > +DROP TABLE t1, t2; > +SET GLOBAL max_binlog_size= @old_max_binlog_size; > > === modified file 'sql/log.h' > --- sql/log.h 2012-01-16 19:16:35 +0000 > +++ sql/log.h 2012-05-14 09:51:40 +0000 > @@ -348,6 +348,15 @@ > time_t last_time; > }; > > +/* > + We assign each binlog file an internal ID, used to identify them for unlog(). > + Ids start from BINLOG_COOKIE_START; the value BINLOG_COOKIE_DUMMY is special > + meaning "no binlog" (we cannot use zero as that is reserved for error return > + from log_and_order). > +*/ > +#define BINLOG_COOKIE_DUMMY 1 > +#define BINLOG_COOKIE_START 2 Are these values completely internal and can be changed in any minor release without any compatibility concerns? Or they're written to binlog or something? > + > class binlog_cache_mngr; > class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG > { > @@ -388,10 +397,40 @@ > bool all; > }; > > + /* > + A list of struct xid_count_per_binlog is used to keep track of how many > + XIDs are in preared, but not committed, state in each binlog. "prepared" > + > + When count drops to zero in a binlog after rotation, it means that there > + are no more XIDs in prepared state, so that binlog is no longer needed > + for XA crash recovery, and we can log a new binlog checkpoint event. > + > + The list is protected against simultaneous access from multiple > + threads by LOCK_xid_list. > + */ > + struct xid_count_per_binlog : public ilink { > + char *binlog_name; > + uint binlog_name_len; > + ulong binlog_id; > + long xid_count; > + xid_count_per_binlog(); /* Give link error if constructor used. */ > + }; > + ulong current_binlog_id; > + I_List<xid_count_per_binlog> binlog_xid_count_list; Why I_List? > + /* > + When this is set, a RESET MASTER is in progress. > + > + Then we should not write any binlog checkpoints into the binlog (that > + could result in deadlock on LOCK_log, and we will delete all binlog files > + anyway). Instead we should signal COND_prep_xids whenever a new binlog COND_xid_list? > + checkpoint arrives - when all have arrived, RESET MASTER will complete. > + */ > + bool reset_master_pending; > + > /* LOCK_log and LOCK_index are inited by init_pthread_objects() */ > mysql_mutex_t LOCK_index; > - mysql_mutex_t LOCK_prep_xids; > - mysql_cond_t COND_prep_xids; > + mysql_mutex_t LOCK_xid_list; > + mysql_cond_t COND_xid_list; > mysql_cond_t update_cond; > ulonglong bytes_written; > IO_CACHE index_file; > @@ -415,7 +454,6 @@ It'd be great, if your diff would include function names (diff -p). An easy way of doing it is to use my diff_p plugin, see the last section in http://kb.askmonty.org/en/how-to-get-more-out-of-bzr-when-working-on-mariadb it's the most flexible, robust and universal solution that I have, and it puts function names in all bzr-generated diffs, not only in "bzr diff" command. > fix_max_relay_log_size). > */ > ulong max_size; > - long prepared_xids; /* for tc log - number of xids to remember */ > // current file sequence number for load data infile binary logging > uint file_id; > uint open_count; // For replication > === modified file 'sql/log_event.cc' > --- sql/log_event.cc 2012-05-09 07:35:46 +0000 > +++ sql/log_event.cc 2012-05-14 09:51:40 +0000 > @@ -5842,6 +5848,84 @@ > > > /************************************************************************** > + Binlog_checkpoint_log_event methods > +**************************************************************************/ > + > +#if defined(HAVE_REPLICATION) && !defined(MYSQL_CLIENT) > +void Binlog_checkpoint_log_event::pack_info(Protocol *protocol) > +{ > + protocol->store(binlog_file_name, binlog_file_len, &my_charset_bin); > +} > +#endif > + > + > +#ifdef MYSQL_CLIENT > +void Binlog_checkpoint_log_event::print(FILE *file, > + PRINT_EVENT_INFO *print_event_info) > +{ > + Write_on_release_cache cache(&print_event_info->head_cache, file, > + Write_on_release_cache::FLUSH_F); > + > + if (print_event_info->short_form) > + return; > + print_header(&cache, print_event_info, FALSE); > + my_b_printf(&cache, "\tBinlog checkpoint "); > + my_b_write(&cache, (uchar*)binlog_file_name, binlog_file_len); > + my_b_printf(&cache, "\n"); > +} > +#endif /* MYSQL_CLIENT */ > + > + > +#ifdef MYSQL_SERVER > +Binlog_checkpoint_log_event::Binlog_checkpoint_log_event( > + const char *binlog_file_name_arg, > + uint binlog_file_len_arg) > + :Log_event(), > + binlog_file_name(my_strndup(binlog_file_name_arg, binlog_file_len_arg, > + MYF(MY_WME))), > + binlog_file_len(binlog_file_len_arg) > +{ > + cache_type= EVENT_NO_CACHE; > +} > +#endif /* MYSQL_SERVER */ > + > + > +Binlog_checkpoint_log_event::Binlog_checkpoint_log_event( > + const char *buf, uint event_len, > + const Format_description_log_event *description_event) > + :Log_event(buf, description_event), binlog_file_name(0) > +{ > + uint8 header_size= description_event->common_header_len; > + uint8 post_header_len= > + description_event->post_header_len[BINLOG_CHECKPOINT_EVENT-1]; > + if (event_len < header_size + post_header_len || > + post_header_len < 4) I'd replace this 4 with BINLOG_CHECKPOINT_HEADER_LEN > + return; > + buf+= header_size; and here I'd add compile_time_assert(BINLOG_CHECKPOINT_HEADER_LEN == 4); // see uint4korr and int4store below > + binlog_file_len= uint4korr(buf); > + if (event_len - (header_size + post_header_len) < binlog_file_len) > + return; > + binlog_file_name= my_strndup(buf + post_header_len, binlog_file_len, > + MYF(MY_WME)); > + return; > +} > + > + > +#ifndef MYSQL_CLIENT > +bool Binlog_checkpoint_log_event::write(IO_CACHE *file) > +{ > + uchar buf[BINLOG_CHECKPOINT_HEADER_LEN]; > + int4store(buf, binlog_file_len); > + return write_header(file, BINLOG_CHECKPOINT_HEADER_LEN + binlog_file_len) || > + wrapper_my_b_safe_write(file, buf, BINLOG_CHECKPOINT_HEADER_LEN) || > + wrapper_my_b_safe_write(file, (const uchar *)binlog_file_name, > + binlog_file_len) || > + write_footer(file); > +} > +#endif /* MYSQL_CLIENT */ > + > + > +/************************************************************************** > Intvar_log_event methods > **************************************************************************/ > > === modified file 'sql/log.cc' > --- sql/log.cc 2012-04-10 06:28:13 +0000 > +++ sql/log.cc 2012-05-14 09:51:40 +0000 > @@ -2912,13 +2929,30 @@ > DBUG_ENTER("cleanup"); > if (inited) > { > + xid_count_per_binlog *b; > + > inited= 0; > close(LOG_CLOSE_INDEX|LOG_CLOSE_STOP_EVENT); > delete description_event_for_queue; > delete description_event_for_exec; > + > + while ((b= binlog_xid_count_list.get())) 'get' - what a bad name. I checked the implementation and now I know what it's doing, but absoletely not what one would expect :( It's not your fault, of course, just ranting... > + { > + /* > + There should be no pending XIDs at shutdown, and only one entry (for > + the active binlog file) in the list. > + */ > + DBUG_ASSERT(b->xid_count == 0); > + DBUG_ASSERT(!binlog_xid_count_list.head()); > + my_free(b); > + } > + > mysql_mutex_destroy(&LOCK_log); > mysql_mutex_destroy(&LOCK_index); > + mysql_mutex_destroy(&LOCK_xid_list); > mysql_cond_destroy(&update_cond); > + mysql_cond_destroy(&COND_queue_busy); > + mysql_cond_destroy(&COND_xid_list); > } > DBUG_VOID_RETURN; > } > @@ -3506,6 +3587,42 @@ > mysql_mutex_lock(&LOCK_log); > mysql_mutex_lock(&LOCK_index); > > + if (!is_relay_log) > + { > + /* > + We are going to nuke all binary log files. > + So first wait until all pending binlog checkpoints have completed. > + */ > + mysql_mutex_lock(&LOCK_xid_list); > + xid_count_per_binlog *b; > + reset_master_pending= true; > + for (;;) > + { > + I_List_iterator<xid_count_per_binlog> it(binlog_xid_count_list); > + while ((b= it++)) > + { > + if (b->xid_count > 0) > + break; > + } > + if (!b) > + break; /* No more pending XIDs */ > + /* > + Wait until signalled that one more binlog dropped to zero, then check > + again. > + */ > + mysql_cond_wait(&COND_xid_list, &LOCK_xid_list); > + } I would've done it simpler, like while (b= binlog_xid_count_list.head()) { while (b->xid_count > 0) mysql_cond_wait(&COND_xid_list, &LOCK_xid_list); my_free(binlog_xid_count_list.get()); } > + > + /* > + Now all XIDs are fully flushed to disk, and we are holding LOCK_log so > + no new ones will be written. So we can proceed to delete the logs. > + */ > + while ((b= binlog_xid_count_list.get())) > + my_free(b); > + reset_master_pending= false; > + mysql_mutex_unlock(&LOCK_xid_list); > + } > + > /* > The following mutex is needed to ensure that no threads call > 'delete thd' as we would then risk missing a 'rollback' from this > @@ -5761,6 +5877,37 @@ > DBUG_RETURN(error); > } > > +void > +MYSQL_BIN_LOG::write_binlog_checkpoint_event_already_locked(const char *name, > + uint len) > +{ > + Binlog_checkpoint_log_event ev(name, len); > + /* > + Note that we must sync the binlog checkpoint to disk. > + Otherwise a subsequent log purge could delete binlogs that XA recovery > + thinks are needed (even though they are not really). > + */ > + if (!ev.write(&log_file) && !flush_and_sync(0)) > + { > + bool check_purge= false; > + signal_update(); > + rotate(false, &check_purge); > + if (check_purge) > + purge(); why "write binlog checkpoint event" implies signal_update(), rotate(), and purge() ? > + return; > + } > + > + /* > + If we fail to write the checkpoint event, something is probably really > + bad with the binlog. We complain in the error log. > + Note that failure to write binlog checkpoint does not compromise the > + ability to do crash recovery - crash recovery will just have to scan a > + bit more of the binlog than strictly necessary. > + */ > + sql_print_error("Failed to write binlog checkpoint event to binary log\n"); > +} > + > + > /** > Write a cached log entry to the binary log. > - To support transaction over replication, we wrap the transaction > @@ -6061,11 +6207,11 @@ > { > /* > If we fail to rotate, which thread should get the error? > - We give the error to the *last* transaction thread; that seems to > - make the most sense, as it was the last to write to the log. > + We give the error to the leader, as any my_error() thrown inside > + rotate() will have been registered for the leader THD. > */ > - last_in_queue->error= ER_ERROR_ON_WRITE; > - last_in_queue->commit_errno= errno; > + leader->error= ER_ERROR_ON_WRITE; > + leader->commit_errno= errno; Where did that change happen? Is it related to MDEV-181 at all, or it's an unrelated bugfix? > check_purge= false; > } > } > @@ -6082,9 +6228,6 @@ > */ > mysql_mutex_unlock(&LOCK_log); > > - if (check_purge) > - purge(); Why was it moved down? > - > DEBUG_SYNC(leader->thd, "commit_after_release_LOCK_log"); > ++num_group_commits; > > @@ -7427,11 +7560,23 @@ > > cache_mngr->using_xa= TRUE; > cache_mngr->xa_xid= xid; > +#ifndef DBUG_OFF > + cache_mngr->cookie= 0; > +#endif > err= binlog_commit_flush_xid_caches(thd, cache_mngr, all, xid); > > DEBUG_SYNC(thd, "binlog_after_log_and_order"); > > - DBUG_RETURN(!err); > + if (err) > + DBUG_RETURN(0); > + /* > + If using explicit user XA, we will not have XID. We must still return a > + non-zero cookie (as zero cookie signals error). > + */ > + if (!xid) > + DBUG_RETURN(1); s/1/BINLOG_COOKIE_DUMMY/ > + DBUG_ASSERT(cache_mngr->cookie != 0); > + DBUG_RETURN(cache_mngr->cookie); > } > > /* > @@ -7446,40 +7591,135 @@ > binary log. > */ > void > -TC_LOG_BINLOG::mark_xids_active(uint xid_count) > +TC_LOG_BINLOG::mark_xids_active(ulong cookie, uint xid_count) > { > + xid_count_per_binlog *b; > + > DBUG_ENTER("TC_LOG_BINLOG::mark_xids_active"); > - DBUG_PRINT("info", ("xid_count=%u", xid_count)); > - mysql_mutex_lock(&LOCK_prep_xids); > - prepared_xids+= xid_count; > - mysql_mutex_unlock(&LOCK_prep_xids); > + DBUG_PRINT("info", ("cookie=%lu xid_count=%u", cookie, xid_count)); > + DBUG_ASSERT(cookie != 0 && cookie != BINLOG_COOKIE_DUMMY); > + > + mysql_mutex_lock(&LOCK_xid_list); > + I_List_iterator<xid_count_per_binlog> it(binlog_xid_count_list); > + while ((b= it++)) > + { > + if (b->binlog_id == cookie) > + { > + b->xid_count += xid_count; > + break; > + } > + } > + /* > + As we do not delete elements until count reach zero, elements should always > + be found. > + */ > + DBUG_ASSERT(b); > + mysql_mutex_unlock(&LOCK_xid_list); > DBUG_VOID_RETURN; > } > > /* > - Once an XID is committed, it is safe to rotate the binary log, as it can no > - longer be needed during crash recovery. > + Once an XID is committed, it can no longer be needed during crash recovery, > + as it has been durably recorded on disk as "committed". > > This function is called to mark an XID this way. It needs to decrease the > - count of pending XIDs, and signal the log rotator thread when it reaches zero. > + count of pending XIDs in the corresponding binlog. When the count reaches > + zero (for an "old" binlog that is not the active one), that binlog file no > + longer need to be scanned during crash recovery, so we can log a new binlog > + checkpoint. > */ > void > -TC_LOG_BINLOG::mark_xid_done() > +TC_LOG_BINLOG::mark_xid_done(ulong cookie) > { > - my_bool send_signal; > + xid_count_per_binlog *b; > + bool first; > + ulong current; > > DBUG_ENTER("TC_LOG_BINLOG::mark_xid_done"); > - mysql_mutex_lock(&LOCK_prep_xids); > - // prepared_xids can be 0 if the transaction had ignorable errors. > - DBUG_ASSERT(prepared_xids >= 0); > - if (prepared_xids > 0) > - prepared_xids--; > - send_signal= (prepared_xids == 0); > - mysql_mutex_unlock(&LOCK_prep_xids); > - if (send_signal) { > - DBUG_PRINT("info", ("prepared_xids=%lu", prepared_xids)); > - mysql_cond_signal(&COND_prep_xids); > - } > + if (cookie == BINLOG_COOKIE_DUMMY) > + DBUG_VOID_RETURN; /* Nothing to do. */ > + > + mysql_mutex_lock(&LOCK_xid_list); > + current= current_binlog_id; > + I_List_iterator<xid_count_per_binlog> it(binlog_xid_count_list); > + first= true; > + while ((b= it++)) > + { > + if (b->binlog_id == cookie) > + { > + --b->xid_count; > + break; > + } > + first= false; > + } > + /* Binlog is always found, as we do not remove until count reaches 0 */ > + DBUG_ASSERT(b); > + if (likely(cookie == current && !reset_master_pending) || > + b->xid_count != 0 || !first) > + { > + /* No new binlog checkpoint reached yet. */ > + mysql_mutex_unlock(&LOCK_xid_list); > + DBUG_VOID_RETURN; > + } > + > + /* > + Now log a binlog checkpoint for the first binlog file with a non-zero count. > + > + Note that it is possible (though perhaps unlikely) that when count of > + binlog (N-2) drops to zero, binlog (N-1) is already at zero. So we may > + need to skip several entries before we find the one to log in the binlog > + checkpoint event. > + > + We chain the locking of LOCK_xid_list and LOCK_log, so that we ensure that > + Binlog_checkpoint_events are logged in order. This simplifies recovery a > + bit, as it can just take the last binlog checkpoint in the log, rather > + than compare all found against each other to find the one pointing to the > + most recent binlog. > + > + Note also that we need to first release LOCK_xid_list, then aquire > + LOCK_log, then re-aquire LOCK_xid_list. If we were to take LOCK_log while > + holding LOCK_xid_list, we might deadlock with other threads that take the > + locks in the opposite order. > + > + If a RESET MASTER is pending, we are about to remove all log files, and > + the RESET MASTER thread is waiting for all pending unlog() calls to > + complete while holding LOCK_log. In this case we should not log a binlog > + checkpoint event (it would be deleted immediately anywat and we would > + deadlock on LOCK_log) but just signal the thread. > + */ > + if (!reset_master_pending) > + { > + mysql_mutex_unlock(&LOCK_xid_list); > + mysql_mutex_lock(&LOCK_log); > + mysql_mutex_lock(&LOCK_xid_list); > + } > + for (;;) > + { > + /* Remove initial element(s) with zero count. */ > + b= binlog_xid_count_list.get(); Eh. You need to check whether binlog_xid_count_list.head()->xid_count == 0 before removing it like that. When you released LOCK_xid_list another thread could've taken over and deleted all zero count elements. So now you could find that binlog_xid_count_list.head() has non-zero count. > + my_free(b); > + b= binlog_xid_count_list.head(); > + /* > + Normally, we must not remove all elements in the list. > + Only if a RESET MASTER is in progress may we delete everything - RESET > + MASTER has LOCK_log held, and will create a new initial element before > + releasing the lock. > + */ > + DBUG_ASSERT(b || reset_master_pending); > + if (unlikely(!b) || likely(b->binlog_id == current) || b->xid_count > 0) > + break; > + } > + if (reset_master_pending) > + { > + mysql_cond_signal(&COND_xid_list); > + mysql_mutex_unlock(&LOCK_xid_list); > + DBUG_VOID_RETURN; > + } > + > + mysql_mutex_unlock(&LOCK_xid_list); > + write_binlog_checkpoint_event_already_locked(b->binlog_name, > + b->binlog_name_len); > + mysql_mutex_unlock(&LOCK_log); > DBUG_VOID_RETURN; > } > > @@ -7507,19 +7755,104 @@ > > fdle->flags&= ~LOG_EVENT_BINLOG_IN_USE_F; // abort on the first error > > - while ((ev= Log_event::read_log_event(log, 0, fdle, > - opt_master_verify_checksum)) > - && ev->is_valid()) > + /* > + Scan the binlog for XIDs that need to be committed if still in the > + prepared stage. > + > + Start with the latest binlog file, then continue with any other binlog > + files if the last found binlog checkpoint indicates it is needed. > + */ > + > + first_round= true; > + for (;;) > { > - if (ev->get_type_code() == XID_EVENT) > - { > - Xid_log_event *xev=(Xid_log_event *)ev; > - uchar *x= (uchar *) memdup_root(&mem_root, (uchar*) &xev->xid, > - sizeof(xev->xid)); > - if (!x || my_hash_insert(&xids, x)) > + while ((ev= Log_event::read_log_event(first_round ? first_log : &log, > + 0, fdle, opt_master_verify_checksum)) > + && ev->is_valid()) > + { > + switch (ev->get_type_code()) > + { > + case XID_EVENT: > + { > + Xid_log_event *xev=(Xid_log_event *)ev; > + uchar *x= (uchar *) memdup_root(&mem_root, (uchar*) &xev->xid, > + sizeof(xev->xid)); > + if (!x || my_hash_insert(&xids, x)) > + { > + delete ev; > + goto err2; > + } > + break; > + } > + case BINLOG_CHECKPOINT_EVENT: > + if (first_round) > + { > + Binlog_checkpoint_log_event *cev= (Binlog_checkpoint_log_event *)ev; > + if (cev->binlog_file_len >= FN_REFLEN) > + { > + sql_print_error("Incorrect binlog checkpoint event with too long " > + "file name found. Aborting."); This is a recovery. After a crash. You can be more tolerant here. In this particular case there is no need to abort, you can safely ignore incorrect checkpoints. This only means that the recovery will start from the previous checkpoint and it'll take longer. > + delete ev; > + goto err2; > + } > + binlog_checkpoint_len= cev->binlog_file_len; > + memcpy(binlog_checkpoint_name, cev->binlog_file_name, > + binlog_checkpoint_len); > + binlog_checkpoint_name[binlog_checkpoint_len]= '\0'; > + break; > + } > + default: > + /* Nothing. */ > + break; > + } > + delete ev; > + } > + > + /* > + If the last binlog checkpoint event points to an older log, we have to > + scan all logs from there also, to get all possible XIDs to recover. > + > + If there was no binlog checkpoint event at all, this means the log was > + written by an older version of MariaDB (or MySQL) - these always have an > + (implicit) binlog checkpoint event at the start of the last binlog file. > + */ > + if (first_round) > + { > + if (!binlog_checkpoint_len) > + break; > + first_round= false; > + if (find_log_pos(linfo, binlog_checkpoint_name, 1)) > + { > + sql_print_error("Binlog file '%s' not found in binlog index, needed " > + "for recovery. Aborting.", binlog_checkpoint_name); > goto err2; > - } > - delete ev; > + } > + } > + else > + { > + end_io_cache(&log); > + mysql_file_close(file, MYF(MY_WME)); > + file= -1; > + } > + > + if (0 == strcmp(linfo->log_file_name, last_log_name)) > + break; // No more files to do > + if ((file= open_binlog(&log, linfo->log_file_name, &errmsg)) < 0) > + { > + sql_print_error("%s", errmsg); > + goto err2; > + } > + /* > + We do not need to read the Format_description_log_event of other binlog > + files. It is not possible for a binlog checkpoint to span multiple > + binlog files written by different versions of the server. So we can use > + the first one read for reading from all binlog files. > + */ > + if (find_next_log(linfo, 1)) > + { > + sql_print_error("Error reading binlog files during recovery. Aborting."); > + goto err2; > + } > } > > if (ha_recover(&xids)) > === modified file 'sql/sql_repl.cc' > --- sql/sql_repl.cc 2012-04-27 08:20:38 +0000 > +++ sql/sql_repl.cc 2012-05-14 09:51:40 +0000 > @@ -624,6 +624,30 @@ > } > > /* > + Do not send binlog checkpoint events to a slave that does not understand it. > + */ > + if (unlikely(event_type == BINLOG_CHECKPOINT_EVENT) && > + mariadb_slave_capability < MARIA_SLAVE_CAPABILITY_BINLOG_CHECKPOINT) > + { > + if (mariadb_slave_capability >= MARIA_SLAVE_CAPABILITY_TOLERATE_HOLES) > + { > + /* This slave can tolerate events omitted from the binlog stream. */ > + return NULL; > + } > + else > + { > + /* > + The slave does not understand BINLOG_CHECKPOINT_EVENT. Send a dummy > + event instead, with same length so slave does not get confused about > + binlog positions. > + */ Hm. Above and below the code that you've added events are simply skipped, without checks and dummy events. Why do you bother to replace with dummies? > + if (Query_log_event::dummy_event(packet, ev_offset, current_checksum_alg)) > + return "Failed to replace binlog checkpoint event with dummy: " > + "too small event."; > + } > + } > + > + /* > Skip events with the @@skip_replication flag set, if slave requested > skipping of such events. > */ Regards, Sergei

2 1

[Maria-developers] Fwd: crash in slave replication with XA transaction
by Zardosht Kasheff 11 Jun '12

11 Jun '12

Hello all, We see this on Maria 5.2 and Maria 5.5 as well. Does the following fix work? -Zardosht ---------- Forwarded message ---------- From: Rich Prohaska <prohaska(a)tokutek.com> Date: Mon, Jun 4, 2012 at 1:23 PM Subject: crash in slave replication with XA transaction To: internals(a)lists.mysql.com Hello, We are running MySQL 5.5.21 with both InnoDB and TokuDB as XA storage engines. When one runs a transaction that inserts into an InnoDB table and a TokuDB table, the commit crashes the replication slave at log.cc line 6602 because cache_mngr == NULL. We found a pattern in various log functions in log.cc that calls binlog_setup_trx_data to initialize the txn state. This change fixes our immediate problem. $ diff log.cc.orig log.cc 6595a6596,6597 > if (thd_get_ha_data(thd, binlog_hton) == NULL) > thd->binlog_setup_trx_data(); Is this a correct fix? If so, are there other places that need a similar change? Thanks Rich Prohaska The transaction is: create table t1 (a int primary key) engine=innodb; create table t2 (a int primary key) engine=tokudb; set autocommit=0; insert into t1 values (1); insert into t2 values (2); commit; the slave crashes while handling the commit binlog entry. -- MySQL Internals Mailing List For list archives: http://lists.mysql.com/internals To unsubscribe: http://lists.mysql.com/internals

3 5

Re: [Maria-developers] [Commits] Rev 3426: LP1008334 : Speedup specific datetime queries that got slower with introduction of microseconds in file:///H:/bzr/5.5/
by Sergei Golubchik 08 Jun '12

08 Jun '12

Hi, Vladislav! On Jun 08, Vladislav Vaintroub wrote: > ------------------------------------------------------------ > revno: 3426 > revision-id: wlad(a)montyprogram.com-20120608000841-ieo4vumio11pc8p9 > parent: wlad(a)montyprogram.com-20120530182054-g7sll9u4gsitvgqe > fixes bug(s): https://launchpad.net/bugs/1008334 > committer: Vladislav Vaintroub <wlad(a)montyprogram.com> > branch nick: 5.5 > timestamp: Fri 2012-06-08 02:08:41 +0200 > message: > LP1008334 : Speedup specific datetime queries that got slower with introduction of microseconds > > - Item::get_seconds() now skips decimal arithmetic, if decimals is 0. This significantly speeds up from_unixtime() if no fractional part is passed. > - replace sprintfs used to format temporal values by hand-coded formatting Looks ok. Would be good to mention the ~25% speedup in the comment above fmt_number. Like "Gives 25% speedup when converting temporal values to strings, as compared to sprintf". So that one wouldn't need to dig up bzr history every time. > === modified file 'sql/item.cc' > --- a/sql/item.cc 2012-05-21 18:54:41 +0000 > +++ b/sql/item.cc 2012-06-08 00:08:41 +0000 > @@ -1265,7 +1265,7 @@ > > bool Item::get_seconds(ulonglong *sec, ulong *sec_part) > { > - if (result_type() == INT_RESULT) > + if (decimals == 0 || result_type() == INT_RESULT) I'd expect that checking for decimals==0 alone should be enough. Could you try to run the test suite with the DBUG_ASSERT(result_type() != INT_RESULT || decimals == 0); please? > { // optimize for an important special case > longlong val= val_int(); > bool neg= val < 0 && !unsigned_flag; Regards, Sergei

1 0

Re: [Maria-developers] [Commits] Rev 3429: MDEV-329: MariaDB 5.5 does not use fdatasync(). in http://bazaar.launchpad.net/~maria-captains/maria/5.5
by Kristian Nielsen 08 Jun '12

08 Jun '12

Hi wlad, Can I get you to review the following one-liner? (Just the Cmake part). The problem is that the code in 5.5 currently does not use fdatasync(), falling back to fsync(). The fdatasync() is detected correctly by cmake, but the HAVE_DECL_FDATASYNC symbol does not get defined so code does not use it. Is adding HAVE_DECL_FDATASYNC to config.h.cmake the correct fix? - Kristian. knielsen(a)knielsen-hq.org writes: > At http://bazaar.launchpad.net/~maria-captains/maria/5.5 > > ------------------------------------------------------------ > revno: 3429 > revision-id: knielsen(a)knielsen-hq.org-20120608091856-jmxb22ehrdp8xjdo > parent: timour(a)askmonty.org-20120606131948-0k4ih4get2fttge0 > committer: knielsen(a)knielsen-hq.org > branch nick: mariadb-5.5 > timestamp: Fri 2012-06-08 11:18:56 +0200 > message: > MDEV-329: MariaDB 5.5 does not use fdatasync(). > > The --debug-no-sync incorrectly defaulted to ON, disabling sync calls > by default which can loose data or cause corruption. Also, the code > used fsync() instead of the sometimes more efficient fdatasync(). > === modified file 'config.h.cmake' > --- a/config.h.cmake 2012-04-19 02:02:28 +0000 > +++ b/config.h.cmake 2012-06-08 09:18:56 +0000 > @@ -150,6 +150,7 @@ > #cmakedefine HAVE_FCNTL 1 > #cmakedefine HAVE_FCONVERT 1 > #cmakedefine HAVE_FDATASYNC 1 > +#cmakedefine HAVE_DECL_FDATASYNC 1 > #cmakedefine HAVE_FESETROUND 1 > #cmakedefine HAVE_FINITE 1 > #cmakedefine HAVE_FP_EXCEPT 1 > > === modified file 'sql/mysqld.cc' > --- a/sql/mysqld.cc 2012-05-21 18:54:41 +0000 > +++ b/sql/mysqld.cc 2012-06-08 09:18:56 +0000 > @@ -6161,7 +6161,7 @@ struct my_option my_long_options[]= > #endif > {"debug-no-sync", 0, > "Disables system sync calls. Only for running tests or debugging!", > - &my_disable_sync, &my_disable_sync, 0, GET_BOOL, NO_ARG, 1, 0, 0, 0, 0, 0}, > + &my_disable_sync, &my_disable_sync, 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0}, > #ifdef HAVE_REPLICATION > {"debug-sporadic-binlog-dump-fail", 0, > "Option used by mysql-test for debugging and testing of replication.", > > _______________________________________________ > commits mailing list > commits(a)mariadb.org > https://lists.askmonty.org/cgi-bin/mailman/listinfo/commits

2 2

[Maria-developers] shrink() in sql_string.h
by MARK CALLAGHAN 07 Jun '12

07 Jun '12

Why doesn't the shrink() method in sql_string.h check the value of alloced before calling my_realloc? my_realloc might free Ptr, but when alloced=0 that memory is not owned by the string. 2 bk@work | inline void shrink(uint32 arg_length) // Shrink buffer 2 bk@work | { 2 bk@work | if (arg_length < Alloced_length) 2 bk@work | { 2 bk@work | char *new_ptr; 2 bk@work | if (!(new_ptr=(char*) my_realloc(Ptr,arg_length,MYF(0)))) 2 bk@work | { 228 sasha@m | Alloced_length = 0; 2 bk@work | real_alloc(arg_length); 2 bk@work | } 2 bk@work | else 2 bk@work | { 2 bk@work | Ptr=new_ptr; 2 bk@work | Alloced_length=arg_length; 2 bk@work | } 2 bk@work | } 2 bk@work | } -- Mark Callaghan mdcallag(a)gmail.com

2 2

[Maria-developers] SHOW EXPLAIN: All concurrency problems should be gone, please test
by Sergei Petrunia 07 Jun '12

07 Jun '12

Hi Elena, I've pushed the fix for all known SHOW EXPLAIN problems. I think, another round of testing is needed. You can do it right away, or wait until I resolve the open "different query output" problems. BR Sergei -- Sergei Petrunia, Software Developer Monty Program AB, http://askmonty.org Blog: http://s.petrunia.net/blog

1 0

Re: [Maria-developers] Please review: [Commits] Rev 3535: Fix for bug lp:1006231 in file:///home/tsk/mprog/src/5.3/
by Sergei Petrunia 01 Jun '12

01 Jun '12

Hi Timour, As discussed on the phone call: - Let's add a separate MDEV item to add "the assert". - Ok to push tis patch. On Wed, May 30, 2012 at 07:12:33PM +0300, Timour Katchaounov wrote: > Sergey, > > Could you please review yet another bug fix for expensive subqueries > executed during optimiziation. > > Timour > > ------------------------------------------------------------ > revno: 3535 > revision-id: timour(a)askmonty.org-20120530161018-kgsiqesmnohtnbc6 > parent: holyfoot(a)askmonty.org-20120529045925-h35akgdit83ql5yq > fixes bug(s): https://launchpad.net/bugs/1006231 > committer: timour(a)askmonty.org > branch nick: 5.3 > timestamp: Wed 2012-05-30 19:10:18 +0300 > message: > Fix for bug lp:1006231 > > Analysis: > > When a subquery that needs a temp table is executed during > the prepare or optimize phase of the outer query, at the end > of the subquery execution all the JOIN_TABs of the subquery > are replaced by a new JOIN_TAB that selects from the temp table. > However that temp table has no corresponding TABLE_LIST. > Once EXPLAIN execution reaches its last phase, it tries to print > the names of the subquery tables through its TABLE_LISTs, but in > the case of this bug there is no such TABLE_LIST (it is NULL), > hence a crash. > > Solution: > The fix is to block subquery evaluation inside > Item_func_like::fix_fields and Item_func_like::select_optimize() > using the Item::is_expensive() test. > === modified file 'mysql-test/r/subselect_innodb.result' > --- a/mysql-test/r/subselect_innodb.result 2012-05-20 12:57:29 +0000 > +++ b/mysql-test/r/subselect_innodb.result 2012-05-30 16:10:18 +0000 > @@ -365,4 +365,19 @@ GROUP BY 1 > MAX( f1 ) > NULL > drop table t1, t2, t3; > +# > +# LP BUG#1006231 crash in select_describe > +# > +create table t1(a1 int) ENGINE=InnoDB; > +insert into t1 values (1); > +explain > +select 1 from t1 where 1 like (select 1 from t1 where 1 <=> (select 1 from t1 group by a1)); > +id select_type table type possible_keys key key_len ref rows Extra > +1 PRIMARY t1 ALL NULL NULL NULL NULL 1 > +2 SUBQUERY t1 ALL NULL NULL NULL NULL 1 > +3 SUBQUERY t1 ALL NULL NULL NULL NULL 1 Using temporary; Using filesort > +select 1 from t1 where 1 like (select 1 from t1 where 1 <=> (select 1 from t1 group by a1)); > +1 > +1 > +drop table t1; > set optimizer_switch=@subselect_innodb_tmp; > > === modified file 'mysql-test/t/subselect_innodb.test' > --- a/mysql-test/t/subselect_innodb.test 2012-05-20 12:57:29 +0000 > +++ b/mysql-test/t/subselect_innodb.test 2012-05-30 16:10:18 +0000 > @@ -356,4 +356,16 @@ WHERE f2 >= ( > > drop table t1, t2, t3; > > +--echo # > +--echo # LP BUG#1006231 crash in select_describe > +--echo # > + > +create table t1(a1 int) ENGINE=InnoDB; > +insert into t1 values (1); > +explain > +select 1 from t1 where 1 like (select 1 from t1 where 1 <=> (select 1 from t1 group by a1)); > +select 1 from t1 where 1 like (select 1 from t1 where 1 <=> (select 1 from t1 group by a1)); > +drop table t1; > + > + > set optimizer_switch=@subselect_innodb_tmp; > > === modified file 'sql/item_cmpfunc.cc' > --- a/sql/item_cmpfunc.cc 2012-05-20 12:57:29 +0000 > +++ b/sql/item_cmpfunc.cc 2012-05-30 16:10:18 +0000 > @@ -4656,7 +4656,7 @@ longlong Item_func_like::val_int() > > Item_func::optimize_type Item_func_like::select_optimize() const > { > - if (args[1]->const_item()) > + if (args[1]->const_item() && !args[1]->is_expensive()) > { > String* res2= args[1]->val_str((String *)&cmp.value2); > const char *ptr2; > @@ -4743,7 +4743,8 @@ bool Item_func_like::fix_fields(THD *thd > We could also do boyer-more for non-const items, but as we would have to > recompute the tables for each row it's not worth it. > */ > - if (args[1]->const_item() && !use_strnxfrm(collation.collation)) > + if (args[1]->const_item() && !use_strnxfrm(collation.collation) && > + !args[1]->is_expensive()) > { > String* res2 = args[1]->val_str(&cmp.value2); > if (!res2) > > _______________________________________________ > commits mailing list > commits(a)mariadb.org > https://lists.askmonty.org/cgi-bin/mailman/listinfo/commits -- BR Sergei -- Sergei Petrunia, Software Developer Monty Program AB, http://askmonty.org Blog: http://s.petrunia.net/blog

1 0

[Maria-developers] WL#252 New (by DonQuichote): IF (NOT) EXIST clauses for ALTER TABLE
by worklog-noreply＠askmonty.org 01 Jun '12

01 Jun '12

----------------------------------------------------------------------- WORKLOG TASK -=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=- TASK...........: IF (NOT) EXIST clauses for ALTER TABLE CREATION DATE..: Fri, 01 Jun 2012, 09:35 SUPERVISOR.....: IMPLEMENTOR....: COPIES TO......: CATEGORY.......: Server-RawIdeaBin TASK ID........: 252 (https://askmonty.org/worklog/?tid=252) VERSION........: WorkLog-4.0 STATUS.........: Un-Assigned PRIORITY.......: 60 WORKED HOURS...: 0 ESTIMATE.......: 0 (hours remain) ORIG. ESTIMATE.: 0 PROGRESS NOTES: DESCRIPTION: MySQL / MariaDB SQL is great as a functional language: you tell what you want and not how to do it. This includes suppressing of errors when the situation you want already exists. So there is a CREATE TABLE IF NOT EXISTS statement, for example (you say that you want the table to exist, not that it has to be built right now). It would be nice if altering a table could be done the same way: ALTER TABLE SomeTable ADD COLUMN IF NOT EXISTS SomeColumn ... ALTER TABLE SomeTable DROP COLUMN IF EXISTS SomeColumn ... ALTER TABLE SomeTable DROP FOREIGN KEY IF EXISTS SomeConstraint ... This would make definition scripts more legible and more friendly to existing databases. It would facilitate what I call "repeatable scripts", that can both create a new database and update an existing one to the latest structure. Mind you, this is already possible using temporary stored procedures (as shown in http://www.howtoforge.com/node/4833) but it would make definition scripts more maintainable and the SQL language more consistent. ESTIMATED WORK TIME ESTIMATED COMPLETION DATE ----------------------------------------------------------------------- WorkLog (v4.0.0)

1 0

Re: [Maria-developers] MariaDB 5.5.24 release prep
by Sergei Golubchik 31 May '12

31 May '12

Hi, Jocelyn! On May 31, Jocelyn Fournier wrote: > > Just to be sure : it means also the debian package will be properly > linked against libaio ? (it wasn't the case in 5.5.23 release). Unfortunately not. I mean that debian packages will be linked against libaio only in 5.5.25, but not in 5.5.24. Currently (in 5.5.24) only RPM packages are linked against libaio. Debian packages and bintar package are not. Regards, Sergei

1 0

Re: [Maria-developers] MariaDB 5.5.24 release prep
by Sergei Golubchik 31 May '12

31 May '12

Hi, md! On May 31, md wrote: > Sergei: > > I guess you can get 5.5.24 to build ok. I had a bunch of trouble with > 5.5.23 and a compiler error that I could not seem to make go away. > > [ 47%] Building CXX object > storage/oqgraph/CMakeFiles/oqgraph.dir/graphcore.cc.o > > In file included from > /usr/include/boost/smart_ptr/detail/sp_counted_base_gcc_x86.hpp:27:0, This is a known issue. An the OQGraph engine that we include is incompatible with the new Boost. It is a third-party engine, not ours. OQGraph developer knows about this problem and he's working on it. When he'll fix OQGraph, we will update it in our sources. Meanwhile we build without. Try to run cmake -DWITHOUT_OQGRAPH=1 in your build tree, and run make again. In 5.5.25 I'll make this the default behavior, until OQGraph is fixed. Regards, Sergei

1 0