[MDEV-26383] SUMMARY: AddressSanitizer: heap-use-after-free storage/innobase/btr/btr0sea.cc:209 in btr_search_lazy_free - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5, 10.6, 10.7(EOL)
Fix Version/s: 10.2.41, 10.3.32, 10.4.22, 10.5.13, 10.6.5, 10.7.0
Component/s: Storage Engine - InnoDB
Labels:

Description

origin/10.5 255313048ca00c48fe78250014570034475a9178 2021-08-16T17:02:55+05:30

[rr 596513 477033]SUMMARY: AddressSanitizer: heap-use-after-free /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:209 in btr_search_lazy_free

...

# 2021-08-16T14:08:08 [591946] | Query (0x62b0000a8238): ALTER TABLE k ENGINE = INNODB

# 2021-08-16T14:08:08 [591946] | [rr 596513 492930]Status: KILL_TIMEOUT

[rr 596513 477467]Shadow bytes around the buggy address:

  0x0c3080028260: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd

  0x0c3080028270: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd

  0x0c3080028280: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa

  0x0c3080028290: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd

  0x0c30800282a0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd

=>0x0c30800282b0: fd fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd fd

  0x0c30800282c0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd

  0x0c30800282d0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd

  0x0c30800282e0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd

  0x0c30800282f0: fd fd fd fd fd fd fa fa fa fa fa fa fa fa fa fa

  0x0c3080028300: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa

sdp:/data/Results/1629134327/TBR-863

(rr) bt

#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50

#1  0x00007f68bb3e4859 in __GI_abort () at abort.c:79

#2  0x00007f68bbd306a2 in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.5

#3  0x00007f68bbd3b24c in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.5

#4  0x00007f68bbd1c8ec in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.5

#5  0x00007f68bbd1c363 in ?? () from /usr/lib/x86_64-linux-gnu/libasan.so.5

#6  0x00007f68bbd1d1ab in __asan_report_load8 () from /usr/lib/x86_64-linux-gnu/libasan.so.5

#7  0x00005635b0a9ee9f in btr_search_lazy_free (index=0x617000015f08) at /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:209

#8  0x00005635b0aa5834 in btr_search_drop_page_hash_index (block=0x7f68addce760) at /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:1409

#9  0x00005635b0b176d1 in buf_LRU_free_page (bpage=0x7f68addce760, zip=true) at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:972

#10 0x00005635b0b115d5 in buf_LRU_free_from_common_LRU_list (limit=100) at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:246

#11 0x00005635b0b119ed in buf_LRU_scan_and_free_block (limit=100) at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:278

#12 0x00005635b0b130f2 in buf_LRU_get_free_block (have_mutex=false) at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:441

#13 0x00005635b0b1e32e in buf_page_init_for_read (mode=132, page_id=..., zip_size=0, unzip=false) at /data/Server/10.5A/storage/innobase/buf/buf0rea.cc:109

#14 0x00005635b0b1f4b0 in buf_read_page_low (err=0x7f689e8f9850, space=0x615009576380, sync=true, mode=132, page_id=..., zip_size=0, unzip=false) at /data/Server/10.5A/storage/innobase/buf/buf0rea.cc:313

#15 0x00005635b0b207ff in buf_read_page (page_id=..., zip_size=0) at /data/Server/10.5A/storage/innobase/buf/buf0rea.cc:489

#16 0x00005635b0acb237 in buf_page_get_low (page_id=..., zip_size=0, rw_latch=1, guess=0x0, mode=10, file=0x5635b1ccabe0 "/data/Server/10.5A/storage/innobase/include/btr0pcur.ic", line=545, mtr=0x7f689e8fb220, err=0x7f689e8f9fd0,

    allow_ibuf_merge=false) at /data/Server/10.5A/storage/innobase/buf/buf0buf.cc:2958

