Bug #110479 database crash during the pquery long-term test
Submitted: 23 Mar 2023 9:10 Modified: 23 Mar 2023 13:22
Reporter: jim dickens Email Updates:
Status: Unsupported Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:5.7.38 OS:Any
Assigned to: CPU Architecture:Any

[23 Mar 2023 9:10] jim dickens
Description:
12:45:27 UTC - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
 
key_buffer_size=8388608
read_buffer_size=1048576
max_used_connections=82
max_threads=0
thread_count=80
connection_count=80
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 22138 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f2b65364800
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
InnoDB: Cannot reset all values for monitor counter os_log_pending_writes while it is on. Please turn it off and retry.
stack_bottom = 7f2b6207d520 thread_stack 0x40000
/sda/percona//5.7_dev/sql/bin/mysqld(my_print_stacktrace+0x3c)[0x5654315dca3c]
/sda/percona//5.7_dev/sql/bin/mysqld(handle_fatal_signal+0x4d8)[0x565430cb0b68]
/usr/lib64/libpthread.so.0(+0x135a0)[0x7f2ba07665a0]
/usr/lib64/libc.so.6(+0x15bf7d)[0x7f2ba00fff7d]
/sda/percona//5.7_dev/sql/bin/mysqld(+0xa3788f)[0x565430c9a88f]
/sda/percona//5.7_dev/sql/bin/mysqld(my_vsnprintf_ex+0x5c2)[0x565430c9a4a2]
/sda/percona//5.7_dev/sql/bin/mysqld(my_error+0xd2)[0x5654315d8c02]
/sda/percona//5.7_dev/sql/bin/mysqld(+0x87bb04)[0x565430adeb04]
/sda/percona//5.7_dev/sql/bin/mysqld(_Z10open_tableP3THDP10TABLE_LISTP18Open_table_context+0x180)[0x565430b77ed0]
/sda/percona//5.7_dev/sql/bin/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0x2f4)[0x565430b766d4]
/sda/percona//5.7_dev/sql/bin/mysqld(_Z21open_tables_for_queryP3THDP10TABLE_LISTj+0x55)[0x565430b7c285]
/sda/percona//5.7_dev/sql/bin/mysqld(+0x940bbd)[0x565430ba3bbd]
/sda/percona//5.7_dev/sql/bin/mysqld(_Z21mysql_execute_commandP3THDb+0x388)[0x565430b99b48]
/sda/percona//5.7_dev/sql/bin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x493)[0x565430b98c53]
/sda/percona//5.7_dev/sql/bin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0x7fe)[0x565430ba122e]
/sda/percona//5.7_dev/sql/bin/mysqld(_Z10do_commandP3THD+0x13e)[0x565430ba069e]
/sda/percona//5.7_dev/sql/bin/mysqld(_Z26threadpool_process_requestP3THD+0x99)[0x565430c7a369]
/sda/percona//5.7_dev/sql/bin/mysqld(+0xa17f48)[0x565430c7af48]
/sda/percona//5.7_dev/sql/bin/mysqld(pfs_spawn_thread+0x4b)[0x5654318fb6eb]
/usr/lib64/libpthread.so.0(+0x8f3b)[0x7f2ba075bf3b]
/usr/lib64/libc.so.6(clone+0x40)[0x7f2ba009c840]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f2b65390838): SELECT * FROM (SELECT c1 FROM t11) AS a1
Connection ID (thread ID): 48
Status: KILL_TIMEOUT

core堆栈:
(gdb) bt
#0  0x00007f2ba0763281 in pthread_kill () from /usr/lib64/libpthread.so.0
#1  0x00005654315dc0cb in my_write_core (sig=<optimized out>) at ../../../include/my_thread.h:105
#2  0x0000565430cb0aee in handle_fatal_signal (sig=11) at ../../../sql/signal_handler.cc:241
#3  <signal handler called>
#4  0x00007f2ba00fff7d in ?? () from /usr/lib64/libc.so.6
#5  0x0000565430c9a88f in process_str_arg (cs=cs@entry=0x5654329078a0 <my_charset_utf8_general_ci>, to=to@entry=0x7f2b6207b03d "\177", 
    end=end@entry=0x7f2b6207b20f "", width=width@entry=18446744073709551615, par=0x18 <error: Cannot access memory at address 0x18>, print_type=0)
    at ../../../strings/my_vsnprintf.c:206
#6  0x0000565430c9a4a2 in my_vsnprintf_ex (cs=0x5654329078a0 <my_charset_utf8_general_ci>, to=0x7f2b6207b03d "\177", 
    to@entry=0x7f2b6207b010 "slave_preserve_commit_order is not supported \177", n=n@entry=512, fmt=<optimized out>, ap=ap@entry=0x7f2b6207aff8)
    at ../../../strings/my_vsnprintf.c:619
#7  0x00005654315d8c02 in my_error (nr=nr@entry=3024, MyFlags=MyFlags@entry=0) at ../../../mysys/my_error.c:218
#8  0x0000565430adeb04 in MDL_context::acquire_lock (this=this@entry=0x7f2b65364898, mdl_request=mdl_request@entry=0x7f2b5415da20, 
    lock_wait_timeout=<optimized out>) at ../../../sql/mdl.cc:3859
#9  0x0000565430b77ed0 in open_table_get_mdl_lock (mdl_ticket=<synthetic pointer>, flags=0, table_list=0x7f2b5415d678, ot_ctx=0x7f2b6207b930, thd=0x7f2b65364800)
    at ../../../sql/sql_base.h:531
