Bug #113663 Crash occurs when applying binlog_transaction_dependency_tracking to slave node.
Submitted: 17 Jan 2024 11:37 Modified: 17 Jan 2024 11:44
Reporter: donghyuk park Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:8.0.32 OS:CentOS
Assigned to: CPU Architecture:x86
Tags: replication

[17 Jan 2024 11:37] donghyuk park 
Description:
hi 

sysbench testing ...

The options below were applied to reduce replication delays.

binlog_transaction_dependency_tracking = writeset 

And while testing by changing the option below, a signal 11 error occurred and MySQL Server restarted.

binlog_transaction_dependency_tracking = writeset  >> writeset_session 

The opposite also happens.

binlog_transaction_dependency_tracking = writeset_session  >> writeset

The following is the error log contents.

2024-01-16T12:06:02Z UTC - mysqld got signal 11 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
BuildID[sha1]=d2278b3be8dd910aa7a52159bba3b72d8ac0277c
Thread pointer: 0x7fbdb83090d0
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 = 7fe8ba8b2c80 thread_stack 0x100000
/home/mysql/MySQL_8032/bin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x2e) [0x207b9be]
/home/mysql/MySQL_8032/bin/mysqld(print_fatal_signal(int)+0x3c3) [0x1114d23]
/home/mysql/MySQL_8032/bin/mysqld(handle_fatal_signal+0x65) [0x1114d95]
/lib64/libpthread.so.0(+0xf630) [0x7fea25815630]
/lib64/libstdc++.so.6(std::_Rb_tree_insert_and_rebalance(bool, std::_Rb_tree_node_base*, std::_Rb_tree_node_base*, std::_Rb_tree_node_base&)+0x68) [0x7fea24373318]
/home/mysql/MySQL_8032/bin/mysqld(std::pair<std::_Rb_tree_iterator<std::pair<unsigned long const, long> >, bool> std::_Rb_tree<unsigned long, std::pair<unsigned long const, long>, std::_Select1st<std::pair<unsigned long const, long> >, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, long> > >::_M_emplace_unique<std::pair<unsigned long, long> >(std::pair<unsigned long, long>&&)+0x96) [0x1cfa466]
/home/mysql/MySQL_8032/bin/mysqld(Writeset_trx_dependency_tracker::get_dependency(THD*, long&, long&)+0x1fe) [0x1cfa6fe]
/home/mysql/MySQL_8032/bin/mysqld(Transaction_dependency_tracker::get_dependency(THD*, long&, long&)+0x87) [0x1cfa7a7]
/home/mysql/MySQL_8032/bin/mysqld(MYSQL_BIN_LOG::write_transaction(THD*, binlog_cache_data*, Binlog_event_writer*)+0x4d) [0x1cb051d]
/home/mysql/MySQL_8032/bin/mysqld(binlog_cache_data::flush(THD*, unsigned long long*, bool*)+0x146) [0x1cb09f6]
/home/mysql/MySQL_8032/bin/mysqld(MYSQL_BIN_LOG::flush_thread_caches(THD*)+0x8e) [0x1cb0abe]
/home/mysql/MySQL_8032/bin/mysqld(MYSQL_BIN_LOG::process_flush_stage_queue(unsigned long long*, bool*, THD**)+0xd8) [0x1cb0c68]
/home/mysql/MySQL_8032/bin/mysqld(MYSQL_BIN_LOG::ordered_commit(THD*, bool, bool)+0xf5) [0x1cb0e35]
/home/mysql/MySQL_8032/bin/mysqld(MYSQL_BIN_LOG::commit(THD*, bool)+0x7c6) [0x1cb26c6]
/home/mysql/MySQL_8032/bin/mysqld(ha_commit_trans(THD*, bool, bool)+0x1ec) [0x1214ecc]
/home/mysql/MySQL_8032/bin/mysqld(trans_commit(THD*, bool)+0x4b) [0x10ca01b]
/home/mysql/MySQL_8032/bin/mysqld(mysql_execute_command(THD*, bool)+0x1f6e) [0xfaedde]
/home/mysql/MySQL_8032/bin/mysqld(Prepared_statement::execute(THD*, String*, bool)+0x9f4) [0xfddeb4]
/home/mysql/MySQL_8032/bin/mysqld(Prepared_statement::execute_loop(THD*, String*, bool)+0xfc) [0xfe2c2c]
/home/mysql/MySQL_8032/bin/mysqld(mysqld_stmt_execute(THD*, Prepared_statement*, bool, unsigned long, PS_PARAM*)+0x1a4) [0xfe3264]
/home/mysql/MySQL_8032/bin/mysqld(dispatch_command(THD*, COM_DATA const*, enum_server_command)+0x284a) [0xfb461a]
/home/mysql/MySQL_8032/bin/mysqld(do_command(THD*)+0x1df) [0xfb4e5f]
/home/mysql/MySQL_8032/bin/mysqld() [0x1105538]
/home/mysql/MySQL_8032/bin/mysqld() [0x280397a]
/lib64/libpthread.so.0(+0x7ea5) [0x7fea2580dea5]
/lib64/libc.so.6(clone+0x6d) [0x7fea23b168dd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7fbdb8216878): COMMIT
Connection ID (thread ID): 88
Status: NOT_KILLED

 

