[MDEV-28123] ASAN heap-use-after-free in btr_search_disable() Created: 2022-03-18  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Marko Mäkelä Assignee: Thirunarayanan Balathandayuthapani
Resolution: Unresolved Votes: 0
Labels: ASAN, race, rr-profile-analyzed


 Description   

We got the following crash:

10.6 8840583a92243f6ac543689148ca79c85fa0a09d

==2978529==ERROR: AddressSanitizer: heap-use-after-free on address 0x616001730228 at pc 0x56180d3d30b0 bp 0x7ff01aac03b0 sp 0x7ff01aac03a0
READ of size 18 at 0x616001730228 thread T4
2022-03-18  5:54:49 131 [Warning] Aborted connection 131 to db: 'test' user: 'root' host: 'localhost' (This connection closed normally)
    #0 0x56180d3d30af in dict_index_t::freed() const /data/Server/bb-10.6-MDEV-27909/storage/innobase/include/dict0mem.h:1323
    #1 0x56180d741a34 in buf_pool_t::clear_hash_index() /data/Server/bb-10.6-MDEV-27909/storage/innobase/btr/btr0sea.cc:946
    #2 0x56180d732933 in btr_search_disable() /data/Server/bb-10.6-MDEV-27909/storage/innobase/btr/btr0sea.cc:262
    #3 0x56180d771c87 in buf_pool_t::resize() /data/Server/bb-10.6-MDEV-27909/storage/innobase/buf/buf0buf.cc:1663
    #4 0x56180d756bff in buf_resize_callback /data/Server/bb-10.6-MDEV-27909/storage/innobase/buf/buf0buf.cc:1998

Yes, the memory was freed even though we have block->index pointing to it:

10.6 8840583a92243f6ac543689148ca79c85fa0a09d

#2  0x00007ff02b5eb799 in free () from /usr/lib/x86_64-linux-gnu/libasan.so.5
#3  0x000056180d3c6832 in mem_heap_block_free (heap=0x61100018d700, block=0x616001730180) at /data/Server/bb-10.6-MDEV-27909/storage/innobase/mem/mem0mem.cc:416
#4  0x000056180d81a264 in mem_heap_free (heap=0x61100018d700) at /data/Server/bb-10.6-MDEV-27909/storage/innobase/include/mem0mem.inl:419
#5  0x000056180d822b97 in dict_mem_index_free (index=0x616001730208) at /data/Server/bb-10.6-MDEV-27909/storage/innobase/dict/dict0mem.cc:1096
#6  0x000056180d7e5b81 in dict_index_remove_from_cache_low (table=0x618000012908, index=0x616001730208, lru_evict=0) at /data/Server/bb-10.6-MDEV-27909/storage/innobase/dict/dict0dict.cc:2132
#7  0x000056180d7e2f64 in dict_sys_t::remove (this=0x56180f82a840 <dict_sys>, table=0x618000012908, lru=false, keep=false) at /data/Server/bb-10.6-MDEV-27909/storage/innobase/dict/dict0dict.cc:1850
#8  0x000056180d259c68 in innobase_reload_table (thd=0x62b000230218, table=0x618000012908, table_name=..., ctx=...) at /data/Server/bb-10.6-MDEV-27909/storage/innobase/handler/handler0alter.cc:10189
#9  0x000056180d25f51b in ha_innobase::commit_inplace_alter_table (this=0x61d000d3aeb8, altered_table=0x7ff0053d62d0, ha_alter_info=0x7ff0053d5bd0, commit=true)
    at /data/Server/bb-10.6-MDEV-27909/storage/innobase/handler/handler0alter.cc:11254

The actual cause of this error is the following assignment that was done earlier by the thread that would end up dereferencing a block->index that points to the freed object:

10.6 8840583a92243f6ac543689148ca79c85fa0a09d

Thread 3 hit Hardware watchpoint 4: -location index.search_info.ref_count
 
