Bug #70685 incorrectly printed binlog dump information
Submitted: 22 Oct 2013 9:53 Modified: 13 Nov 2013 12:45
Reporter: zhai weixiang (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.6 OS:Any
Assigned to:

[22 Oct 2013 9:53] zhai weixiang
Description:
I noticed some strange output in error log like this:

131022  0:43:06 [Note] Start binlog_dump to slave_server(-1340259414), pos(mysql-bin.001663, 325187493)

bellow is the related code in function mysql_binlog_send( MySQL5.6.14)

 912   if (log_warnings > 1)
 913     sql_print_information("Start binlog_dump to master_thread_id(%lu) slave_server(%d), pos(%s, %lu)",
 914                         thd->thread_id, thd->server_id, log_ident, (ulong)pos);

 
the type of thd->server_id is uint32,  but here it will be converted to signed int

How to repeat:
read the code.

Suggested fix:
correct it !!
[22 Oct 2013 16:16] Sinisa Milivojevic
Your findings are true, although the output you presented seems to be from some earler version.

Yes, server_id is unsigned and "sprintf" is set to %d, so for server_id higher then 2 billion (!!!!) it will be a wrong value.
[23 Oct 2013 1:33] zhai weixiang
Yes, the output is quoted from the error log on our production environment(Percona Server 5.5.18). So I checked the latest version to confirm if this bug still exists  :)
[13 Nov 2013 12:45] Jon Stephens
Documented fix in the 5.5.36 and 5.6.16 changelogs, as follows:

        When log_warnings is greater than 1, the master prints binary
        log dump thread information--containing the slave server
        ID, binary log file name, and binary log position--in
        mysqld.1.err. A slave server ID value greater than 2 billion was
        printed with a negative value in such cases.
      

Closed.
[2 Feb 2014 17:28] Laurynas Biveinis
5.5$ bzr log -r 4546
------------------------------------------------------------
revno: 4546
committer: Venkatesh Duggirala<venkatesh.duggirala@oracle.com>
branch nick: mysql-5.5
timestamp: Tue 2013-11-12 22:09:10 +0530
message:
  Bug#17641586 INCORRECTLY PRINTED BINLOG DUMP INFORMATION
  
  Problem:
  When log_warnings is greater than 1, master prints binlog
  dump thread information in mysqld.1.err file.
  The information contains slave server id, binlog file and
  binlog position. The slave server id is uint32 and the print
  format was wrongly specifified (%d instead of %u).
  Hence a server id which is more than 2 billion is getting
  printed with a negative value.
  Eg: Start binlog_dump to slave_server(-1340259414),
  pos(mysql-bin.001663, 325187493)
  
  Fix: Changed the uint32 format to %u.