#At file:///home/lsoares/Workspace/bzr/work/bugfixing/55387/mysql-trunk-bugfixing/ based on revid:jonathan.perkin@stripped
3133 Luis Soares 2010-07-22
BUG#55387: binlog.binlog_tmp_table crashes the server
sporadically
There are two problems:
1. When closing temporary tables, during the THD clean up - and
after the session connection was already closed, there is a
chance we can push an error into the THD diagnostics area, if
the writing of the implicit DROP event to the binary log fails
for some reason. As a consequence an assertion can be
triggered, because at that point the diagnostics area is
already set.
2. Using push_warning with MYSQL_ERROR::WARN_LEVEL_ERROR is not a
recomended practice, and should not be used.
Given that close_temporary_tables is mostly called from
THD::cleanup - ie, with the session already closed, we fix
problem #1 by allowing the diagnostics area to be
overwritten. There is one other place in the code that calls
close_temporary_tables - while applying Start_log_event_v3. To
cover that case, we make close_temporary_tables to return the
error, thus, propagating upwards in the stack.
To fix problem #2, we replace push_warning with sql_print_error.
@ mysql-test/suite/binlog/t/binlog_tmp_table.test
Test case.
@ sql/log.cc
Added fault injection point while writing an event.
@ sql/log_event.cc
Added handling of error returned by close_temporary_tables to
Start_log_event_v3::do_apply_event.
@ sql/sql_base.cc
Three changes to close_temporary_tables:
1. it returns an integer now (instead of void)
2. it uses sql_print_error instead of push_warning when writing to
binary log fails
3. we set can_overwrite_status before writing to the binary log,
thence not risking triggering an assertion by any other push
into diagnostics area happening inside mysql_bin_log.write.
@ sql/sql_base.h
Changed the interface of close_temporary_tables so that it returns
int instead of void.
modified:
mysql-test/suite/binlog/r/binlog_tmp_table.result
mysql-test/suite/binlog/t/binlog_tmp_table.test
sql/log.cc
sql/log_event.cc
sql/sql_base.cc
sql/sql_base.h
=== modified file 'mysql-test/suite/binlog/r/binlog_tmp_table.result'
--- a/mysql-test/suite/binlog/r/binlog_tmp_table.result 2010-04-27 11:25:55 +0000
+++ b/mysql-test/suite/binlog/r/binlog_tmp_table.result 2010-07-22 09:19:06 +0000
@@ -40,3 +40,10 @@ ERROR 42S01: Table 't1' already exists
insert into t1 values(1);
DROP DATABASE b51226;
FLUSH LOGS;
+RESET MASTER;
+SET @old_debug= @global.debug;
+CREATE TEMPORARY TABLE t1 (a int);
+INSERT INTO t1 VALUES (1),(2);
+SET GLOBAL DEBUG= '+d,fault_injection_event_wite_error';
+SET GLOBAL DEBUG= @old_debug;
+RESET MASTER;
=== modified file 'mysql-test/suite/binlog/t/binlog_tmp_table.test'
--- a/mysql-test/suite/binlog/t/binlog_tmp_table.test 2010-04-28 12:47:49 +0000
+++ b/mysql-test/suite/binlog/t/binlog_tmp_table.test 2010-07-22 09:19:06 +0000
@@ -157,3 +157,34 @@ FLUSH LOGS;
# instead of failing with "Table 'XXX.YYY' doesn't exist"
-- let $MYSQLD_DATADIR= `select @@datadir`
-- exec $MYSQL_BINLOG $MYSQLD_DATADIR/master-bin.000001 | $MYSQL
+
+#
+# BUG#55387: binlog.binlog_tmp_table crashes the server sporadically
+#
+
+#
+# DESCRIPTION
+# ===========
+#
+# On con1 create a temporary table, insert some values
+# and disconnect. This shall log an implicit drop for the
+# temporary table. However, before droping we activate
+# fault injection so that when writing the implicit drop
+# event we get an error. This shall push an error into the
+# stmt_da, but after the fix, will not cause the ASSERTION.
+#
+
+RESET MASTER;
+SET @old_debug= @global.debug;
+connect (con1,localhost,root,,test,$MASTER_MYPORT,$MASTER_MYSOCK);
+connection con1;
+CREATE TEMPORARY TABLE t1 (a int);
+INSERT INTO t1 VALUES (1),(2);
+SET GLOBAL DEBUG= '+d,fault_injection_event_wite_error';
+disconnect con1;
+connection default;
+let $wait_binlog_event= DROP;
+--source include/wait_for_binlog_event.inc
+SET GLOBAL DEBUG= @old_debug;
+RESET MASTER;
+
=== modified file 'sql/log.cc'
--- a/sql/log.cc 2010-07-15 13:47:50 +0000
+++ b/sql/log.cc 2010-07-22 09:19:06 +0000
@@ -4804,7 +4804,7 @@ unlock:
mysql_mutex_unlock(&LOCK_log);
}
- if (error)
+ if (error || DBUG_EVALUATE_IF("fault_injection_event_write_error", 1, 0))
{
set_write_error(thd);
if (check_write_error(thd) && cache_data &&
=== modified file 'sql/log_event.cc'
--- a/sql/log_event.cc 2010-07-15 13:47:50 +0000
+++ b/sql/log_event.cc 2010-07-22 09:19:06 +0000
@@ -3719,6 +3719,7 @@ bool Start_log_event_v3::write(IO_CACHE*
int Start_log_event_v3::do_apply_event(Relay_log_info const *rli)
{
DBUG_ENTER("Start_log_event_v3::do_apply_event");
+ int error= 0;
switch (binlog_version)
{
case 3:
@@ -3731,7 +3732,7 @@ int Start_log_event_v3::do_apply_event(R
*/
if (created)
{
- close_temporary_tables(thd);
+ error= close_temporary_tables(thd);
cleanup_load_tmpdir();
}
else
@@ -3759,7 +3760,7 @@ int Start_log_event_v3::do_apply_event(R
Can distinguish, based on the value of 'created': this event was
generated at master startup.
*/
- close_temporary_tables(thd);
+ error= close_temporary_tables(thd);
}
/*
Otherwise, can't distinguish a Start_log_event generated at
@@ -3771,7 +3772,7 @@ int Start_log_event_v3::do_apply_event(R
/* this case is impossible */
DBUG_RETURN(1);
}
- DBUG_RETURN(0);
+ DBUG_RETURN(error);
}
#endif /* defined(HAVE_REPLICATION) && !defined(MYSQL_CLIENT) */
=== modified file 'sql/sql_base.cc'
--- a/sql/sql_base.cc 2010-07-15 13:47:50 +0000
+++ b/sql/sql_base.cc 2010-07-22 09:19:06 +0000
@@ -1634,7 +1634,7 @@ static inline uint tmpkeyval(THD *thd,
creates one DROP TEMPORARY TABLE binlog event for each pseudo-thread
*/
-void close_temporary_tables(THD *thd)
+int close_temporary_tables(THD *thd)
{
DBUG_ENTER("close_temporary_tables");
TABLE *table;
@@ -1642,9 +1642,10 @@ void close_temporary_tables(THD *thd)
TABLE *prev_table;
/* Assume thd->variables.option_bits has OPTION_QUOTE_SHOW_CREATE */
bool was_quote_show= TRUE;
+ int error= 0;
if (!thd->temporary_tables)
- DBUG_VOID_RETURN;
+ DBUG_RETURN(error);
if (!mysql_bin_log.is_open())
{
@@ -1655,7 +1656,7 @@ void close_temporary_tables(THD *thd)
close_temporary(table, 1, 1);
}
thd->temporary_tables= 0;
- DBUG_VOID_RETURN;
+ DBUG_RETURN(error);
}
/* Better add "if exists", in case a RESET MASTER has been done */
@@ -1754,11 +1755,27 @@ void close_temporary_tables(THD *thd)
qinfo.db= db.ptr();
qinfo.db_len= db.length();
thd->variables.character_set_client= cs_save;
- if (mysql_bin_log.write(&qinfo))
+
+ thd->stmt_da->can_overwrite_status= TRUE;
+ if ((error= error | mysql_bin_log.write(&qinfo)))
{
- push_warning(thd, MYSQL_ERROR::WARN_LEVEL_ERROR, MYF(0),
- "Failed to write the DROP statement for temporary tables to binary log");
+ /*
+ If we're here following THD::cleanup, thence the connection
+ has been closed already. So lets print a message to the
+ error log instead of pushing yet another error into the
+ stmt_da.
+
+ Also, we keep the error flag so that we porpagate the error
+ up in the stack. This way, if we're the SQL thread we notice
+ that close_temporary_tables failed. (Actually, the SQL
+ thread only calls close_temporary_tables while applying old
+ Start_log_event_v3 events.)
+ */
+ sql_print_error("Failed to write the DROP statement for "
+ "temporary tables to binary log");
}
+ thd->stmt_da->can_overwrite_status= FALSE;
+
thd->variables.pseudo_thread_id= save_pseudo_thread_id;
thd->thread_specific_used= save_thread_specific_used;
}
@@ -1771,7 +1788,7 @@ void close_temporary_tables(THD *thd)
if (!was_quote_show)
thd->variables.option_bits&= ~OPTION_QUOTE_SHOW_CREATE; /* restore option */
thd->temporary_tables=0;
- DBUG_VOID_RETURN;
+ DBUG_RETURN(error);
}
/*
=== modified file 'sql/sql_base.h'
--- a/sql/sql_base.h 2010-06-11 15:28:18 +0000
+++ b/sql/sql_base.h 2010-07-22 09:19:06 +0000
@@ -222,7 +222,7 @@ int decide_logging_format(THD *thd, TABL
void free_io_cache(TABLE *entry);
void intern_close_table(TABLE *entry);
bool close_thread_table(THD *thd, TABLE **table_ptr);
-void close_temporary_tables(THD *thd);
+int close_temporary_tables(THD *thd);
TABLE_LIST *unique_table(THD *thd, TABLE_LIST *table, TABLE_LIST *table_list,
bool check_alias);
int drop_temporary_table(THD *thd, TABLE_LIST *table_list);
Attachment: [text/bzr-bundle] bzr/luis.soares@sun.com-20100722091906-v23orepleyobbanq.bundle