#17 0x00005635b0acd032 in buf_page_get_gen (page_id=..., zip_size=0, rw_latch=1, guess=0x0, mode=10, file=0x5635b1ccabe0 "/data/Server/10.5A/storage/innobase/include/btr0pcur.ic", line=545, mtr=0x7f689e8fb220, err=0x7f689e8f9fd0,

    allow_ibuf_merge=false) at /data/Server/10.5A/storage/innobase/buf/buf0buf.cc:3420

#18 0x00005635b0a64f40 in btr_cur_open_at_index_side_func (from_left=true, index=0x61700025c788, latch_mode=1, cursor=0x7f689e8fb0f0, level=0, file=0x5635b1ccabe0 "/data/Server/10.5A/storage/innobase/include/btr0pcur.ic", line=545,

    mtr=0x7f689e8fb220) at /data/Server/10.5A/storage/innobase/btr/btr0cur.cc:2638

#19 0x00005635b081e51e in btr_pcur_open_at_index_side (from_left=true, index=0x61700025c788, latch_mode=1, pcur=0x7f689e8fb0f0, init_pcur=true, level=0, mtr=0x7f689e8fb220) at /data/Server/10.5A/storage/innobase/include/btr0pcur.ic:545

#20 0x00005635b0829c3e in row_merge_read_clustered_index (trx=0x7f68af675388, table=0x7f689e8fd990, old_table=0x6180000cd908, new_table=0x61800015d108, online=true, index=0x619000ad7368, fts_sort_idx=0x0, psort_info=0x0, files=0x60400134bd90,

    key_numbers=0x619000ad7380, n_index=2, defaults=0x0, add_v=0x0, col_map=0x619000ad7470, add_autoinc=18446744073709551615, sequence=..., block=0x7f6894da8000 "", skip_pk_sort=true, tmpfd=0x7f689e8fba10, stage=0x6020000738f0,

    pct_cost=33.333333333333336, crypt_block=0x0, eval_table=0x7f689e8fd990, allow_not_null=true) at /data/Server/10.5A/storage/innobase/row/row0merge.cc:1834

#21 0x00005635b083bdbf in row_merge_build_indexes (trx=0x7f68af675388, old_table=0x6180000cd908, new_table=0x61800015d108, online=true, indexes=0x619000ad7368, key_numbers=0x619000ad7380, n_indexes=2, table=0x7f689e8fd990, defaults=0x0,

    col_map=0x619000ad7470, add_autoinc=18446744073709551615, sequence=..., skip_pk_sort=true, stage=0x6020000738f0, add_v=0x0, eval_table=0x7f689e8fd990, allow_not_null=true) at /data/Server/10.5A/storage/innobase/row/row0merge.cc:4536

#22 0x00005635b058b09f in ha_innobase::inplace_alter_table (this=0x61f00016b2b8, altered_table=0x7f689e8fd990, ha_alter_info=0x7f689e8fd2b0) at /data/Server/10.5A/storage/innobase/handler/handler0alter.cc:8461

#23 0x00005635af6ccc56 in handler::ha_inplace_alter_table (this=0x61f00016b2b8, altered_table=0x7f689e8fd990, ha_alter_info=0x7f689e8fd2b0) at /data/Server/10.5A/sql/handler.h:4536

#24 0x00005635b04049eb in ha_partition::inplace_alter_table (this=0x61d000b3ecb8, altered_table=0x7f689e8fd990, ha_alter_info=0x7f689e8fd2b0) at /data/Server/10.5A/sql/ha_partition.cc:10331

#25 0x00005635af6ccc56 in handler::ha_inplace_alter_table (this=0x61d000b3ecb8, altered_table=0x7f689e8fd990, ha_alter_info=0x7f689e8fd2b0) at /data/Server/10.5A/sql/handler.h:4536

#26 0x00005635af6aecba in mysql_inplace_alter_table (thd=0x62b0000d9218, table_list=0x62b0000a8390, table=0x619000e92098, altered_table=0x7f689e8fd990, ha_alter_info=0x7f689e8fd2b0, target_mdl_request=0x7f689e8fd390, alter_ctx=0x7f689e8fe3f0)

    at /data/Server/10.5A/sql/sql_table.cc:8113

