InnoDB: Failing assertion: purge_sys->state == PURGE_STATE_RUN | abort (sig=6) in innodb_sched_priority_purge_update

Bug #1368552 reported by Roel Van de Paar on 2014-09-12
20
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.1
Invalid
Undecided
Unassigned
5.5
Invalid
Undecided
Unassigned
5.6
Fix Released
Medium
Yura Sorokin
5.7
Fix Released
Medium
Yura Sorokin

Bug Description

Version: '5.6.20-68.0-debug' socket: '/sda/Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug/socket.sock' port: 13781 Percona Server (GPL), Release 68.0,
Revision 657, DEBUG BINARY
2014-09-13 02:50:03 6364 [Note] InnoDB: Stopping purge
2014-09-13 02:50:03 7f6723415700 InnoDB: Assertion failure in thread 140080949843712 in file ha_innodb.cc line 16159
InnoDB: Failing assertion: purge_sys->state == PURGE_STATE_RUN

(gdb) bt
#0 0x00007f78d3413771 in pthread_kill () from /lib64/libpthread.so.0
#1 0x0000000000ab09a2 in my_write_core (sig=6) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/mysys/stacktrace.c:422
#2 0x000000000072ca03 in handle_fatal_signal (sig=6) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/signal_handler.cc:236
#3 <signal handler called>
#4 0x00007f78d2017989 in raise () from /lib64/libc.so.6
#5 0x00007f78d2019098 in abort () from /lib64/libc.so.6
#6 0x0000000000adfda8 in innodb_sched_priority_purge_update (thd=0x7f78246a2000, var=0x15900a0 <mysql_sysvar_sched_priority_purge>, var_ptr=0x1597a90 <srv_sched_priority_purge>, save=0x7f77d881f1c8) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/innobase/handler/ha_innodb.cc:16159
#7 0x00000000007f7e98 in sys_var_pluginvar::global_update (this=0x7f78d17e5958, thd=0x7f78246a2000, var=0x7f77d881f1a8) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_plugin.cc:3314
#8 0x000000000072a423 in sys_var::update (this=0x7f78d17e5958, thd=0x7f78246a2000, var=0x7f77d881f1a8) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/set_var.cc:193
#9 0x000000000072b5be in set_var::update (this=0x7f77d881f1a8, thd=0x7f78246a2000) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/set_var.cc:679
#10 0x000000000072b132 in sql_set_variables (thd=0x7f78246a2000, var_list=0x7f78246a5200) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/set_var.cc:579
#11 0x00000000007e304d in mysql_execute_command (thd=0x7f78246a2000) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_parse.cc:4117
#12 0x00000000007ea051 in mysql_parse (thd=0x7f78246a2000, rawbuf=0x7f77d881f010 "SET GLOBAL innodb_sched_priority_purge=0", length=40, parser_state=0x7f78d3a03df0) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_parse.cc:6744
#13 0x00000000007dc5ec in dispatch_command (command=COM_QUERY, thd=0x7f78246a2000, packet=0x7f7814306001 "SET GLOBAL innodb_sched_priority_purge=0", packet_length=40) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_parse.cc:1432
#14 0x00000000007db518 in do_command (thd=0x7f78246a2000) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_parse.cc:1049
#15 0x00000000007a34d5 in do_handle_one_connection (thd_arg=0x7f78246a2000) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_connect.cc:1532
#16 0x00000000007a2fdd in handle_one_connection (arg=0x7f78246a2000) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/sql_connect.cc:1443
#17 0x0000000000dbdbb8 in pfs_spawn_thread (arg=0x7f78b73c9f20) at /mnt/workspace/percona-server-5.6-binaries-debug-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/perfschema/pfs.cc:1860
#18 0x00007f78d340edf3 in start_thread () from /lib64/libpthread.so.0
#19 0x00007f78d20d83dd in clone () from /lib64/libc.so.6

Tags: qa Edit Tag help
Roel Van de Paar (roel11) wrote :

================== Use version:
Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug

================== Testcase:
SET GLOBAL INNODB_PURGE_STOP_NOW=ON;
SET GLOBAL innodb_sched_priority_purge=0;

