[MDEV-23097] heap-use-after-free in mysqlimport - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.1(EOL), 10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5
Fix Version/s: 10.3.36, 10.4.26, 10.5.17, 10.6.9, 10.7.5, 10.8.4
Component/s: Scripts & Clients
Labels:
- ASAN
- corruption
- race
- rr-profile

Description

The test main.mysqldump occasionally fails like this on ASAN, suggesting that mysqlimport is accessing freed memory:

10.5 90d5d906409025d64a4ab8eff3e5704c13c256a4
CURRENT_TEST: main.mysqldump
mysqldump: Couldn't find table: "non_existing"
mysqldump: Got error: 1356: "View 'test.v1' references invalid table(s) or column(s) or function(s) or definer/invoker of view lack rights to use them" when using LOCK TABLES
mysqldump: Couldn't execute 'SHOW FIELDS FROM `v1`': View 'test.v1' references invalid table(s) or column(s) or function(s) or definer/invoker of view lack rights to use them (1356)
mysqldump: Got error: 1083: "Field separator argument is not what is expected; check the manual" when executing 'SELECT INTO OUTFILE'
mysqldump: Got error: 1083: "Field separator argument is not what is expected; check the manual" when executing 'SELECT INTO OUTFILE'
mysqldump: Got error: 1083: "Field separator argument is not what is expected; check the manual" when executing 'SELECT INTO OUTFILE'
mysqldump: user2 has insufficient privileges to SHOW CREATE PROCEDURE `sp1`!
mysqldump: Got error: 1146: "Table 'test.???????????????????????' doesn't exist" when using LOCK TABLES
/dev/shm/10.5a/client/mysqlimport: Error: 1146, Table 'test.words' doesn't exist, when using table: words
=================================================================
==126464==ERROR: AddressSanitizer: heap-use-after-free on address 0x61500000020f at pc 0x000000485417 bp 0x7ff7af1fb4f0 sp 0x7ff7af1facb0
READ of size 5 at 0x61500000020f thread T4
#0 0x485416 in strdup (/dev/shm/10.5a/client/mariadb-import+0x485416)
#1 0x4d8bc4 in mthd_my_real_connect /mariadb/10.5m/libmariadb/libmariadb/mariadb_lib.c:1535:21
#2 0x4d79d1 in mysql_real_connect /mariadb/10.5m/libmariadb/libmariadb/mariadb_lib.c:1295:10
#3 0x4cb629 in db_connect /mariadb/10.5m/client/mysqlimport.c:473:9
#4 0x4cb184 in worker_thread /mariadb/10.5m/client/mysqlimport.c:605:16
#5 0x7ff7b464af26 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x8f26)
#6 0x7ff7b3ea331e in clone (/lib/x86_64-linux-gnu/libc.so.6+0xfd31e)

0x61500000020f is located 399 bytes inside of 496-byte region [0x615000000080,0x615000000270)
freed by thread T3 here:
#0 0x498e7d in free (/dev/shm/10.5a/client/mariadb-import+0x498e7d)
#1 0x57654b in my_free /mariadb/10.5m/mysys/my_malloc.c:209:3
#2 0x567ce6 in free_root /mariadb/10.5m/mysys/my_alloc.c:416:7
#3 0x55ffe9 in free_defaults /mariadb/10.5m/mysys/my_default.c:500:3
#4 0x4cc18b in safe_exit /mariadb/10.5m/client/mysqlimport.c:518:3
#5 0x4cc18b in db_error_with_table /mariadb/10.5m/client/mysqlimport.c:533:3
#6 0x4cc18b in write_to_table /mariadb/10.5m/client/mysqlimport.c:384:5
#7 0x4cb1ae in worker_thread /mariadb/10.5m/client/mysqlimport.c:619:14

