Bug #69253 mysqlbinlog prints incorrect value while using decimal
Submitted: 16 May 2013 7:31 Modified: 27 Aug 2014 4:50
Reporter: zhai weixiang (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Row Based Replication ( RBR ) Severity:S3 (Non-critical)
Version:5.6.11 OS:Any
Assigned to: CPU Architecture:Any

[16 May 2013 7:31] zhai weixiang
Description:
execute the following command:

flush logs;

CREATE TABLE `aaa`( `d_tax` decimal(4,2) DEFAULT NULL ) ENGINE=InnoDB DEFAULT CHARSET=gbk;

insert into aaa values(0.18);

insert into aaa values(1.18);

mysqlbinlog  --no-defaults -v -v /u01/mysql/log/mysql-bin.00008

quoted output:

BINLOG '
R4mUURNdJgAAMAAAAGcBAAAAALECAAAAAAEABHRlc3QAA2FhYQAB9gIEAgHG9qaR
R4mUUR5dJgAAJgAAAI0BAAAAALECAAAAAAEAAgAB//6AEhoh9hE=
'/*!*/;
### INSERT INTO `test`.`aaa`
### SET
###   @1=180000000 /* DECIMAL(4,2) meta=1026 nullable=1 is_null=0 */
# at 397
#130516 15:22:47 server id 9821  end_log_pos 428 CRC32 0xd02a2732       Xid = 6937888
COMMIT/*!*/;

Here, @1=180000000, but  actually it's 0.18

# at 428
#130516 15:22:50 server id 9821  end_log_pos 476 CRC32 0x62eebf42       GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '7a07cd08-ac1b-11e2-9fcf-0010184e9e08:3452761'/*!*/;
# at 476
#130516 15:22:50 server id 9821  end_log_pos 548 CRC32 0x34990447       Query   thread_id=91810 exec_time=0     error_code=0
SET TIMESTAMP=1368688970/*!*/;
BEGIN
/*!*/;
# at 548
#130516 15:22:50 server id 9821  end_log_pos 596 CRC32 0x27656767       Table_map: `test`.`aaa` mapped to number 689
# at 596
#130516 15:22:50 server id 9821  end_log_pos 634 CRC32 0x9d35a6b0       Write_rows: table id 689 flags: STMT_END_F

BINLOG '
SomUURNdJgAAMAAAAFQCAAAAALECAAAAAAEABHRlc3QAA2FhYQAB9gIEAgFnZ2Un
SomUUR5dJgAAJgAAAHoCAAAAALECAAAAAAEAAgAB//6BErCmNZ0=
'/*!*/;
### INSERT INTO `test`.`aaa`
### SET
###   @1=000000001.180000000 /* DECIMAL(4,2) meta=1026 nullable=1 is_null=0 */
# at 634
#130516 15:22:50 server id 9821  end_log_pos 665 CRC32 0x4370c735       Xid = 6937889
COMMIT/*!*/;
DELIMITER ;

How to repeat:
as described above 

Suggested fix:
I don't know
[16 May 2013 8:23] zhai weixiang
a simple change..

$svn diff sql/log_event.cc
Index: sql/log_event.cc
===================================================================
--- sql/log_event.cc    (revision 3992)
+++ sql/log_event.cc    (working copy)
@@ -2014,8 +2014,12 @@
       pos= buff;
       pos+= sprintf(buff, "%s", dec.sign() ? "-" : "");
       end= ROUND_UP(dec.frac) + ROUND_UP(dec.intg)-1;
-      for (i=0; i < end; i++)
-        pos+= sprintf(pos, "%09d.", dec.buf[i]);
+      if (end == 0)
+        pos+= sprintf(pos, "%09d.", 0);
+      else {
+        for (i=0; i < end; i++)
+                pos+= sprintf(pos, "%09d.", dec.buf[i]);
+      }
       pos+= sprintf(pos, "%09d", dec.buf[i]);
       my_b_printf(file, "%s", buff);
       my_snprintf(typestr, typestr_length, "DECIMAL(%d,%d)",
[16 May 2013 8:34] MySQL Verification Team
Hello zhai,

Thank you for the report.
Verified as described.

Thanks,
Umesh
[16 May 2013 8:38] MySQL Verification Team
How to repeat:

set global binlog_format=ROW;
flush logs;
drop table if exists aaa;
CREATE TABLE `aaa`( `d_tax` decimal(4,2) DEFAULT NULL ) ENGINE=InnoDB DEFAULT CHARSET=gbk;
insert into aaa values(0.18);
insert into aaa values(1.18);

// 

mysqlbinlog  --no-defaults -v -v /path/to/mysql-bin.xxxxx

// 

mysqlbinlog  --no-defaults -v -v /tmp/5611/ushastry-bin.000010

/*!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
#130516 13:45:01 server id 1  end_log_pos 120 CRC32 0x817bd049 	Start: binlog v 4, server v 5.6.11-debug-log created 130516 13:45:01
# Warning: this binlog is either in use or was not closed properly.
BINLOG '
hZWUUQ8BAAAAdAAAAHgAAAABAAQANS42LjExLWRlYnVnLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAUnQ
e4E=
'/*!*/;
# at 120
#130516 13:45:01 server id 1  end_log_pos 191 CRC32 0xebae74f3 	Previous-GTIDs
# ce0a3a53-b956-11e2-b617-0800272e2cce:1-3930
# at 191
#130516 13:45:01 server id 1  end_log_pos 239 CRC32 0xaa7f668f 	GTID [commit=yes]
SET @@SESSION.GTID_NEXT= 'ce0a3a53-b956-11e2-b617-0800272e2cce:3931'/*!*/;
# at 239
#130516 13:45:01 server id 1  end_log_pos 402 CRC32 0x72dbd07c 	Query	thread_id=7	exec_time=0	error_code=0
use `test`/*!*/;
SET TIMESTAMP=1368692101/*!*/;
SET @@session.pseudo_thread_id=7/*!*/;
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 utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=1/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
CREATE TABLE `aaa`( `d_tax` decimal(4,2) DEFAULT NULL ) ENGINE=InnoDB DEFAULT CHARSET=gbk
/*!*/;
# at 402
#130516 13:45:01 server id 1  end_log_pos 450 CRC32 0xd9119de2 	GTID [commit=yes]
SET @@SESSION.GTID_NEXT= 'ce0a3a53-b956-11e2-b617-0800272e2cce:3932'/*!*/;
# at 450
#130516 13:45:01 server id 1  end_log_pos 522 CRC32 0xc484c4a0 	Query	thread_id=7	exec_time=0	error_code=0
SET TIMESTAMP=1368692101/*!*/;
BEGIN
/*!*/;
# at 522
#130516 13:45:01 server id 1  end_log_pos 570 CRC32 0x103f3a95 	Table_map: `test`.`aaa` mapped to number 79
# at 570
#130516 13:45:01 server id 1  end_log_pos 608 CRC32 0x7ee39697 	Write_rows: table id 79 flags: STMT_END_F

BINLOG '
hZWUURMBAAAAMAAAADoCAAAAAE8AAAAAAAEABHRlc3QAA2FhYQAB9gIEAgGVOj8Q
hZWUUR4BAAAAJgAAAGACAAAAAE8AAAAAAAEAAgAB//6AEpeW434=
'/*!*/;
### INSERT INTO `test`.`aaa`
### SET
###   @1=180000000 /* DECIMAL(4,2) meta=1026 nullable=1 is_null=0 */
# at 608
#130516 13:45:01 server id 1  end_log_pos 639 CRC32 0x2a712d07 	Xid = 3959
COMMIT/*!*/;
# at 639
#130516 13:45:02 server id 1  end_log_pos 687 CRC32 0x65b1d97c 	GTID [commit=yes]
SET @@SESSION.GTID_NEXT= 'ce0a3a53-b956-11e2-b617-0800272e2cce:3933'/*!*/;
# at 687
#130516 13:45:02 server id 1  end_log_pos 759 CRC32 0x3158fc84 	Query	thread_id=7	exec_time=0	error_code=0
SET TIMESTAMP=1368692102/*!*/;
BEGIN
/*!*/;
# at 759
#130516 13:45:02 server id 1  end_log_pos 807 CRC32 0xfe1e1136 	Table_map: `test`.`aaa` mapped to number 79
# at 807
#130516 13:45:02 server id 1  end_log_pos 845 CRC32 0x5000c441 	Write_rows: table id 79 flags: STMT_END_F

BINLOG '
hpWUURMBAAAAMAAAACcDAAAAAE8AAAAAAAEABHRlc3QAA2FhYQAB9gIEAgE2ER7+
hpWUUR4BAAAAJgAAAE0DAAAAAE8AAAAAAAEAAgAB//6BEkHEAFA=
'/*!*/;
### INSERT INTO `test`.`aaa`
### SET
###   @1=000000001.180000000 /* DECIMAL(4,2) meta=1026 nullable=1 is_null=0 */
# at 845
#130516 13:45:02 server id 1  end_log_pos 876 CRC32 0x8780d25a 	Xid = 3960
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
[root@ushastry mysql-5.6.11-release]#
[16 May 2013 8:53] zhai weixiang
another incorrect output:

create table t1 (a decimal(12,2));

insert into t1(a) values (2004681056);

quoted output:

BINLOG '
RZ6UURNdJgAALwAAAGYBAAAAANICAAAAAAEABHRlc3QAAnQxAAH2AgwCAX+FcpQ=
RZ6UUR5dJgAAKgAAAJABAAAAANICAAAAAAEAAgAB//6CAEdtYABtCcz2
'/*!*/;
### INSERT INTO `test`.`t1`
### SET
###   @1=000000002.004681056.000000000 /* DECIMAL(12,2) meta=3074 nullable=1 is_null=0 */
# at 400
#130516 16:52:21 server id 9821  end_log_pos 431 CRC32 0x517ecc68       Xid = 6938004
COMMIT/*!*/;
DELIMITER ;
# End of log file
[16 May 2013 8:55] MySQL Verification Team
Seen http://bugs.mysql.com/bug.php?id=65812 ?
[16 May 2013 9:29] zhai weixiang
thanks , Shane

I've checked the code in MySQL 5.7.1 . It seems the second issue was fixed. As to the first issue,  the mysqlbinlog still prints the incorrect value:

BINLOG '
maCUURNdJgAAMAAAAGcBAAAAALECAAAAAAEABHRlc3QAA2FhYQAB9gIEAgGm0Lvx
maCUUR5dJgAAJgAAAI0BAAAAALECAAAAAAEAAgAB//6AEibsx0I=
'/*!*/;
### INSERT INTO `test`.`aaa`
### SET
###   @1=.180000000 /* DECIMAL(4,2) meta=1026 nullable=1 is_null=0 */
# at 397
#130516 17:02:17 server id 9821  end_log_pos 428 CRC32 0xc3b78e9d       Xid = 6938085
COMMIT/*!*/;
DELIMITER ;
[27 Aug 2014 4:50] Erlend Dahl
This appears to have been fixed in 5.6.16 with

BUG#17544169 MYSQLBINLOG -V DOES NOT PROPERLY DECODE DECIMAL VALUES IN AN RBR LOG