================== Server start command:
[roel@localhost Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug]$ cat start
if [ -r /usr/lib64/libjemalloc.so.1 ]; then export LD_PRELOAD=/usr/lib64/libjemalloc.so.1
elif [ -r /usr/lib/x86_64-linux-gnu/libjemalloc.so.1 ]; then export LD_PRELOAD=/usr/lib/x86_64-linux-gnu/libjemalloc.so.1
elif [ -r /sda/Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug/lib/mysql/libjemalloc.so.1 ]; then export LD_PRELOAD=/sda/Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug/lib/mysql/libjemalloc.so.1
else echo 'Error: jemalloc not found, please install it first'; exit 1; fi
/sda/Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug/bin/mysqld --innodb_buffer_pool_size=2147483648 --basedir=/sda/Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug --datadir=/sda/Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug/data --plugin-load=tokudb=ha_tokudb.so --core --socket=/sda/Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug/socket.sock --port=13781 --log-error=/sda/Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug/log/master.err 2>&1 &
echo 'Server socket: /sda/Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug/socket.sock with datadir: /sda/Percona-Server-5.6.20-rel68.0-657.Linux.x86_64-debug/data'

Roel Van de Paar (roel11) wrote :
Roel Van de Paar (roel11) wrote :

Idem for SET GLOBAL innodb_sched_priority_purge=-1

A debug build-only facility for MTR testcases does not support this particular scenario: setting the purge thread priority while the purge is paused.

Roel Van de Paar (roel11) wrote :

Another testcase

CREATE TABLE t2(s1 INT);
CREATE TABLE t1(c INT);
flush tables t1,t2 with read lock;
SET GLOBAL innodb_sched_priority_purge=0;

Roel -

Can you provide more info re. #5? First, the top three statements seem to be rather arbitrary in relation to the bug, second, running it does not fail.

Ramesh Sivaraman (rameshvs02) wrote :

Another testcase

DROP DATABASE test;CREATE DATABASE test;USE test;
CREATE TABLE t2(ticket int,inhalt text,KEY tig (ticket),fulltext index tix (inhalt)) ENGINE=InnoDB;
create table t1(t1 timestamp default now(),t2 DATE,t3 timestamp DEFAULT '0000-00-00 00:00:00');
FLUSH LOCAL TABLES test.t1,test.t2 for ExPoRt;
SET GLOBAL innodb_sched_priority_purge=19;

Roel Van de Paar (roel11) wrote :

As mentioned elsewhere, please use CLI

mysql> \s
--------------
/sda/Percona-Server-5.6.21-rel69.0-681.Linux.x86_64-debug/bin/mysql Ver 14.14 Distrib 5.6.21-69.0, for Linux (x86_64) using EditLine wrapper

Connection id: 1
Current database: test
Current user: root@localhost
SSL: Not in use
Current pager: stdout
Using outfile: ''
Using delimiter: ;
Server version: 5.6.21-69.0-debug Percona Server (GPL), Release 69.0, Revision 681, DEBUG BINARY
Protocol version: 10
Connection: Localhost via UNIX socket
Server characterset: latin1
Db characterset: latin1
Client characterset: utf8
Conn. characterset: utf8
UNIX socket: /sda/Percona-Server-5.6.21-rel69.0-681.Linux.x86_64-debug/socket.sock
Uptime: 4 sec

Threads: 1 Questions: 5 Slow queries: 0 Opens: 67 Flush tables: 1 Open tables: 60 Queries per second avg: 1.250
--------------

mysql> CREATE TABLE t2(s1 INT);
sched_priority_purge=0;Query OK, 0 rows affected (0.21 sec)

mysql> CREATE TABLE t1(c INT);
Query OK, 0 rows affected (0.09 sec)

mysql> flush tables t1,t2 with read lock;
Query OK, 0 rows affected (0.06 sec)

mysql> SET GLOBAL innodb_sched_priority_purge=0;
ERROR 2013 (HY000): Lost connection to MySQL server during query

Roel Van de Paar (roel11) wrote :

(Sorry, that was before realizing it was CLI vs MTR issue)

The difference between CLI and MTR here is extremely suspicious in the context of this bug.

Elena Stepanova (elenst) wrote :

The difference between CLI and MTR is that the latter runs with default-storage-engine=MyISAM by default. Change it on the command line or specify InnoDB explicitly in DDL, it will fail just fine.
Tried 5.6.21-69.0-debug-log

Thanks Elena

Roel Van de Paar (roel11) wrote :

Thanks Elena, never looked into what option it was that triggered non-replay on all cli vs mtr issues (regular topic)

Roel Van de Paar (roel11) wrote :
Yura Sorokin (yura-sorokin) wrote :

A much simpler test case to reproduce this problem
*******************************************
SET GLOBAL innodb_purge_stop_now = ON;
SET GLOBAL innodb_sched_priority_purge=0;
*******************************************

Yura Sorokin (yura-sorokin) wrote :

It looks like "innodb_sched_priority_purge_update()" does not take into account that "SET GLOBAL innodb_sched_priority_purge = xxx" can be called when purge threads are disabled.
Therefore, we run into the following assertion
"ut_ad(purge_sys->state == PURGE_STATE_RUN);"

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1535

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.