[MDEV-29463] mysqlimport occasionally fails to fail in main.mysqldump Created: 2022-09-05  Updated: 2022-10-20  Resolved: 2022-10-20

Status: Closed
Project: MariaDB Server
Component/s: Scripts & Clients, SSL
Affects Version/s: 10.10
Fix Version/s: 10.10.2

Type: Bug Priority: Critical
Reporter: Marko Mäkelä Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: affects-tests

Issue Links:
Relates
relates to MDEV-23097 heap-use-after-free in mysqlimport Closed

 Description   

Ever since MDEV-23097 was closed, the test main.mysqldump only seems to fail in the 10.10 and 10.11 branches. Here is a recent example on Fedora 36, AMD64:

10.10 f6118acda961a7fde17f2984d7600e211cd47ee3

 
main.mysqldump 'innodb'                  w1 [ fail ]
 
        Test ended at 2022-09-02 15:05:57
 
 
 
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
 
/usr/bin/mysqlimport: Error: 1146, Table 'test.words' doesn't exist, when using table: words
 
mysqltest: At line 1773: 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: 0



 Comments   
Comment by Marko Mäkelä [ 2022-09-21 ]

A crash (SIGSEGV) may occur as well. Unfortunately, no core dump was produced:

10.10 5deccac4aaf1be948a0ae10f40bb5f668ac37a4d

 
/dev/shm/10.10/client//mysqlimport: Error: 1146, Table 'test.words' doesn't exist, when using table: words
 
Segmentation fault
 
mysqltest: At line 1773: 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: 139

Comment by Elena Stepanova [ 2022-09-24 ]

Underneath It is a crash in both cases, it appears that Debian/Ubuntu return 139 while RPM-based and FreeBSD return 0.

The failure itself is a race-condition upon multi-thread execution of mysqlimport with SSL enabled (by default for the clients since MDEV-27105).
It dominantly happens on SSL-3 distributions (RHEL 9, Rocky 9, Fedora 36, Ubuntu 22.04, Sid), although there have been occurrences with SSL 1.1.1.

The test case below reproduces it almost momentarily on Rocky 9 (with OpenSSL 3), but it takes hundreds repetitions on FreeBSD (with OpenSSL 1.1.1k). This corresponds the cross-reference statistics: ~2000 occurrences with SSL 3, ~70 with SSL 1. I couldn't however reproduce it on my local Debian 11 so far, and there are no recorded occurrences for Debian 10/11.

create table words2(b varchar(255));
 
--error 1
 
--exec $MYSQL_IMPORT --silent --use-threads=2 test $MYSQLTEST_VARDIR/std_data/words.dat $MYSQLTEST_VARDIR/std_data/words2.dat
 
drop table words2;

10.10 on Rocky 9 with OpenSSL 3

 
mysqltest: At line 3: command "$MYSQL_IMPORT --silent --use-threads=2 test $MYSQLTEST_VARDIR/std_data/words.dat $MYSQLTEST_VARDIR/std_data/words2.dat" failed with wrong error: 0
 
...
 
