Bug #76370 User_var name is empty
Submitted: 18 Mar 2015 9:08 Modified: 29 Oct 2015 13:32
Reporter: Timur Solodovnikov Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.6.14-log MySQL Community Server (GPL), 5.6.25 OS:Linux (Centos5.10)
Assigned to: CPU Architecture:Any

[18 Mar 2015 9:08] Timur Solodovnikov 
Description:
mysqlbinlog  with --read-from-remote-server User_var name is empty.

How to repeat:
Run from some remote server:
mysqlbinlog -uUSER -p --read-from-remote-server --host=HOST --database=DB --to-last-log --stop-never --start-position=977602419 db-cst-bin.002582:

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 977602419
#691231 16:00:00 server id 7088054  end_log_pos 0       Rotate to db-cst-bin.002582  pos: 977602419
# at 977602419
#150316 10:50:18 server id 7088054  end_log_pos 0 CRC32 0x08ae3cb5      Start: binlog v 4, server v 5.6.14-log created 150316 10:50:18
BINLOG '
2hcHVQ+2J2wAdAAAAAAAAAAAAAQANS42LjE0LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAbU8
rgg=
'/*!*/;
# at 977602419
#150316 22:50:10 server id 7088054  end_log_pos 977602536 CRC32 0x2d5fa951      Query   thread_id=889966        exec_time=0     error_code=0
SET TIMESTAMP=1426571410/*!*/;
SET @@session.pseudo_thread_id=889966/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C latin1 *//*!*/;
SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
SET @@session.time_zone='SYSTEM'/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 977602536
# at 977602568
#150316 22:50:10 server id 7088054  end_log_pos 977602568 CRC32 0x1746cc16      Intvar
SET INSERT_ID=75682515/*!*/;
#150316 22:50:10 server id 7088054  end_log_pos 977602814 CRC32 0x1f4b847b      Query   thread_id=889966        exec_time=0     error_code=0
use `DB`/*!*/;
SET TIMESTAMP=1426571410/*!*/;
insert into partition_103063_crm
         (`modified`, `created_time`)
        values
         (unix_timestamp(now()) * 1000, unix_timestamp(now()) * 1000)
/*!*/;
# at 977602814
# at 977602866
# at 977602921
#150316 22:50:10 server id 7088054  end_log_pos 977602866 CRC32 0xb17ea1ee      User_var
SET @``:=432345564231770112/*!*/;

Take a look on the last line. However, if you check it out locally( login to this host and run  mysqlbinlog without --read-from-remote-server), everything is ok. Variable name is `crm_fk` instead of ``;

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#150316 10:50:18 server id 7088054  end_log_pos 120 CRC32 0xb46cf4ff 	Start: binlog v 4, server v 5.6.14-log created 150316 10:50:18
BINLOG '
2hcHVQ+2J2wAdAAAAHgAAAAAAAQANS42LjE0LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAf/0
bLQ=
'/*!*/;
# at 977602419
#150316 22:50:10 server id 7088054  end_log_pos 977602536 CRC32 0x2d5fa951 	Query	thread_id=889966	exec_time=0	error_code=0
SET TIMESTAMP=1426571410/*!*/;
SET @@session.pseudo_thread_id=889966/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C latin1 *//*!*/;
SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
SET @@session.time_zone='SYSTEM'/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 977602536
# at 977602568
#150316 22:50:10 server id 7088054  end_log_pos 977602568 CRC32 0x1746cc16 	Intvar
SET INSERT_ID=75682515/*!*/;
#150316 22:50:10 server id 7088054  end_log_pos 977602814 CRC32 0x1f4b847b 	Query	thread_id=889966	exec_time=0	error_code=0
use `DB`/*!*/;
SET TIMESTAMP=1426571410/*!*/;
insert into partition_103063_crm
	 (`modified`, `created_time`)
	values
	 (unix_timestamp(now()) * 1000, unix_timestamp(now()) * 1000)
/*!*/;
# at 977602814
# at 977602866
# at 977602921
#150316 22:50:10 server id 7088054  end_log_pos 977602866 CRC32 0xb17ea1ee 	User_var
SET @`crm_fk`:=75682515/*!*/;

Both servers have the same OS, environment and mysql version.
[18 Mar 2015 13:31] Timur Solodovnikov 
I've reproduced the issue on:
Fedora release 20 (Heisenbug)
mysql-community-libs-5.6.22-1.fc20.x86_64
mysql-community-release-fc20-5.noarch
mysql-community-common-5.6.22-1.fc20.x86_64
mysql-community-server-5.6.22-1.fc20.x86_64
mysql-community-client-5.6.22-1.fc20.x86_64
[18 Mar 2015 13:39] Timur Solodovnikov 
correction to previous comment.

create databasse test;
use test;
create table test(id bigint);
set @a=1;
insert into test values (@a);
[30 Mar 2015 12:52] MySQL Verification Team 
Hello Timur Solodovnikov,

Thank you for the report and test case.
Observed similar behavior with 5.6.25 build.

Thanks,
Umesh
[30 Mar 2015 12:53] MySQL Verification Team 
test results

Attachment: 76370.txt (text/plain), 7.46 KiB.