How to repeat:

MySQL Server Version 8.0.32 

sysbench testing 

Master server to apply option 

binlog_transaction_dependency_tracking = writeset  >> writeset_session 
binlog_transaction_dependency_tracking = writeset_session  >> writeset
[17 Jan 2024 11:44] MySQL Verification Team 
HI Mr. park,

Thank you for your bug report.

However, we can not repeat your report, since we require a fully repeatable test case.

Simply writing that you tested MySQL with sysbench does not mean anything ........

We need entire test case, so that we can try to repeat it.

Also, please use latest release, which is 8.0.35. Use the binary from our download site, which is on dev.mysql.com

When you have a repeatable test case with 8.0.35, please file a new bug report.

Can't repeat.
[17 Jan 2024 11:45] MySQL Verification Team 
Hi,

You have also noted that this is about replication, but we do not see in your description any mention of the replication.

Hence, include those informations in your new bug report.
[17 Jan 2024 12:04] MySQL Verification Team 
One last note.

We also require all your replication setting, since the problem occurs on the slave.

When filing a new bug, please set Category as we have  set it above.

Do also note that CentOS Linux is discontinued, so if we are not able to repeat it on Red Hat Linux or some new compatible Linux, we would not be able to verify your new report.
[20 Mar 4:59] Jinyou Ma 
Hello,

The bug can be reproduced in 8.0.41.
- running sysbench

mysql -BNe "create database test;"
sysbench oltp_update_index --threads=500 --time=60000 --tables=1 --table-size=100000 --db-driver=mysql --mysql-db=test --mysql-user="root" --mysql-password="" --mysql-storage-engine=InnoDB --report-interval=10 --mysql-socket=/var/lib/mysql/mysql.sock prepare
sysbench oltp_update_index --threads=500 --time=60000 --tables=1 --table-size=100000 --db-driver=mysql --mysql-db=test --mysql-user="root" --mysql-password="" --mysql-storage-engine=InnoDB --report-interval=10 --mysql-socket=/var/lib/mysql/mysql.sock run

- changing binlog_transaction_dependency_tracking

for i in {1..100}; do
{
	mysql -BNe "set global binlog_transaction_dependency_tracking = writeset_session ; set global binlog_transaction_dependency_tracking = writeset;"
}
done

The crash log for the 8.0.41 is below:

