Bug #110594 Race condition between xa recover and xa start on Transaction_ctx object
Submitted: 3 Apr 2023 11:28 Modified: 5 Apr 2023 7:17
Reporter: Zhejun Cai Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: XA transactions Severity:S2 (Serious)
Version:8.0.32 OS:Any
Assigned to: CPU Architecture:Any

[3 Apr 2023 11:28] Zhejun Cai 
Description:
Race condition between xa recover and xa start on Transaction_ctx object.

Because there are two locations that point to the same Transaction_ctx *transaction,
one is in THD named m_transaction, another is in m_transaction_cache.

T69: xa start insert a new std::shared_ptr<Transaction_ctx>  into m_transaction_cache.

T70: xa recover call get_cached_transactions, get a list of std::shared_ptr<Transaction_ctx> from m_transaction_cache.

Then, T69 disconnect, release thd->m_transaction.
T70 go to traverse the list and visit Transaction_ctx* which is released by T69.

==287860==ERROR: AddressSanitizer: heap-use-after-free on address 0x61600040ff80 at pc 0x00000300cf7b bp 0x2ae1f0602e30 sp 0x2ae1f0602e28
READ of size 4 at 0x61600040ff80 thread T70 (connection)
    #0 0x300cf7a in XID_STATE::has_state(XID_STATE::xa_states) const /data3/caizj/source/mysql-8.0.32/sql/xa.h:346
    #1 0x3ed1d2e in Sql_cmd_xa_recover::trans_xa_recover(THD*) /data3/caizj/source/mysql-8.0.32/sql/xa/sql_xa_recover.cc:69
    #2 0x3ed1fe7 in Sql_cmd_xa_recover::execute(THD*) /data3/caizj/source/mysql-8.0.32/sql/xa/sql_xa_recover.cc:40
    #3 0x3231371 in mysql_execute_command(THD*, bool) /data3/caizj/source/mysql-8.0.32/sql/sql_parse.cc:4688
    #4 0x3234971 in dispatch_sql_command(THD*, Parser_state*) /data3/caizj/source/mysql-8.0.32/sql/sql_parse.cc:5322
    #5 0x3237344 in dispatch_command(THD*, COM_DATA const*, enum_server_command) /data3/caizj/source/mysql-8.0.32/sql/sql_parse.cc:2036
    #6 0x323aac4 in do_command(THD*) /data3/caizj/source/mysql-8.0.32/sql/sql_parse.cc:1439
    #7 0x35dd1af in handle_connection /data3/caizj/source/mysql-8.0.32/sql/conn_handler/connection_handler_per_thread.cc:302
    #8 0x67b42c1 in pfs_spawn_thread /data3/caizj/source/mysql-8.0.32/storage/perfschema/pfs.cc:2986
    #9 0x2adf1341fea4 in start_thread (/lib64/libpthread.so.0+0x7ea4)
    #10 0x2adf150c4b0c in clone (/lib64/libc.so.6+0xfeb0c)

0x61600040ff80 is located 256 bytes inside of 544-byte region [0x61600040fe80,0x6160004100a0)
freed by thread T69 (connection) here:
    #0 0x2adf128f9f05 in operator delete(void*, unsigned long) ../../../../libsanitizer/asan/asan_new_delete.cc:177
    #1 0x352eb8b in Transaction_ctx::~Transaction_ctx() (/data3/caizj/ob_rel/mysql-8.0.32/bin/mysqld+0x352eb8b)
    #2 0x30c3ebb in std::default_delete<Transaction_ctx>::operator()(Transaction_ctx*) const (/data3/caizj/ob_rel/mysql-8.0.32/bin/mysqld+0x30c3ebb)
    #3 0x30c8b54 in std::unique_ptr<Transaction_ctx, std::default_delete<Transaction_ctx> >::~unique_ptr() /data3/local/gcc-9.2.0/include/c++/9.2.0/bits/unique_ptr.h:284
    #4 0x30bf519 in THD::~THD() /data3/caizj/source/mysql-8.0.32/sql/sql_class.cc:1408
    #5 0x30bf756 in THD::~THD() /data3/caizj/source/mysql-8.0.32/sql/sql_class.cc:1468
    #6 0x35dd0f1 in handle_connection /data3/caizj/source/mysql-8.0.32/sql/conn_handler/connection_handler_per_thread.cc:324
    #7 0x67b42c1 in pfs_spawn_thread /data3/caizj/source/mysql-8.0.32/storage/perfschema/pfs.cc:2986
    #8 0x2adf1341fea4 in start_thread (/lib64/libpthread.so.0+0x7ea4)

previously allocated by thread T69 (connection) here:
    #0 0x2adf128f8a7f in operator new(unsigned long) ../../../../libsanitizer/asan/asan_new_delete.cc:104
    #1 0x30bc7be in THD::THD(bool) /data3/caizj/source/mysql-8.0.32/sql/sql_class.cc:661
    #2 0x3ee4d09 in Channel_info::create_thd() /data3/caizj/source/mysql-8.0.32/sql/conn_handler/channel_info.cc:45
    #3 0x35e4d2d in Channel_info_local_socket::create_thd() /data3/caizj/source/mysql-8.0.32/sql/conn_handler/socket_connection.cc:173
    #4 0x35dc546 in init_new_thd /data3/caizj/source/mysql-8.0.32/sql/conn_handler/connection_handler_per_thread.cc:194
    #5 0x35dd13f in handle_connection /data3/caizj/source/mysql-8.0.32/sql/conn_handler/connection_handler_per_thread.cc:263
    #6 0x67b42c1 in pfs_spawn_thread /data3/caizj/source/mysql-8.0.32/storage/perfschema/pfs.cc:2986
    #7 0x2adf1341fea4 in start_thread (/lib64/libpthread.so.0+0x7ea4)

