Assertion `!thd->spcont' failed in net_send_error on server shutdown

[Elena Stepanova]

120323 0:32:52 [Note] debug/sql/mysqld: ready for connections.
Version: '5.5.21-MariaDB-debug-log' socket: 'debug/mysql-test/var/tmp/mysqld.1.sock' port: 16000 Source distribution
120323 0:33:07 [Note] Start binlog_dump to slave_server(2), pos(master-bin.000001, 4)
120323 0:33:08 [Note] Semi-sync replication initialized for transactions.
120323 0:33:08 [Note] Semi-sync replication enabled on the master.
120323 0:33:08 [Note] Stop asynchronous binlog_dump to slave (server_id: 2)
120323 0:33:08 [Note] Start binlog_dump to slave_server(2), pos(master-bin.000001, 245)
120323 0:33:08 [Note] Start semi-sync binlog_dump to slave (server_id: 2), pos(master-bin.000001, 245)
120323 0:33:09 [Note] debug/sql/mysqld: Normal shutdown

120323 0:33:10 [Note] Event Scheduler: Purging the queue. 0 events
120323 0:33:10 [Note] Stop semi-sync binlog_dump to slave (server_id: 2)
120323 0:33:12 [Warning] debug/sql/mysqld: Forcing close of thread 7 user: 'root'

120323 0:33:12 [Warning] debug/sql/mysqld: Forcing close of thread 6 user: 'root'

mysqld: sql/protocol.cc:151: bool net_send_error(THD*, uint, const char*, const char*): Assertion `!thd->spcont' failed.
120323 0:33:12 [ERROR] mysqld got signal 6 ;

#7 0xb74f50f0 in abort () from /lib/libc.so.6
#8 0xb74ec014 in __assert_fail () from /lib/libc.so.6
#9 0x081a7bef in net_send_error (thd=0x97760e8, sql_errno=1053,
    err=0x95b0242 "Server shutdown in progress", sqlstate=0x0)
    at sql/protocol.cc:151
#10 0x08197d83 in close_connection (thd=0x97760e8, sql_errno=1053)
    at sql/mysqld.cc:2358
#11 0x081963bc in close_connections () at sql/mysqld.cc:1476
#12 0x0819672f in kill_server (sig_ptr=0x0) at sql/mysqld.cc:1640
#13 0x0819676f in kill_server_thread (arg=0xad1a4328) at sql/mysqld.cc:1668
#14 0x0854933b in pfs_spawn_thread (arg=0x965d9c0)
    at storage/perfschema/pfs.cc:1015
#15 0xb77cbb25 in start_thread () from /lib/libpthread.so.0

bzr version-info
revision-id: <email address hidden>
date: 2012-03-22 20:21:14 +0100
build-date: 2012-03-23 00:35:31 +0400
revno: 3345

Could not reproduce on MySQL 5.5 or MySQL trunk.

Please note that the test case requires semisync plugins, so they should be built and placed in the plugin folder.
On the same reason the test case is not applicable to versions below 5.5.

The test case works pretty reliably for me, but a couple of times (out of dozens) it didn't cause the assertion, so I needed to re-run it.

# Test case:

--source include/master-slave.inc
--source include/have_binlog_format_mixed.inc
--source include/have_semisync_plugin.inc

eval INSTALL PLUGIN rpl_semi_sync_master SONAME '$SEMISYNC_MASTER_SO';
SET GLOBAL rpl_semi_sync_master_enabled = 1;

--connection slave
eval INSTALL PLUGIN rpl_semi_sync_slave SONAME '$SEMISYNC_SLAVE_SO';
SET GLOBAL rpl_semi_sync_slave_enabled = 1;
STOP SLAVE;
START SLAVE;

--connection master
CREATE TABLE t1 (
  pk INT NOT NULL AUTO_INCREMENT PRIMARY KEY,
  a DATETIME
) ENGINE = MyISAM;

--delimiter |
CREATE PROCEDURE pr ()
BEGIN
  DECLARE done INT DEFAULT 10000;
  wl: WHILE done DO
    INSERT INTO t1 (a) VALUES ( NOW() );
    SET done = done - 1;
  END WHILE wl;
END|
--delimiter ;

--send
CALL pr();
--sleep 1
--let $rpl_server_number= 1
--source include/rpl_stop_server.inc

# End of test case

[Elena Stepanova (elenst)]

I am setting the importance to medium for now because it's a debug server, I have not seen any visible issues with a release build. If further analysis shows that there is a hidden problem, please adjust the importance accordingly.

[Elena Stepanova (elenst)]

Also filed in JIRA as MDEV-201.

[Elena Stepanova (elenst)]

Synchronizing with JIRA: the bug has been fixed and closed there.

[Elena Stepanova (elenst)]

Fix released in 5.5.22