Thread 532 "connection" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7f4223dfb700 (LWP 7313)]
0x00007f4837efa1a4 in std::local_Rb_tree_decrement(std::_Rb_tree_node_base*) () from /lib64/libstdc++.so.6
(gdb) bt
#0  0x00007f4837efa1a4 in std::local_Rb_tree_decrement(std::_Rb_tree_node_base*) () from /lib64/libstdc++.so.6
#1  0x0000000001dc7335 in std::_Rb_tree_iterator<std::pair<unsigned long const, long> >::operator-- (this=<synthetic pointer>) at /opt/rh/gcc-toolset-12/root/usr/include/c++/12/bits/stl_tree.h:300
#2  std::_Rb_tree<unsigned long, std::pair<unsigned long const, long>, std::_Select1st<std::pair<unsigned long const, long> >, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, long> > >::_M_get_insert_hint_unique_pos (this=this@entry=0x4306928 <mysql_bin_log+3816>, __position= {first = 139934128370554, second = 10}, __k=@0x7f4570031990: 18302066027489388667, __k@entry=@0x7f4570031990: 0) at /opt/rh/gcc-toolset-12/root/usr/include/c++/12/bits/stl_tree.h:2231
#3  0x0000000001dc743a in std::_Rb_tree<unsigned long, std::pair<unsigned long const, long>, std::_Select1st<std::pair<unsigned long const, long> >, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, long> > >::_M_emplace_hint_unique<std::pair<unsigned long, long> > ( this=this@entry=0x4306928 <mysql_bin_log+3816>, __pos={first = 139934128370554, second = 10}) at /opt/rh/gcc-toolset-12/root/usr/include/c++/12/bits/stl_function.h:1182
#4  0x0000000001dc76f2 in std::map<unsigned long, long, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, long> > >::emplace_hint<std::pair<unsigned long, long> > (__pos=..., this=<optimized out>) at /opt/rh/gcc-toolset-12/root/usr/include/c++/12/bits/stl_map.h:636
#5  std::map<unsigned long, long, std::less<unsigned long>, std::allocator<std::pair<unsigned long const, long> > >::insert<std::pair<unsigned long, long> > (__x=..., this=<optimized out>) at /opt/rh/gcc-toolset-12/root/usr/include/c++/12/bits/stl_map.h:858
#6  Writeset_trx_dependency_tracker::get_dependency (this=this@entry=0x4306918 <mysql_bin_log+3800>, thd=thd@entry=0x7f445401b550, sequence_number=@0x7f4223df7180: 71481, commit_parent=@0x7f4223df7188: 71323) at ../../mysql-8.0.41/sql/rpl_trx_tracking.cc:273
#7  0x0000000001dc77e7 in Transaction_dependency_tracker::get_dependency (this=0x4306910 <mysql_bin_log+3792>, thd=thd@entry=0x7f445401b550,parallelization_barrier=<optimized out>, sequence_number=@0x7f4223df7180: 71481, commit_parent=@0x7f4223df7188: 71323) at ../../mysql-8.0.41/sql/rpl_trx_tracking.cc:348
#8  0x0000000001d66799 in MYSQL_BIN_LOG::write_transaction (this=<optimized out>, thd=0x7f445401b550, cache_data=0x7f445403e9f8, writer=0x7f4223df73f0, parallelization_barrier=<optimized out>) at ../../mysql-8.0.41/sql/binlog.cc:1677
#9  0x0000000001d66cd2 in binlog_cache_data::flush (parallelization_barrier=false, wrote_xid=0x7f4223df7497, bytes_written=0x7f4223df74a0, thd=0x7f445401b550, this=<optimized out>) at ../../mysql-8.0.41/sql/binlog.cc:2455
#10 binlog_cache_data::flush (this=0x7f445403e9f8, thd=0x7f445401b550, bytes_written=0x7f4223df74a0, wrote_xid=0x7f4223df7497, parallelization_barrier=<optimized out>) at ../../mysql-8.0.41/sql/binlog.cc:2392
#11 0x0000000001d6c8cc in binlog_cache_mngr::flush (wrote_xid=0x7f4223df7497, bytes_written=<synthetic pointer>, thd=0x7f445401b550, this=0x7f445403e810) at ../../mysql-8.0.41/sql/binlog.cc:1279
#12 MYSQL_BIN_LOG::flush_thread_caches (this=this@entry=0x4305a40 <mysql_bin_log>, thd=thd@entry=0x7f445401b550) at ../../mysql-8.0.41/sql/binlog.cc:8349
#13 0x0000000001d6cab5 in MYSQL_BIN_LOG::process_flush_stage_queue (this=0x4305a40 <mysql_bin_log>, total_bytes_var=0x7f4223df75c8, out_queue_var=0x7f4223df75d0) at ../../mysql-8.0.41/sql/binlog.cc:8458
#14 0x0000000001d771f1 in MYSQL_BIN_LOG::ordered_commit (this=0x4305a40 <mysql_bin_log>, thd=0x7f44a401b550, all=<optimized out>, skip_commit=<optimized out>) at ../../mysql-8.0.41/sql/binlog.cc:8908
#15 0x0000000001d7887a in MYSQL_BIN_LOG::commit (this=0x4305a40 <mysql_bin_log>, thd=0x7f44a401b550, all=<optimized out>) at ../../mysql-8.0.41/sql/binlog.cc:8300
#16 0x0000000001113a12 in ha_commit_trans (thd=thd@entry=0x7f44a401b550, all=all@entry=false, ignore_global_read_lock=ignore_global_read_lock@entry=false) at ../../mysql-8.0.41/sql/handler.cc:1781
#17 0x0000000000fbb050 in trans_commit_stmt (thd=thd@entry=0x7f44a401b550, ignore_global_read_lock=ignore_global_read_lock@entry=false) at ../../mysql-8.0.41/sql/transaction.cc:533
#18 0x0000000000e97d7d in mysql_execute_command (thd=<optimized out>, first_level=first_level@entry=true) at ../../mysql-8.0.41/sql/sql_parse.cc:4928
#19 0x0000000000ec52f9 in Prepared_statement::execute (this=0x7f44a4025650, thd=<optimized out>, expanded_query=<optimized out>, open_cursor=<optimized out>) at ../../mysql-8.0.41/sql/sql_prepare.cc:3669
#20 0x0000000000eca02d in Prepared_statement::execute_loop (this=this@entry=0x7f44a4025650, thd=thd@entry=0x7f44a401b550, expanded_query=expanded_query@entry=0x7f4223df9a70, open_cursor=open_cursor@entry=false) at ../../mysql-8.0.41/sql/sql_prepare.cc:3063
#21 0x0000000000eca72c in mysqld_stmt_execute (thd=thd@entry=0x7f44a401b550, stmt=0x7f44a4025650, has_new_types=<optimized out>, execute_flags=0, parameters=parameters@entry=0x7f44a4023640) at ../../mysql-8.0.41/sql/sql_prepare.cc:1909
#22 0x0000000000e9c073 in dispatch_command (thd=0x7f44a401b550, com_data=<optimized out>, command=COM_STMT_EXECUTE) at ../../mysql-8.0.41/sql/sql_parse.cc:1943
#23 0x0000000000e9e00e in do_command (thd=thd@entry=0x7f44a401b550) at ../../mysql-8.0.41/sql/sql_parse.cc:1440
#24 0x0000000000ff7588 in handle_connection (arg=arg@entry=0x892c330) at ../../mysql-8.0.41/sql/conn_handler/connection_handler_per_thread.cc:303
#25 0x0000000002871b84 in pfs_spawn_thread (arg=0x892c380) at ../../../mysql-8.0.41/storage/perfschema/pfs.cc:3050
#26 0x00007f48391841ca in start_thread () from /lib64/libpthread.so.0
#27 0x00007f4837526e73 in clone () from /lib64/libc.so.6
[20 Mar 13:51] ANIL JOSHI 
Hi,