#27 0x00005635af6c0c49 in mysql_alter_table (thd=0x62b0000d9218, new_db=0x62b0000dda78, new_name=0x62b0000dde98, create_info=0x7f689e8ff760, table_list=0x62b0000a8390, alter_info=0x7f689e8ff650, order_num=0, order=0x0, ignore=false, if_exists=false)

    at /data/Server/10.5A/sql/sql_table.cc:10730

#28 0x00005635af834d51 in Sql_cmd_alter_table::execute (this=0x62b0000a8a90, thd=0x62b0000d9218) at /data/Server/10.5A/sql/sql_alter.cc:539

#29 0x00005635af455b73 in mysql_execute_command (thd=0x62b0000d9218) at /data/Server/10.5A/sql/sql_parse.cc:6056

#30 0x00005635af4620b0 in mysql_parse (thd=0x62b0000d9218, rawbuf=0x62b0000a8238 "ALTER TABLE k ENGINE = INNODB /* E_R Thread1 QNO 280 CON_ID 14 */", length=65, parser_state=0x7f689e900cb0, is_com_multi=false, is_next_command=false)

    at /data/Server/10.5A/sql/sql_parse.cc:8100

#31 0x00005635af43a162 in dispatch_command (command=COM_QUERY, thd=0x62b0000d9218, packet=0x629000b1d219 "ALTER TABLE k ENGINE = INNODB /* E_R Thread1 QNO 280 CON_ID 14 */ ", packet_length=66, is_com_multi=false, is_next_command=false)

    at /data/Server/10.5A/sql/sql_parse.cc:1891

#32 0x00005635af4371fb in do_command (thd=0x62b0000d9218) at /data/Server/10.5A/sql/sql_parse.cc:1370

#33 0x00005635af81c6fd in do_handle_one_connection (connect=0x6080000032b8, put_in_cache=true) at /data/Server/10.5A/sql/sql_connect.cc:1418

#34 0x00005635af81bf1b in handle_one_connection (arg=0x6080000032b8) at /data/Server/10.5A/sql/sql_connect.cc:1312

#35 0x00007f68bb90d609 in start_thread (arg=<optimized out>) at pthread_create.c:477

#36 0x00007f68bb4e1293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

(rr)

RQG

====

git clone https://github.com/mleich1/rqg --branch experimental RQG

perl rqg.pl \

--grammar=conf/mariadb/partitions_innodb.yy \

--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 \

--duration=300 \

--mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \

--mysqld=--loose-innodb-sync-debug \

--mysqld=--innodb_stats_persistent=on \

--mysqld=--innodb_adaptive_hash_index=on \

--mysqld=--loose-innodb_evict_tables_on_commit_debug=off \

--mysqld=--loose-max-statement-time=30 \

--threads=9 \

--mysqld=--innodb-use-native-aio=0 \

--rr=Extended \

--rr_options=--wait \

--mysqld=--innodb_page_size=32K \

--mysqld=--innodb-buffer-pool-size=24M \

--no_mask \

--workdir=<local settings> \

--vardir=<local settings> \

--mtr-build-thread=<local settings> \

--basedir1=<local settings> \

--script_debug=_nix

Error pattern for RQG

[ 'TBR-863-ASAN-btr_search_lazy_free-MDEV-26383', 'SUMMARY: AddressSanitizer: heap-use-after-free .{1,200}btr0sea.cc:.{1,30} in btr_search_lazy_free' ],

This problem was also observed on

origin/bb-10.6-MDEV-25998 79016c9e2db6036b1f94b31cb9bb4a713aef39c6 2021-07-09T21:22:40+05:30

Attachments

Issue Links

duplicates

MDEV-24505 innodb.innodb-ucs2 test failed, assertion: list.count > 0, in file storage/innobase/include/ut0lst.h line 334

Closed

MDEV-25065 binlog_encryption.encrypted_master failed in bb with a crash

Closed

MDEV-25465 innodb_zip.create_options ' fails in bb, assertion: list.count > 0 in ut0lst.h line 334

