Bug #45632 query_cache_debug.test fails
Description:
query_cache_debug.test fails as follows:
TEST RESULT TIME (ms)
------------------------------------------------------------
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
timer 16942: expired after 900 seconds
worker[1] Trying to dump core for [mysqltest - pid: 16968, winpid: 16968]
worker[1] Trying to dump core for [mysqld.1 - pid: 16938, winpid: 16938]
main.query_cache_debug [ fail ] timeout after 900 seconds
Test ended at 2009-06-20 11:14:18
Test case timeout after 900 seconds
== /home/psergey/dev/mysql-5.1-look/mysql-test/var/log/query_cache_debug.log ==
** and finally release the mutex. The threads will continue to wait
** until a broadcast signal reaches them causing both threads to
** come alive and check the condition.
SELECT SQL_NO_CACHE id FROM information_schema.processlist WHERE state='wait_in_query_cache_insert' LIMIT 1 INTO @thread_id;
KILL QUERY @thread_id;
SELECT SQL_NO_CACHE id FROM information_schema.processlist WHERE state='wait_in_query_cache_insert' LIMIT 1 INTO @thread_id;
KILL QUERY @thread_id;
**
** Finally signal the DELETE statement on THD1 one last time.
** The stmt will complete the query cache invalidation and return
** cache status to NO_FLUSH_IN_PROGRESS. On the status change
** One signal will be sent to the thread group waiting for executing
** invalidations and a broadcast signal will be sent to the thread
** group holding result set writers.
SELECT SQL_NO_CACHE id FROM information_schema.processlist WHERE state='wait_in_query_cache_invalidate2' LIMIT 1 INTO @flush_thread_id;
KILL QUERY @flush_thread_id;
**
*************************************************************************
** No tables should be locked
=================================== Connection thd2
== /home/psergey/dev/mysql-5.1-look/mysql-test/var/tmp/analyze-timeout-mysqld.1.err ==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local MySQL server through socket '/home/psergey/dev/mysql-5.1-look/mysql-test/var/tmp/mysqld.1.sock' (111)
- saving '/home/psergey/dev/mysql-5.1-look/mysql-test/var/log/main.query_cache_debug/' to '/home/psergey/dev/mysql-5.1-look/mysql-test/var/log/main.query_cache_debug/'
- found 'core.16939' (0/5)
Trying 'dbx' to get a backtrace
Trying 'gdb' to get a backtrace
Core generated by '/home/psergey/dev/mysql-5.1-look/sql/mysqld'
Output from gdb follows. The first stack trace is from the failing thread.
The following stack traces are from all threads (so the failing one is
duplicated).
--------------------------
warning: Can't read pathname for load map: Input/output error.
Core was generated by `/home/psergey/dev/mysql-5.1-look/sql/mysqld --defaults-group-suffix=.1 --defaul'.
Program terminated with signal 6, Aborted.
[New process 16939]
[New process 16991]
[New process 16941]
#0 0xb7fa914e in pthread_kill () from /lib/libpthread.so.0
#0 0xb7fa914e in pthread_kill () from /lib/libpthread.so.0
#1 0x086f5b03 in my_write_core (sig=6) at stacktrace.c:310
#2 0x082bf080 in handle_segfault (sig=6) at mysqld.cc:2537
#3 <signal handler called>
#4 0xb7ea7c77 in select () from /lib/libc.so.6
#5 0x082bf9a7 in handle_connections_sockets (arg=0x0) at mysqld.cc:4973
#6 0x082c2ae8 in main (argc=7, argv=0xbf856594) at mysqld.cc:4471
Thread 3 (process 16941):
#0 0xb7fabc39 in do_sigwait () from /lib/libpthread.so.0
#1 0xb7fabcdf in sigwait () from /lib/libpthread.so.0
#2 0x082be8a4 in signal_hand (arg=0x0) at mysqld.cc:2739
#3 0xb7fa4013 in start_thread () from /lib/libpthread.so.0
#4 0xb7eae49e in clone () from /lib/libc.so.6
Thread 2 (process 16991):
#0 0xb7ea7c77 in select () from /lib/libc.so.6
#1 0x086eed37 in my_sleep (m_seconds=1000) at my_sleep.c:31
#2 0x08446aea in debug_wait_for_kill (info=0x8848b5f "wait_in_query_cache_insert") at sql_cache.cc:388
#3 0x0844dcf1 in query_cache_insert (net=0x8aa6984, packet=0x8ab8430 "\001", length=186) at sql_cache.cc:840
#4 0x082adf60 in net_real_write (net=0x8aa6984, packet=0x8ab8430 "\001", len=186) at net_serv.cc:565
#5 0x082ae60d in net_flush (net=0x8aa6984) at net_serv.cc:342
#6 0x082b1f37 in net_send_eof (thd=0x8aa6908, server_status=34, total_warn_count=0) at protocol.cc:205
#7 0x082b2689 in net_end_statement (thd=0x8aa6908) at protocol.cc:402
#8 0x082db00c in dispatch_command (command=COM_QUERY, thd=0x8aa6908, packet=0x8ab8431 "", packet_length=49) at sql_parse.cc:1583
#9 0x082db3c8 in do_command (thd=0x8aa6908) at sql_parse.cc:854
#10 0x082c7c14 in handle_one_connection (arg=0x8aa6908) at sql_connect.cc:1127
#11 0xb7fa4013 in start_thread () from /lib/libpthread.so.0
#12 0xb7eae49e in clone () from /lib/libc.so.6
Thread 1 (process 16939):
#0 0xb7fa914e in pthread_kill () from /lib/libpthread.so.0
#1 0x086f5b03 in my_write_core (sig=6) at stacktrace.c:310
#2 0x082bf080 in handle_segfault (sig=6) at mysqld.cc:2537
#3 <signal handler called>
#4 0xb7ea7c77 in select () from /lib/libc.so.6
#5 0x082bf9a7 in handle_connections_sockets (arg=0x0) at mysqld.cc:4973
#6 0x082c2ae8 in main (argc=7, argv=0xbf856594) at mysqld.cc:4471
------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 963 seconds executing testcases
Failed 1/1 tests, 0.00% were successful.
Failing test(s): main.query_cache_debug
How to repeat:
* Compile with BUILD/compile-pentium-debug-max
* Run ./mysql-test-run t/query_cache_debug.test,
or the entire test suite: http://askmonty.org/buildbot/builders/gentoo-x86-dbg/builds/44/steps/test/logs/stdio
Observe the failure
Suggested fix:
Sanja investigated this from our side, you might want to get in touch with him.
Portions of this website are copyright © 2001, 2002 The PHP Group
Page generated in 0.043 sec. using MySQL 8.4.7-u6-cloud
Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the
respective copyright holders.
It is not reviewed in advance
by Oracle and does not necessarily represent the opinion of
Oracle or any other party.
Description: query_cache_debug.test fails as follows: TEST RESULT TIME (ms) ------------------------------------------------------------ worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 timer 16942: expired after 900 seconds worker[1] Trying to dump core for [mysqltest - pid: 16968, winpid: 16968] worker[1] Trying to dump core for [mysqld.1 - pid: 16938, winpid: 16938] main.query_cache_debug [ fail ] timeout after 900 seconds Test ended at 2009-06-20 11:14:18 Test case timeout after 900 seconds == /home/psergey/dev/mysql-5.1-look/mysql-test/var/log/query_cache_debug.log == ** and finally release the mutex. The threads will continue to wait ** until a broadcast signal reaches them causing both threads to ** come alive and check the condition. SELECT SQL_NO_CACHE id FROM information_schema.processlist WHERE state='wait_in_query_cache_insert' LIMIT 1 INTO @thread_id; KILL QUERY @thread_id; SELECT SQL_NO_CACHE id FROM information_schema.processlist WHERE state='wait_in_query_cache_insert' LIMIT 1 INTO @thread_id; KILL QUERY @thread_id; ** ** Finally signal the DELETE statement on THD1 one last time. ** The stmt will complete the query cache invalidation and return ** cache status to NO_FLUSH_IN_PROGRESS. On the status change ** One signal will be sent to the thread group waiting for executing ** invalidations and a broadcast signal will be sent to the thread ** group holding result set writers. SELECT SQL_NO_CACHE id FROM information_schema.processlist WHERE state='wait_in_query_cache_invalidate2' LIMIT 1 INTO @flush_thread_id; KILL QUERY @flush_thread_id; ** ************************************************************************* ** No tables should be locked =================================== Connection thd2 == /home/psergey/dev/mysql-5.1-look/mysql-test/var/tmp/analyze-timeout-mysqld.1.err == mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local MySQL server through socket '/home/psergey/dev/mysql-5.1-look/mysql-test/var/tmp/mysqld.1.sock' (111) - saving '/home/psergey/dev/mysql-5.1-look/mysql-test/var/log/main.query_cache_debug/' to '/home/psergey/dev/mysql-5.1-look/mysql-test/var/log/main.query_cache_debug/' - found 'core.16939' (0/5) Trying 'dbx' to get a backtrace Trying 'gdb' to get a backtrace Core generated by '/home/psergey/dev/mysql-5.1-look/sql/mysqld' Output from gdb follows. The first stack trace is from the failing thread. The following stack traces are from all threads (so the failing one is duplicated). -------------------------- warning: Can't read pathname for load map: Input/output error. Core was generated by `/home/psergey/dev/mysql-5.1-look/sql/mysqld --defaults-group-suffix=.1 --defaul'. Program terminated with signal 6, Aborted. [New process 16939] [New process 16991] [New process 16941] #0 0xb7fa914e in pthread_kill () from /lib/libpthread.so.0 #0 0xb7fa914e in pthread_kill () from /lib/libpthread.so.0 #1 0x086f5b03 in my_write_core (sig=6) at stacktrace.c:310 #2 0x082bf080 in handle_segfault (sig=6) at mysqld.cc:2537 #3 <signal handler called> #4 0xb7ea7c77 in select () from /lib/libc.so.6 #5 0x082bf9a7 in handle_connections_sockets (arg=0x0) at mysqld.cc:4973 #6 0x082c2ae8 in main (argc=7, argv=0xbf856594) at mysqld.cc:4471 Thread 3 (process 16941): #0 0xb7fabc39 in do_sigwait () from /lib/libpthread.so.0 #1 0xb7fabcdf in sigwait () from /lib/libpthread.so.0 #2 0x082be8a4 in signal_hand (arg=0x0) at mysqld.cc:2739 #3 0xb7fa4013 in start_thread () from /lib/libpthread.so.0 #4 0xb7eae49e in clone () from /lib/libc.so.6 Thread 2 (process 16991): #0 0xb7ea7c77 in select () from /lib/libc.so.6 #1 0x086eed37 in my_sleep (m_seconds=1000) at my_sleep.c:31 #2 0x08446aea in debug_wait_for_kill (info=0x8848b5f "wait_in_query_cache_insert") at sql_cache.cc:388 #3 0x0844dcf1 in query_cache_insert (net=0x8aa6984, packet=0x8ab8430 "\001", length=186) at sql_cache.cc:840 #4 0x082adf60 in net_real_write (net=0x8aa6984, packet=0x8ab8430 "\001", len=186) at net_serv.cc:565 #5 0x082ae60d in net_flush (net=0x8aa6984) at net_serv.cc:342 #6 0x082b1f37 in net_send_eof (thd=0x8aa6908, server_status=34, total_warn_count=0) at protocol.cc:205 #7 0x082b2689 in net_end_statement (thd=0x8aa6908) at protocol.cc:402 #8 0x082db00c in dispatch_command (command=COM_QUERY, thd=0x8aa6908, packet=0x8ab8431 "", packet_length=49) at sql_parse.cc:1583 #9 0x082db3c8 in do_command (thd=0x8aa6908) at sql_parse.cc:854 #10 0x082c7c14 in handle_one_connection (arg=0x8aa6908) at sql_connect.cc:1127 #11 0xb7fa4013 in start_thread () from /lib/libpthread.so.0 #12 0xb7eae49e in clone () from /lib/libc.so.6 Thread 1 (process 16939): #0 0xb7fa914e in pthread_kill () from /lib/libpthread.so.0 #1 0x086f5b03 in my_write_core (sig=6) at stacktrace.c:310 #2 0x082bf080 in handle_segfault (sig=6) at mysqld.cc:2537 #3 <signal handler called> #4 0xb7ea7c77 in select () from /lib/libc.so.6 #5 0x082bf9a7 in handle_connections_sockets (arg=0x0) at mysqld.cc:4973 #6 0x082c2ae8 in main (argc=7, argv=0xbf856594) at mysqld.cc:4471 ------------------------------------------------------------ The servers were restarted 0 times Spent 0.000 of 963 seconds executing testcases Failed 1/1 tests, 0.00% were successful. Failing test(s): main.query_cache_debug How to repeat: * Compile with BUILD/compile-pentium-debug-max * Run ./mysql-test-run t/query_cache_debug.test, or the entire test suite: http://askmonty.org/buildbot/builders/gentoo-x86-dbg/builds/44/steps/test/logs/stdio Observe the failure Suggested fix: Sanja investigated this from our side, you might want to get in touch with him.