This bug was observed in some older version as well.

8.0.40

2025-03-20T08:11:04Z UTC - mysqld got signal 11 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Thread pointer: 0x12a964a00
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 = 176f9af28 thread_stack 0x100000
0   mysqld                              0x0000000103e928fc my_print_stacktrace(unsigned char const*, unsigned long) + 68
1   mysqld                              0x000000010347b840 print_fatal_signal(int) + 568
2   mysqld                              0x000000010347b9a0 handle_fatal_signal + 68
3   libsystem_platform.dylib            0x000000019f61ade4 _sigtramp + 56
4   mysqld                              0x0000000103c4f0fc Writeset_trx_dependency_tracker::get_dependency(THD*, long long&, long long&) + 148
5   mysqld                              0x0000000103c4f524 Transaction_dependency_tracker::get_dependency(THD*, bool, long long&, long long&) + 496
6   mysqld                              0x0000000103bef7fc MYSQL_BIN_LOG::write_transaction(THD*, binlog_cache_data*, Binlog_event_writer*, bool) + 80
7   mysqld                              0x0000000103bf2548 binlog_cache_data::flush(THD*, unsigned long long*, bool*, bool) + 264
8   mysqld                              0x0000000103c051bc binlog_cache_mngr::flush(THD*, unsigned long long*, bool*) + 168
9   mysqld                              0x0000000103c05060 MYSQL_BIN_LOG::flush_thread_caches(THD*) + 72
10  mysqld                              0x0000000103c053ac MYSQL_BIN_LOG::process_flush_stage_queue(unsigned long long*, THD**) + 160
11  mysqld                              0x0000000103bf3920 MYSQL_BIN_LOG::ordered_commit(THD*, bool, bool) + 328
12  mysqld                              0x0000000103bf0670 MYSQL_BIN_LOG::commit(THD*, bool) + 1916
13  mysqld                              0x0000000102fd4914 ha_commit_trans(THD*, bool, bool) + 1196
14  mysqld                              0x00000001034246a0 trans_commit_stmt(THD*, bool) + 68
15  mysqld                              0x000000010332c92c mysql_execute_command(THD*, bool) + 3488
16  mysqld                              0x0000000103357e38 Prepared_statement::execute(THD*, String*, bool) + 1168
17  mysqld                              0x00000001033563e0 Prepared_statement::execute_loop(THD*, String*, bool) + 320
18  mysqld                              0x00000001033561bc mysqld_stmt_execute(THD*, Prepared_statement*, bool, unsigned long, PS_PARAM*) + 308
19  mysqld                              0x0000000103328f28 dispatch_command(THD*, COM_DATA const*, enum_server_command) + 5092
20  mysqld                              0x0000000103329c8c do_command(THD*) + 488
21  mysqld                              0x00000001034656d4 handle_connection(void*) + 484
22  mysqld                              0x0000000104423e74 pfs_spawn_thread(void*) + 288
23  libsystem_pthread.dylib             0x000000019f5e42e4 _pthread_start + 136
24  libsystem_pthread.dylib             0x000000019f5df0fc thread_start + 8