Old value = 6
New value = 0
btr_search_disable_ref_count (table=0x618000012908) at /data/Server/bb-10.6-MDEV-27909/storage/innobase/btr/btr0sea.cc:199
199	       index= dict_table_get_next_index(index))
(rr) backtrace
#0  btr_search_disable_ref_count (table=0x618000012908) at /data/Server/bb-10.6-MDEV-27909/storage/innobase/btr/btr0sea.cc:199
#1  0x000056180d7328de in btr_search_disable () at /data/Server/bb-10.6-MDEV-27909/storage/innobase/btr/btr0sea.cc:256
#2  0x000056180d771c88 in buf_pool_t::resize (this=0x56180f7e6b80 <buf_pool>) at /data/Server/bb-10.6-MDEV-27909/storage/innobase/buf/buf0buf.cc:1663
#3  0x000056180d756c00 in buf_resize_callback () at /data/Server/bb-10.6-MDEV-27909/storage/innobase/buf/buf0buf.cc:1998

I think that the logic of btr_search_disable() must be revised. We should first clear all buf_block_t::index pointers and only after that reset the reference counts.



 Comments   
Comment by Matthias Leich [ 2022-03-18 ]

# git clone https://github.com/mleich1/rqg --branch experimental RQG
#
# GIT_SHOW: HEAD -> experimental, origin/experimental c6bfc84dd29e6ecb8b1deba2893881008fc9b855 2022-03-17T14:29:27+01:00
# rqg.pl  : Version 4.0.4 (2021-12)
#
# $RQG_HOME/rqg.pl \
# --grammar=conf/mariadb/table_stress_innodb.yy \
# --gendata=conf/mariadb/table_stress.zz \
# --gendata_sql=conf/mariadb/table_stress.sql \
# --reporters=CrashRecovery1 \
# --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \
# --mysqld=--loose-idle_write_transaction_timeout=0 \
# --mysqld=--loose-idle_transaction_timeout=0 \
# --mysqld=--loose-idle_readonly_transaction_timeout=0 \
# --mysqld=--connect_timeout=60 \
# --mysqld=--interactive_timeout=28800 \
# --mysqld=--slave_net_timeout=60 \
# --mysqld=--net_read_timeout=30 \
# --mysqld=--net_write_timeout=60 \
# --mysqld=--loose-table_lock_wait_timeout=50 \
# --mysqld=--wait_timeout=28800 \
# --mysqld=--lock-wait-timeout=86400 \
# --mysqld=--innodb-lock-wait-timeout=50 \
# --no-mask \
# --queries=10000000 \
# --seed=random \
# --reporters=Backtrace \
# --reporters=ErrorLog \
# --reporters=Deadlock1 \
# --validators=None \
# --mysqld=--log_output=none \
# --mysqld=--log_bin_trust_function_creators=1 \
# --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
# --engine=InnoDB \
# --restart_timeout=240 \
# --mysqld=--plugin-load-add=file_key_management.so \
# --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
# --mysqld=--plugin-load-add=provider_lzo.so \
# --mysqld=--plugin-load-add=provider_bzip2.so \
# --mysqld=--plugin-load-add=provider_lzma.so \
# --mysqld=--plugin-load-add=provider_snappy.so \
# --mysqld=--plugin-load-add=provider_lz4.so \
# --duration=300 \
# --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
# --mysqld=--loose-innodb_read_only_compressed=OFF \
# --mysqld=--innodb_stats_persistent=off \
# --mysqld=--innodb_adaptive_hash_index=on \
# --mysqld=--loose-innodb_evict_tables_on_commit_debug=on \
# --mysqld=--loose-max-statement-time=30 \
# --threads=33 \
# --mysqld=--innodb-use-native-aio=0 \
# --mysqld=--loose-gdb \
# --mysqld=--loose-debug-gdb \
# --rr=Extended \
# --rr_options=--wait \
# --mysqld=--innodb_undo_tablespaces=3 \
# --mysqld=--innodb_undo_log_truncate=ON \
# --mysqld=--innodb_rollback_on_timeout=OFF \
# --vardir_type=fast \
# --mysqld=--innodb_page_size=4K \
# --mysqld=--innodb-buffer-pool-size=5M \
# --no_mask \
# <local settings>
 
Error pattern
[ 'TBR-918-MDEV-27891', 'SUMMARY: AddressSanitizer: heap-use-after-free.{1,200}dict0mem.h:.{1,20} in dict_index_t::freed\(\) const' ],

Generated at Thu Feb 08 09:58:14 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.