May 2012 - 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

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

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 wondering if the build issue with binaries and packages which don't > use native AIO is fixed as well ? > > (See https://bugs.launchpad.net/maria/+bug/988204 ) Doesn't seem so :( For some reason it was submitted in the wrong bugtracker, and I missed it when preparing a release. Sorry for this, it'll be in 5.5.25. This time - for sure. Note that 5.5 RPM packages are not affected by this bug - they are all properly linked with AIO. Regards, Sergei

1 0

[Maria-developers] MariaDB 5.5.24 release prep
by Daniel Bartholomew 31 May '12

31 May '12

All, I'm uploading the files for MariaDB 5.5.24 and getting other bits and pieces ready. Preliminary versions of the Release Notes and Changelog are available here: http://kb.askmonty.org/en/mariadb-5524-release-notes/ http://kb.askmonty.org/en/mariadb-5524-changelog/ The big news in this release is the new RPM packages and the YUM repositories. I'm still working on getting all the various bits set up, but it's all coming together and with any luck, I should be able to flip the switch and announce the release tomorrow morning (U.S. Eastern Time). In the mean time, if there is anything which should be mentioned in the Release Notes, please let me know ASAP or jump in and edit the Release Notes directly. Thanks! -- Daniel Bartholomew MariaDB - http://mariadb.org Monty Program - http://montyprogram.com AskMonty Knowledgebase - http://kb.askmonty.org

1 0

Re: [Maria-developers] Support of the extended syntax for ANALYZE
by Sergei Golubchik 26 May '12

26 May '12

Hi, Igor! On May 10, Igor Babaev wrote: > Serg, > > Here's the patch we talked about on IRC today. ... > +ANALYZE TABLE t1(COLUMN(), INDEX()); > +ANALYZE TABLE t1(COLUMN(c,e,b), INDEX(idx2,idx4)); > +ANALYZE TABLE t1(COLUMN(*), INDEX(*)); I see what you want to do. I think it'll be more SQL-like, if it'll be more verbose, for example ANALYZE TABLE t1 FOR COLUMNS (c,e,d) INDEXES (idx2, idx4); I would prefer to drop parentheses too, but then the grammar will become ambiguous :( And instead of double (*) it could simply be ANALYZE TABLE t1 FULL; or ALL; it'd be similar to CHECK TABLE t1 EXTENDED; REPAIR TABLE t1 QUICK; etc Alternatively, it could have an explicit "PERSISTENT" keyword: ANALYZE TABLE t1 PERSISTENT; -- meaning all columns and indexes ANALYZE TABLE t1 PERSISTENT FOR COLUMNS (c,e,d) INDEXES (idx2, idx4); That's probably the best one. Reasonably SQL-like. And the most common use case (analyze all) is short, it's clearly the main, default behavior. And the clause to specify columns and indexes extends the default syntax. Regards, Sergei

4 6

[Maria-developers] SHOW EXPLAIN and LOCK_thd_data
by Sergei Petrunia 26 May '12

26 May '12

Hi Sergei, I've got a problem with SHOW EXPLAIN and LOCK_thd_data. SHOW EXPLAIN was modeled after the KILL command: it's actions are: lock LOCK_thread_count; find the thread $target_thr we need explain for; lock $target_thr->LOCK_thread_count; unlock LOCK_thread_count; send SHOW EXPLAIN request to $target_thr. wait until request is executed (or discarded) unlock $target_thr->LOCK_thread_count; This scheme works, as long as the target thread doesn't select from information_schema tables. With queries over I_S tables, it breaks, because I_S table may try to acquire current_thd->LOCK_thread_count during execution. Below I provide a stacktrace of one such case, line numbers are from lp:~maria-captains/maria/5.5-show-explain. My first thought was to change LOCK_thread_count to be a read/write mutex, but I wanted to hear your opinion, too. (gdb) wher #0 inline_mysql_mutex_lock (that=0xa1111d4, src_file=0x894b75c "sql/sql_class.h", src_line=3020) at include/mysql/psi/mysql_thread.h:608 #1 0x081dda85 in THD::set_open_tables (this=0xa1104b0, open_tables_arg=0xa12de10) at sql/sql_class.h:3020 #2 0x081d9024 in open_table (thd=0xa1104b0, table_list=0xa1289b0, mem_root=0x99134000, ot_ctx=0x99134020) at sql/sql_base.cc:3180 #3 0x081d9aee in open_and_process_table (thd=0xa1104b0, lex=0x9913417c, tables=0xa1289b0, counter=0x991340bc, flags=1026, prelocking_strategy=0x991340c0, has_prelocking_list=false, ot_ctx=0x99134020, new_frm_mem=0x99134000) at sql/sql_base.cc:4509 #4 0x081da269 in open_tables (thd=0xa1104b0, start=0x991340d4, counter=0x991340bc, flags=1026, prelocking_strategy=0x991340c0) at sql/sql_base.cc:4958 #5 0x081da6de in open_normal_and_derived_tables (thd=0xa1104b0, tables=0xa1289b0, flags=1026, dt_phases=34) at sql/sql_base.cc:5617 #6 0x082a3e23 in fill_schema_table_by_open (thd=0xa1104b0, is_show_fields_or_keys=true, table=0xa1263c0, schema_table=0x8c262b0, orig_db_name=0x99134e04, orig_table_name=0x99134e1c, open_tables_state_backup=0x99134d94, can_deadlock=false) at sql/sql_show.cc:3659 #7 0x082b8638 in get_all_tables (thd=0xa1104b0, tables=0xa11d560, cond=0x0) at sql/sql_show.cc:4214 #8 0x0829f943 in do_fill_table (thd=0xa1104b0, table_list=0xa11d560, join_table=0xa128548) at sql/sql_show.cc:7503 #9 0x0829fce2 in get_schema_tables_result (join=0xa1279a8, executed_place=PROCESSED_BY_JOIN_EXEC) at sql/sql_show.cc:7610 #10 0x0829468d in JOIN::exec_inner (this=0xa1279a8) at sql/sql_select.cc:2354 #11 0x082931c8 in JOIN::exec (this=0xa1279a8) at sql/sql_select.cc:2201 BR Sergei -- Sergei Petrunia, Software Developer Monty Program AB, http://askmonty.org Blog: http://s.petrunia.net/blog

2 1

Re: [Maria-developers] Please review: [Commits] Rev 3405: Test case for bug lp:1001117, MySQL BUG#12330344 in file:///home/tsk/mprog/src/5.5-lpb944706/
by Sergei Petrunia 24 May '12

24 May '12

Hi Timour, On Thu, May 24, 2012 at 02:12:12PM +0300, Timour Katchaounov wrote: > Sergey, > > Could you please review the following patch. So far it is only in my > tree for bug lp:944706 (because this tree already fixes the problem as > explained below). > Ok to push. BR Sergei -- Sergei Petrunia, Software Developer Monty Program AB, http://askmonty.org Blog: http://s.petrunia.net/blog

1 0

[Maria-developers] MDEV-83: pushdown of expensive predicates
by Sergei Petrunia 21 May '12

21 May '12

Hi Timour, Some thoughts about MDEV-83. The jira entry says: > The main difference in these two plans is that with the first execution plan > the dependent subquery: ... is evaluated before the table part is accessed > while many rows where (p_name like 'forest%') is not true are filtered out > and evaluation of the dependent subquery is not needed for them. The way I read this, the only way one could figure out that the subquery should be evaluated at later phase (after table part) is to figure out that selectivity of table `part`, together with its condition of p_name like 'forest%' is less than one. That way, subquery is evaluated fewer times, and query execution will be cheaper. I don't see any index that covers p_name column. This means that current optimizer has no clue about selectivity of conditions over p_name column, and hence is unable to make the correct decision. If I add an index on p_name, then I get a different query plan (I didn't check if is slower or faster than the original). I think, one of the first things this MDEV needs is to figure out how exactly we will get selectivities for non-indexed columns. If we get them, and start to take them into account in join optimizer(*), the example provided in this MDEV/ bug may just go away :-). The general problem will remain, though. (*) { Currently, the optimizer has "quick_condition_rows", which may cause join fanout to be less than 1 (check out examples with EXPLAIN EXTENDED and filtered != 100% in the testsuite). The problem is that quick_condition_rows is not used consistently for all ways to access the table, for example it is not taken into account when considering ref access. I do not know whether Igor's work in best_access_path() includes making it consistently make use of quick_condition_rows estimates. } == Subquery predicate attachment considerations == Some thoughts about the problem. There are three factors we may want/need to take into account when attaching subquery predicate to some join_tab: 1. Fanout of join tabs 2. Cost of the subquery predicate evaluation 3. Selectivity of the subquery predicate. The example used in this MDEV item can be resolved by taking into account #1 and #2. For the first step, we only need to know - accurate join tab fanout (#1), - that subquery predicate evaluation has some cost ( #2 != 0) these two allow us to set/resolve a task of attaching the subquery predicate to the join_tab where total cost of its evaluations is minimized. The exact value of subquery evaluation cost is irrelevant. It will only become relevant when/if we start to make a choice between evaluating subquery predicate, or preforming join with the next join_tab. In order for that choice to be meaningful, we will need to have an idea about subquery predicate's selectivity. That way, we will be able to make a choice between 1. evaluate subquery, then make join with next join tab cost(subquery_pred) + selectivity(subquery_pred) * cost(join_tab) and 2. make join with next join_tab, then evaluate the subquery: cost(join_tab) + selectivity(join_tab) * cost(join_tab) BR Sergei -- Sergei Petrunia, Software Developer Monty Program AB, http://askmonty.org Blog: http://s.petrunia.net/blog

1 0

Re: [Maria-developers] MDEV-136 Non-blocking "set read_only"
by Sergei Golubchik 20 May '12

20 May '12

Hi, Holyfoot! Looks good to me! See a couple of comments below. Please push after fixing all that. On May 17, holyfoot(a)askmonty.org wrote: > ------------------------------------------------------------ > revno: 3518 > revision-id: holyfoot(a)askmonty.org-20120517131405-y12erfkgta2ym2pn > parent: sanja(a)montyprogram.com-20120507181437-1zl1v1uxje7v6994 > committer: Alexey Botchkov <holyfoot(a)askmonty.org> > branch nick: mdev-136 > timestamp: Thu 2012-05-17 18:14:05 +0500 > message: > MDEV-136 Non-blocking "set read_only". > Handle the 'set read_only=1' in lighter way, than the FLUSH TABLES READ LOCK; > For the transactional engines we don't wait for operations on that tables to finish. > > === modified file 'mysql-test/t/read_only_innodb.test' > --- a/mysql-test/t/read_only_innodb.test 2008-04-08 05:20:58 +0000 > +++ b/mysql-test/t/read_only_innodb.test 2012-05-17 13:14:05 +0000 > @@ -75,7 +75,28 @@ > SELECT * FROM t1; > COMMIT; > > -connection default; > +# > +# Tests that LOCK TABLE doesn't block the SET READ_ONLY=1 for the InnoDB tables > +# > +connection default; > +UNLOCK TABLES; > + > +--echo connection con1; > +connection con1; > +lock table t1 write; See whether you can directly test that the table was not reopened. Perhaps by examining the corresponding SHOW STATUS variables you could do that. > + > +--echo connection default; > +connection default; > +set global read_only=1; > + > +--echo connection con1; > +connection con1; > +unlock tables; > + > +--echo connection default; > +connection default; > +SET GLOBAL read_only=0; > + > UNLOCK TABLES; > DROP TABLE t1; > DROP USER test@localhost; > === modified file 'sql/sql_base.cc' > --- a/sql/sql_base.cc 2012-04-19 06:16:30 +0000 > +++ b/sql/sql_base.cc 2012-05-17 13:14:05 +0000 > @@ -933,7 +938,14 @@ > for (uint idx=0 ; idx < open_cache.records ; idx++) > { > TABLE *table=(TABLE*) hash_element(&open_cache,idx); > - if (table->in_use) > + /* We don't increment the refresh_version when set_readonly_mode, */ > + /* but we still need non-transactional tables to be reopened. */ > + /* So we set their versions as 'refresh_version - 1', which marks */ > + /* them for the 'needs_reopen_or_table_lock()' */ please, use the standard mysql comment style as you can see everywhere in the sources > + if (set_readonly_mode && !table->file->has_transactions()) > + table->s->version= refresh_version-1; better set it to 0, that's what tdc_remove_table() does. And we won't need to think about possible race conditions. > + if (table->in_use && > + (!set_readonly_mode || !table->file->has_transactions())) > table->in_use->some_tables_deleted= 1; > } > } Regards, Sergei

1 0