Details
-
Type:
Bug
-
Status: Closed
-
Priority:
Major
-
Resolution: Fixed
-
Affects Version/s: 5.5.40
-
Fix Version/s: 5.5.44
-
Component/s: Replication
-
Labels:None
-
Environment:centos-6.5
x86_64
-
Sprint:5.5.44
Description
If the middle of a pt-online-schema change using --set-vars binlogformat=ROW the following replication error.
The table was created on 5.0.34 and has since been upgraded over time to 5.5.29. Could it be the column is the old decimal format?
http://forums.mysql.com/read.php?26,619649,619718#msg-619718 references (Bug #16416302).
Server version: 5.5.29-MariaDB-log MariaDB Server
Same effects where observed on 5.5.40 slave.
MariaDB [weather]> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 192.168.124.35
Master_User: replication
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.046692
Read_Master_Log_Pos: 67654425
Relay_Log_File: mysqld-relay-bin.930329
Relay_Log_Pos: 30748354
Relay_Master_Log_File: mysql-bin.046557
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 1677
Last_Error: Column 3 of table 'weather.lightning' cannot be converted from type 'decimal(0,?)' to type 'decimal(10,7)'
Skip_Counter: 0
Exec_Master_Log_Pos: 30748070
Relay_Log_Space: 14291648459
Until_Condition: None
on master:
mysqlbinlog --start-position 30748070 mysql-bin.046557 | more BEGIN /*!*/; # at 30748141 # at 30748202 # at 30748274 #141204 10:12:43 server id 1 end_log_pos 30748202 Table_map: `weather`.`lightning` mapped to number 177647 #141204 10:12:43 server id 1 end_log_pos 30748274 Table_map: `weather`.`_lightning_new` mapped to number 177646 #141204 10:12:43 server id 1 end_log_pos 30748356 Delete_rows: table id 177647 flags: STMT_END_F BINLOG ' 65h/VBMBAAAAPQAAACou1QEAAO+1AgAAAAEAB3dlYXRoZXIACWxpZ2h0bmluZwAHAw8MAAAADwQK AAoAYA== 65h/VBMBAAAASAAAAHIu1QEAAO61AgAAAAEAB3dlYXRoZXIADl9saWdodG5pbmdfbmV3AAcDDwz2 9vYPCgoACgcKBwUBCgBg 65h/VBkBAAAAUgAAAMQu1QEAAO+1AgAAAAEAB/+AG4GOBAVHUEFUU5OG1tNFEgAAIC0zMy42MzA3 NDc5IDE1Mi44MzIwNjk3ICAtNDEuMgJHUw== '/*!*/; # at 30748356 #141204 10:12:43 server id 1 end_log_pos 30748383 Xid = 12786901894 COMMIT/*!*/;
decoded version
mysqlbinlog --start-position 30748070 --verbose --base64-output=decode-rows mysql-bin.046557 | more BEGIN /*!*/; # at 30748141 # at 30748202 # at 30748274 #141204 10:12:43 server id 1 end_log_pos 30748202 Table_map: `weather`.`lightning` mapped to number 177647 #141204 10:12:43 server id 1 end_log_pos 30748274 Table_map: `weather`.`_lightning_new` mapped to number 177646 #141204 10:12:43 server id 1 end_log_pos 30748356 Delete_rows: table id 177647 flags: STMT_END_F ### DELETE FROM `weather`.`lightning` ### WHERE ### @1=76448027 ### @2='GPATS' ### @3=2009-11-16 09:51:23 ### @4=!! Don't know how to handle column type=0 meta=0 (0000)# at 30748356 #141204 10:12:43 server id 1 end_log_pos 30748383 Xid = 12786901894 COMMIT/*!*/;
| lightning | CREATE TABLE `lightning` ( `id` int(10) unsigned NOT NULL AUTO_INCREMENT, `source` varchar(10) NOT NULL DEFAULT '', `timestamp_utc` datetime NOT NULL DEFAULT '0000-00-00 00:00:00', `latitude` decimal(10,7) NOT NULL DEFAULT '0.0000000', `longitude` decimal(10,7) NOT NULL DEFAULT '0.0000000', `amperage` decimal(5,1) DEFAULT NULL, `event_type` varchar(10) DEFAULT NULL, PRIMARY KEY (`id`), UNIQUE KEY `idx_lightning_1` (`source`,`timestamp_utc`,`latitude`,`longitude`) ) ENGINE=InnoDB AUTO_INCREMENT=484282187 DEFAULT CHARSET=latin1 MAX_ROWS=1000000000 ROW_FORMAT=DYNAMIC | | _lightning_new | CREATE TABLE `_lightning_new` ( `id` int(10) unsigned NOT NULL AUTO_INCREMENT, `source` varchar(10) NOT NULL DEFAULT '', `timestamp_utc` datetime(3) NOT NULL COMMENT 'UTC time (millisecond precision)', `latitude` decimal(10,7) NOT NULL DEFAULT '0.0000000', `longitude` decimal(10,7) NOT NULL DEFAULT '0.0000000', `amperage` decimal(5,1) DEFAULT NULL, `event_type` varchar(10) DEFAULT NULL, PRIMARY KEY (`id`), UNIQUE KEY `idx_lightning_1` (`source`,`timestamp_utc`,`latitude`,`longitude`) ) ENGINE=InnoDB AUTO_INCREMENT=484282186 DEFAULT CHARSET=latin1 MAX_ROWS=1000000000 ROW_FORMAT=DYNAMIC |
After changing the format to doubles I had different conversion error at the same position.
alter table _lightning_new modify latitude double NOT NULL DEFAULT 0.0000000,modify longitude double NOT NULL DEFAULT 0.0000000, modify amperage double DEFAULT NULL;
slart slave;
MariaDB [weather]> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 192.168.124.35
Master_User: replication
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.046693
Read_Master_Log_Pos: 34510815
Relay_Log_File: mysqld-relay-bin.930329
Relay_Log_Pos: 30748354
Relay_Master_Log_File: mysql-bin.046557
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 1677
Last_Error: Column 3 of table 'weather._lightning_new' cannot be converted from type 'decimal(10,7)' to type 'double'
Skip_Counter: 0
Exec_Master_Log_Pos: 30748070
Relay_Log_Space: 14363364234
Until_Condition: None
Gliffy Diagrams
Attachments
Activity
- All
- Comments
- Work Log
- History
- Activity
- Transitions
The "what's next" part.
The workaround for the problem is pretty obvious: do the job that pt-online-schema-change was trying to do – create a new table via the full create table statement (not via CREATE TABLE .. LIKE), alter it as you need, populate from the old table, and then switch to the new one.
For actual fixing, I see two points of misbehavior here. I don't know which of them can and must be fixed, so I will reassign it to the datatype expert Alexander Barkov to make the decision.
Problem 1: the deprecated datatype does not get upgraded.
When mysql_upgrade from a 5.x version checks the table taken from 4.1, it does actually notice that something is seriously wrong with it, and says that ALTER TABLE .. FORCE must be performed (and it actually performs it). However, ALTER TABLE .. FORCE does not change DECIMAL to NEWDECIMAL. Maybe it should?
Problem 2: When a row event which was written for DECIMAL is applied to NEWDECIMAL, the described error occurs. It doesn't seem reasonable, I suppose the slave can handle it better.
> Most likely the slave was initialized at some point on a 5.x version, e.g. from a master dump
Yes it was.
> why exactly pt-online-schema-change failed? What was the error?
It was user aborted due to slave errors.
> server uses binlog_format=mixed (is it so?
Yes. In fact this in very new too (last 1-2 weeks ago).
> Problem 1
> ALTER TABLE .. FORCE does not change DECIMAL to NEWDECIMAL. Maybe it should
Only its really needed, with some really big warnings, or leave it for the user to fix, a large table alter can take several hours compared to what is normally a really quick mysql_update.
> Problem 2: When a row event which was written for DECIMAL is applied to NEWDECIMAL, the described error occurs. It doesn't seem reasonable, I suppose the slave can handle it better.
Especially considering its handing it now fine. I guess its reverted to SBR method since its still mixed.
Problem 3:
seg fault with set global slave_type_conversions='ALL_NON_LOSSY,ALL_LOSSY'; (comment 1)
> Problem 1
> ALTER TABLE .. FORCE does not change DECIMAL to NEWDECIMAL. Maybe it should
Only its really needed, with some really big warnings, or leave it for the user to fix, a large table alter can take several hours compared to what is normally a really quick mysql_update.
Yeah, but keep in mind that mysql_upgrade already performs ALTER TABLE .. FORCE when it encounters a table like that; it's just that this ALTER TABLE doesn't change the internal column type.
I guess its reverted to SBR method since its still mixed.
It should have if you removed the triggers that pt-online-schema-change created, but if you didn't I think it shouldn't have reverted to SBR. In the latter case it would be interesting to see how the binlog looks now.
Problem 3:
seg fault with set global slave_type_conversions='ALL_NON_LOSSY,ALL_LOSSY'
Right, thanks for reminding. And at some point I also had a debug assertion failure that I hopefully will be able to reproduce. Depending on what Alexander Barkov decides about the first two problems, the crash/assertion can either stay a part of this issue (if it gets fixed), or go into a separate one, since segfault should be fixed regardless the fate of the other problems.
It should have if you removed the triggers that pt-online-schema-change created,
Yes I removed the triggers, then added replication filters, then started replication to bypass the issue.
In the latter case it would be interesting to see how the binlog looks now.
Not applicable. And enough interesting aspects already 
On note there were other slaves, older and perhaps having an original old decimal table definition that didn't encounter this replication error.
The segfault was an upstream issue, fixed in MySQL 5.5.34 – not sure exactly by which patch, but it was reproducible on older versions of MySQL and on MariaDB 5.5 up to revno 3975 (the merge of MySQL 5.5.34 into MariaDB 5.5), and disappeared after that. Now it returns the error instead:
Last_SQL_Errno: 1678
Last_SQL_Error: Can't create conversion table for table 'test.lightning'
which is understandable since the allowed conversions are defined explicitly ( http://dev.mysql.com/doc/refman/5.5/en/replication-features-differing-tables.html#replication-features-attribute-promotion ) and DECIMAL=>NEWDECIMAL is not one of them.