previously allocated by thread T0 here:
#0 0x4990fd in malloc (/dev/shm/10.5a/client/mariadb-import+0x4990fd)
#1 0x575bfc in my_malloc /mariadb/10.5m/mysys/my_malloc.c:88:29
#2 0x567002 in alloc_root /mariadb/10.5m/mysys/my_alloc.c:243:30
#3 0x55fb2f in init_default_directories /mariadb/10.5m/mysys/my_default.c:1016:24
#4 0x55e8eb in my_load_defaults /mariadb/10.5m/mysys/my_default.c:414:14
#5 0x4cc3b7 in main /mariadb/10.5m/client/mysqlimport.c:643:3
#6 0x7ff7b3dcce0a in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x26e0a)

Thread T4 created by T0 here:
#0 0x483eaa in pthread_create (/dev/shm/10.5a/client/mariadb-import+0x483eaa)
#1 0x4cc999 in main /mariadb/10.5m/client/mysqlimport.c:693:11
#2 0x7ff7b3dcce0a in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x26e0a)

Thread T3 created by T0 here:
#0 0x483eaa in pthread_create (/dev/shm/10.5a/client/mariadb-import+0x483eaa)
#1 0x4cc999 in main /mariadb/10.5m/client/mysqlimport.c:693:11
#2 0x7ff7b3dcce0a in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x26e0a)

SUMMARY: AddressSanitizer: heap-use-after-free (/dev/shm/10.5a/client/mariadb-import+0x485416) in strdup
Shadow bytes around the buggy address:
0x0c2a7fff7ff0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c2a7fff8000: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c2a7fff8010: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c2a7fff8020: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c2a7fff8030: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c2a7fff8040: fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd fa fa
0x0c2a7fff8050: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c2a7fff8060: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c2a7fff8070: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c2a7fff8080: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c2a7fff8090: fd fd fd fd fd fd fd fd fd fd fd fd fd fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
Addressable: 00
Partially addressable: 01 02 03 04 05 06 07
Heap left redzone: fa
Freed heap region: fd
Stack left redzone: f1
Stack mid redzone: f2
Stack right redzone: f3
Stack after return: f5
Stack use after scope: f8
Global redzone: f9
Global init order: f6
Poisoned by user: f7
Container overflow: fc
Array cookie: ac
Intra object redzone: bb
ASan internal: fe
Left alloca redzone: ca
Right alloca redzone: cb
Shadow gap: cc
==126464==ABORTING
Aborted
mysqltest: At line 1785: command "$MYSQL_IMPORT --silent --use-threads=2 test $MYSQLTEST_VARDIR/tmp/t1.txt $MYSQLTEST_VARDIR/tmp/t2.txt $MYSQLTEST_VARDIR/std_data/words.dat $MYSQLTEST_VARDIR/std_data/words2.dat" failed with wrong error: 134

Cross-reference finds at least 2 occurrences of this on 10.1 (back when we still had kvm-asan running on 10.1). The newest kvm-asan occurrence seems to be on 10.5 424dc49d415ae27345cc3b9548329da4 (sorry, no logs available outside cross-reference).

Over the past few days, I have repeated a failure twice when running an ASAN build of 10.5 locally. WIth the following invocation, I can repeat it after a few tries:

ASAN_OPTIONS=abort_on_error=1 ./mtr --repeat=10 --parallel=auto main.mysqldump{,,,,,,,,,,,,,}

10.5 90d5d906409025d64a4ab8eff3e5704c13c256a4
main.mysqldump 'innodb' w11 [ 2 pass ] 14034
main.mysqldump 'innodb' w11 [ 3 fail ]

Attachments

Issue Links

relates to

MDEV-29463 mysqlimport occasionally fails to fail in main.mysqldump

Closed

Activity

Ascending order - Click to sort in descending order

Marko Mäkelä added a comment - 2021-03-12 07:29

This failed on 10.5 kvm-asan again. I was able to repeat this locally with the following patch:

diff --git a/mysql-test/main/mysqldump.test b/mysql-test/main/mysqldump.test

index 799f24665ee..a68f3b2871d 100644

--- a/mysql-test/main/mysqldump.test

+++ b/mysql-test/main/mysqldump.test

@@ -1768,7 +1768,7 @@ drop table words;

 --replace_regex /.*mysqlimport(\.exe)*/mysqlimport/

 --replace_result mysqldump.exe mysqldump

 --error 1

