[MDEV-10156] Group commit tests fail on 10.2 InnoDB (branch bb-10.2-jan) Created: 2016-05-31  Updated: 2016-09-02  Resolved: 2016-08-30

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Tests
Affects Version/s: 10.2
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Jan Lindström (Inactive) Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
PartOf
is part of MDEV-10024 Fix test failures on InnoDB 5.7 in Ma... Closed

 Description   

bb-10.2-jan
commit 3f1b8c9474e351e50a6556675108864d5aac5528



 Comments   
Comment by Jan Lindström (Inactive) [ 2016-05-31 ]

innodb.group_commit_binlog_pos [ disabled ] MDEV-10156
innodb.group_commit_binlog_pos_no_optimize_thread [ disabled ] MDEV-10156

Comment by Jan Lindström (Inactive) [ 2016-08-12 ]

This with InnoDB 5.7 in branch bb-10.2-jan (please wait for email about status):

--- /home/jan/mysql/10.2/mysql-test/suite/innodb/r/group_commit_binlog_pos_no_optimize_thread.result	2016-06-30 15:27:02.879686356 +0300
+++ /home/jan/mysql/10.2/mysql-test/suite/innodb/r/group_commit_binlog_pos_no_optimize_thread.reject	2016-08-12 09:40:33.801544117 +0300
@@ -44,6 +44,6 @@
 1
 2
 3
-InnoDB: Last MySQL binlog file position 0 <pos>, file name ./master-bin.000001
+InnoDB: Last MySQL binlog file position 0 645, file name ./master-bin.000001
 SET DEBUG_SYNC= 'RESET';
 DROP TABLE t1;
 
mysqltest: Result length mismatch
 
 - saving '/dev/shm/log/innodb.group_commit_binlog_pos_no_optimize_thread-xtradb/' to '/dev/shm/log/innodb.group_commit_binlog_pos_no_optimize_thread-xtradb/'
innodb.group_commit_crash_no_optimize_thread 'xtradb' [ pass ]   9963
innodb.group_commit_no_optimize_thread 'xtradb' [ pass ]     31
innodb.group_commit_binlog_pos 'xtradb'  [ fail ]
        Test ended at 2016-08-12 09:40:50
 
CURRENT_TEST: innodb.group_commit_binlog_pos
--- /home/jan/mysql/10.2/mysql-test/suite/innodb/r/group_commit_binlog_pos.result	2016-06-30 15:27:02.879686356 +0300
+++ /home/jan/mysql/10.2/mysql-test/suite/innodb/r/group_commit_binlog_pos.reject	2016-08-12 09:40:50.673675294 +0300
@@ -43,6 +43,6 @@
 1
 2
 3
-InnoDB: Last MySQL binlog file position 0 <pos>, file name ./master-bin.000001
+InnoDB: Last MySQL binlog file position 0 645, file name ./master-bin.000001
 SET DEBUG_SYNC= 'RESET';
 DROP TABLE t1;

Comment by Michael Widenius [ 2016-08-29 ]

In 10.2 base, the first 2 INSERT statements are committed and the last INSERT is in prepared stage when the server is forced to restart.
In bb-10.2-jan all threads are in prepared stage when the server is restarted.

This causes the binlog file position to be different, as this points to where in the binlog the last row was committed, which is now different.

This can be see in this part of the mysqld.1.err log for the new tree:
2016-08-29 12:12:07 140508343482240 [Note] InnoDB: Starting recovery for XA transactions...
2016-08-29 12:12:07 140508343482240 [Note] InnoDB: Transaction 1286 in prepared state after recovery
2016-08-29 12:12:07 140508343482240 [Note] InnoDB: Transaction contains changes to 1 rows
2016-08-29 12:12:07 140508343482240 [Note] InnoDB: Transaction 1285 in prepared state after recovery
2016-08-29 12:12:07 140508343482240 [Note] InnoDB: Transaction contains changes to 1 rows
2016-08-29 12:12:07 140508343482240 [Note] InnoDB: Transaction 1284 in prepared state after recovery
2016-08-29 12:12:07 140508343482240 [Note] InnoDB: Transaction contains changes to 1 rows
2016-08-29 12:12:07 140508343482240 [Note] InnoDB: 3 transactions in prepared state after recovery

One possible reason for this is that the signalling of the condition con1_loop is now done before the transaction is fully committed.

Comment by Michael Widenius [ 2016-08-30 ]

Bug fix given to Jan
Problem was that Innobase_commit didn't call trx_commit_complete_for_mysql()

Generated at Thu Feb 08 07:40:05 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.