[MDEV-8889] Assertion `next_insert_id == 0' failed in handler::ha_external_lock Created: 2015-10-02  Updated: 2016-04-22  Resolved: 2016-04-22

Status: Closed
Project: MariaDB Server
Component/s: Admin statements, Data Manipulation - Insert
Affects Version/s: 5.5, 10.0, 10.1
Fix Version/s: 10.0.25

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergey Vojtovich
Resolution: Fixed Votes: 0
Labels: assertion

Sprint: 10.0.23, 10.0.25

 Description   

Stack trace from 5.5 commit ce7d8c5ee8c459ac692715994fa73b8f29e9e48a

 
5.5/sql/handler.cc:5107: int handler::ha_external_lock(THD*, int): Assertion `next_insert_id == 0' failed.
 
151002 21:20:47 [ERROR] mysqld got signal 6 ;
 
 
 
#6  0x00007f3390ef7311 in *__GI___assert_fail (assertion=0xe0ef02 "next_insert_id == 0", file=<optimized out>, line=5107, function=0xe0fb00 "int handler::ha_external_lock(THD*, int)") at assert.c:81
 
#7  0x00000000007f3a46 in handler::ha_external_lock (this=0x7f337cd1a878, thd=0x7f337ccb4080, lock_type=2) at 5.5/sql/handler.cc:5107
 
#8  0x00000000008c0f44 in unlock_external (thd=0x7f337ccb4080, table=0x7f337449b328, count=1) at 5.5/sql/lock.cc:673
 
#9  0x00000000008c04a2 in mysql_unlock_tables (thd=0x7f337ccb4080, sql_lock=0x7f337449b300, free_lock=true) at 5.5/sql/lock.cc:384
 
#10 0x00000000005d576a in close_thread_tables (thd=0x7f337ccb4080) at 5.5/sql/sql_base.cc:1580
 
#11 0x000000000061ddef in handle_delayed_insert (arg=0x7f337ccb4060) at 5.5/sql/sql_insert.cc:2947
 
#12 0x00007f3392cf1b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
 
#13 0x00007f3390fa795d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x7f3377d96b20): 
Connection ID (thread ID): 1123
 
Status: KILL_CONNECTION

RQG grammar test.yy

 
thread1:
 
	SELECT Id INTO @kill_id FROM INFORMATION_SCHEMA.PROCESSLIST WHERE Info LIKE 'REPLACE DELAYED%' LIMIT 1; KILL QUERY @kill_id ;
 
 
 
thread2:
 
	ALTER TABLE _table FORCE ;
 
 
 
query:
 
	REPLACE DELAYED INTO _table ( _field ) VALUES ( NULL ) ;

RQG command line

 
perl .runall-new.pl --threads=3 --duration=600 --queries=100M --grammar=test.yy --engine=MyISAM --basedir1=<your basedir> --vardir1=<your vardir>

For RQG, I recommend to use lp:~elenst/randgen/mariadb-patches

 Comments   
Comment by Sergey Vojtovich [ 2015-12-15 ]

The problem is in handle_delayed_insert():

      if (thd->killed)
 
      {
 
        uint lock_count;
 
        /*
 
          Remove this from delay insert list so that no one can request a
 
          table from this
 
        */
 
        mysql_mutex_unlock(&di->mutex);
 
 
 
        /* !!! Another (killed) thread may call end_delayed_insert() in this gap and change tables_in_use so that we exit this loop inadvertent. */
 
 
 
        mysql_mutex_lock(&LOCK_delayed_insert);
 
        di->unlink();
 
        lock_count=di->lock_count();
 
        mysql_mutex_unlock(&LOCK_delayed_insert);
 
        mysql_mutex_lock(&di->mutex);
 
        if (!lock_count && !di->tables_in_use && !di->stacked_inserts)
 
          break;                                        // Time to die
 
      }

Comment by Sergey Vojtovich [ 2016-04-21 ]

I failed to create reasonable test case because it needs signal from delayed thread. The following test works but pollutes debug_sync state because signal is issued unconditionally:

diff --git a/mysql-test/r/delayed_sync.result b/mysql-test/r/delayed_sync.result
 
new file mode 100644
 
index 0000000..c6d6395
 
--- /dev/null
 
+++ b/mysql-test/r/delayed_sync.result
 
@@ -0,0 +1,11 @@
 
+#
 
+# MDEV-8889 - Assertion `next_insert_id == 0' failed in
 
+#             handler::ha_external_lock
 
+#
 
+CREATE TABLE t1(a INT PRIMARY KEY AUTO_INCREMENT);
 
+SET debug_sync='after_write_delayed SIGNAL rows_written WAIT_FOR insert_delayed_killed';
 
+INSERT DELAYED INTO t1 VALUES(NULL);
 
+SET debug_sync='now WAIT_FOR rows_written';
 
+FLUSH TABLE t1;
 
+SET debug_sync='RESET';
 
+DROP TABLE t1;
 
diff --git a/mysql-test/t/delayed_sync.test b/mysql-test/t/delayed_sync.test
 
new file mode 100644
 
index 0000000..02d3501
 
--- /dev/null
 
+++ b/mysql-test/t/delayed_sync.test
 
@@ -0,0 +1,21 @@
 
+# delayed works differently in embedded server
 
+--source include/not_embedded.inc
 
+--source include/have_debug_sync.inc
 
+
 
+--echo #
 
+--echo # MDEV-8889 - Assertion `next_insert_id == 0' failed in
 
+--echo #             handler::ha_external_lock
 
+--echo #
 
+CREATE TABLE t1(a INT PRIMARY KEY AUTO_INCREMENT);
 
+SET debug_sync='after_write_delayed SIGNAL rows_written WAIT_FOR insert_delayed_killed';
 
+send INSERT DELAYED INTO t1 VALUES(NULL);
 
+
 
+connect(con2, localhost, root);
 
+SET debug_sync='now WAIT_FOR rows_written';
 
+FLUSH TABLE t1;
 
+disconnect con2;
 
+
 
+connection default;
 
+reap;
 
+SET debug_sync='RESET';
 
+DROP TABLE t1;
 
diff --git a/sql/sql_insert.cc b/sql/sql_insert.cc
 
index 42d8839..cd16803 100644
 
--- a/sql/sql_insert.cc
 
+++ b/sql/sql_insert.cc
 
@@ -2862,8 +2862,13 @@ pthread_handler_t handle_delayed_insert(void *arg)
 
         di->unlink();
 
         lock_count=di->lock_count();
 
         mysql_mutex_unlock(&LOCK_delayed_insert);
 
+#ifdef ENABLED_DEBUG_SYNC
 
+        if (debug_sync_service)
 
+          debug_sync_set_action(thd, STRING_WITH_LEN("now SIGNAL insert_delayed_killed"));
 
+#endif
 
         mysql_mutex_lock(&di->mutex);
 
         if (!lock_count && !di->tables_in_use && !di->stacked_inserts)
 
           break;					// Time to die
 
       }

Comment by Sergey Vojtovich [ 2016-04-21 ]

serg, please review fix for this bug.

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