---exec $MYSQL_IMPORT --silent --use-threads=2 test $MYSQLTEST_VARDIR/tmp/t1.txt $MYSQLTEST_VARDIR/tmp/t2.txt $MYSQLTEST_VARDIR/std_data/words.dat $MYSQLTEST_VARDIR/std_data/words2.dat

+--exec rr record $MYSQL_IMPORT --silent --use-threads=2 test $MYSQLTEST_VARDIR/tmp/t1.txt $MYSQLTEST_VARDIR/tmp/t2.txt $MYSQLTEST_VARDIR/std_data/words.dat $MYSQLTEST_VARDIR/std_data/words2.dat

 drop table t1;

 drop table t2;

and with the following invocation:

ASAN_OPTIONS=abort_on_error=1 _RR_TRACE_DIR=/dev/shm/rr ./mtr --repeat=100 --parallel=auto main.mysqldump{,,,,,,,,,,,,,,,}

Due to the parallel invocation, it took some time to find the trace. But I got it:

10.5 4c2b6be38e7c62d585b137ab9b3af4907a08a737
/dev/shm/10.5a/client/mysqlimport: Error: 1146, Table 'test.words' doesn't exist, when using table: words
=================================================================
==234496==ERROR: AddressSanitizer: heap-use-after-free on address 0x6150000001bd at pc 0x0000004ce5d9 bp 0x7f42b0dfbd70 sp 0x7f42b0dfbd68
READ of size 1 at 0x6150000001bd thread T4
#0 0x4ce5d8 in db_connect /mariadb/10.5m/client/mysqlimport.c:467:25
#1 0x4cdf94 in worker_thread /mariadb/10.5m/client/mysqlimport.c:610:16
#2 0x7f42b67e0ea6 in start_thread nptl/pthread_create.c:477:8
#3 0x7f42b602fdee in clone misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95

0x6150000001bd is located 317 bytes inside of 496-byte region [0x615000000080,0x615000000270)
freed by thread T3 here:
#0 0x49b75d in free (/dev/shm/10.5a/client/mariadb-import+0x49b75d)
#1 0x56b097 in free_root /mariadb/10.5m/mysys/my_alloc.c:416:7
#2 0x4cedcb in safe_exit /mariadb/10.5m/client/mysqlimport.c:523:3
#3 0x4cedcb in db_error_with_table /mariadb/10.5m/client/mysqlimport.c:538:3
#4 0x4cedcb in write_to_table /mariadb/10.5m/client/mysqlimport.c:389:5
#5 0x4cdfbe in worker_thread /mariadb/10.5m/client/mysqlimport.c:624:14
…
Shadow bytes around the buggy address:
…
=>0x0c2a7fff8030: fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd fd fd
…
(rr) watch -l (char)0x0c2a7fff8037
Hardware watchpoint 1: -location (char)0x0c2a7fff8037
(rr) rc
Continuing.

Thread 3 received signal SIGABRT, Aborted.
__GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50 in ../sysdeps/unix/sysv/linux/raise.c
(rr)
Continuing.
[Switching to Thread 234496.234743]

Thread 4 hit Hardware watchpoint 1: -location (char)0x0c2a7fff8037

Old value = -3 '\375'
New value = -9 '\367'
__memset_avx2_unaligned_erms ()
at ../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S:178
178 ../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S: Tiedostoa tai hakemistoa ei ole.
(rr) bt
#0 __memset_avx2_unaligned_erms ()
at ../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S:178
#1 0x00000000004273bd in __asan::Allocator::QuarantineChunk(__asan::AsanChunk, void, __sanitizer::BufferedStackTrace*) ()
#2 0x000000000049b7e2 in free ()
#3 0x00000000005772e0 in my_free (ptr=<optimized out>)
at /mariadb/10.5m/mysys/my_malloc.c:211
#4 0x000000000056b098 in free_root (root=root@entry=0x7f42b15fa1a0,
MyFlags=<optimized out>, MyFlags@entry=0)
at /mariadb/10.5m/mysys/my_alloc.c:416
#5 0x000000000056081a in free_defaults (argv=<optimized out>)
at /mariadb/10.5m/mysys/my_default.c:500
#6 0x00000000004cedcc in safe_exit (error=1, mysql=0x61a00001fe80)
at /mariadb/10.5m/client/mysqlimport.c:523
#7 db_error_with_table (mysql=0x61a00001fe80, table=<optimized out>)
at /mariadb/10.5m/client/mysqlimport.c:538
#8 write_to_table (filename=<optimized out>, mysql=<optimized out>)
at /mariadb/10.5m/client/mysqlimport.c:389
#9 0x00000000004cdfbf in worker_thread (arg=0x7ffdba3512d4)
at /mariadb/10.5m/client/mysqlimport.c:624

