Mysql - how to debug problem with ROW based logging
How to debug ROW based replication problem.
Row based replication doesn't show SQL statement in troubles, because replicate changes only. There is one way, how to show as much details as possible. Lets say, we have this problem:
MariaDB [(none)]> show slave status\G;
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 192.168.55.51
Master_User: replicator
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: master-bin.007221
Read_Master_Log_Pos: 467465148
Relay_Log_File: db-relaylog.000017
Relay_Log_Pos: 85221923
Relay_Master_Log_File: master-bin.007220
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB: mysql,test
Replicate_Do_Table:
Replicate_Ignore_Table: CISELNIKY.admin
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table: TEMPTABLES.%,test.%
Last_Errno: 1032
Last_Error: Could not execute Update_rows event on table CISELNIKY.hyporates; Can't find record in 'hyporates', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.007220, end_log_pos 85222632
Skip_Counter: 0
Exec_Master_Log_Pos: 85221638
Relay_Log_Space: 766705562
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 1032
Last_SQL_Error: Could not execute Update_rows event on table CISELNIKY.hyporates; Can't find record in 'hyporates', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.007220, end_log_pos 85222632
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1
1 row in set (0.00 sec)
ERROR: No query specified
We have problem at Relay_Log_File: db-relaylog.000017 and Relay_Log_Pos: 85221923. So, we have to get some details about it. We have to try decode binlog to human readable format, like this:
mysqlbinlog --base64-output=DECODE-ROWS -v db-relaylog.000017 > decoded.log
and subsequently, use less to display output file, and find appropriated position (Relay_Log_Pos: 85221923):
and it shows problematic update:
# at 85221923 #161007 0:35:04 server id 1 end_log_pos 85221714 Query thread_id=6764694 exec_time=0 error_code=0 SET TIMESTAMP=1475793304/*!*/; BEGIN /*!*/; # at 85221999 # at 85222059 #161007 0:35:04 server id 1 end_log_pos 85221774 Table_map: `CISELNIKY`.`hyporates` mapped to number 301639 #161007 0:35:04 server id 1 end_log_pos 85222632 Update_rows: table id 301639 flags: STMT_END_F ### UPDATE `CISELNIKY`.`hyporates` ### WHERE ### @1=3493 ### @2=1 ### @3=19 ### @4=0 ### @5=3 ### @6=1.99 ### SET ### @1=3529 ### @2=1 ### @3=19 ### @4=0 .. .. ..
Full explanation is on https://www.percona.com/blog/2010/05/06/debugging-problems-with-row-based-replication/