Closed

MDEV-25527 ERROR: AddressSanitizer: attempting double-free in __interceptor_free nearby dict_mem_table_free

Closed

is caused by

MDEV-22456 Dropping the adaptive hash index may cause DDL to lock up InnoDB

Closed

mentioned in: Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...

(12 mentioned in)

Activity

Ascending order - Click to sort in descending order

Marko Mäkelä added a comment - 2021-08-17 12:23

This is a race condition between two threads that are dropping the adaptive hash index:

ssh sdp

rr replay /data/Results/1629134327/TBR-863/dev/shm/vardir/1629134327/170/1/rr/latest-trace

continue

watch -l *(char*)0x0c30800282b8

reverse-continue

reverse-continue

bt

thr a 3 bt

10.5 255313048ca00c48fe78250014570034475a9178
Thread 19 hit Hardware watchpoint 1: -location (char)0x0c30800282b8
…
#5 0x00005635b0b95b49 in dict_mem_table_free (table=0x618000181508)
at /data/Server/10.5A/storage/innobase/dict/dict0mem.cc:247
#6 0x00005635b0a9efb5 in btr_search_lazy_free (index=0x617000016608)
at /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:213
#7 0x00005635b0aa5834 in btr_search_drop_page_hash_index (
block=0x7f68addcd9a0)
at /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:1409
#8 0x00005635b0b176d1 in buf_LRU_free_page (bpage=0x7f68addcd9a0, zip=true)
at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:972
#9 0x00005635b0b115d5 in buf_LRU_free_from_common_LRU_list (limit=100)
at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:246
…
Thread 3 (Thread 596513.612094):
…
#8 0x00005635b052f5de in PolicyMutex<TTASEventMutex<GenericPolicy> >::enter (th--Type <RET> for more, q to quit, c to continue without paging--
is=0x5635b39ea060 <rw_lock_list_mutex>, n_spins=30, n_delay=4, name=0x5635b1d751e0 "/data/Server/10.5A/storage/innobase/sync/sync0rw.cc", line=258) at /data/Server/10.5A/storage/innobase/include/ib0mutex.h:588
#9 0x00005635b094a8cd in rw_lock_free_func (lock=0x617000016078) at /data/Server/10.5A/storage/innobase/sync/sync0rw.cc:258
#10 0x00005635b0a9ee6c in btr_search_lazy_free (index=0x617000015f08) at /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:206
#11 0x00005635b0aa5834 in btr_search_drop_page_hash_index (block=0x7f68addce760) at /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:1409
#12 0x00005635b0b176d1 in buf_LRU_free_page (bpage=0x7f68addce760, zip=true) at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:972
#13 0x00005635b0b115d5 in buf_LRU_free_from_common_LRU_list (limit=100) at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:246
…

The last AHI page for two indexes of an evicted or dropped table is being freed at the same time. Both index->table are pointing to the same evicted or dropped table, which the first thread is freeing. It looks like btr_search_lazy_free() is missing mutex protection. Before 10.6, we could hold dict_sys.mutex; after 10.6, table->lock_mutex, around all the access of index->freed_indexes:

/** Lazily free detached metadata when removing the last reference. */

ATTRIBUTE_COLD static void btr_search_lazy_free(dict_index_t *index)

  ut_ad(index->freed());

  dict_table_t *table= index->table;

  /* Perform the skipped steps of dict_index_remove_from_cache_low(). */

  UT_LIST_REMOVE(table->freed_indexes, index);

  index->lock.free();

  dict_mem_index_free(index);

  if (!UT_LIST_GET_LEN(table->freed_indexes) &&

      !UT_LIST_GET_LEN(table->indexes))

    ut_ad(table->id == 0);

    dict_mem_table_free(table);

Alternatively, we could acquire all AHI latches in exclusive mode. In any case, we must be sure that the latching order is not being violated by adding the mutex acquisition.