At the time the memory is freed, the thread that catches the error is blocked in a system call (I guess, being created):

(rr) thread apply 3 backtrace

Thread 3 (Thread 234496.234752 (mmap_copy_4_mar)):

#0  0x0000000070000002 in ?? ()

#1  0x00007f42b68272f3 in _raw_syscall () at /build/rr-7fqooc/rr-5.4.0/src/preload/raw_syscall.S:120

#2  0x00007f42b68252f7 in traced_raw_syscall (call=0x7f42b18fdfa0) at ./src/preload/syscallbuf.c:272

#3  syscall_hook_internal (call=0x7f42b18fdfa0) at ./src/preload/syscallbuf.c:3295

#4  syscall_hook (call=0x7f42b18fdfa0) at ./src/preload/syscallbuf.c:3329

#5  0x00007f42b6822270 in _syscall_hook_trampoline () at /build/rr-7fqooc/rr-5.4.0/src/preload/syscall_hook.S:313

#6  0x00007f42b68222cf in __morestack () at /build/rr-7fqooc/rr-5.4.0/src/preload/syscall_hook.S:458

#7  0x00007f42b682237a in _syscall_hook_trampoline_c3_nop () at /build/rr-7fqooc/rr-5.4.0/src/preload/syscall_hook.S:527

#8  0x0000000000000000 in ?? ()

Finally, this thread will trip ASAN:

#6  0x00000000004a1be8 in __asan_report_load1 ()

#7  0x00000000004ce5d9 in db_connect (host=<optimized out>,

    database=<optimized out>, user=<optimized out>, passwd=<optimized out>)

    at /mariadb/10.5m/client/mysqlimport.c:467

#8  0x00000000004cdf95 in worker_thread (arg=0x7ffdba351307)

    at /mariadb/10.5m/client/mysqlimport.c:610

#9  0x00007f42b67e0ea7 in start_thread (arg=<optimized out>)

    at pthread_create.c:477

#10 0x00007f42b602fdef in clone ()

    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

As far as I understand, safe_exit() isn’t, because it does not wait for all worker_thread to exit. At the time of the crash, the exiting thread is still executing an atexit() handler that was installed for AddressSanitizer:

(rr) thread apply 4 backtrace

Thread 4 (Thread 234496.234743 (mmap_copy_4_mar)):

#0  0x00000000004b1f70 in __sanitizer::BlockingMutex::Lock() ()

#1  0x00000000004c5229 in __lsan::LockStuffAndStopTheWorldCallback(dl_phdr_info*, unsigned long, void*) ()

#2  0x00007f42b60691e5 in __GI___dl_iterate_phdr (

    callback=0x4c5220 <__lsan::LockStuffAndStopTheWorldCallback(dl_phdr_info*, unsigned long, void*)>, data=0x7f42b15fa148) at dl-iteratephdr.c:75

#3  0x00000000004c520f in __lsan::LockStuffAndStopTheWorld(void (*)(__sanitizer::SuspendedThreadsList const&, void*), __lsan::CheckForLeaksParam*) ()

#4  0x00000000004c29d8 in __lsan::CheckForLeaks() ()

#5  0x00000000004c2942 in __lsan::DoLeakCheck() ()

#6  0x00007f42b5f704d7 in __run_exit_handlers (status=1,

    listp=0x7f42b60f0718 <__exit_funcs>,

    run_list_atexit=run_list_atexit@entry=true, run_dtors=run_dtors@entry=true)

    at exit.c:108

#7  0x00007f42b5f7067a in __GI_exit (status=<optimized out>) at exit.c:139

