[MDEV-11693] Assertion `prev != 0 && next != 0' failed in ilink::assert_linked upon shutdown with certain values of innodb_spin_wait_delay Created: 2016-12-30  Updated: 2017-01-03  Resolved: 2017-01-03

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2
Fix Version/s: 10.2.4

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Duplicate
duplicates MDEV-11695 Define a reasonable upper limit for i... Closed

 Description   

To reproduce:

  • start server with all defaults;
  • run mysql -e "set global innodb_spin_wait_delay = 164723660; shutdown"
  • wait

It takes a while (up to a couple of minutes on my machine), but eventually the server goes down with the assertion failure:

2016-12-30 17:57:50 140352190149376 [Note] /data/bld/10.2/bin/mysqld (root[root] @ localhost [127.0.0.1]): Normal shutdown
 
2016-12-30 17:57:50 140352190149376 [Note] Event Scheduler: Purging the queue. 0 events
mysqld: /data/src/10.2/sql/sql_list.h:665: void ilink::assert_linked(): Assertion `prev != 0 && next != 0' failed.
161230 17:58:15 [ERROR] mysqld got signal 6 ;
..
#6  0x00007fbb74a9c266 in __assert_fail_base (fmt=0x7fbb74bd5238 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7fbb77fd3ece "prev != 0 && next != 0", file=file@entry=0x7fbb77fd3eb0 "/data/src/10.2/sql/sql_list.h", line=line@entry=665, function=function@entry=0x7fbb77fddd30 <ilink::assert_linked()::__PRETTY_FUNCTION__> "void ilink::assert_linked()") at assert.c:92
#7  0x00007fbb74a9c312 in __GI___assert_fail (assertion=0x7fbb77fd3ece "prev != 0 && next != 0", file=0x7fbb77fd3eb0 "/data/src/10.2/sql/sql_list.h", line=665, function=0x7fbb77fddd30 <ilink::assert_linked()::__PRETTY_FUNCTION__> "void ilink::assert_linked()") at assert.c:101
#8  0x00007fbb774ab553 in ilink::assert_linked (this=0x7fbb33416070) at /data/src/10.2/sql/sql_list.h:665
#9  0x00007fbb774ac5ee in unlink_not_visible_thd (thd=0x7fbb33416070) at /data/src/10.2/sql/sql_class.h:4409
#10 0x00007fbb7749e846 in delete_running_thd (thd=0x7fbb33416070) at /data/src/10.2/sql/mysqld.cc:2909
#11 0x00007fbb7753a4b3 in destroy_thd (thd=0x7fbb33416070) at /data/src/10.2/sql/sql_class.cc:4481
#12 0x00007fbb77a1e35b in innobase_destroy_background_thd (thd=0x7fbb33416070) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:1815
#13 0x00007fbb77beb9bb in srv_worker_thread (arg=0x0) at /data/src/10.2/storage/innobase/srv/srv0srv.cc:2800
#14 0x00007fbb76ba90a4 in start_thread (arg=0x7fbb353f8700) at pthread_create.c:309
#15 0x00007fbb74b5687d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

On 10.1 or MySQL 5.7 the shutdown is also slow, which I assume is totally expected, but it ends all right, without any trouble:

5.7

2016-12-30T15:50:12.438654Z 0 [Note] InnoDB: Starting shutdown...
2016-12-30T15:50:12.538897Z 0 [Note] InnoDB: Dumping buffer pool(s) to /data/bld/mysql-5.7/data/ib_buffer_pool
2016-12-30T15:50:12.545087Z 0 [Note] InnoDB: Buffer pool(s) dump completed at 161230 17:50:12
2016-12-30T15:51:12.576742Z 0 [Note] InnoDB: Waiting for worker threads to be suspended
2016-12-30T15:51:32.666637Z 0 [Note] InnoDB: Shutdown completed; log sequence number 2396622
2016-12-30T15:51:32.671000Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2016-12-30T15:51:32.672984Z 0 [Note] /data/bld/mysql-5.7/bin/mysqld: Shutdown complete

10.1

2016-12-30 17:51:56 139709912304384 [Note] /data/bld/10.1/bin/mysqld: Normal shutdown
 
2016-12-30 17:51:56 139709912304384 [Note] Event Scheduler: Purging the queue. 0 events
2016-12-30 17:51:56 139709141473024 [Note] InnoDB: FTS optimize thread exiting.
2016-12-30 17:51:56 139709912304384 [Note] InnoDB: Starting shutdown...
2016-12-30 17:51:56 139709912304384 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2016-12-30 17:53:15 139709912304384 [Note] InnoDB: Shutdown completed; log sequence number 1662538
2016-12-30 17:53:15 139709912304384 [Note] /data/bld/10.1/bin/mysqld: Shutdown complete



 Comments   
Comment by Marko Mäkelä [ 2017-01-03 ]

Setting an insanely long innodb_spin_wait_delay can cause a number of issues. I think that the cure is to introduce a reasonable upper limit.

Comment by Marko Mäkelä [ 2017-01-03 ]

I think that this was addressed by setting the upper limit to innodb_spin_wait_delay=6000 in MDEV-11695.

Generated at Thu Feb 08 07:51:56 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.