| Bug #98840 | sql syntax error on replication slave(using prepared statement) | ||
|---|---|---|---|
| Submitted: | 5 Mar 2020 10:32 | Modified: | 13 Mar 2020 2:21 |
| Reporter: | youngjae joe | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S1 (Critical) |
| Version: | 5.7.22 | OS: | Linux |
| Assigned to: | CPU Architecture: | x86 | |
| Tags: | case expression, prepared statement, replication | ||
[5 Mar 2020 10:36]
youngjae joe
Master/Slave System Variables - Replication : semi-sync replication, no multi thread replication, no GTID - binlog_format : MIXED - tx_isolation : REPEATABLE-READ - character_set_server : utf8mb4 - collation_server : utf8mb4_general_ci - sql_mode : STRICT_TRANS_TABLES,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION
[6 Mar 2020 5:05]
MySQL Verification Team
Hello youngjae joe, Thank you for the report and test case. With the provided test case, issue seen in 5.7.22/23/24/25/26/27(with MIXED binlog format), but it is not observed since 5.7.28+(also, 5.6.47 and 8.0.19 checked but not affected). Please note that we don't fix bugs in old versions, don't backport bug fixes, so you need to check with latest version anyway. So, please, upgrade and inform us if problem still exists. Thank you. regards, Umesh
[6 Mar 2020 5:36]
youngjae joe
Hello Umesh Shastry, Is it a bug? Can you explain exactly what the problem is? and, If 5.7.28+ does not occur, please let me know the patch (release note link, etc.)? regards, youngjae joe
[6 Mar 2020 6:14]
MySQL Verification Team
Yes, it is a bug(5.7.22/23/24).
If you see the contents of master's binary log from 5.7.22:
master-bin.000001 837 Anonymous_Gtid 1 902 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'
master-bin.000001 902 Query 1 995 BEGIN
master-bin.000001 995 Intvar 1 1027 INSERT_ID=1
master-bin.000001 1027 Query 1 1289 use `testdatbase`; insert into testtable (
status_a
, status_b
)
values (
'CHECK',
case ?
when 'RESERVATION' then 'IMMEDIATLY'
'WAITING'when 'PROCESSING' then 'RESERVATION' <-----
end
)
master-bin.000001 1289 Xid 1 1320 COMMIT /* xid=187 */
^^ clearly 2 issues, value missing for @var_status_b_01 and rest messed.
master-bin.000001 1027 Query 1 1289 use `testdatbase`; insert into testtable (
status_a
, status_b
)
values (
'CHECK',
case 'RESERVATION'
when 'IMMEDIATLY' then 'PROCESSING'
when 'RESERVATION' then 'WAITING'
end
)
master-bin.000001 1289 Xid 1 1320 COMMIT /* xid=187 */
I'm not able to locate exact bug# from the release notes confirming on bug# which fixed this issue from 5.7.28+(diff issue altogether in 5.7.25/26/27 than original), will check internally and hope to respond next week.
regards,
Umesh
[13 Mar 2020 2:21]
youngjae joe
Hello Umesh Shastry, The same problem occurs when you change binlog_format to ROW Wrong parsing from "general log". binlog_format = 'ROW' binlog_row_image = 'MINIMAL' or 'FULL' binlog_rows_query_log_events = 1 Is mysql version upgrade the only solution? regards, youngjae joe
Description: The prepared statement performed on the master causes sql syntax error only on slave, then slave replication stopped. but, sql syntax error does not occur in Master and is normally commited. When I look at the binlog and general log, the syntax changes strangely and the binding doesn't work properly on slave. 1. Why does an error occur in Slave although it runs normally on Master? 2. Is it a problem of case expression, or a problem of application, or a problem of prepared statements? 3. What is the solution? --========================================================= -- after execution. --========================================================= --========================================================= -- on Master : --========================================================= root@localhost:testdatbase 18:48:06>select * from testtable; +----+----------+----------+ | id | status_a | status_b | +----+----------+----------+ | 1 | CHECK | NULL | +----+----------+----------+ 1 row in set (0.00 sec) -- 1. master binary log .......... # at 1388 #200305 18:48:00 server id 2 end_log_pos 1388 CRC32 0xa241146c Intvar SET INSERT_ID=1/*!*/; #200305 18:48:00 server id 2 end_log_pos 1654 CRC32 0x78b07b4d Query thread_id=34403592 exec_time=0 error_code=0 use `testdatbase`/*!*/; SET TIMESTAMP=1583401680/*!*/; insert into testtable ( `status_a` , `status_b` ) values ( 'CHECK', case ? when 'RESERVATION' then 'IMMEDIATLY' 'WAITING'when 'PROCESSING' then 'RESERVATION' end ) /*!*/; # at 1654 #200305 18:48:00 server id 2 end_log_pos 1685 CRC32 0x9c24885f Xid = 226346305 COMMIT/*!*/; .......... -- 2. master general_log 2020-03-05T18:47:53.057269+09:00 34403592 Query PREPARE stmt1 FROM ... 2020-03-05T18:47:53.057496+09:00 34403592 Prepare insert into testtable ( `status_a` , `status_b` ) values ( ?, case ? when ? then ? when ? then ? end ) ...................... 2020-03-05T18:47:56.364371+09:00 34403592 Query set @var_status_a = 'CHECK' 2020-03-05T18:47:56.364818+09:00 34403592 Query set @var_status_b_01 = 'RESERVATION' 2020-03-05T18:47:56.365162+09:00 34403592 Query set @var_status_b_02 = 'IMMEDIATLY' 2020-03-05T18:47:56.365484+09:00 34403592 Query set @var_status_b_03 = 'PROCESSING' 2020-03-05T18:47:56.365793+09:00 34403592 Query set @var_status_b_04 = 'RESERVATION' 2020-03-05T18:47:56.648233+09:00 34403592 Query set @var_status_b_05 = 'WAITING' ...................... 2020-03-05T18:48:00.402209+09:00 34403592 Query EXECUTE stmt1 USING @var_status_a ,@var_status_b_01 ,@var_status_b_02 ,@var_status_b_03 ,@var_status_b_04 ,@var_status_b_05 2020-03-05T18:48:00.402331+09:00 34403592 Execute insert into testtable ( `status_a` , `status_b` ) values ( 'CHECK', case ? when 'RESERVATION' then 'IMMEDIATLY' 'WAITING'when 'PROCESSING' then 'RESERVATION' end ) ...................... 2020-03-05T18:48:02.994193+09:00 34403592 Query DEALLOCATE PREPARE stmt1 root@localhost:testdatbase 18:49:46>select * from testtable; Empty set (0.00 sec) root@localhost:testdatbase 18:49:25>show slave status\G; *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 10.127.33.36 Master_User: repluser Master_Port: 20306 Connect_Retry: 60 Master_Log_File: binary_log.000021 Read_Master_Log_Pos: 6070 Relay_Log_File: relay_log.000035 Relay_Log_Pos: 1413 Relay_Master_Log_File: binary_log.000020 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: 1064 Last_Error: Error 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '? when 'RESERVATION' then 'IMMEDIATLY' 'WAITING'when 'PROCESSING' then 'R' at line 7' on query. Default database: 'testdatbase'. Query: 'insert into testtable ( `status_a` , `status_b` ) values ( 'CHECK', case ? when 'RESERVATION' then 'IMMEDIATLY' 'WAITING'when 'PROCESSING' then 'RESERVATION' end )' Skip_Counter: 0 Exec_Master_Log_Pos: 1198 Relay_Log_Space: 9446 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: Yes Master_SSL_CA_File: /mysql/MyHome/ssldir/ca.pem Master_SSL_CA_Path: Master_SSL_Cert: /mysql/MyHome/ssldir/client-cert.pem Master_SSL_Cipher: Master_SSL_Key: /mysql/MyHome/ssldir/client-key.pem Seconds_Behind_Master: NULL Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 1064 Last_SQL_Error: Error 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '? when 'RESERVATION' then 'IMMEDIATLY' 'WAITING'when 'PROCESSING' then 'R' at line 7' on query. Default database: 'testdatbase'. Query: 'insert into testtable ( `status_a` , `status_b` ) values ( 'CHECK', case ? when 'RESERVATION' then 'IMMEDIATLY' 'WAITING'when 'PROCESSING' then 'RESERVATION' end )' Replicate_Ignore_Server_Ids: Master_Server_Id: 2 Master_UUID: 889e0ea5-7846-11e9-b553-fa163fb75767 Master_Info_File: /home1/mysql/MyHome/data/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: 200305 18:49:10 Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: Executed_Gtid_Set: Auto_Position: 0 Replicate_Rewrite_DB: Channel_Name: Master_TLS_Version: 1 row in set (0.00 sec) How to repeat: -- On Master : CREATE DATABASE testdatbase /*!40100 DEFAULT CHARACTER SET utf8mb4 */ ; use testdatbase; CREATE TABLE testtable ( `id` int(11) NOT NULL AUTO_INCREMENT , `status_a` enum('SUCCESS','CHECK','FAIL','DELETED') , `status_b` enum('WAITING','PROCESSING','SUCCESS','FAIL') DEFAULT 'WAITING' , PRIMARY KEY (`id`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COMMENT='`testtable`'; show create table `testtable`\G; PREPARE stmt1 FROM 'insert into testtable ( `status_a` , `status_b` ) values ( ?, case ? when ? then ? when ? then ? end )'; set @var_status_a = 'CHECK'; set @var_status_b_01 = 'RESERVATION'; set @var_status_b_02 = 'IMMEDIATLY'; set @var_status_b_03 = 'PROCESSING'; set @var_status_b_04 = 'RESERVATION'; set @var_status_b_05 = 'WAITING'; EXECUTE stmt1 USING @var_status_a ,@var_status_b_01 ,@var_status_b_02 ,@var_status_b_03 ,@var_status_b_04 ,@var_status_b_05 ; DEALLOCATE PREPARE stmt1;