#8  0x00000000004cef3d in write_to_table (filename=<optimized out>,

    mysql=<optimized out>) at /mariadb/10.5m/client/mysqlimport.c:368

#9  0x00000000004cdfbf in worker_thread (arg=0x7ffdba3512d4)

As far as I understand, even if this atexit handler did not exist, there is a race condition between other worker_thread and this code in safe_exit():

  free_defaults(argv_to_free);

  my_free(opt_password);

  if (error)

    sf_leaking_memory= 1; /* dirty exit, some threads are still running */

  else

    my_end(my_end_arg); /* clean exit */

  exit(error);

Before all threads are actually terminated, they can access the freed memory. Here is the start of worker_thread():

  if (mysql_thread_init())

    goto error;

  if (!(mysql= db_connect(current_host,current_db,current_user,opt_password)))

We crashed inside db_connect(), for accessing opt_plugin_dir. Note that also opt_password had been explicitly freed by safe_exit().

It seems to me that to fix this race condition, the scope of init_mutex or counter_mutex must be extended, and possibly a condition variable would be needed so that safe_exit() can wait for all worker_thread to exit.

Marko Mäkelä added a comment - 2021-03-12 07:29 This failed on 10.5 kvm-asan again. I was able to repeat this locally with the following patch: diff --git a/mysql-test/main/mysqldump.test b/mysql-test/main/mysqldump.test index 799f24665ee..a68f3b2871d 100644 --- a/mysql-test/main/mysqldump.test +++ b/mysql-test/main/mysqldump.test @@ -1768,7 +1768,7 @@ drop table words; --replace_regex /.*mysqlimport(\.exe)*/mysqlimport/ --replace_result mysqldump.exe mysqldump --error 1 ---exec $MYSQL_IMPORT --silent --use-threads=2 test $MYSQLTEST_VARDIR/tmp/t1.txt $MYSQLTEST_VARDIR/tmp/t2.txt $MYSQLTEST_VARDIR/std_data/words.dat $MYSQLTEST_VARDIR/std_data/words2.dat +--exec rr record $MYSQL_IMPORT --silent --use-threads=2 test $MYSQLTEST_VARDIR/tmp/t1.txt $MYSQLTEST_VARDIR/tmp/t2.txt $MYSQLTEST_VARDIR/std_data/words.dat $MYSQLTEST_VARDIR/std_data/words2.dat drop table t1; drop table t2; and with the following invocation: ASAN_OPTIONS=abort_on_error=1 _RR_TRACE_DIR=/dev/shm/rr ./mtr --repeat=100 --parallel=auto main.mysqldump{,,,,,,,,,,,,,,,} Due to the parallel invocation, it took some time to find the trace. But I got it: 10.5 4c2b6be38e7c62d585b137ab9b3af4907a08a737 /dev/shm/10.5a/client/mysqlimport: Error: 1146, Table 'test.words' doesn't exist, when using table: words ================================================================= ==234496==ERROR: AddressSanitizer: heap-use-after-free on address 0x6150000001bd at pc 0x0000004ce5d9 bp 0x7f42b0dfbd70 sp 0x7f42b0dfbd68 READ of size 1 at 0x6150000001bd thread T4 #0 0x4ce5d8 in db_connect /mariadb/10.5m/client/mysqlimport.c:467:25 #1 0x4cdf94 in worker_thread /mariadb/10.5m/client/mysqlimport.c:610:16 #2 0x7f42b67e0ea6 in start_thread nptl/pthread_create.c:477:8 #3 0x7f42b602fdee in clone misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95 0x6150000001bd is located 317 bytes inside of 496-byte region [0x615000000080,0x615000000270) freed by thread T3 here: #0 0x49b75d in free (/dev/shm/10.5a/client/mariadb-import+0x49b75d) #1 0x56b097 in free_root /mariadb/10.5m/mysys/my_alloc.c:416:7 #2 0x4cedcb in safe_exit /mariadb/10.5m/client/mysqlimport.c:523:3 #3 0x4cedcb in db_error_with_table /mariadb/10.5m/client/mysqlimport.c:538:3 #4 0x4cedcb in write_to_table /mariadb/10.5m/client/mysqlimport.c:389:5 #5 0x4cdfbe in worker_thread /mariadb/10.5m/client/mysqlimport.c:624:14 … Shadow bytes around the buggy address: … =>0x0c2a7fff8030: fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd fd fd … (rr) watch -l *(char*)0x0c2a7fff8037 Hardware watchpoint 1: -location *(char*)0x0c2a7fff8037 (rr) rc Continuing. Thread 3 received signal SIGABRT, Aborted. __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 50 in ../sysdeps/unix/sysv/linux/raise.c (rr) Continuing. [Switching to Thread 234496.234743] Thread 4 hit Hardware watchpoint 1: -location *(char*)0x0c2a7fff8037 Old value = -3 '\375' New value = -9 '\367' __memset_avx2_unaligned_erms () at ../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S:178 178 ../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S: Tiedostoa tai hakemistoa ei ole. (rr) bt #0 __memset_avx2_unaligned_erms () at ../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S:178 #1 0x00000000004273bd in __asan::Allocator::QuarantineChunk(__asan::AsanChunk*, void*, __sanitizer::BufferedStackTrace*) () #2 0x000000000049b7e2 in free () #3 0x00000000005772e0 in my_free (ptr=<optimized out>) at /mariadb/10.5m/mysys/my_malloc.c:211 #4 0x000000000056b098 in free_root (root=root@entry=0x7f42b15fa1a0, MyFlags=<optimized out>, MyFlags@entry=0) at /mariadb/10.5m/mysys/my_alloc.c:416 #5 0x000000000056081a in free_defaults (argv=<optimized out>) at /mariadb/10.5m/mysys/my_default.c:500 #6 0x00000000004cedcc in safe_exit (error=1, mysql=0x61a00001fe80) at /mariadb/10.5m/client/mysqlimport.c:523 #7 db_error_with_table (mysql=0x61a00001fe80, table=<optimized out>) at /mariadb/10.5m/client/mysqlimport.c:538 #8 write_to_table (filename=<optimized out>, mysql=<optimized out>) at /mariadb/10.5m/client/mysqlimport.c:389 #9 0x00000000004cdfbf in worker_thread (arg=0x7ffdba3512d4) at /mariadb/10.5m/client/mysqlimport.c:624 At the time the memory is freed, the thread that catches the error is blocked in a system call (I guess, being created): (rr) thread apply 3 backtrace Thread 3 (Thread 234496.234752 (mmap_copy_4_mar)): #0 0x0000000070000002 in ?? () #1 0x00007f42b68272f3 in _raw_syscall () at /build/rr-7fqooc/rr-5.4.0/src/preload/raw_syscall.S:120 #2 0x00007f42b68252f7 in traced_raw_syscall (call=0x7f42b18fdfa0) at ./src/preload/syscallbuf.c:272 #3 syscall_hook_internal (call=0x7f42b18fdfa0) at ./src/preload/syscallbuf.c:3295 #4 syscall_hook (call=0x7f42b18fdfa0) at ./src/preload/syscallbuf.c:3329 #5 0x00007f42b6822270 in _syscall_hook_trampoline () at /build/rr-7fqooc/rr-5.4.0/src/preload/syscall_hook.S:313 #6 0x00007f42b68222cf in __morestack () at /build/rr-7fqooc/rr-5.4.0/src/preload/syscall_hook.S:458 #7 0x00007f42b682237a in _syscall_hook_trampoline_c3_nop () at /build/rr-7fqooc/rr-5.4.0/src/preload/syscall_hook.S:527 #8 0x0000000000000000 in ?? () Finally, this thread will trip ASAN: #6 0x00000000004a1be8 in __asan_report_load1 () #7 0x00000000004ce5d9 in db_connect (host=<optimized out>, database=<optimized out>, user=<optimized out>, passwd=<optimized out>) at /mariadb/10.5m/client/mysqlimport.c:467 #8 0x00000000004cdf95 in worker_thread (arg=0x7ffdba351307) at /mariadb/10.5m/client/mysqlimport.c:610 #9 0x00007f42b67e0ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477 #10 0x00007f42b602fdef in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 As far as I understand, safe_exit() isn’t, because it does not wait for all worker_thread to exit. At the time of the crash, the exiting thread is still executing an atexit() handler that was installed for AddressSanitizer: (rr) thread apply 4 backtrace Thread 4 (Thread 234496.234743 (mmap_copy_4_mar)): #0 0x00000000004b1f70 in __sanitizer::BlockingMutex::Lock() () #1 0x00000000004c5229 in __lsan::LockStuffAndStopTheWorldCallback(dl_phdr_info*, unsigned long, void*) () #2 0x00007f42b60691e5 in __GI___dl_iterate_phdr ( callback=0x4c5220 <__lsan::LockStuffAndStopTheWorldCallback(dl_phdr_info*, unsigned long, void*)>, data=0x7f42b15fa148) at dl-iteratephdr.c:75 #3 0x00000000004c520f in __lsan::LockStuffAndStopTheWorld(void (*)(__sanitizer::SuspendedThreadsList const&, void*), __lsan::CheckForLeaksParam*) () #4 0x00000000004c29d8 in __lsan::CheckForLeaks() () #5 0x00000000004c2942 in __lsan::DoLeakCheck() () #6 0x00007f42b5f704d7 in __run_exit_handlers (status=1, listp=0x7f42b60f0718 <__exit_funcs>, run_list_atexit=run_list_atexit@entry=true, run_dtors=run_dtors@entry=true) at exit.c:108 #7 0x00007f42b5f7067a in __GI_exit (status=<optimized out>) at exit.c:139 #8 0x00000000004cef3d in write_to_table (filename=<optimized out>, mysql=<optimized out>) at /mariadb/10.5m/client/mysqlimport.c:368 #9 0x00000000004cdfbf in worker_thread (arg=0x7ffdba3512d4) As far as I understand, even if this atexit handler did not exist, there is a race condition between other worker_thread and this code in safe_exit() : free_defaults(argv_to_free); my_free(opt_password); if (error) sf_leaking_memory= 1; /* dirty exit, some threads are still running */ else my_end(my_end_arg); /* clean exit */ exit (error); Before all threads are actually terminated, they can access the freed memory. Here is the start of worker_thread() : if (mysql_thread_init()) goto error; if (!(mysql= db_connect(current_host,current_db,current_user,opt_password))) We crashed inside db_connect() , for accessing opt_plugin_dir . Note that also opt_password had been explicitly freed by safe_exit() . It seems to me that to fix this race condition, the scope of init_mutex or counter_mutex must be extended, and possibly a condition variable would be needed so that safe_exit() can wait for all worker_thread to exit.