Thread T70 (connection) created by T0 here:
    #0 0x2adf12829332 in __interceptor_pthread_create ../../../../libsanitizer/asan/asan_interceptors.cc:208
    #1 0x58f2fb3 in my_thread_create(my_thread_handle*, pthread_attr_t const*, void* (*)(void*), void*) /data3/caizj/source/mysql-8.0.32/mysys/my_thread.cc:80
    #2 0x67b4154 in pfs_spawn_thread_vc(unsigned int, unsigned int, my_thread_handle*, pthread_attr_t const*, void* (*)(void*), void*) /data3/caizj/source/mysql-8.0.32/storage/perfschema/pfs.cc:3032
    #3 0x35dc0fc in inline_mysql_thread_create /data3/caizj/source/mysql-8.0.32/include/mysql/psi/mysql_thread.h:139
    #4 0x35dd5a8 in Per_thread_connection_handler::add_connection(Channel_info*) /data3/caizj/source/mysql-8.0.32/sql/conn_handler/connection_handler_per_thread.cc:414
    #5 0x37ef932 in Connection_handler_manager::process_new_connection(Channel_info*) /data3/caizj/source/mysql-8.0.32/sql/conn_handler/connection_handler_manager.cc:260
    #6 0x2f664c6 in Connection_acceptor<Mysqld_socket_listener>::connection_event_loop() (/data3/caizj/ob_rel/mysql-8.0.32/bin/mysqld+0x2f664c6)
    #7 0x2f60403 in mysqld_main(int, char**) /data3/caizj/source/mysql-8.0.32/sql/mysqld.cc:8207
    #8 0x2f395da in main /data3/caizj/source/mysql-8.0.32/sql/main.cc:25
    #9 0x2adf14fe8554 in __libc_start_main (/lib64/libc.so.6+0x22554)

Thread T69 (connection) created by T0 here:
    #0 0x2adf12829332 in __interceptor_pthread_create ../../../../libsanitizer/asan/asan_interceptors.cc:208
    #1 0x58f2fb3 in my_thread_create(my_thread_handle*, pthread_attr_t const*, void* (*)(void*), void*) /data3/caizj/source/mysql-8.0.32/mysys/my_thread.cc:80
    #2 0x67b4154 in pfs_spawn_thread_vc(unsigned int, unsigned int, my_thread_handle*, pthread_attr_t const*, void* (*)(void*), void*) /data3/caizj/source/mysql-8.0.32/storage/perfschema/pfs.cc:3032
    #3 0x35dc0fc in inline_mysql_thread_create /data3/caizj/source/mysql-8.0.32/include/mysql/psi/mysql_thread.h:139
    #4 0x35dd5a8 in Per_thread_connection_handler::add_connection(Channel_info*) /data3/caizj/source/mysql-8.0.32/sql/conn_handler/connection_handler_per_thread.cc:414
    #5 0x37ef932 in Connection_handler_manager::process_new_connection(Channel_info*) /data3/caizj/source/mysql-8.0.32/sql/conn_handler/connection_handler_manager.cc:260
    #6 0x2f664c6 in Connection_acceptor<Mysqld_socket_listener>::connection_event_loop() (/data3/caizj/ob_rel/mysql-8.0.32/bin/mysqld+0x2f664c6)
    #7 0x2f60403 in mysqld_main(int, char**) /data3/caizj/source/mysql-8.0.32/sql/mysqld.cc:8207
    #8 0x2f395da in main /data3/caizj/source/mysql-8.0.32/sql/main.cc:25
    #9 0x2adf14fe8554 in __libc_start_main (/lib64/libc.so.6+0x22554)

How to repeat:
(1) add a DBUG_EXECUTE_IF in function Sql_cmd_xa_recover::trans_xa_recover, after get_cached_transactions , before for loop to traverse:

    auto list = xa::Transaction_cache::get_cached_transactions();
    DBUG_EXECUTE_IF("simulate_delay_after_xa_start_disconnect", sleep(10););
    for (const auto &transaction : list) {
    
(2) build mysql with ASAN and debug type
    -DCMAKE_BUILD_TYPE=Debug -DWITH_ASAN=ON

(3) run the test case(my_xa_recover.test) uploaded.
[3 Apr 2023 11:30] Zhejun Cai 
simulate xa recover and xa start

Attachment: my_xa_recover.test (application/octet-stream, text), 710 bytes.
[5 Apr 2023 7:17] MySQL Verification Team 
Hello Zhejun Cai,

Thank you for the report and test case.
Verified as described.

regards,
Umesh
[5 Apr 2023 7:19] MySQL Verification Team 
8.0.32 test results

Attachment: 110594.results (application/octet-stream, text), 20.33 KiB.