Core was generated by `/home/buildbot/10.10/client//mysqlimport --defaults-file=/home/buildbot/10.10/m'.
 
Program terminated with signal SIGSEGV, Segmentation fault.
 
#0  0x00007f34cff5e443 in OPENSSL_LH_doall () from /lib64/libcrypto.so.3
 
[Current thread is 1 (Thread 0x7f34cf070640 (LWP 97474))]
 
#0  0x00007f34cff5e443 in OPENSSL_LH_doall () from /lib64/libcrypto.so.3
 
#1  0x00007f34cff9a04a in ossl_method_store_add.part () from /lib64/libcrypto.so.3
 
#2  0x00007f34cff3b04a in put_evp_method_in_store.lto_priv () from /lib64/libcrypto.so.3
 
#3  0x00007f34cff66c39 in ossl_method_construct_this.lto_priv () from /lib64/libcrypto.so.3
 
#4  0x00007f34cff66b3e in algorithm_do_this.lto_priv () from /lib64/libcrypto.so.3
 
#5  0x00007f34cff7b67b in ossl_provider_doall_activated () from /lib64/libcrypto.so.3
 
#6  0x00007f34d0041e05 in ossl_method_construct.constprop () from /lib64/libcrypto.so.3
 
#7  0x00007f34d0044684 in inner_evp_generic_fetch.constprop () from /lib64/libcrypto.so.3
 
#8  0x00007f34cff3bc49 in evp_generic_do_all () from /lib64/libcrypto.so.3
 
#9  0x00007f34cff4927c in EVP_KEYMGMT_do_all_provided () from /lib64/libcrypto.so.3
 
#10 0x00007f34cff1d302 in OSSL_DECODER_CTX_new_for_pkey () from /lib64/libcrypto.so.3
 
#11 0x00007f34cfff11c4 in x509_pubkey_ex_d2i_ex () from /lib64/libcrypto.so.3
 
#12 0x00007f34cfe81b9b in asn1_item_embed_d2i () from /lib64/libcrypto.so.3
 
#13 0x00007f34cfe833e8 in asn1_template_noexp_d2i () from /lib64/libcrypto.so.3
 
#14 0x00007f34cfe81d19 in asn1_item_embed_d2i () from /lib64/libcrypto.so.3
 
#15 0x00007f34cfe833e8 in asn1_template_noexp_d2i () from /lib64/libcrypto.so.3
 
#16 0x00007f34cfe81d19 in asn1_item_embed_d2i () from /lib64/libcrypto.so.3
 
#17 0x00007f34cfe82493 in ASN1_item_d2i_ex () from /lib64/libcrypto.so.3
 
#18 0x00007f34cff8a809 in PEM_X509_INFO_read_bio_ex () from /lib64/libcrypto.so.3
 
#19 0x00007f34cffc6474 in X509_load_cert_crl_file_ex () from /lib64/libcrypto.so.3
 
#20 0x00007f34cffc675c in by_file_ctrl_ex.part.0.lto_priv () from /lib64/libcrypto.so.3
 
#21 0x00007f34cffe0a8a in X509_STORE_set_default_paths_ex () from /lib64/libcrypto.so.3
 
#22 0x000055d691a71b92 in ma_tls_set_certs (mysql=0x7f34c0000b60, ctx=0x7f34c0009a80) at /home/buildbot/10.10/libmariadb/libmariadb/secure/openssl.c:343
 
#23 0x000055d691a71ee6 in ma_tls_init (mysql=0x7f34c0000b60) at /home/buildbot/10.10/libmariadb/libmariadb/secure/openssl.c:433
 
#24 0x000055d691a5e97b in ma_pvio_tls_init (mysql=0x7f34c0000b60) at /home/buildbot/10.10/libmariadb/libmariadb/ma_tls.c:71
 
#25 0x000055d691a5e611 in ma_pvio_start_ssl (pvio=0x7f34c00033e0) at /home/buildbot/10.10/libmariadb/libmariadb/ma_pvio.c:531
 
#26 0x000055d691a7b3ac in send_client_reply_packet (mpvio=0x7f34cf06f800, data=0x0, data_len=0) at /home/buildbot/10.10/libmariadb/plugins/auth/my_auth.c:343
 
#27 0x000055d691a7b844 in client_mpvio_write_packet (mpv=0x7f34cf06f800, pkt=0x0, pkt_len=0) at /home/buildbot/10.10/libmariadb/plugins/auth/my_auth.c:505
 
#28 0x000055d691a7a7d4 in native_password_auth_client (vio=0x7f34cf06f800, mysql=0x7f34c0000b60) at /home/buildbot/10.10/libmariadb/plugins/auth/my_auth.c:94
 
#29 0x000055d691a7bc4e in run_plugin_auth (mysql=0x7f34c0000b60, data=0x7f34c00074c8 "]2|?dZt\\MO&lnc(:*c8+", data_len=21, data_plugin=0x7f34c00074dd "mysql_native_password", db=0x7ffea0ebbe8a "test") at /home/buildbot/10.10/libmariadb/plugins/auth/my_auth.c:665
 
#30 0x000055d691a542b0 in mthd_my_real_connect (mysql=0x7f34c0000b60, host=0x55d69386357f "localhost", user=0x55d69386356f "root", passwd=0x55d6938636b8 "", db=0x7ffea0ebbe8a "test", port=16040, unix_socket=0x55d693863599 "/home/buildbot/10.10/mysql-test/var/tmp/3/mysqld.1.sock", client_flag=128) at /home/buildbot/10.10/libmariadb/libmariadb/mariadb_lib.c:1930
 
#31 0x000055d691a52c83 in mysql_real_connect (mysql=0x7f34c0000b60, host=0x55d69386357f "localhost", user=0x55d69386356f "root", passwd=0x55d6938636b8 "", db=0x7ffea0ebbe8a "test", port=16040, unix_socket=0x55d693863599 "/home/buildbot/10.10/mysql-test/var/tmp/3/mysqld.1.sock", client_flag=0) at /home/buildbot/10.10/libmariadb/libmariadb/mariadb_lib.c:1477
 
#32 0x000055d691a4efa1 in db_connect (host=0x55d69386357f "localhost", database=0x7ffea0ebbe8a "test", user=0x55d69386356f "root", passwd=0x55d6938636b8 "") at /home/buildbot/10.10/client/mysqlimport.c:533
 
#33 0x000055d691a4f400 in worker_thread (arg=0x7ffea0ebbec8) at /home/buildbot/10.10/client/mysqlimport.c:667
 
#34 0x00007f34cf9196c2 in start_thread () from /lib64/libc.so.6
 
#35 0x00007f34cf8b93f0 in clone3 () from /lib64/libc.so.6

10.10 5e996fbad9 on FreeBSD 13 with OpenSSL 1.1.1k

 
mysqltest: At line 3: command "$MYSQL_IMPORT --silent --use-threads=2 test $MYSQLTEST_VARDIR/std_data/words.dat $MYSQLTEST_VARDIR/std_data/words2.dat" failed with wrong error: 0
 
...
 
Core was generated by `/usr/home/buildbot/10.10/client//mysqlimport --defaults-file=/usr/home/buildbot/'.
 