Marko Mäkelä added a comment - 2021-08-17 12:23 This is a race condition between two threads that are dropping the adaptive hash index: ssh sdp rr replay /data/Results/1629134327/TBR-863/dev/shm/vardir/1629134327/170/1/rr/latest-trace continue watch -l *(char*)0x0c30800282b8 reverse-continue reverse-continue bt thr a 3 bt 10.5 255313048ca00c48fe78250014570034475a9178 Thread 19 hit Hardware watchpoint 1: -location *(char*)0x0c30800282b8 … #5 0x00005635b0b95b49 in dict_mem_table_free (table=0x618000181508) at /data/Server/10.5A/storage/innobase/dict/dict0mem.cc:247 #6 0x00005635b0a9efb5 in btr_search_lazy_free (index=0x617000016608) at /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:213 #7 0x00005635b0aa5834 in btr_search_drop_page_hash_index ( block=0x7f68addcd9a0) at /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:1409 #8 0x00005635b0b176d1 in buf_LRU_free_page (bpage=0x7f68addcd9a0, zip=true) at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:972 #9 0x00005635b0b115d5 in buf_LRU_free_from_common_LRU_list (limit=100) at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:246 … Thread 3 (Thread 596513.612094): … #8 0x00005635b052f5de in PolicyMutex<TTASEventMutex<GenericPolicy> >::enter (th--Type <RET> for more, q to quit, c to continue without paging-- is=0x5635b39ea060 <rw_lock_list_mutex>, n_spins=30, n_delay=4, name=0x5635b1d751e0 "/data/Server/10.5A/storage/innobase/sync/sync0rw.cc", line=258) at /data/Server/10.5A/storage/innobase/include/ib0mutex.h:588 #9 0x00005635b094a8cd in rw_lock_free_func (lock=0x617000016078) at /data/Server/10.5A/storage/innobase/sync/sync0rw.cc:258 #10 0x00005635b0a9ee6c in btr_search_lazy_free (index=0x617000015f08) at /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:206 #11 0x00005635b0aa5834 in btr_search_drop_page_hash_index (block=0x7f68addce760) at /data/Server/10.5A/storage/innobase/btr/btr0sea.cc:1409 #12 0x00005635b0b176d1 in buf_LRU_free_page (bpage=0x7f68addce760, zip=true) at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:972 #13 0x00005635b0b115d5 in buf_LRU_free_from_common_LRU_list (limit=100) at /data/Server/10.5A/storage/innobase/buf/buf0lru.cc:246 … The last AHI page for two indexes of an evicted or dropped table is being freed at the same time. Both index->table are pointing to the same evicted or dropped table, which the first thread is freeing. It looks like btr_search_lazy_free() is missing mutex protection. Before 10.6, we could hold dict_sys.mutex ; after 10.6, table->lock_mutex , around all the access of index->freed_indexes : /** Lazily free detached metadata when removing the last reference. */ ATTRIBUTE_COLD static void btr_search_lazy_free(dict_index_t *index) { ut_ad(index->freed()); dict_table_t *table= index->table; /* Perform the skipped steps of dict_index_remove_from_cache_low(). */ UT_LIST_REMOVE(table->freed_indexes, index); index->lock. free (); dict_mem_index_free(index); if (!UT_LIST_GET_LEN(table->freed_indexes) && !UT_LIST_GET_LEN(table->indexes)) { ut_ad(table->id == 0); dict_mem_table_free(table); } } Alternatively, we could acquire all AHI latches in exclusive mode. In any case, we must be sure that the latching order is not being violated by adding the mutex acquisition.

Marko Mäkelä added a comment - 2021-08-20 11:56

I realized that we that we could simply (mis)use dict_table_t::autoinc_mutex for protecting table->freed_indexes.

Marko Mäkelä added a comment - 2021-08-20 11:56 I realized that we that we could simply (mis)use dict_table_t::autoinc_mutex for protecting table->freed_indexes .

People

Assignee:: Thirunarayanan Balathandayuthapani

Reporter:: Matthias Leich

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Dates

Created:: 2021-08-17 10:49

Updated:: 2024-09-05 20:03

Resolved:: 2021-08-23 08:48

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server