[MDEV-22663] void Protocol::end_statement(): Assertion `0' failed in Protocol::end_statement Created: 2020-05-22  Updated: 2022-06-27

Status: Confirmed
Project: MariaDB Server
Component/s: OTHER
Affects Version/s: 10.4, 10.5
Fix Version/s: 10.4, 10.5

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Rucha Deodhar
Resolution: Unresolved Votes: 0
Labels: not-10.1, not-10.2, not-10.3, not-10.6, not-10.7, not-10.8, not-10.9, regression


 Description    

USE test;
 
SET SQL_MODE='';
 
CREATE TABLE t (id INT);
 
INSERT INTO t VALUES (1);
 
INSERT INTO t VALUES (2);
 
INSERT INTO t VALUES (3);
 
INSERT INTO t VALUES (4);
 
ALTER TABLE mysql.help_keyword engine=InnoDB;
 
HELP going_to_crash;

Leads to:

10.5.3 cfe5ee90c8e4b9dfa98a41fcd299197a59261be7

 
mysqld: /test/10.5_dbg/sql/protocol.cc:617: void Protocol::end_statement(): Assertion `0' failed.

10.5.3 cfe5ee90c8e4b9dfa98a41fcd299197a59261be7

 
Core was generated by `/test/MD110520-mariadb-10.5.3-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
[Current thread is 1 (Thread 0x15171b206700 (LWP 136256))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
#1  0x0000557873284c11 in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
 
#2  0x0000557872a29f8d in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:329
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#5  0x000015171994a801 in __GI_abort () at abort.c:79
 
#6  0x000015171993a39a in __assert_fail_base (fmt=0x151719ac17d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x5578735b5da1 "0", file=file@entry=0x5578733d4520 "/test/10.5_dbg/sql/protocol.cc", line=line@entry=617, function=function@entry=0x5578733d5710 <Protocol::end_statement()::__PRETTY_FUNCTION__> "void Protocol::end_statement()") at assert.c:92
 
#7  0x000015171993a412 in __GI___assert_fail (assertion=assertion@entry=0x5578735b5da1 "0", file=file@entry=0x5578733d4520 "/test/10.5_dbg/sql/protocol.cc", line=line@entry=617, function=function@entry=0x5578733d5710 <Protocol::end_statement()::__PRETTY_FUNCTION__> "void Protocol::end_statement()") at assert.c:101
 
#8  0x000055787268ffc1 in Protocol::end_statement (this=0x1516f8415650) at /test/10.5_dbg/sql/protocol.cc:617
 
#9  0x000055787277c2fd in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1516f8415088, packet=<optimized out>, packet@entry=0x1516f8467089 "HELP going_to_crash", packet_length=<optimized out>, packet_length@entry=19, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:2430
 
#10 0x00005578727788cc in do_command (thd=0x1516f8415088) at /test/10.5_dbg/sql/sql_parse.cc:1358
 
#11 0x00005578728d299d in do_handle_one_connection (connect=<optimized out>, connect@entry=0x1516fa0433a8, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1411
 
#12 0x00005578728d30b9 in handle_one_connection (arg=arg@entry=0x1516fa0433a8) at /test/10.5_dbg/sql/sql_connect.cc:1313
 
#13 0x0000557872d3110a in pfs_spawn_thread (arg=0x151718c45888) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
 
#14 0x000015171a62d6db in start_thread (arg=0x15171b206700) at pthread_create.c:463
 
#15 0x0000151719a2b88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.4.13 (dbg), 10.5.2 (dbg), 10.5.3 (dbg)

Bug confirmed not present in:
MariaDB: 10.1.45 (dbg), 10.1.45 (opt), 10.2.32 (dbg), 10.2.32 (opt), 10.3.23 (dbg), 10.3.23 (opt), 10.4.13 (opt), 10.5.2 (opt), 10.5.3 (opt), 10.5.4 (dbg), 10.5.4 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.47 (dbg), 5.6.47 (opt), 5.7.29 (dbg), 5.7.29 (opt), 8.0.19 (dbg), 8.0.19 (opt)

 Comments   
Comment by Roel Van de Paar [ 2020-05-22 ]

Very generic assert; may mask other bugs.

Comment by Roel Van de Paar [ 2020-06-15 ]

Secondary testcase with threadpool code path being hit

# mysqld options required for replay:  --thread_handling=pool-of-threads
 
USE test;
 
SET SQL_MODE='';
 
CREATE TABLE t(c INT UNSIGNED AUTO_INCREMENT NULL UNIQUE KEY) AUTO_INCREMENT=10;
 
insert INTO t VALUES ('abcdefghijklmnopqrstuvwxyz');
 
ALTER TABLE t ALGORITHM=INPLACE, ENGINE=InnoDB;
 
DELETE FROM t ;
 
INSERT INTO t VALUES(3872);
 
ALTER TABLE mysql.help_topic ENGINE=InnoDB;
 
HELP no_such_topic;

Leads to:

10.5.4 4080e3acefd7e58d88c2f3539fb6a0fb359cf057

 
mysqld: /test/10.5_dbg/sql/protocol.cc:617: void Protocol::end_statement(): Assertion `0' failed.

