Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Won't Fix
-
10.2(EOL), 10.3(EOL), 10.4(EOL)
Description
buffer pool page hash is being accessed after freeing it.
Thread 61:
|
|
|
#0 0x000055f89f2cf52b in hash_get_lock (table=0x607000021a40,
|
fold=24117287)
|
at /home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/include/hash0hash.ic:213
|
#1 0x000055f89f30031c in buf_page_hash_lock_get (page_id=...,
|
buf_pool=0x61b000001580)
|
at /home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/include/buf0types.h:167
|
#2 buf_page_get_low (page_id=..., page_size=...,
|
rw_latch=rw_latch@entry=1, guess=guess@entry=0x0,
|
mode=mode@entry=10,
|
file=file@entry=0x55f8a023baa0 "/home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/btr/btr0cur.cc", line=<optimized out>,
|
mtr=<optimized out>, err=<optimized out>)
|
at /home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/buf/buf0buf.cc:4298
|
#3 0x000055f89f30450a in buf_page_get_gen (page_id=...,
|
page_size=..., rw_latch=rw_latch@entry=1, guess=guess@entry=0x0,
|
mode=mode@entry=10,
|
file=file@entry=0x55f8a023baa0 "/home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/btr/btr0cur.cc", line=7980, mtr=0x14b2c39fa750,
|
err=0x0)
|
at /home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/buf/buf0buf.cc:4927
|
#4 0x000055f89f25b7be in btr_copy_blob_prefix (
|
buf=buf@entry=0x625000791c88 '\276' <repeats 200 times>...,
|
len=len@entry=3329, space_id=space_id@entry=23,
|
page_no=page_no@entry=16, offset=offset@entry=38)
|
at /home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/include/buf0types.h:139
|
#5 0x000055f89f260b03 in btr_copy_externally_stored_field_prefix_low (
|
buf=buf@entry=0x625000791c88 '\276' <repeats 200 times>...,
|
len=len@entry=3329, page_size=..., space_id=space_id@entry=23,
|
page_no=page_no@entry=16, offset=offset@entry=38)
|
at /home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/btr/btr0cur.cc:8190
|
|
|
(rr) when
|
Current event: 849992
|
Another thread does buffer pool resizing and it replaces buf_pool->page_hash also.
Thread 28 hit Breakpoint 3, buf_pool_resize_hash (
|
buf_pool=0x61b000001580)
|
at /home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/buf/buf0buf.cc:2630
|
2630 buf_pool->page_hash_old = buf_pool->page_hash;
|
(rr) where
|
#0 buf_pool_resize_hash (buf_pool=0x61b000001580)
|
at /home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/buf/buf0buf.cc:2630
|
#1 0x000055f89f311ee5 in buf_pool_resize ()
|
at /home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/buf/buf0buf.cc:3076
|
#2 0x000055f89f3139ad in buf_resize_thread ()
|
at /home/mleich/Server/bb-10.3-MDEV-23693/storage/innobase/buf/buf0buf.cc:3189
|
#3 0x000014b2cf0f2609 in start_thread (arg=<optimized out>)
|
at pthread_create.c:477
|
#4 0x0000143d39509103 in clone ()
|
at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
|
|
(rr) when
|
Current event: 850000
|
buf_pool_resize():
It frees the page_hash_old table too.
if (buf_pool->page_hash_old != NULL) {
|
hash_table_free(buf_pool->page_hash_old);
|
buf_pool->page_hash_old = NULL;
|
}
|
So t61 ended up accessing the freed page_hash of buf_pool.
Attachments
Issue Links
- is duplicated by
-
-
- Closed
-
- relates to
-
-
- Closed
-
Activity
Error patterns for RQG
|
[ 'TBR-719B' , 'in hash_get_lock.{1,1000}in buf_page_hash_lock_get.{1,1000}in buf_page_get_low.{1,1000}in buf_page_get_gen.{1,1000}in btr_copy_blob_prefix.{1,1000}in btr_copy_externally_stored_field_prefix_low.{1,1000}in btr_copy_externally_stored_field' ],
|
[ 'TBR-719A' , 'SUMMARY: AddressSanitizer: heap-use-after-free .{1,200}hash0hash.ic:.{1,30} in hash_get_lock' ],
|
During the development of MDEV-22871, I translated a call hash_lock_x_all(buf_pool->page_hash) into a member function buf_pool_t::write_lock_all_page_hash(). I think that the motivation of that code was to prevent exactly this type of race condition. Apparently, the logic is flawed after all, or it needs to be revised.
Some quite similar ASAN failure in that region
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 527775] #0 0x55abdfa30998 in hash_get_nth_lock /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/hash0hash.ic:197
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 527777] #1 0x55abdfa30998 in hash_get_lock /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/hash0hash.ic:222
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 527787] #2 0x55abdfa61317 in buf_page_hash_lock_get /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/buf0buf.h:2268
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 527789] #3 0x55abdfa61317 in buf_page_get_low(page_id_t, page_size_t const&, unsigned long, buf_block_t*, unsigned long, char const*, unsigned int, mtr_t*, dberr_t*) /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/buf/buf0buf.cc:4298
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 527791] #4 0x55abdfa65505 in buf_page_get_gen(page_id_t, page_size_t const&, unsigned long, buf_block_t*, unsigned long, char const*, unsigned int, mtr_t*, dberr_t*) /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/buf/buf0buf.cc:4927
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528248] #5 0x55abdf87aa21 in trx_undo_page_get_s_latched /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/trx0undo.ic:161
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528250] #6 0x55abdf87aa21 in trx_purge_get_next_rec /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/trx/trx0purge.cc:1316
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528252] #7 0x55abdf87b8b7 in trx_purge_fetch_next_rec /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/trx/trx0purge.cc:1382
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528254] #8 0x55abdf87c454 in trx_purge_attach_undo_recs /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/trx/trx0purge.cc:1456
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528256] #9 0x55abdf881f97 in trx_purge(unsigned long, bool, srv_slot_t*) /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/trx/trx0purge.cc:1592
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528434] #10 0x55abdf7e5534 in srv_do_purge /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/srv/srv0srv.cc:2637
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528436] #11 0x55abdf7ec09e in srv_purge_coordinator_thread /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/srv/srv0srv.cc:2769
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528465] #12 0x1468b4fe0608 in start_thread /build/glibc-YYA7BZ/glibc-2.31/nptl/pthread_create.c:477
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528467] #13 0x4e4c1c571102 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122102)
|
|
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528469]
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528479]0x607000028540 is located 64 bytes inside of 72-byte region [0x607000028500,0x607000028548)
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528485]freed by thread T27 here:
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528491] #0 0x6d506e62d7cf in __interceptor_free (/lib/x86_64-linux-gnu/libasan.so.5+0x10d7cf)
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528565] #1 0x55abdfca20f4 in hash_table_free(hash_table_t*) /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/ha/hash0hash.cc:144
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528570] #2 0x55abe09d5e77 (/data/mleich/Server_bin/bb-10.3-MDEV-23693A_asan_Og/bin/mysqld+0x33d2e77)
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528572]
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528578]previously allocated by thread T27 here:
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528584] #0 0x6d506e62dbc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528589] #1 0x55abdfca1e69 in hash0_create(unsigned long) /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/ha/hash0hash.cc:107
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528591]
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528599]Thread T21 created by T0 here:
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528605] #0 0x6d506e55a805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528628] #1 0x55abdf533cc4 in os_thread_create_func(void* (*)(void*), void*, unsigned long*) /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/os/os0thread.cc:138
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528630]
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528640]Thread T27 created by T0 here:
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528646] #0 0x6d506e55a805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528648] #1 0x55abdf533cc4 in os_thread_create_func(void* (*)(void*), void*, unsigned long*) /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/os/os0thread.cc:138
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528650]
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 528662]SUMMARY: AddressSanitizer: heap-use-after-free /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/hash0hash.ic:197 in hash_get_nth_lock
|
# 2020-10-26T19:43:16 [45476] | [rr 47250 529096]Shadow bytes around the buggy address:
|
# 2020-10-26T19:43:16 [45476] | 0x0c0e7fffd050: fd fd fd fd fd fa fa fa fa fa fd fd fd fd fd fd
|
# 2020-10-26T19:43:16 [45476] | 0x0c0e7fffd060: fd fd fd fa fa fa fa fa fd fd fd fd fd fd fd fd
|
# 2020-10-26T19:43:16 [45476] | 0x0c0e7fffd070: fd fa fa fa fa fa fd fd fd fd fd fd fd fd fd fa
|
# 2020-10-26T19:43:16 [45476] | 0x0c0e7fffd080: fa fa fa fa fd fd fd fd fd fd fd fd fd fa fa fa
|
# 2020-10-26T19:43:16 [45476] | 0x0c0e7fffd090: fa fa fd fd fd fd fd fd fd fd fd fa fa fa fa fa
|
# 2020-10-26T19:43:16 [45476] | =>0x0c0e7fffd0a0: fd fd fd fd fd fd fd fd[fd]fa fa fa fa fa fd fd
|
# 2020-10-26T19:43:16 [45476] | 0x0c0e7fffd0b0: fd fd fd fd fd fd fd fa fa fa fa fa fd fd fd fd
|
# 2020-10-26T19:43:16 [45476] | 0x0c0e7fffd0c0: fd fd fd fd fd fa fa fa fa fa fd fd fd fd fd fd
|
# 2020-10-26T19:43:16 [45476] | 0x0c0e7fffd0d0: fd fd fd fa fa fa fa fa fd fd fd fd fd fd fd fd
|
# 2020-10-26T19:43:16 [45476] | 0x0c0e7fffd0e0: fd fa fa fa fa fa fd fd fd fd fd fd fd fd fd fa
|
# 2020-10-26T19:43:16 [45476] | 0x0c0e7fffd0f0: fa fa fa fa fd fd fd fd fd fd fd fd fd fa fa fa
|
|
|
(rr) bt
|
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
|
#1 0x00004e4c1c474859 in __GI_abort () at abort.c:79
|
#2 0x00006d506e64b6a2 in ?? () from /lib/x86_64-linux-gnu/libasan.so.5
|
#3 0x00006d506e65624c in ?? () from /lib/x86_64-linux-gnu/libasan.so.5
|
#4 0x00006d506e6378ec in ?? () from /lib/x86_64-linux-gnu/libasan.so.5
|
#5 0x00006d506e637363 in ?? () from /lib/x86_64-linux-gnu/libasan.so.5
|
#6 0x00006d506e6381ab in __asan_report_load8 () from /lib/x86_64-linux-gnu/libasan.so.5
|
#7 0x000055abdfa30999 in hash_get_nth_lock (i=6, table=0x607000028500) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/hash0hash.ic:196
|
#8 hash_get_lock (table=0x607000028500, fold=833) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/hash0hash.ic:222
|
#9 0x000055abdfa61318 in buf_page_hash_lock_get (page_id=..., buf_pool=0x61b000001580) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/buf0types.h:167
|
#10 buf_page_get_low (page_id=..., page_size=..., rw_latch=rw_latch@entry=1, guess=guess@entry=0x0, mode=mode@entry=10, file=file@entry=0x55abe09589a0 "/home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/trx0undo.ic", line=<optimized out>,
|
mtr=<optimized out>, err=<optimized out>) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/buf/buf0buf.cc:4298
|
#11 0x000055abdfa65506 in buf_page_get_gen (page_id=..., page_size=..., rw_latch=rw_latch@entry=1, guess=guess@entry=0x0, mode=mode@entry=10, file=file@entry=0x55abe09589a0 "/home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/trx0undo.ic",
|
line=161, mtr=0x64000046e320, err=0x0) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/buf/buf0buf.cc:4927
|
#12 0x000055abdf87aa22 in trx_undo_page_get_s_latched (mtr=0x64000046e320, page_id=...) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/include/trx0undo.ic:161
|
#13 trx_purge_get_next_rec (n_pages_handled=n_pages_handled@entry=0x64000046e960, heap=heap@entry=0x613000002880) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/trx/trx0purge.cc:1316
|
#14 0x000055abdf87b8b8 in trx_purge_fetch_next_rec (roll_ptr=roll_ptr@entry=0x613000002910, n_pages_handled=n_pages_handled@entry=0x64000046e960, heap=0x613000002880) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/trx/trx0purge.cc:1382
|
#15 0x000055abdf87c455 in trx_purge_attach_undo_recs (n_purge_threads=n_purge_threads@entry=4) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/trx/trx0purge.cc:1456
|
#16 0x000055abdf881f98 in trx_purge (n_purge_threads=4, truncate=<optimized out>, slot=slot@entry=0x55abe14dc348 <srv_sys+328>) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/trx/trx0purge.cc:1592
|
#17 0x000055abdf7e5535 in srv_do_purge (n_total_purged=n_total_purged@entry=0x64000046ec40, slot=slot@entry=0x55abe14dc348 <srv_sys+328>) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/srv/srv0srv.cc:2637
|
#18 0x000055abdf7ec09f in srv_purge_coordinator_thread (arg=<optimized out>) at /home/mleich/Server/bb-10.3-MDEV-23693A/storage/innobase/srv/srv0srv.cc:2769
|
#19 0x00001468b4fe0609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#20 0x00004e4c1c571103 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
(rr)
|
|
|
rr:/data/mleich/RQG_mleich/storage/1603730772/TBR-723/dev/shm/vardir/1603730772/9/1/rr
|
_RR_TRACE_DIR="." rr replay --mark-stdio
|
|
|
[ 'TBR-723B' , 'in hash_get_nth_lock.{1,1000}in hash_get_lock.{1,1000}in buf_page_hash_lock_get.{1,1000}in buf_page_get_low.{1,1000}in buf_page_get_gen.{1,1000}in trx_undo_page_get_s_latched.{1,1000}in trx_purge_get_next_rec' ],
|
[ 'TBR-723A' , 'SUMMARY: AddressSanitizer: heap-use-after-free .{1,200}hash0hash.ic:.{1,30} in hash_get_nth_lock' ],
|
I think that this has been fixed by MDEV-26033 in MariaDB 10.5.12 and 10.6.3.
We fix the race condition by never resizing (and reallocating) the buf_pool.page_hash. We assume that resizing the buffer pool is a rare operation. Yes, there might be a performance regression if a server is first started up with a tiny buffer pool, which is later enlarged.
Porting that fix to earlier releases would involve some nontrivial effort, because before MDEV-15058 the buffer pool was split into multiple instances.
This was fixed by MDEV-26033 in the MariaDB Server 10.5 release series. I don’t think we should spend time on fixing this in earlier major versions.
In 10.5, the code was refactored by
MDEV-22871, but I would not rule out this race condition. The hash table is being reallocated in buf_pool_t::resize_hash().