Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.3(EOL)
-
None
Description
http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest2/builds/9482/steps/test_3/logs/stdio
rpl.rpl_concurrency_error 'innodb,stmt' w2 [ fail ]
|
Test ended at 2017-09-05 12:47:50
|
|
|
CURRENT_TEST: rpl.rpl_concurrency_error
|
/mnt/buildbot/build/mariadb-10.3.2/client/mysqltest: Error on delete of '/mnt/buildbot/build/mariadb-10.3.2/mysql-test/var/2/tmp/_var_file_479b03f5-921f-11e7-81e7-525400123456.inc' (Errcode: 2 "No such file or directory")
|
/mnt/buildbot/build/mariadb-10.3.2/client/mysqltest: Error on delete of '/mnt/buildbot/build/mariadb-10.3.2/mysql-test/var/2/tmp/_var_file_47ae05a4-921f-11e7-81e7-525400123456.inc' (Errcode: 2 "No such file or directory")
|
mysqltest: In included file "./include/rpl_diff.inc":
|
included from /mnt/buildbot/build/mariadb-10.3.2/mysql-test/suite/rpl/t/rpl_concurrency_error.test at line 134:
|
At line 113: command "diff_files" failed with error: 1 my_errno: 175 errno: -1
|
|
|
The result from queries just before the failure was:
|
< snip >
|
master-bin.000001 # Xid # # COMMIT /* XID */
|
master-bin.000001 # Gtid # # BEGIN GTID #-#-#
|
master-bin.000001 # Query # # use `test`; UPDATE IGNORE t SET f = 'dark blue 1' WHERE f = 'red'
|
master-bin.000001 # Query # # use `test`; INSERT INTO t VALUES (6 + (1 * 10),"brown")
|
master-bin.000001 # Xid # # COMMIT /* XID */
|
connection master;
|
connection slave;
|
include/rpl_diff.inc
|
include/rpl_diff.inc
|
--- /mnt/buildbot/build/mariadb-10.3.2/mysql-test/var/2/tmp/_rpl_diff_server-2.tmp 2017-09-05 12:47:50.274257071 +0300
|
+++ /mnt/buildbot/build/mariadb-10.3.2/mysql-test/var/2/tmp/_rpl_diff_server-1.tmp 2017-09-05 12:47:50.250257073 +0300
|
@@ -5,7 +5,7 @@
|
2017-09-05 12:47:42 updated t: red -> dark blu
|
2017-09-05 12:47:42 updated t: yellow 2 -> gray 2
|
2017-09-05 12:47:44 brown
|
-2017-09-05 12:47:44 updated t: gray 2 -> yellow 1
|
+2017-09-05 12:47:45 updated t: gray 2 -> yellow 1
|
2017-09-05 12:47:45 updated t: red -> magenta
|
2017-09-05 12:47:47 brown
|
2017-09-05 12:47:47 updated t: red -> dark blu
|
|
|
2017-09-05 12:47:39 16 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE t SET f = 'yellow 2' WHERE i = 3
|
2017-09-05 12:47:41 17 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE IGNORE t SET f = 'magenta 2' WHERE f = 'red'
|
2017-09-05 12:47:41 17 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. UPDATE IGNORE is unsafe because the order in which rows are updated determines which (if any) rows are ignored. This order cannot be predicted and may differ on master and the slave Statement: UPDATE IGNORE t SET f = 'magenta 2' WHERE f = 'red'
|
2017-09-05 12:47:42 16 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE t SET f = 'gray 2' WHERE i = 3
|
2017-09-05 12:47:44 17 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE IGNORE t SET f = 'dark blue 2' WHERE f = 'red'
|
2017-09-05 12:47:44 17 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. UPDATE IGNORE is unsafe because the order in which rows are updated determines which (if any) rows are ignored. This order cannot be predicted and may differ on master and the slave Statement: UPDATE IGNORE t SET f = 'dark blue 2' WHERE f = 'red'
|
2017-09-05 12:47:45 16 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE t SET f = 'yellow 1' WHERE i = 3
|
2017-09-05 12:47:47 17 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE IGNORE t SET f = 'magenta 1' WHERE f = 'red'
|
2017-09-05 12:47:47 17 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. UPDATE IGNORE is unsafe because the order in which rows are updated determines which (if any) rows are ignored. This order cannot be predicted and may differ on master and the slave Statement: UPDATE IGNORE t SET f = 'magenta 1' WHERE f = 'red'
|
2017-09-05 12:47:47 16 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE t SET f = 'gray 1' WHERE i = 3
|
2017-09-05 12:47:49 17 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE IGNORE t SET f = 'dark blue 1' WHERE f = 'red'
|
2017-09-05 12:47:49 17 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. UPDATE IGNORE is unsafe because the order in which rows are updated determines which (if any) rows are ignored. This order cannot be predicted and may differ on master and the slave Statement: UPDATE IGNORE t SET f = 'dark blue 1' WHERE f = 'red'
|
2017-09-05 12:47:41 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE t SET f = 'yellow 2' WHERE i = 3
|
2017-09-05 12:47:41 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE IGNORE t SET f = 'magenta 2' WHERE f = 'red'
|
2017-09-05 12:47:41 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. UPDATE IGNORE is unsafe because the order in which rows are updated determines which (if any) rows are ignored. This order cannot be predicted and may differ on master and the slave Statement: UPDATE IGNORE t SET f = 'magenta 2' WHERE f = 'red'
|
2017-09-05 12:47:44 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE t SET f = 'gray 2' WHERE i = 3
|
2017-09-05 12:47:44 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE IGNORE t SET f = 'dark blue 2' WHERE f = 'red'
|
2017-09-05 12:47:44 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. UPDATE IGNORE is unsafe because the order in which rows are updated determines which (if any) rows are ignored. This order cannot be predicted and may differ on master and the slave Statement: UPDATE IGNORE t SET f = 'dark blue 2' WHERE f = 'red'
|
2017-09-05 12:47:47 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE t SET f = 'yellow 1' WHERE i = 3
|
2017-09-05 12:47:47 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE IGNORE t SET f = 'magenta 1' WHERE f = 'red'
|
2017-09-05 12:47:47 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. UPDATE IGNORE is unsafe because the order in which rows are updated determines which (if any) rows are ignored. This order cannot be predicted and may differ on master and the slave Statement: UPDATE IGNORE t SET f = 'magenta 1' WHERE f = 'red'
|
2017-09-05 12:47:49 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE t SET f = 'gray 1' WHERE i = 3
|
2017-09-05 12:47:49 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement accesses nontransactional table as well as transactional or temporary table, and writes to any of them Statement: UPDATE IGNORE t SET f = 'dark blue 1' WHERE f = 'red'
|
2017-09-05 12:47:49 13 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. UPDATE IGNORE is unsafe because the order in which rows are updated determines which (if any) rows are ignored. This order cannot be predicted and may differ on master and the slave Statement: UPDATE IGNORE t SET f = 'dark blue 1' WHERE f = 'red'
|
Attachments
Activity
Hi Elkin,
the patch "[Commits] 99c40e0628d: MDEV-13727 rpl.rpl_concurrency_error failed" looks ok for me.
Thanks.
Made a patch, discussed it with Bar. Todo: need to understand fully what the changes of MDEV-8305 has to do wrt the current timestamp computation (apart from the slow log reporting).
Analyzed MDEV-8305 in details to stick to initial patch that blocks the session timestamp resetting (via THD::set_time()) when the current statement belongs to either a stored func or a trigger.
Alternative method is drafted into the patch as comments (limited to the trigger case while it applies to the SF as well).
Which method to settle upon is left to review discussion.
Monty, hello.
The patch deals with a relatively new feature of MDEV-8305. I discussed the issue and my fixing method initially with Bar (who made me something to think about), but considering complexity of the case we decided to engage you for reviewing.
Could you please look at few-liner patch:
From: andrei.elkin@pp.inet.fi
Subject: [Commits] 0768dcbbde5: MDEV-13727 top-level query timestamp reset
at stored func/trigger internal statements
I also show another method which in commented lines that you will see.
Cheers,
Andrei
Agreed with Andrei about a simpler patch to solve this issue.
- Just remove the time setting code in execute(). It's not needed.
Took over Monty's refinement of my patch and added up removal of QUERY_START_TIME_INFO related which served exclusively to help
implementing of being removed the time backup/reset/restore inside sp_instr_stmt::execute.
Tested (on very slow BB- and analyzed failures potentially related - none to find).
recent occurance http://buildbot.askmonty.org/buildbot/builders/mac-1012-bintar/builds/3177/steps/test/logs/stdio
rpl.rpl_concurrency_error 'innodb,stmt' [ fail ]Test ended at 2018-04-03 09:17:44CURRENT_TEST: rpl.rpl_concurrency_error/Users/buildbot/maria-slave/mac-1012-bintar/build/client/mysqltest: Error on delete of '/Users/buildbot/maria-slave/mac-1012-bintar/build/mysql-test/var/tmp/_var_file_64d0ac48-3741-11e8-be37-ac87a33b471c.inc' (Errcode: 2 "No such file or directory")/Users/buildbot/maria-slave/mac-1012-bintar/build/client/mysqltest: Error on delete of '/Users/buildbot/maria-slave/mac-1012-bintar/build/mysql-test/var/tmp/_var_file_64d8aab0-3741-11e8-be37-ac87a33b471c.inc' (Errcode: 2 "No such file or directory")mysqltest: In included file "./include/rpl_diff.inc":included from /Users/buildbot/maria-slave/mac-1012-bintar/build/mysql-test/suite/rpl/t/rpl_concurrency_error.test at line 134:At line 113: command "diff_files" failed with error: 1 my_errno: 175 errno: -1The result from queries just before the failure was:< snip >master-bin.000001 # Query # # use `test`; UPDATE t SET f = 'gray 1' WHERE i = 3master-bin.000001 # Xid # # COMMIT /* XID */master-bin.000001 # Gtid # # BEGIN GTID #-#-#master-bin.000001 # Query # # use `test`; UPDATE IGNORE t SET f = 'dark blue 1' WHERE f = 'red'master-bin.000001 # Query # # use `test`; INSERT INTO t VALUES (6 + (1 * 10),"brown")master-bin.000001 # Xid # # COMMIT /* XID */connection master;connection slave;include/rpl_diff.incinclude/rpl_diff.inc--- /Users/buildbot/maria-slave/mac-1012-bintar/build/mysql-test/var/tmp/_rpl_diff_server-2.tmp 2018-04-03 09:17:43.000000000 -0400+++ /Users/buildbot/maria-slave/mac-1012-bintar/build/mysql-test/var/tmp/_rpl_diff_server-1.tmp 2018-04-03 09:17:43.000000000 -0400@@ -1,6 +1,6 @@d f-2018-04-03 09:17:34 updated t: yelow -> yellow 22018-04-03 09:17:35 updated t: red -> magenta+2018-04-03 09:17:35 updated t: yelow -> yellow 22018-04-03 09:17:37 brown2018-04-03 09:17:37 updated t: red -> dark blu2018-04-03 09:17:37 updated t: yellow 2 -> gray 2