Michael Widenius added a comment - 2021-11-16 11:19

I increase the level to critical as it happens often enough on buildbot and also at my desktop when running the mtr test suite

Michael Widenius added a comment - 2021-11-16 11:19 I increase the level to critical as it happens often enough on buildbot and also at my desktop when running the mtr test suite

Oleksandr Byelkin added a comment - 2022-06-22 12:01

I tried to repeat, 150 times run with no problem.

Oleksandr Byelkin added a comment - 2022-06-22 12:01 I tried to repeat, 150 times run with no problem.

Oleksandr Byelkin added a comment - 2022-06-22 12:07

(I will be thankful for any idea how to repeat, while I am trying to fix it by looking on sources)

Oleksandr Byelkin added a comment - 2022-06-22 12:07 (I will be thankful for any idea how to repeat, while I am trying to fix it by looking on sources)

Oleksandr Byelkin added a comment - 2022-06-22 13:27

I do not see how it is possible, will return to it later

Oleksandr Byelkin added a comment - 2022-06-22 13:27 I do not see how it is possible, will return to it later

People

Assignee:: Sergei Golubchik

Reporter:: Marko Mäkelä

Votes:: 1 Vote for this issue

Watchers:: 4 Start watching this issue

Dates

Created:: 2020-07-05 13:10

Updated:: 2022-09-05 06:12

Resolved:: 2022-08-02 18:59

Git Integration

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

MariaDB Server