8.0.33

2025-03-20T08:55:16Z UTC - mysqld got signal 11 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Thread pointer: 0x16824b000
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 = 310ffaf28 thread_stack 0x100000
0   mysqld                              0x0000000103002268 my_print_stacktrace(unsigned char const*, unsigned long) + 68
1   mysqld                              0x00000001026b5120 print_fatal_signal(int) + 572
2   mysqld                              0x00000001026b5280 handle_fatal_signal + 68
3   libsystem_platform.dylib            0x000000019f61ade4 _sigtramp + 56
4   mysqld                              0x0000000102d99b80 Writeset_trx_dependency_tracker::get_dependency(THD*, long long&, long long&) + 148
5   mysqld                              0x0000000102d3ab64 MYSQL_BIN_LOG::write_transaction(THD*, binlog_cache_data*, Binlog_event_writer*) + 72
6   mysqld                              0x0000000102d3d560 binlog_cache_data::flush(THD*, unsigned long long*, bool*) + 252
7   mysqld                              0x0000000102d5154c MYSQL_BIN_LOG::flush_thread_caches(THD*) + 100
8   mysqld                              0x0000000102d517d8 MYSQL_BIN_LOG::process_flush_stage_queue(unsigned long long*, bool*, THD**) + 168
9   mysqld                              0x0000000102d3ee74 MYSQL_BIN_LOG::ordered_commit(THD*, bool, bool) + 336
10  mysqld                              0x0000000102d3bad8 MYSQL_BIN_LOG::commit(THD*, bool) + 2008
11  mysqld                              0x000000010220a108 ha_commit_trans(THD*, bool, bool) + 1192
12  mysqld                              0x000000010265b67c trans_commit_stmt(THD*, bool) + 68
13  mysqld                              0x000000010255df5c mysql_execute_command(THD*, bool) + 3832
14  mysqld                              0x000000010258b778 Prepared_statement::execute(THD*, String*, bool) + 1360
15  mysqld                              0x0000000102589d94 Prepared_statement::execute_loop(THD*, String*, bool) + 276
16  mysqld                              0x0000000102589b88 mysqld_stmt_execute(THD*, Prepared_statement*, bool, unsigned long, PS_PARAM*) + 304
17  mysqld                              0x000000010255a804 dispatch_command(THD*, COM_DATA const*, enum_server_command) + 5768
18  mysqld                              0x000000010255b5e8 do_command(THD*) + 468
19  mysqld                              0x000000010269e8ec handle_connection(void*) + 480
20  mysqld                              0x00000001035a2ad0 pfs_spawn_thread(void*) + 288
21  libsystem_pthread.dylib             0x000000019f5e42e4 _pthread_start + 136
22  libsystem_pthread.dylib             0x000000019f5df0fc thread_start + 8

Interestingly, I tried with the persist… option also, but the result was  same, it crahses.
set persist binlog_transaction_dependency_tracking = writeset;

It's not happening when we change the tracking to commit_order

for i in {1..10}; do
{
    ./n1 --user=root -BNe "set global   binlog_transaction_dependency_tracking = commit_order;"
}
done

It can be experienced less threads also say 5 or 10  (--threads=5) while with (--threads=1) its always stable.

sysbench oltp_update_index --threads=5 --time=60000 --tables=1 --table-size=100000 --db-driver=mysql --mysql-db=test --mysql-user="sbtest_user" --mysql-password="Sbtest@2022" --mysql-storage-engine=InnoDB --report-interval=10 --mysql-host=127.0.0.1 --mysql-port=23041  run