[MDEV-18730] MariaDB 10.4 debug build failed with Streaming Replication and Binary Logging enabled Created: 2019-02-25  Updated: 2019-03-15  Resolved: 2019-03-15

Status: Closed
Project: MariaDB Server
Component/s: Galera
Affects Version/s: 10.4.3
Fix Version/s: 10.4.4

Type: Bug Priority: Major
Reporter: Shahriyar Rzayev (Inactive) Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: galera


 Description   

Basically the scenario is:
• Debug build - 10.4
• Cluster with both streaming replication and binlog enabled
• Sysbench load with more than one threads

MariaDB [(none)]> select @@wsrep_trx_fragment_size;
+---------------------------+
| @@wsrep_trx_fragment_size |
+---------------------------+
|                         3 |
+---------------------------+
1 row in set (0.001 sec)
 
MariaDB [(none)]> select @@wsrep_trx_fragment_unit;
+---------------------------+
| @@wsrep_trx_fragment_unit |
+---------------------------+
| bytes                     |
+---------------------------+
1 row in set (0.002 sec)
 
MariaDB [(none)]> select @@log_bin;
+-----------+
| @@log_bin |
+-----------+
|         1 |
+-----------+
1 row in set (0.002 sec)

Doing sysbench run:

$ sysbench oltp_read_write --mysql-host=localhost --mysql-user=root --mysql-db=sbtest2 --mysql-socket=/tmp/mysql-node2.sock --tables=10 --table-size=10000 --threads=10 run
sysbench 1.0.16 (using bundled LuaJIT 2.1.0-beta2)
 
Running the test with following options:
Number of threads: 10
Initializing random number generator from current time
 
 
Initializing worker threads...
 
Threads started!
 
FATAL: mysql_stmt_execute() returned error 2013 (Lost connection to MySQL server during query) for query 'COMMIT'
(last message repeated 4 times)
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:409: SQL error, errno = 2013, state = 'HY000': Lost connection to MySQL server during query
(last message repeated 1 times)
FATAL: mysql_stmt_execute() returned error 2013 (Lost connection to MySQL server during query) for query 'COMMIT'
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:409: SQL error, errno = 2013, state = 'HY000': Lost connection to MySQL server during query
(last message repeated 3 times)
FATAL: mysql_stmt_execute() returned error 2013 (Lost connection to MySQL server during query) for query 'COMMIT'
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:409: SQL error, errno = 2013, state = 'HY000': Lost connection to MySQL server during query
FATAL: mysql_stmt_execute() returned error 2013 (Lost connection to MySQL server during query) for query 'COMMIT'
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:409: SQL error, errno = 2013, state = 'HY000': Lost connection to MySQL server during query
FATAL: mysql_stmt_execute() returned error 2013 (Lost connection to MySQL server during query) for query 'COMMIT'
(last message repeated 1 times)
FATAL: `thread_run' function failed: /usr/share/sysbench/oltp_common.lua:409: SQL error, errno = 2013, state = 'HY000': Lost connection to MySQL server during query

From node2:

mysqld: /home/shako/Galera_Tests/MariaDB/storage/innobase/trx/trx0rseg.cc:92: void trx_rseg_update_wsrep_checkpoint(trx_rsegf_t*, const XID*, mtr_t*): Assertion `xid_seqno > wsrep_seqno' failed.
190225 16:39:22 [ERROR] mysqld got signal 6 ;
Server version: 10.4.3-MariaDB-debug-log
 