10.5.4 4080e3acefd7e58d88c2f3539fb6a0fb359cf057

 
Core was generated by `/test/MD150620-mariadb-10.5.4-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
[Current thread is 1 (Thread 0x14c88950c700 (LWP 2469733))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
#1  0x0000562935ec34c6 in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
 
#2  0x0000562935665d60 in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:330
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#5  0x000014c891efe801 in __GI_abort () at abort.c:79
 
#6  0x000014c891eee39a in __assert_fail_base (fmt=0x14c8920757d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x5629361fd56f "0", file=file@entry=0x56293601a5a0 "/test/10.5_dbg/sql/protocol.cc", line=line@entry=617, function=function@entry=0x56293601b790 <Protocol::end_statement()::__PRETTY_FUNCTION__> "void Protocol::end_statement()") at assert.c:92
 
#7  0x000014c891eee412 in __GI___assert_fail (assertion=assertion@entry=0x5629361fd56f "0", file=file@entry=0x56293601a5a0 "/test/10.5_dbg/sql/protocol.cc", line=line@entry=617, function=function@entry=0x56293601b790 <Protocol::end_statement()::__PRETTY_FUNCTION__> "void Protocol::end_statement()") at assert.c:101
 
#8  0x00005629352ca2b1 in Protocol::end_statement (this=0x14c86f81d650) at /test/10.5_dbg/sql/protocol.cc:617
 
#9  0x00005629353b6cdf in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14c86f81d088, packet=<optimized out>, packet@entry=0x14c86f867089 "HELP no_such_topic", packet_length=<optimized out>, packet_length@entry=18, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:2467
 
#10 0x00005629353b343a in do_command (thd=thd@entry=0x14c86f81d088) at /test/10.5_dbg/sql/sql_parse.cc:1355
 
#11 0x00005629355d35a2 in threadpool_process_request (thd=0x14c86f81d088) at /test/10.5_dbg/sql/threadpool_common.cc:354
 
#12 tp_callback (c=0x14c890832680) at /test/10.5_dbg/sql/threadpool_common.cc:194
 
#13 0x0000562935879a99 in worker_main (param=param@entry=0x14c873624788) at /test/10.5_dbg/sql/threadpool_generic.cc:1549
 
#14 0x0000562935970902 in pfs_spawn_thread (arg=0x14c890847188) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
 
#15 0x000014c892be16db in start_thread (arg=0x14c88950c700) at pthread_create.c:463
 
#16 0x000014c891fdf88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.4.14 (dbg), 10.5.4 (dbg)

Bug confirmed not present in:
MariaDB: 10.1.46 (dbg), 10.1.46 (opt), 10.2.33 (dbg), 10.2.33 (opt), 10.3.24 (dbg), 10.3.24 (opt), 10.4.14 (opt), 10.5.4 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.47 (dbg), 5.6.47 (opt), 5.7.29 (dbg), 5.7.29 (opt), 8.0.19 (dbg), 8.0.19 (opt)

Comment by Oleksandr Byelkin [ 2021-09-17 ]

It looks like fixed, here is the test.test:

--source include/have_innodb.inc
 
USE test;
 
SET SQL_MODE='';
 
CREATE TABLE t (id INT);
 
INSERT INTO t VALUES (1);
 
INSERT INTO t VALUES (2);
 
INSERT INTO t VALUES (3);
 
INSERT INTO t VALUES (4);
 
ALTER TABLE mysql.help_keyword engine=InnoDB;
 
HELP going_to_crash;
 
drop table t;

here is result of run:

sanja@sanjalaptop:~/maria/git/10.4/mysql-test$ ./mysql-test-run test
 
Logging: ./mysql-test-run  test
 
vardir: /home/sanja/maria/git/10.4/mysql-test/var
 
Checking leftover processes...
 
Removing old var directory...
 
Creating var directory '/home/sanja/maria/git/10.4/mysql-test/var'...
 
Checking supported features...
 
MariaDB Version 10.4.22-MariaDB
 
 - SSL connections supported
 
 - binaries built with wsrep patch
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
USE test;
 
SET SQL_MODE='';
 
CREATE TABLE t (id INT);
 
INSERT INTO t VALUES (1);
 
INSERT INTO t VALUES (2);
 
INSERT INTO t VALUES (3);
 
INSERT INTO t VALUES (4);
 
ALTER TABLE mysql.help_keyword engine=InnoDB;
 
HELP going_to_crash;
 
name	is_it_category
 
drop table t;
 
main.test 'innodb'                       [ pass ]     37
 
--------------------------------------------------------------------------
 
The servers were restarted 0 times
 
Spent 0.037 of 5 seconds executing testcases
 
 
 
Completed: All 1 tests were successful.
 
 
 
sanja@sanjalaptop:~/maria/git/10.4/mysql-test$

Comment by Roel Van de Paar [ 2021-09-17 ]

Thank you sanja. I tested in both MTR and CLI (also did MTR test with both original testcase as well as ENGINE=InnoDB addition for CREATE TABLE to cover for MTR using MyISAM by default whereas CLI uses InnoDB by default).

Found that CLI is the only one that produces the issue, MTR does not. CLI crashes, only 10.4 and 10.5 crash. 10.6+ does not crash.

10.4.22-dbg>HELP going_to_crash;
 
ERROR 2013 (HY000): Lost connection to MySQL server during query


10.5.13-dbg>HELP going_to_crash;
 
ERROR 2013 (HY000): Lost connection to MySQL server during query

Comment by Alice Sherepa [ 2022-01-04 ]

to repeat with mtr - run the test as 

./mtr  --mysqld=--innodb --mysqld=--innodb_stats_persistent=on a.test

Comment by Roel Van de Paar [ 2022-02-19 ]

Confirmed again today that only 10.4 and 10.5 are affected. 10.6-10.9 do not crash. Hence removed affect-tests label and the relevant filter.

Generated at Thu Feb 08 09:16:30 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.