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.
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.