Thread pointer: 0x7ff960000d60
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x7ffa194c4ea0 thread_stack 0x49000
/home/shako/Galera_Tests/dbs/maria_10.4/bin/mysqld(my_print_stacktrace+0x40)[0x55eb8c4a974b]
mysys/stacktrace.c:269(my_print_stacktrace)[0x55eb8bcd7fc6]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7ffa4228a890]
linux/raise.c:51(__GI_raise)[0x7ffa41382e97]
stdlib/abort.c:81(__GI_abort)[0x7ffa41384801]
assert/assert.c:89(__assert_fail_base)[0x7ffa4137439a]
/lib/x86_64-linux-gnu/libc.so.6(+0x30412)[0x7ffa41374412]
/home/shako/Galera_Tests/dbs/maria_10.4/bin/mysqld(+0xf01448)[0x55eb8c11a448]
trx/trx0rseg.cc:94(trx_rseg_update_wsrep_checkpoint(unsigned char*, xid_t const*, mtr_t*))[0x55eb8c0ff5a4]
trx/trx0purge.cc:290(trx_purge_add_undo_to_history(trx_t const*, trx_undo_t*&, mtr_t*))[0x55eb8c12499f]
trx/trx0trx.cc:1095(trx_write_serialisation_history(trx_t*, mtr_t*))[0x55eb8c126424]
trx/trx0trx.cc:1523(trx_commit_low(trx_t*, mtr_t*))[0x55eb8c126577]
trx/trx0trx.cc:1557(trx_commit(trx_t*))[0x55eb8c126983]
trx/trx0trx.cc:1708(trx_commit_for_mysql(trx_t*))[0x55eb8bf06186]
handler/ha_innodb.cc:4409(innobase_commit_low(trx_t*))[0x55eb8bf0654d]
handler/ha_innodb.cc:4531(innobase_commit_ordered_2(trx_t*, THD*))[0x55eb8bf0677e]
handler/ha_innodb.cc:4591(innobase_commit_ordered(handlerton*, THD*, bool))[0x55eb8be05427]
sql/log.cc:8860(TC_LOG::run_commit_ordered(THD*, bool))[0x55eb8be032cf]
sql/log.cc:8110(MYSQL_BIN_LOG::trx_group_commit_leader(MYSQL_BIN_LOG::group_commit_entry*))[0x55eb8be01f28]
sql/log.cc:7700(MYSQL_BIN_LOG::write_transaction_to_binlog_events(MYSQL_BIN_LOG::group_commit_entry*))[0x55eb8be01510]
sql/log.cc:7370(MYSQL_BIN_LOG::write_transaction_to_binlog(THD*, binlog_cache_mngr*, Log_event*, bool, bool, bool))[0x55eb8bdf16dc]
sql/log.cc:1785(binlog_flush_cache(THD*, binlog_cache_mngr*, Log_event*, bool, bool, bool))[0x55eb8bdf1cf6]
sql/log.cc:1893(binlog_commit_flush_xid_caches(THD*, binlog_cache_mngr*, bool, unsigned long long))[0x55eb8be076a9]
sql/log.cc:9642(MYSQL_BIN_LOG::log_and_order(THD*, unsigned long long, bool, bool, bool))[0x55eb8bcdd465]
sql/handler.cc:1585(ha_commit_trans(THD*, bool))[0x55eb8bb21310]
sql/transaction.cc:313(trans_commit(THD*))[0x55eb8b9a2cd7]
sql/sql_parse.cc:5865(mysql_execute_command(THD*))[0x55eb8b9c86c1]
sql/sql_prepare.cc:4735(Prepared_statement::execute(String*, bool))[0x55eb8b9c6c97]
sql/sql_prepare.cc:4221(Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*))[0x55eb8b9c4551]
sql/sql_prepare.cc:3230(mysql_stmt_execute_common(THD*, unsigned long, unsigned char*, unsigned char*, unsigned long, bool, bool))[0x55eb8b9c40f3]
sql/sql_prepare.cc:3127(mysqld_stmt_execute(THD*, char*, unsigned int))[0x55eb8b994e54]
sql/sql_parse.cc:1753(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x55eb8b993b48]
sql/sql_parse.cc:1357(do_command(THD*))[0x55eb8bb0c4d7]
sql/sql_connect.cc:1399(do_handle_one_connection(CONNECT*))[0x55eb8bb0c23b]
nptl/pthread_create.c:463(start_thread)[0x7ffa4227f6db]
x86_64/clone.S:97(clone)[0x7ffa4146588f]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7ff96001d088): COMMIT
Connection ID (thread ID): 118640
Status: NOT_KILLED



 Comments   
Comment by Teemu Ollakka [ 2019-02-25 ]

The assertion is caused by commit order violation between streaming transaction fragment commit and transaction commit which is going through binlog group commit.

Generated at Thu Feb 08 08:46:18 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.