Bug #62329 5.6.2-m5 crash on mysql_kill
Submitted: 2 Sep 2011 8:57 Modified: 29 Jan 2012 0:28
Reporter: Ulf Wendel Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version:5.6.2.-m5 OS:Any
Assigned to: CPU Architecture:Any

[2 Sep 2011 8:57] Ulf Wendel
Description:
Two lines of PHP are enough to crash MySQL 5.6.2-m5: 

 - open connection
 - kill connection

This breaks the PHP MySQL Connector test ext/mysqli/tests/071.phpt

110902 10:55:57 mysqld_safe Number of processes running now: 0
110902 10:55:57 mysqld_safe mysqld restarted                  
mysqld: /home/nixnutz/ftp/mysql-5.6.2-m5/sql/protocol.cc:522: void Protocol::end_statement(): Assertion `0' failed.
110902 10:55:57 - 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=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338620 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x1e25c10
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 = 0x7f2fd0bce080 thread_stack 0x40000
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(my_print_stacktrace+0x35)[0x93bb5e]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(handle_segfault+0x31f)[0x56ecba]
/lib64/libpthread.so.0[0x7f2fe0891c00]
/lib64/libc.so.6(gsignal+0x35)[0x7f2fdf8a54e5]
/lib64/libc.so.6(abort+0x180)[0x7f2fdf8a69b0]
/lib64/libc.so.6(__assert_fail+0xea)[0x7f2fdf89e24a]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(_ZN8Protocol13end_statementEv+0x254)[0x64d95c]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1d3c)[0x6eb613]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(_Z10do_commandP3THD+0x297)[0x6e96c4]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(_Z24do_handle_one_connectionP3THD+0x468)[0x6c2855]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(handle_one_connection+0x33)[0x6c23e6]
/lib64/libpthread.so.0[0x7f2fe088965d]
/lib64/libc.so.6(clone+0x6d)[0x7f2fdf943ecd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query ((nil)): is an invalid pointer
Connection ID (thread ID): 1
Status: KILL_CONNECTION

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.
110902 10:55:57 mysqld_safe Number of processes running now: 0
110902 10:55:57 mysqld_safe mysqld restarted
110902 10:55:57 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
110902 10:55:57 InnoDB: The InnoDB memory heap is disabled
110902 10:55:57 InnoDB: Mutexes and rw_locks use GCC atomic builtins
110902 10:55:57 InnoDB: Compressed tables use zlib 1.2.3
110902 10:55:57 InnoDB: Using Linux native AIO
110902 10:55:57 InnoDB: Initializing buffer pool, size = 128.0M
110902 10:55:57 InnoDB: Completed initialization of buffer pool
110902 10:55:57 InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
110902 10:55:57  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
110902 10:55:57 InnoDB: 1.2.2 started; log sequence number 109408306
110902 10:55:57 [Note] Event Scheduler: Loaded 0 events
110902 10:55:57 [Note] /home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld: ready for connections.
Version: '5.6.2-m5-debug'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution

How to repeat:
Compile PHP against libmysql from MySQL 5.6.2-m5

rm -rf autom4te.cache/ ; rm ext/mysqlnd_ms/*.lo; svn up && ./buildconf --force && ./configure --with-mysql=/home/nixnutz/ftp/mysql-5.6.2-m5/install --with-mysqli=/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysql_config  --with-pdo-mysql=/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysql_config --enable-debug  --with-openssl  --enable-pcntl && make clean && make -j4

Run:

sapi/cli/php -r '$link = new mysqli("localhost", "root", "", "test"); $link->kill($link->thread_id); var_dump($link->error);'

Suggested fix:
No crash, please.
[2 Sep 2011 9:14] Valeriy Kravchuk
I do not see any problem when killing current connection from mysql command line client with current mysql-trunk:

[openxs@chief trunk]$ bin/mysql --no-defaults -uroot test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.6.4-m5-debug Source distribution

Copyright (c) 2000, 2011, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> show processlist;
+----+------+-----------+------+---------+------+-------+------------------+
| Id | User | Host      | db   | Command | Time | State | Info             |
+----+------+-----------+------+---------+------+-------+------------------+
|  3 | root | localhost | test | Query   |    0 | init  | show processlist |
+----+------+-----------+------+---------+------+-------+------------------+
1 row in set (0.00 sec)

mysql> kill connection 3;
ERROR 1317 (70100): Query execution was interrupted
[4 Sep 2011 15:30] MySQL Verification Team
i get this crash all the time on 5.5.15-debug:
Version: '5.5.15-debug-log'  socket: ''  port: 3306  MySQL Community Server - Debug (GPL)
Assertion failed: 0, file ..\..\mysql-5.5.15\sql\protocol.cc, line 518
mysqld-debug.exe!my_sigabrt_handler()[my_thr_init.c:501]
mysqld-debug.exe!raise()[winsig.c:590]
mysqld-debug.exe!abort()[abort.c:71]
mysqld-debug.exe!_wassert()[assert.c:163]
mysqld-debug.exe!Protocol::end_statement()[protocol.cc:518]
mysqld-debug.exe!dispatch_command()[sql_parse.cc:1395]
mysqld-debug.exe!do_command()[sql_parse.cc:771]
mysqld-debug.exe!do_handle_one_connection()[sql_connect.cc:789]

In two threads I do this:
1)  kill a connection
2)  mysql_refresh() with all the options...

binlogging must be enabled on server.
[6 Sep 2011 10:07] Ulf Wendel
Here's another variation of the theme, breaking yet another Connector/PHP test (ext/mysqli/tests/mysqli_stmt_close.phpt). Crash happens upon kill.

----------------- "isolated" code sequence -----------------------

	require_once("connect.inc");

	$tmp    = NULL;
	$link   = NULL;

	require('table.inc');

	if (!$stmt = mysqli_stmt_init($link))
		printf("[008] [%d] %s\n", mysqli_errno($link), mysqli_error($link));

	if (!mysqli_stmt_prepare($stmt, "INSERT INTO test(id, label) VALUES (?, ?)"))
		printf("[009] [%d] %s\n", mysqli_stmt_errno($stmt), mysqli_stmt_error($stmt));

	$id = $label = null;
	if (!mysqli_stmt_bind_param($stmt, "is", $id, $label))
		printf("[010] [%d] %s\n", mysqli_stmt_errno($stmt), mysqli_stmt_error($stmt));

	$id = 100; $label = 'z';
	if (!mysqli_stmt_execute($stmt))
		printf("[011] [%d] %s\n", mysqli_stmt_errno($stmt), mysqli_stmt_error($stmt));

	mysqli_kill($link, mysqli_thread_id($link));

---------------- crash -------------------------------------------

110906 11:44:15 mysqld_safe Number of processes running now: 0
110906 11:44:15 mysqld_safe mysqld restarted                  
mysqld: /home/nixnutz/ftp/mysql-5.6.2-m5/sql/protocol.cc:522: void Protocol::end_statement(): Assertion `0' failed.
110906 11:44:15 - 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=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338620 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x1ea4e30
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 = 0x7fad71a52080 thread_stack 0x40000
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(my_print_stacktrace+0x35)[0x93fa4e]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(handle_segfault+0x31f)[0x56f495]
/lib64/libpthread.so.0[0x7fad81715c00]
/lib64/libc.so.6(gsignal+0x35)[0x7fad807294e5]
/lib64/libc.so.6(abort+0x180)[0x7fad8072a9b0]
/lib64/libc.so.6(__assert_fail+0xea)[0x7fad8072224a]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(_ZN8Protocol13end_statementEv+0x254)[0x650388]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1d3c)[0x6eeb4f]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(_Z10do_commandP3THD+0x297)[0x6ecc00]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(_Z24do_handle_one_connectionP3THD+0x468)[0x6c5d91]
/home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld(handle_one_connection+0x33)[0x6c5922]
/lib64/libpthread.so.0[0x7fad8170d65d]
/lib64/libc.so.6(clone+0x6d)[0x7fad807c7ecd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query ((nil)): is an invalid pointer
Connection ID (thread ID): 2
Status: KILL_CONNECTION

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.
110906 11:44:15 mysqld_safe Number of processes running now: 0
110906 11:44:15 mysqld_safe mysqld restarted
110906 11:44:15 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
110906 11:44:15 InnoDB: The InnoDB memory heap is disabled
110906 11:44:15 InnoDB: Mutexes and rw_locks use GCC atomic builtins
110906 11:44:15 InnoDB: Compressed tables use zlib 1.2.3
110906 11:44:15 InnoDB: Using Linux native AIO
110906 11:44:15 InnoDB: Initializing buffer pool, size = 128.0M
110906 11:44:15 InnoDB: Completed initialization of buffer pool
110906 11:44:15 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 348020694
110906 11:44:15  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 348023698
110906 11:44:16  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
110906 11:44:16 InnoDB: 1.2.2 started; log sequence number 348023698
110906 11:44:16 [Note] Event Scheduler: Loaded 0 events
110906 11:44:16 [Note] /home/nixnutz/ftp/mysql-5.6.2-m5/install/bin/mysqld: ready for connections.
Version: '5.6.2-m5-debug'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
[29 Dec 2011 0:28] Sveta Smirnova
Thank you for the report.

I can not repeat described behavior against latest mysql-trunk (5.6.5-m8) and PHP 5.3.8 Please try in your environment with these versions and inform us if problem still exists.
[29 Jan 2012 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[29 Jan 2012 6:18] MySQL Verification Team
this still happens alot, but there's an internal bug filed already.  try killing actual dml/ddl/sql statements randomly to reproduce it.