Bug #61207 binlog does not set pseudo_thread_id for temporary tables
Submitted: 17 May 2011 19:44 Modified: 1 Jan 2012 18:54
Reporter: Brian Martin Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.1.56 OS:Linux
Assigned to: CPU Architecture:Any
Tags: binlog, pseudo_thread_id, temporary

[17 May 2011 19:44] Brian Martin
Description:
the binlog does not get written with SET @@session.pseudo_thread_id statements when switching threads while using temporary tables which causes ERROR 1146

How to repeat:
drop database if exists tempdb;
create database tempdb;
use tempdb;

# at 36737239
#110512 11:22:37 server id 101  end_log_pos 36737960    Query   thread_id=71404 exec_time=5     error_code=0
SET TIMESTAMP=1305213757;
SET @@session.pseudo_thread_id=71404;
CREATE TEMPORARY TABLE temptbl (   `tempfld` varchar(10) DEFAULT '');

select '==========================',database();
show variables like 'pseudo_thread_id';
describe temptbl;

# at 36737960
#110512 11:22:41 server id 101  end_log_pos 36738069    Query   thread_id=71412 exec_time=1     error_code=0
SET @@session.pseudo_thread_id=71412;

 select '==========================',database();
 show variables like 'pseudo_thread_id';

SET TIMESTAMP=1305213761;
DROP TEMPORARY TABLE IF EXISTS temptbl;
# at 36738069
#110512 11:22:50 server id 101  end_log_pos 36738180    Query   thread_id=71404 exec_time=4294967288    error_code=0
SET @@session.pseudo_thread_id=71404;

 select '==========================',database();
 show variables like 'pseudo_thread_id';
 describe temptbl;

output from above code:

==========================      database()
==========================      tempdb
Variable_name   Value
pseudo_thread_id        71404
Field   Type    Null    Key     Default Extra
tempfld varchar(10)     YES
==========================      database()
==========================      tempdb
Variable_name   Value
pseudo_thread_id        71412    <--------------------------  correct
==========================      database()
==========================      tempdb
Variable_name   Value
pseudo_thread_id        71404
Field   Type    Null    Key     Default Extra
tempfld varchar(10)     YES

 
This is the generated binlog after running the above code:

 [root@OPS-S7b binlogs]# mysqlbinlog S7-bin.000005

/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#110517 13:42:52 server id 37  end_log_pos 106  Start: binlog v 4, server v 5.1.56-log created 110517 13:42:52 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
nLPSTQ8lAAAAZgAAAGoAAAABAAQANS4xLjU2LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAACcs9JNEzgNAAgAEgAEBAQEEgAAUwAEGggAAAAICAgC
'/*!*/;
# at 106
#110517 13:42:57 server id 37  end_log_pos 206  Query   thread_id=2     exec_time=0     error_code=0
SET TIMESTAMP=1305654177/*!*/;
SET @@session.pseudo_thread_id=2/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=10, @@session.auto_increment_offset=2/*!*/;
/*!\C latin1 *//*!*/;
SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
drop database if exists tempdb
/*!*/;
# at 206
#110517 13:42:57 server id 37  end_log_pos 298  Query   thread_id=2     exec_time=0     error_code=0
SET TIMESTAMP=1305654177/*!*/;
create database tempdb
/*!*/;
# at 298
#110512 11:22:37 server id 37  end_log_pos 436  Query   thread_id=71404 exec_time=440420        error_code=0
use tempdb/*!*/;
SET TIMESTAMP=1305213757/*!*/;
SET @@session.pseudo_thread_id=71404/*!*/;
CREATE TEMPORARY TABLE temptbl (   `tempfld` varchar(10) DEFAULT '')
/*!*/;
# at 436
#110512 11:22:41 server id 37  end_log_pos 544  Query   thread_id=71412 exec_time=440416        error_code=0
SET TIMESTAMP=1305213761/*!*/;
DROP TEMPORARY TABLE IF EXISTS temptbl
/*!*/;
# at 544
#110512 11:22:41 server id 37  end_log_pos 666  Query   thread_id=71404 exec_time=440416        error_code=0
SET TIMESTAMP=1305213761/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
DROP /*!40005 TEMPORARY */ TABLE IF EXISTS `temptbl`
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

Suggested fix:
write the binlog to include SET @@session.pseudo_thread_id

# at 436
#110512 11:22:41 server id 37  end_log_pos 544  Query   thread_id=71412 exec_time=440416        error_code=0
SET TIMESTAMP=1305213761/*!*/;
SET @@session.pseudo_thread_id=71412/*!*/;    <---------------------- ADD
DROP TEMPORARY TABLE IF EXISTS temptbl
/*!*/;
# at 544
#110512 11:22:41 server id 37  end_log_pos 666  Query   thread_id=71404 exec_time=440416        error_code=0
SET TIMESTAMP=1305213761/*!*/;
SET @@session.pseudo_thread_id=71404/*!*/;    <---------------------- ADD
/*!\C utf8 *//*!*/;
[14 Jul 2011 19:53] Sveta Smirnova
Thank you for the report.

According to http://dev.mysql.com/doc/refman/5.1/en/server-system-variables.html#sysvar_pseudo_thread_i... "This variable is for internal server use. " Do you set it manually?
[14 Aug 2011 23:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[17 Nov 2011 12:36] James Michael DuPont
We have a workaround for this bug , 
commenting out the checks for the flag LOG_EVENT_THREAD_SPECIFIC_F and just setting the pseudo thread id for all log entries.

Specific Problem : The flag LOG_EVENT_THREAD_SPECIFIC_F is not being set properly for the truncate temp tables command.  I dont have time to debug this code, it is not clear where the flag is being set.
[17 Nov 2011 12:49] James Michael DuPont
here is a patch for the version we are using :
mysql-5.0.77/sql

diff -u log_event.bak.cc  log_event.cc 
--- log_event.bak.cc	2011-11-17 13:28:26.000000000 +0100
+++ log_event.cc	2011-11-17 13:30:28.000000000 +0100
@@ -1727,7 +1727,7 @@
   end= strmov(end, print_event_info->delimiter);
   *end++='\n';
   my_fwrite(file, (byte*) buff, (uint) (end-buff),MYF(MY_NABP | MY_WME));
-  if (flags & LOG_EVENT_THREAD_SPECIFIC_F)
+  //  if (flags & LOG_EVENT_THREAD_SPECIFIC_F) //workaround for Bug #61207binlog does not set pseudo_thread_id for temporary tables
     fprintf(file,"SET @@session.pseudo_thread_id=%lu%s\n",
             (ulong)thread_id, print_event_info->delimiter);
 
@@ -3026,7 +3026,7 @@
             commented ? "# " : "",
             db, print_event_info->delimiter);
 
-  if (flags & LOG_EVENT_THREAD_SPECIFIC_F)
+  //  if (flags & LOG_EVENT_THREAD_SPECIFIC_F) workaround Bug #61207binlog does not set pseudo_thread_id for temporary tables
     fprintf(file,"%sSET @@session.pseudo_thread_id=%lu%s\n",
             commented ? "# " : "", (ulong)thread_id,
             print_event_info->delimiter);
[1 Dec 2011 18:54] Sveta Smirnova
James,

thank you for the patch. But why do you need pseudo_thread_id? Do you apply binary log from another server and want its events to be stored to binary log?
[2 Jan 2012 7:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[13 Sep 2018 5:29] MySQL Verification Team
See https://bugs.mysql.com/bug.php?id=51226