#10 open_table (thd=0x7f2b65364800, table_list=0x7f2b5415d678, ot_ctx=0x7f2b6207b930) at ../../../sql/sql_base.cc:3332
#11 0x0000565430b766d4 in open_and_process_table (flags=<optimized out>, ot_ctx=0x7f2b6207b930, has_prelocking_list=<optimized out>, 
    prelocking_strategy=<optimized out>, counter=<optimized out>, tables=0x7f2b5415d678, lex=0x7f2b65366ae8, thd=0x7f2b65364800) at ../../../sql/sql_base.cc:5336
#12 open_tables (thd=0x7f2b65364800, start=0x7f2b6207b9b8, counter=0x7f2b65366ba8, flags=<optimized out>, prelocking_strategy=0x7f2b6207b9c8)
    at ../../../sql/sql_base.cc:5976
#13 0x0000565430b7c285 in open_tables_for_query (thd=thd@entry=0x7f2b65364800, tables=<optimized out>, tables@entry=0x7f2b5415e198, flags=flags@entry=0)
    at ../../../sql/sql_base.cc:6755
#14 0x0000565430ba3bbd in execute_sqlcom_select (thd=0x7f2b65364800, all_tables=0x7f2b5415e198) at ../../../sql/sql_parse.cc:6351
#15 0x0000565430b99b48 in mysql_execute_command (thd=0x7f2b65364800, first_level=<optimized out>) at ../../../sql/sql_parse.cc:3690
#16 0x0000565430b98c53 in mysql_parse (thd=0x7f2b65364800, parser_state=<optimized out>) at ../../../sql/sql_parse.cc:6855
#17 0x0000565430ba122e in dispatch_command (thd=0x7f2b65364800, com_data=<optimized out>, command=<optimized out>) at ../../../sql/sql_parse.cc:1825
#18 0x0000565430ba069e in do_command (thd=thd@entry=0x7f2b65364800) at ../../../sql/sql_parse.cc:1074
#19 0x0000565430c7a369 in threadpool_process_request (thd=0x7f2b65364800) at ../../../../plugin/threadpool/threadpool_common.cc:275
#20 0x0000565430c7af48 in handle_event (connection=0x7f2b9e823f28) at ../../../../plugin/threadpool/threadpool_unix.cc:1916
#21 worker_main (param=param@entry=0x565432fab600 <all_groups>) at ../../../../plugin/threadpool/threadpool_unix.cc:1975
#22 0x00005654318fb6eb in pfs_spawn_thread (arg=0x7f2b6168e028) at ../../../../storage/perfschema/pfs.cc:2197
#23 0x00007f2ba075bf3b in ?? () from /usr/lib64/libpthread.so.0
#24 0x00007f2ba009c840 in clone () from /usr/lib64/libc.so.6
(gdb) f 16
#16 0x0000565430b98c53 in mysql_parse (thd=0x7f2b65364800, parser_state=<optimized out>) at ../../../sql/sql_parse.cc:6855
6855 ../../../sql/sql_parse.cc: No such file or directory.
(gdb) p thd->m_query_string
$1 = {str = 0x7f2b65390838 "SELECT * FROM (SELECT c1 FROM t11) AS a1", length = 40}

How to repeat:
[20:45:15] [17] ====== TRIAL #85 ======
[20:45:15] [17] Ensuring there are no relevant servers running...
[20:45:15] [17] Clearing rundir...
[20:45:15] [17] Generating new trial workdir /sda/percona//5.7_dev/tmp/077159/85...
[20:45:15] [17] Copying datadir from template...
[20:45:15] [17] ADD_RANDOM_OPTIONS=1: adding mysqld option(s)  --relay-log to this run's MYEXTRA...
[20:45:15] [17] Starting mysqld. Error log is stored at /sda/percona//5.7_dev/tmp/077159/85/log/master.err
[20:45:15] [17] Waiting for mysqld (pid: 3826744) to fully start (note this is slow for Valgrind runs, and can easily take 35-90 seconds even on an high end server)...
[20:45:16] [17] Server started ok. Client: /sda/percona//5.7_dev/sql/bin/mysql -uroot -S/sda/percona//5.7_dev/tmp/077159/85/socket.sock. Admin/Extra Client: /sda/percona//5.7_dev/sql/bin/mysql -urdsAdmin -h127.0.0.1 -P55158
[20:45:16] [17] Begin sysbench run. Log is stored at /sda/percona//5.7_dev/tmp/077159/85/sysbench_run.log
[20:45:16] [17] pquery running (Max duration: 600s)...
[20:45:28] [17] Cleaning up & saving results if needed...
[20:45:33] [17] pquery run details: 20850/29176 queries failed, (28.54% were successful)
[20:45:33] [17] mysqld coredump detected at /sda/percona//5.7_dev/tmp/077159/85/data/core-mysqld-0-11-1673527527-agent1.3826744
[20:45:34] [17] Bug found (as per error log): Z10open_tableP3THDP10TABLE_LISTP18Open_table_context
[20:45:34] [17] Copying rundir from /sda/percona//5.7_dev/tmp/077159/85 to /sda/percona//5.7_dev/logs/077159/85
[23 Mar 2023 13:22] MySQL Verification Team
Hi Mr. dickens,

Thank you for your bug report.

However .........

ThreadPool is a commercial product/plugin and using community Bugs DB is not an appropriate place to report issues against this product/plugin. If you are Oracle customer, please open SR and we will assist you via our Support team.

Have a nice day ......