Program terminated with signal SIGSEGV, Segmentation fault.
 
Address not mapped to object.
 
#0  0x00000008009f7366 in ?? () from /lib/libthr.so.3
 
[Current thread is 1 (LWP 104448)]
 
#0  0x00000008009f7366 in ?? () from /lib/libthr.so.3
 
#1  0x00000008006bcfa9 in CRYPTO_THREAD_write_lock () from /lib/libcrypto.so.111
 
#2  0x00000008007e3705 in RAND_get_rand_method () from /lib/libcrypto.so.111
 
#3  0x00000008007e3b05 in RAND_priv_bytes () from /lib/libcrypto.so.111
 
#4  0x0000000800761b09 in ?? () from /lib/libcrypto.so.111
 
#5  0x00000008007b2c7b in EVP_PKEY_keygen () from /lib/libcrypto.so.111
 
#6  0x0000000800549e2f in ?? () from /usr/lib/libssl.so.111
 
#7  0x0000000800574136 in ?? () from /usr/lib/libssl.so.111
 
#8  0x0000000800571653 in ?? () from /usr/lib/libssl.so.111
 
#9  0x000000080057d326 in ?? () from /usr/lib/libssl.so.111
 
#10 0x000000080057b62c in ?? () from /usr/lib/libssl.so.111
 
#11 0x0000000000424bd1 in ma_tls_connect (ctls=0x801e050e0) at secure/openssl.c:485
 
#12 0x000000000040a895 in ma_pvio_tls_connect (ctls=0x801e050e0) at ma_tls.c:83
 
#13 0x000000000040a578 in ma_pvio_start_ssl (pvio=0x801e23000) at ma_pvio.c:535
 
#14 0x0000000000408c7b in send_client_reply_packet (mpvio=0x7fffdfdfc780, data=0x0, data_len=0) at /usr/home/buildbot/10.10/libmariadb/plugins/auth/my_auth.c:343
 
#15 0x0000000000408016 in client_mpvio_write_packet (mpv=0x7fffdfdfc780, pkt=0x0, pkt_len=0) at /usr/home/buildbot/10.10/libmariadb/plugins/auth/my_auth.c:505
 
#16 0x00000000004076b0 in native_password_auth_client (vio=0x7fffdfdfc780, mysql=0x801e00000) at /usr/home/buildbot/10.10/libmariadb/plugins/auth/my_auth.c:94
 
#17 0x0000000000407b99 in run_plugin_auth (mysql=0x801e00000, data=0x801e10038 "R{7;c_6/&p#[\"4\"J0Nx5", data_len=21, data_plugin=0x801e1004d "mysql_native_password", db=0x7fffffffc467 "test") at /usr/home/buildbot/10.10/libmariadb/plugins/auth/my_auth.c:665
 
#18 0x00000000003fa08e in mthd_my_real_connect (mysql=0x801e00000, host=0x8012321e7 "localhost", user=0x80123220f "root", passwd=0x801235088 "", db=0x7fffffffc467 "test", port=16060, unix_socket=0x801232221 "/usr/home/buildbot/10.10/mysql-test/var/tmp/3/mysqld.1.sock", client_flag=128) at mariadb_lib.c:1930
 
#19 0x00000000003f8a5d in mysql_real_connect (mysql=0x801e00000, host=0x8012321e7 "localhost", user=0x80123220f "root", passwd=0x801235088 "", db=0x7fffffffc467 "test", port=16060, unix_socket=0x801232221 "/usr/home/buildbot/10.10/mysql-test/var/tmp/3/mysqld.1.sock", client_flag=0) at mariadb_lib.c:1477
 
#20 0x00000000003f0e11 in db_connect (host=0x8012321e7 "localhost", database=0x7fffffffc467 "test", user=0x80123220f "root", passwd=0x801235088 "") at mysqlimport.c:533
 
#21 0x00000000003f09ef in worker_thread (arg=0x7fffffffc4a9) at mysqlimport.c:667
 
#22 0x00000008009ef82b in ?? () from /lib/libthr.so.3
 
#23 0x0000000000000000 in ?? ()

Comment by Sergei Golubchik [ 2022-10-05 ]

What happens here — mysqlimport starts two threads, one hits an error and calls exit(), this invokes openssl atexit hook OPENSSL_cleanup(). It starts cleaning up and at this time the other mysqlimport threads tries to connect using SSL_connect, that uses data structures already freed by the cleanup.

There isn't much we can do here. One option is not to invoke atexit handlers (with _exit())

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