[MDEV-15490] XA: ASAN heap-use-after-free or valgrind Invalid write in trx_update_mod_tables_timestamp Created: 2018-03-06  Updated: 2020-02-13  Resolved: 2020-02-13

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

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergey Vojtovich
Resolution: Duplicate Votes: 0
Labels: None

Issue Links:
Duplicate
duplicates MDEV-14693 XA: Assertion `!clust_index->online_l... Closed
Relates
relates to MDEV-15518 XA: Server crash or ASAN heap-use-aft... Closed
relates to MDEV-15533 Assertion `log->blobs' failed in row_... Closed
relates to MDEV-15532 XA: Assertion `!log->same_pk' failed ... Closed
relates to MDEV-15791 XA: Server crashes in lock_release up... Closed
Sprint: 10.2.14

 Description    

#--source include/have_log_bin.inc
 
--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
 
 
 
--connect (con1,localhost,root,,test)
 
XA START 'xid';
 
INSERT INTO t1 VALUES (1);
 
--error ER_XAER_RMFAIL
 
FLUSH LOGS;
 
 
 
--connection default
 
CREATE OR REPLACE TABLE t1 (b INT);
 
 
 
--connection con1
 
XA END 'xid';
 
XA COMMIT 'xid' ONE PHASE;
 
 
 
# Cleanup
 
--disconnect con1
 
--connection default
 
DROP TABLE t1;

10.2 8f98835bb865

 
==3078==ERROR: AddressSanitizer: heap-use-after-free on address 0x617000049b60 at pc 0x5617bf2ced8f bp 0x7fccd48ba080 sp 0x7fccd48ba078
 
WRITE of size 8 at 0x617000049b60 thread T28
 
    #0 0x5617bf2ced8e in trx_update_mod_tables_timestamp /data/src/10.2/storage/innobase/trx/trx0trx.cc:1637
 
    #1 0x5617bf2d30d1 in trx_commit_for_mysql(trx_t*) /data/src/10.2/storage/innobase/trx/trx0trx.cc:2224
 
    #2 0x5617bef00ce1 in innobase_commit_low(trx_t*) /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4521
 
    #3 0x5617bef01478 in innobase_commit_ordered_2 /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4640
 
    #4 0x5617bef01d0c in innobase_commit /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4767
 
    #5 0x5617be774116 in commit_one_phase_2 /data/src/10.2/sql/handler.cc:1569
 
    #6 0x5617be773eaf in ha_commit_one_phase(THD*, bool) /data/src/10.2/sql/handler.cc:1550
 
    #7 0x5617be773149 in ha_commit_trans(THD*, bool) /data/src/10.2/sql/handler.cc:1417
 
    #8 0x5617be4f6bdd in trans_xa_commit(THD*) /data/src/10.2/sql/transaction.cc:929
 
    #9 0x5617be1a2ad5 in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:6074
 
    #10 0x5617be1adb01 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:7902
 
    #11 0x5617be188e5b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1806
 
    #12 0x5617be185eff in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1360
 
    #13 0x5617be4c13e9 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1335
 
    #14 0x5617be4c0dfe in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
 
    #15 0x5617beecc4c1 in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862
 
    #16 0x7fccf0fce493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
 
    #17 0x7fccef3b493e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)

Variation with binary log enabled:

==2990==ERROR: AddressSanitizer: heap-use-after-free on address 0x617000049ee0 at pc 0x55cab0b0ad8f bp 0x7f4d6b97b590 sp 0x7f4d6b97b588
 
WRITE of size 8 at 0x617000049ee0 thread T29
 
    #0 0x55cab0b0ad8e in trx_update_mod_tables_timestamp /data/src/10.2/storage/innobase/trx/trx0trx.cc:1637
 
    #1 0x55cab0b0f0d1 in trx_commit_for_mysql(trx_t*) /data/src/10.2/storage/innobase/trx/trx0trx.cc:2224
 
    #2 0x55cab073cce1 in innobase_commit_low(trx_t*) /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4521
 
    #3 0x55cab073d478 in innobase_commit_ordered_2 /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4640
 
    #4 0x55cab073d7cd in innobase_commit_ordered /data/src/10.2/storage/innobase/handler/ha_innodb.cc:4701
 
    #5 0x55cab0238053 in TC_LOG::run_commit_ordered(THD*, bool) /data/src/10.2/sql/log.cc:8790
 
    #6 0x55cab0233449 in MYSQL_BIN_LOG::trx_group_commit_leader(MYSQL_BIN_LOG::group_commit_entry*) /data/src/10.2/sql/log.cc:8019
 
    #7 0x55cab0230cdc in MYSQL_BIN_LOG::write_transaction_to_binlog_events(MYSQL_BIN_LOG::group_commit_entry*) /data/src/10.2/sql/log.cc:7612
 
    #8 0x55cab022f5c8 in MYSQL_BIN_LOG::write_transaction_to_binlog(THD*, binlog_cache_mngr*, Log_event*, bool, bool, bool) /data/src/10.2/sql/log.cc:7286
 
    #9 0x55cab0212dfa in binlog_flush_cache /data/src/10.2/sql/log.cc:1742
 
    #10 0x55cab0213943 in binlog_commit_flush_xid_caches /data/src/10.2/sql/log.cc:1860
 
    #11 0x55cab023cbc5 in MYSQL_BIN_LOG::log_and_order(THD*, unsigned long long, bool, bool, bool) /data/src/10.2/sql/log.cc:9573
 
    #12 0x55caaffaf50b in ha_commit_trans(THD*, bool) /data/src/10.2/sql/handler.cc:1462
 
    #13 0x55caafd32bdd in trans_xa_commit(THD*) /data/src/10.2/sql/transaction.cc:929
 
    #14 0x55caaf9dead5 in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:6074
 
    #15 0x55caaf9e9b01 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:7902
 
    #16 0x55caaf9c4e5b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1806
 
    #17 0x55caaf9c1eff in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1360
 
    #18 0x55caafcfd3e9 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1335
 
    #19 0x55caafcfcdfe in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
 
    #20 0x55cab07084c1 in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862
 
    #21 0x7f4d883fc493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
 
    #22 0x7f4d867e293e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)

Could not reproduce on 10.1 or 10.3.

 Comments   
Comment by Marko Mäkelä [ 2018-03-07 ]

The problem is that CREATE OR REPLACE TABLE is allowed to proceed to DROP TABLE, even though the XA START 'xid' transaction should hold MDL on the table name.

The access to freed memory occurs, because trx_t::mod_tables (which is how InnoDB implements non-persistent update_time in MySQL 5.7.2) would contain a reference to the dropped-and-replaced table t1, and at XA COMMIT we would adjust the update_time of that table.

This problem probably affect earlier MariaDB versions as well. It is worth checking what would happen on XA ROLLBACK; it could cause some other trouble. Rollback should generally assume that all tables and records are available and locked. On the other hand, rollback is implemented by table ID, and the table ID would no longer exist. Rollback might be OK with that missing table; at least it is OK when rolling back recovered transactions on server restart.

Comment by Marko Mäkelä [ 2018-03-07 ]

This bug shares a root cause with MDEV-14693: the XA transaction fails to hold MDL on the table that would prevent the DDL operation (DROP TABLE implied by CREATE OR REPLACE TABLE).

Comment by Marko Mäkelä [ 2018-03-07 ]

MDEV-14693 demonstrates a problem in InnoDB error handling that should be repeatable without exploiting this XA MDL bug. It must be fixed separately in InnoDB.

Comment by Marko Mäkelä [ 2018-05-11 ]

I decided to revisit the InnoDB part of this because of the reports that InnoDB sometimes accesses a freed trx object (MDEV-16063, MDEV-16136). I cannot repeat a failure in 10.3, but I can repeat it in the most recent 10.2 (commit e5bd75fb4e246b9f0494aab05dd557b18d5921cd).

In 10.3 the access to a freed table seems to have been removed before 10.3.4 already. I was able to repeat with commit acdfacee75141886e15eaee31af0ffe8c49bdf75 (2017-12-20), but I was unable to identify the exact commit that fixed the bug in 10.3. It could be that because mod_tables is also being used for id-based system versioning, something changed in the merge commit 5c0a19c873382c9fec696f827e6766f61c6682af (2017-12-21). An obvious explanation would be MDEV-14477, but I was able to repeat the failure with its fix (d8ada081526c9dedb004a2dcf216f1a0596a9c57, 2017-11-22).

Comment by Alice Sherepa [ 2020-02-13 ]

not reproducible anymore/ 10.2 a241d411951f72d6c

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