From: Luis Soares Date: May 24 2010 4:43pm Subject: bzr commit into mysql-5.1-bugteam branch (luis.soares:3395) Bug#53657 List-Archive: http://lists.mysql.com/commits/109081 X-Bug: 53657 Message-Id: <0L2X00H47NSQ9H80@fe-emea-10.sun.com> MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="Boundary_(ID_3+0Z+HBajPGo7TSXXOWOHw)" --Boundary_(ID_3+0Z+HBajPGo7TSXXOWOHw) MIME-version: 1.0 Content-type: text/plain; CHARSET=US-ASCII Content-transfer-encoding: 7BIT Content-disposition: inline #At file:///home/lsoares/Workspace/bzr/work/bugfixing/53657/mysql-5.1-bugteam-latest/ based on revid:mattias.jonsson@stripped 3395 Luis Soares 2010-05-24 BUG#53657: Slave crashed with error 22 when trying to lock mutex at mf_iocache.c, line 1722 The slave crashed while two threads: IO thread and user thread raced for the same mutex (the append_buffer_lock protecting the relay log's IO_CACHE). The IO thread was trying to flush the cache, and for that was grabbing the append_buffer_lock. However, the other thread was closing and reopening the relay log when the IO thread tried to lock. Closing and reopening the log includes destroying and reinitialising the IO_CACHE mutex. Therefore, the IO thread tried to lock a destroyed mutex. We fix this by backporting patch for BUG#50364 which fixed this bug in mysql server 5.5+. The patch deploys missing synchronization when flush_master_info is called and the relay log is flushed by the IO thread. In detail the patch backports revision (from mysql-trunk): - luis.soares@stripped This patch already includes the post-push fix also in BUG#50364: - luis.soares@stripped modified: sql/repl_failsafe.cc sql/rpl_mi.cc sql/rpl_mi.h sql/rpl_rli.cc sql/slave.cc sql/sql_repl.cc === modified file 'sql/repl_failsafe.cc' --- a/sql/repl_failsafe.cc 2010-01-22 10:58:21 +0000 +++ b/sql/repl_failsafe.cc 2010-05-24 16:43:27 +0000 @@ -976,7 +976,7 @@ bool load_master_data(THD* thd) host was specified; there could have been a problem when replication started, which led to relay log's IO_CACHE to not be inited. */ - if (flush_master_info(active_mi, 0)) + if (flush_master_info(active_mi, FALSE, FALSE)) sql_print_error("Failed to flush master info file"); } mysql_free_result(master_status_res); === modified file 'sql/rpl_mi.cc' --- a/sql/rpl_mi.cc 2007-12-14 13:21:37 +0000 +++ b/sql/rpl_mi.cc 2010-05-24 16:43:27 +0000 @@ -312,7 +312,7 @@ file '%s')", fname); mi->inited = 1; // now change cache READ -> WRITE - must do this before flush_master_info reinit_io_cache(&mi->file, WRITE_CACHE, 0L, 0, 1); - if ((error=test(flush_master_info(mi, 1)))) + if ((error=test(flush_master_info(mi, TRUE, TRUE)))) sql_print_error("Failed to flush master info file"); pthread_mutex_unlock(&mi->data_lock); DBUG_RETURN(error); @@ -338,10 +338,13 @@ err: 1 - flush master info failed 0 - all ok */ -int flush_master_info(Master_info* mi, bool flush_relay_log_cache) +int flush_master_info(Master_info* mi, + bool flush_relay_log_cache, + bool need_lock_relay_log) { IO_CACHE* file = &mi->file; char lbuf[22]; + int err= 0; DBUG_ENTER("flush_master_info"); DBUG_PRINT("enter",("master_pos: %ld", (long) mi->master_log_pos)); @@ -358,9 +361,23 @@ int flush_master_info(Master_info* mi, b When we come to this place in code, relay log may or not be initialized; the caller is responsible for setting 'flush_relay_log_cache' accordingly. */ - if (flush_relay_log_cache && - flush_io_cache(mi->rli.relay_log.get_log_file())) - DBUG_RETURN(2); + if (flush_relay_log_cache) + { + pthread_mutex_t *log_lock= mi->rli.relay_log.get_log_lock(); + IO_CACHE *log_file= mi->rli.relay_log.get_log_file(); + + if (need_lock_relay_log) + pthread_mutex_lock(log_lock); + + safe_mutex_assert_owner(log_lock); + err= flush_io_cache(log_file); + + if (need_lock_relay_log) + pthread_mutex_unlock(log_lock); + + if (err) + DBUG_RETURN(2); + } /* We flushed the relay log BEFORE the master.info file, because if we crash === modified file 'sql/rpl_mi.h' --- a/sql/rpl_mi.h 2007-08-16 06:52:50 +0000 +++ b/sql/rpl_mi.h 2010-05-24 16:43:27 +0000 @@ -108,7 +108,8 @@ int init_master_info(Master_info* mi, co bool abort_if_no_master_info_file, int thread_mask); void end_master_info(Master_info* mi); -int flush_master_info(Master_info* mi, bool flush_relay_log_cache); - +int flush_master_info(Master_info* mi, + bool flush_relay_log_cache, + bool need_lock_relay_log); #endif /* HAVE_REPLICATION */ #endif /* RPL_MI_H */ === modified file 'sql/rpl_rli.cc' --- a/sql/rpl_rli.cc 2009-12-14 16:50:22 +0000 +++ b/sql/rpl_rli.cc 2010-05-24 16:43:27 +0000 @@ -120,7 +120,7 @@ int init_relay_log_info(Relay_log_info* /* The relay log will now be opened, as a SEQ_READ_APPEND IO_CACHE. Note that the I/O thread flushes it to disk after writing every - event, in flush_master_info(mi, 1). + event, in flush_master_info(mi, 1, ?). */ /* === modified file 'sql/slave.cc' --- a/sql/slave.cc 2010-05-04 09:41:28 +0000 +++ b/sql/slave.cc 2010-05-24 16:43:27 +0000 @@ -1480,7 +1480,7 @@ static void write_ignored_events_info_to " to the relay log, SHOW SLAVE STATUS may be" " inaccurate"); rli->relay_log.harvest_bytes_written(&rli->log_space_total); - if (flush_master_info(mi, 1)) + if (flush_master_info(mi, TRUE, TRUE)) sql_print_error("Failed to flush master info file"); delete ev; } @@ -2731,7 +2731,7 @@ Stopping slave I/O thread due to out-of- "could not queue event from master"); goto err; } - if (flush_master_info(mi, 1)) + if (flush_master_info(mi, TRUE, TRUE)) { sql_print_error("Failed to flush master info file"); goto err; === modified file 'sql/sql_repl.cc' --- a/sql/sql_repl.cc 2010-05-04 09:17:20 +0000 +++ b/sql/sql_repl.cc 2010-05-24 16:43:27 +0000 @@ -1282,7 +1282,7 @@ bool change_master(THD* thd, Master_info Relay log's IO_CACHE may not be inited, if rli->inited==0 (server was never a slave before). */ - if (flush_master_info(mi, 0)) + if (flush_master_info(mi, FALSE, FALSE)) { my_error(ER_RELAY_LOG_INIT, MYF(0), "Failed to flush master info file"); unlock_slave_threads(mi); --Boundary_(ID_3+0Z+HBajPGo7TSXXOWOHw) MIME-version: 1.0 Content-type: text/bzr-bundle; CHARSET=US-ASCII; name="bzr/luis.soares@stripped" Content-transfer-encoding: 7BIT Content-disposition: inline; filename="bzr/luis.soares@stripped" # Bazaar merge directive format 2 (Bazaar 0.90) # revision_id: luis.soares@stripped # target_branch: file:///home/lsoares/Workspace/bzr/work/bugfixing\ # /53657/mysql-5.1-bugteam-latest/ # testament_sha1: fd2160e467c9dd94ba640599869d1b7bce67b5fc # timestamp: 2010-05-24 17:43:37 +0100 # source_branch: file:///home/lsoares/Workspace/bzr/clones/mysql-\ # trunk/ # base_revision_id: mattias.jonsson@stripped\ # 4jo3kb82hd4jhr39 # # Begin bundle IyBCYXphYXIgcmV2aXNpb24gYnVuZGxlIHY0CiMKQlpoOTFBWSZTWXXDE18ABX7/gFSQEABY//// /+eegL////pgC0+eQBQAAATlMBoKAKAFKAISnqGh6QAGmnpAABoYTI00NGgNBoJJTSZqnqafqgaA DTQyMgGjRskYmgAYQ4yZNGIaaGAmhiaNMmIGRhNGmmEGTCRJMSFP1T0T9Q1H5KeSMmmmmgaGgNAB oNDQ4yZNGIaaGAmhiaNMmIGRhNGmmEGTCSIEBNMgACNNATU0RMmmhhqfqgHpN6UMgIicAJTeo1Ez xEz25SBhRIWGMIFf6k3+QK92vyzBNrDCRGAw399gOamjT1IbcnR5wuIU9bg/RhI+zIP0qMSY5ZZA +OU7p1wOUP+YUUvv+/jhnpUa0g6/QHEIsQLnS07EGN2vhFzivE2222xtA3byfgFSeW6Nt4OG2aHD 3bdzCJ6a2VxnQlNmZ0c+vbKltdMQWQ6OxwYZt+arHdAOmCJxg8RQX/vbdHkuZWdJ1xYiQ/7hdujI TM3nwlIb9Ck6zNbHxUbM2acowi6vkf4F/7TAtupdh9PEWJLXAVUDO1dbjEknozgqZUxtzwUKrbI1 Ppf7JmNEpMynZfAyaHj1gazgcevJr51/GpvJD9hVZheNvbHrdzSKMkL+a16Kc/toUf3sFbKczhNE V8BW0XJ4R9gZv4tWWzekH42lplqKhtNg4yZQw2Pn+hx+JCN5T9fRArzjm8hdU0MC4umwBm63SNNh vtvqwq+QPRjqJilpYefPgUf/KOrVofca7mdOMOD6kC4nl0MsKLzBhkg6C+9c7Raxemb6860hcmSZ 484saTSOSSbQhoKssHIaEQQNMwIVWGJ0EwKKRwIjkVdZxK0IiwrZOSgt0IkxgJq+v8OlJfP43X1g r3tgNF2o+H4wrsBJxix3LBasxVnMd+m+sy0EYlyaAPSruQxpStiI2GTqOvPjT5v1SjleW/0hILMb AIkjUyMytDroqJWGgzBXjZfUsyAbQRythDcWbYaTdfr12bDOWam2CsK67zIY++wWRYbzfEFceDlU uGk2j3VP8Nq0g7IA0qcKbqijV0nB6Gmkj7kzIYyWEnAO3sc76SoZGYxG5ZhBUVYjPAdbsN5Q4yQV nMuwG4GwiXTNZ313sbVWAeJoFE78zUs0SoxhpwgykOMYAUTp4TQDl5VpZa9TmYsWQ1DwzGsvzzvN 2FBwwKbdk6qjLMaMkyxJErhWjFhgZGYtJl5uKhhadq+6cXkAXHU4Flg1+RDXAwyJgaqRhoAGDONH GsA1x0jErGNJS4q3FJ66caElTycKKD4thbek0S8tGc0yORDAo51FkVrav1Llc2OYbPzkU2UMv5ki uVWAXaCaQVVVFZuEw53y1m+KHT1TN+RIzyLoUMA3BiXG6oNpkYczuQI+J9DQX23Y2tdhkQlIHyFO rOMWUgXj1AFg71M9FceldqVugYcGLBisbpZYU3AconnPOQHGHGNhEN44rCdumj4AGWBi8ah5FIkT aKJgNWYFfiZXKs2kngzbL56bgKthUW4DVleRoO24+T2NhoPQwMWNx38xzDbXk2426IwltjDhMhGh qUDNNdfCtWz2mJEibjBcY8zMZjEt5Y24zJ3FQ5jrAIRzOmYe+wuFeVXDU5E8xeTne7mETSROmAxh EwImJgZi+8sGz5Vnb5jz06JxcGqfNnLYZ2hFpy0quKVlJAOcoYFMiB2vMibXhSv7xfjm1SIGDWsW 3JDBOnZ+Iu/oM2iuTwSMCShAfVfcNmrG002DPOH47cy+VSxfRjyjNFERLPySA4ILQcL3YmCE4/+A hNlFkDOA02KbM8XSEjvRYsFYnvK2mW9YFsirpHs5ZIJUytQ8oelBaWoK5ROas4gmpreaiwFMVLRG JVzs7iMplspF7mHEpIXTvJS4USljY2iU62HXRUUFrUS1RhTjyBtlELhpRogg392snjyTXMuJhHUK u2QmGOe3WkvEEfyVwUKxz53oPuN+ni9gXPzYHRzYF8OYDf6nQ7djZDr2IG0iLwr814ESJdZwOlxK nWiutvLSBDxMx5/1PH+weXr0PnZaZGGokJFiPzYRpNB6lRFz4OHubCo/llhvOpcQ0Bn98scklc5g ev9IbO5xXs03kJ52wYRFkOWyLRCyY1xPoAdacQDzeDNWyYGTjsOQ3chRWmqMzkdoEDmOeR0meq05 gKy0B95VJCgWhentOhNSOuvTViQtnXpSwwzmGSLI2jZaW+YC6ZdtgSo4G1xvu1TIi+s+XQkYmzcc goWZc5WcOTj1nI7FxmLyRn+BaRZR8tCTzFFBlG01CNTFV+o0sQsnE1e28icgwDQd9JqIduIS3Nh7 i0XAE3UbaNl/45IFCi8A2xSZMI3MLGHnO6EeN4LgTofj5fxZ4XtdYMkG3pazRM2A9v5VCJoRKlSD aC2H0OBA9dy2G0UziZ/I8Qu41aFDBKGZ0uoaBf4VTdE8RLFtDVwt44DiCitDHxee56FkeBrlWzLF 3AZLvzHSNTsgh8ENR2M4B8yNovI06c3qefEVu1eVbjQtUNB8EkKDCU+qYP3MkzA0RbpKQB6Kc+x7 ESJHDduxPsppF+B2AIC7iPBmGQw51OOI4A5DmylM2Rr5eSF5DxKuXv/d/6jQO6VDro2dhYMknW0u LAfW7iNEMUjn+DFBumoibMbaz09vGFRcW3Mgx7tYM6QYdhHHtY9epaShK0T+2su5rfd69CK9F3L7 M5ySwZHs37fkyNZnJI8FWL0+0+xs4oP1+Tv7XHyZsgy0slxbgm6+ga0Goxh+Gx1UgqTK4q/NlIFu LxIs8Dqh777A69yMZmJqaIaGTcCOHoiFHzxvy5089hkN0/xSYXv8dfdJai07ngIV7j99CCa42rgV JPWYLUVMnHF2H8OpgK4zQFbalEXMqW+0Hk2fLrbnPz6OMQi3RAmzjCkwdywTmjGMhxMgrGJ6RqfH vIBeobqisjS88oYi/YbRRPwopqtIZgGWS4/gzus8ICInp0Ww6Cj60SB+4B9M/AghGCIeaQpiKJvQ 0yvWlD5aB9Q2hNFA8WVpWoq8efDNp+n27OTKvq7NTZpBHM8C7yYTAMDkksxRcBMY6BWoG0G8pZ0O lor4ufl+TT8cT93Y3i/YeWxJbTOLI+AD+Euu7Y2dh1tbAwdclElBCp8QQeN5xIVJHSqs3qvqHqMs ElEdfXeRBE+bTS3l9pX5HcdfwOZRMqLlFXavt03jmcRfeNjZnVwwanEKDicumC1Qd/Z4QQ6QY4lx xrokDexvXn1q3SAKevEnJiCSgsmDWKGcloMUiQomZGDKzTadjfk3NIL1QXI222229g0ZBNSguNV8 cB1txWbTJpGVBB+KBPh4eJspWmIJYwrZ4C+QD6HUpMVDw9wT1/keJQJeuU7+bpH9qeAHUF02ul+T AWMg7psBVRnasdw2abVBXmQaFAZzlApRpAWQVQBKZ79i4A0mQtRqO7d9ZGsPtBIHG99CBaOb59U0 l+IFwqjE2l5nNSPnZy3LF8hhGNRirW8GCcNvfQVlwwtrxMNRvJoXIqJW598CEJtccDZNBgfX1tgV HbE1sdyXIN7fJdMDVxOJo+oBwP/xdyRThQkHXDE18A== --Boundary_(ID_3+0Z+HBajPGo7TSXXOWOHw)--