Bug #56463 main.init_connect fails if MTR run with --mysqld=--query-cache-size=1000000
Submitted: 1 Sep 2010 16:44
Reporter: Sveta Smirnova Email Updates:
Status: Verified Impact on me:
None 
Category:Tests: Server Severity:S3 (Non-critical)
Version:5.1 OS:Any
Assigned to: Assigned Account CPU Architecture:Any
Triage: Triaged: D1 (Critical)

[1 Sep 2010 16:44] Sveta Smirnova
Description:
main.init_connect fails if MTR run with --mysqld=--query-cache-size=1000000

How to repeat:
$./mtr --mysqld=--query-cache-size=1000000 init_connect
Logging: ./mtr  --mysqld=--query-cache-size=1000000 init_connect
100901 18:43:04 [Note] Plugin 'FEDERATED' is disabled.
100901 18:43:04 [Note] Plugin 'ndbcluster' is disabled.
MySQL Version 5.1.51
Checking supported features...
 - using ndbcluster when necessary, mysqld supports it
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
vardir: /users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var
Checking leftover processes...
Removing old var directory...
 - WARNING: Using the 'mysql-test/var' symlink
Creating var directory '/users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var'...
Installing system database...
Using server port 54905
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009

==============================================================================

TEST                                      RESULT   TIME (ms)
------------------------------------------------------------

main.init_connect                        [ fail ]
        Test ended at 2010-09-01 18:43:05

CURRENT_TEST: main.init_connect
mysqltest: At line 96: query 'select @x' failed: 2013: Lost connection to MySQL server during query

The result from queries just before the failure was:
< snip >
5
7
drop procedure p1;
set global init_connect="create procedure p1(x int)\
begin\
  select count(*) from t1;\
  select * from t1;\
  set @x = x;
end";
call p1(42);
count(*)
3
x
3
5
7
select @x;
@x
42
set global init_connect="call p1(4711)";

More results from queries before failure can be found in /users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var/log/init_connect.log

Server [mysqld.1 - pid: 2551, winpid: 2551, exit: 256] failed during test run
Server log from this test:
100901 19:43:04 [Warning] '--default-character-set' is deprecated and will be removed in a future release. Please use '--character-set-server' instead.
100901 19:43:04 [Warning] /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld: Option '--set-variable' is deprecated. Use --variable-name=value instead.
100901 19:43:04 [Note] Plugin 'FEDERATED' is disabled.
100901 19:43:04 [Note] Plugin 'InnoDB' is disabled.
100901 19:43:04 [Note] Plugin 'ndbcluster' is disabled.
100901 19:43:04 [Note] Event Scheduler: Loaded 0 events
100901 19:43:04 [Note] /users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld: ready for connections.
Version: '5.1.51-debug-log'  socket: '/users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var/tmp/mysqld.1.sock'  port: 13000  Source distribution
100901 19:43:04 [Warning] Aborted connection 8 to db: 'test' user: 'user_1' host: 'localhost' (init_connect command failed)
100901 19:43:04 [Warning] You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'adsfsdfsdfs' at line 1
mysqld: sql_cache.cc:1000: void query_cache_end_of_result(THD*): Assertion `0' failed.
100901 19:43:04 - mysqld got signal 6 ;
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.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=7
max_threads=151
threads_connected=3
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60584 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x19ca4878
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...
stack_bottom = 0x40b450f8 thread_stack 0x40000
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(my_print_stacktrace+0x35)[0xb28bd9]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(handle_segfault+0x288)[0x697aa2]
/lib64/libpthread.so.0[0x3429e0dd40]
/lib64/libc.so.6(gsignal+0x35)[0x3429230015]
/lib64/libc.so.6(abort+0x110)[0x3429231980]
/lib64/libc.so.6(__assert_fail+0xf6)[0x3429229726]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_Z25query_cache_end_of_resultP3THD+0x25c)[0x8501a9]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x210)[0x898404]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_ZN7sp_head7executeEP3THD+0x5e8)[0x89433c]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x74c)[0x895fe6]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_Z21mysql_execute_commandP3THD+0x7424)[0x6b0d71]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_Z11mysql_parseP3THDPcjPPKc+0x2ef)[0x6b558b]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xda6)[0x6a7aa3]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(_Z20execute_init_commandP3THDP11sys_var_strP16pthread_rwlock_t+0xea)[0x6a5866]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld[0x6a4a0b]
/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld(handle_one_connection+0x13e)[0x6a4c35]
/lib64/libpthread.so.0[0x3429e061b5]
/lib64/libc.so.6(clone+0x6d)[0x34292cd39d]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x19cb3478 = select count(*) from t1
thd->thread_id=11
thd->killed=NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file

 - saving '/users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var/log/main.init_connect/' to '/users/ssmirnova/blade12/src/mysql-5.1/mysql-test/var/log/main.init_connect/'
 - found 'core.2552' (0/5)
[1 Sep 2010 16:45] Sveta Smirnova
Additional trace:

Trying 'dbx' to get a backtrace

Trying 'gdb' to get a backtrace
Core generated by '/users/ssmirnova/blade12/src/mysql-5.1/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).
--------------------------
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/users/ssmirnova/blade12/src/mysql-5.1/sql/mysqld --defaults-group-suffix=.1 --'.
Program terminated with signal 6, Aborted.
#0  0x0000003429e0b002 in pthread_kill () from /lib64/libpthread.so.0
#0  0x0000003429e0b002 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000b28c5d in my_write_core (sig=6) at stacktrace.c:331
#2  0x0000000000697ca2 in handle_segfault (sig=6) at mysqld.cc:2606
#3  <signal handler called>
#4  0x0000003429230015 in raise () from /lib64/libc.so.6
#5  0x0000003429231980 in abort () from /lib64/libc.so.6
#6  0x0000003429229726 in __assert_fail () from /lib64/libc.so.6
#7  0x00000000008501a9 in query_cache_end_of_result (thd=dwarf2_read_address: Corrupted DWARF expression.
) at sql_cache.cc:1000
#8  0x0000000000898404 in sp_instr_stmt::execute (this=0x19ca2518, thd=0x19ca4878, nextp=0x40b43528) at sp_head.cc:2900
#9  0x000000000089433c in sp_head::execute (this=0x19ca0878, thd=0x19ca4878) at sp_head.cc:1280
#10 0x0000000000895fe6 in sp_head::execute_procedure (this=0x19ca0878, thd=0x19ca4878, args=0x19ca6c78) at sp_head.cc:2011
#11 0x00000000006b0d71 in mysql_execute_command (thd=0x19ca4878) at sql_parse.cc:4438
#12 0x00000000006b558b in mysql_parse (thd=0x19ca4878, rawbuf=0x19ca7288 "call p1(4711)", length=13, found_semicolon=0x40b44ec0) at sql_parse.cc:6032
#13 0x00000000006a7aa3 in dispatch_command (command=COM_QUERY, thd=0x19ca4878, packet=0x19cb7d58 "call p1(4711)", packet_length=13) at sql_parse.cc:1260
#14 0x00000000006a5866 in execute_init_command (thd=0x19ca4878, init_command_var=0x1187ba0, var_mutex=0x1187020) at sql_parse.cc:407
#15 0x00000000006a4a0b in prepare_new_connection_state (thd=0x19ca4878) at sql_connect.cc:1049
#16 0x00000000006a4c35 in handle_one_connection (arg=0x19ca4878) at sql_connect.cc:1131
#17 0x0000003429e061b5 in start_thread () from /lib64/libpthread.so.0
#18 0x00000034292cd39d in clone () from /lib64/libc.so.6
#19 0x0000000000000000 in ?? ()