[MDEV-14491] rpl.rpl_row_mixing_engines, rpl.rpl_non_direct_row_mixing_engines failed in buildbot with long semaphore wait Created: 2017-11-23  Updated: 2018-06-25  Resolved: 2018-05-29

Status: Closed
Project: MariaDB Server
Component/s: Replication, Storage Engine - InnoDB, Tests
Affects Version/s: 10.1
Fix Version/s: 10.1.34, 10.2.16, 10.3.8, 10.4.0

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

Issue Links:
Relates
relates to MDEV-16283 ALTER TABLE...DISCARD TABLESPACE stil... Closed
relates to MDEV-16515 InnoDB: Failing assertion: ++retries ... Closed
Sprint: 10.1.32

 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1336/steps/mtr_ps/logs/stdio

rpl.rpl_row_mixing_engines 'row,xtradb'  w1 [ fail ]
 
        Test ended at 2017-11-18 12:57:13
 
 
 
CURRENT_TEST: rpl.rpl_row_mixing_engines
 
mysqltest: In included file "./extra/rpl_tests/rpl_mixing_engines.inc": 
included from ./extra/rpl_tests/rpl_mixing_engines.test at line 1666:
 
included from /mnt/buildbot/build/mariadb-10.1.30/mysql-test/suite/rpl/t/rpl_row_mixing_engines.test at line 12:
 
At line 562: query 'DROP TABLE IF EXISTS tt_xx_$tb_id, nt_xx_$tb_id' failed: 2013: Lost connection to MySQL server during query
 
 
 
The result from queries just before the failure was:
 
< snip >
 
Log_name	Pos	Event_type	Server_id	End_log_pos	Info
 
master-bin.000001	#	Gtid	#	#	BEGIN GTID #-#-#
 
master-bin.000001	#	Table_map	#	#	table_id: # (test.tt_1)
 
master-bin.000001	#	Write_rows_v1	#	#	table_id: # flags: STMT_END_F
 
master-bin.000001	#	Xid	#	#	COMMIT /* XID */
 
-e-e-e-e-e-e-e-e-e-e-e- >> C << -e-e-e-e-e-e-e-e-e-e-e-
 
-b-b-b-b-b-b-b-b-b-b-b- >> trunc-CS-T B ISe-T<-N T C << -b-b-b-b-b-b-b-b-b-b-b-
 
include/show_binlog_events.inc
 
Log_name	Pos	Event_type	Server_id	End_log_pos	Info
 
master-bin.000001	#	Gtid	#	#	GTID #-#-#
 
master-bin.000001	#	Query	#	#	use `test`; TRUNCATE TABLE tt_xx_7
 
master-bin.000001	#	Gtid	#	#	BEGIN GTID #-#-#
 
master-bin.000001	#	Table_map	#	#	table_id: # (test.tt_1)
 
master-bin.000001	#	Write_rows_v1	#	#	table_id: # flags: STMT_END_F
 
master-bin.000001	#	Xid	#	#	COMMIT /* XID */
 
-e-e-e-e-e-e-e-e-e-e-e- >> trunc-CS-T B ISe-T<-N T C << -e-e-e-e-e-e-e-e-e-e-e-
 
 
 
rpl_mixing_engines.inc [commands=drop-CS]
 
-b-b-b-b-b-b-b-b-b-b-b- >> drop-CS << -b-b-b-b-b-b-b-b-b-b-b-
 
DROP TABLE IF EXISTS tt_xx_7, nt_xx_7;
 
 
 
More results from queries before failure can be found in /mnt/buildbot/build/mariadb-10.1.30/mysql-test/var/1/log/rpl_row_mixing_engines.log
 
 
 
 
 
Server [mysqld.1 - pid: 27802, winpid: 27802, exit: 256] failed during test run
 
Server log from this test:
 
----------SERVER LOG START-----------
 
InnoDB: Error: Waited for 5 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 10 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 15 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 20 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 25 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 30 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 35 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 40 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 45 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 50 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 55 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 60 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 65 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 70 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 75 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 80 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 85 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 90 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 95 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 100 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 105 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 110 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 115 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 120 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 125 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 130 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 135 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 140 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 145 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 150 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 155 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 160 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 165 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 170 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 175 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 180 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 185 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 190 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 195 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 200 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 205 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 210 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 215 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 220 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 225 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 230 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 235 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Warning: a long semaphore wait:
 
--Thread 140168992282368 has waited at srv0srv.cc line 2841 for 241.00 seconds the semaphore:
 
X-lock on RW-latch at 0x55dcf8a76220 '&dict_operation_lock'
 
a writer (thread id 140168906431232) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: Warning: semaphore wait:
 
--Thread 140168992282368 has waited at srv0srv.cc line 2841 for 241.00 seconds the semaphore:
 
X-lock on RW-latch at 0x55dcf8a76220 '&dict_operation_lock'
 
a writer (thread id 140168906431232) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
 
InnoDB: Pending reads 0, writes 0
 
InnoDB: Error: Waited for 240 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 245 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 250 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
 
 
=====================================
 
2017-11-18 12:51:13 7f7ba509a700 INNODB MONITOR OUTPUT
 
=====================================
 
Per second averages calculated from the last 45 seconds
 
-----------------
 
BACKGROUND THREAD
 
-----------------
 
srv_master_thread loops: 729 srv_active, 0 srv_shutdown, 927 srv_idle
 
srv_master_thread log flush and writes: 1655
 
----------
 
SEMAPHORES
 
----------
 
OS WAIT ARRAY INFO: reservation count 1593
 
--Thread 140168992282368 has waited at srv0srv.cc line 2841 for 256.00 seconds the semaphore:
 
X-lock on RW-latch at 0x55dcf8a76220 '&dict_operation_lock'
 
a writer (thread id 140168906431232) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
OS WAIT ARRAY INFO: signal count 1473
 
Mutex spin waits 2966, rounds 53870, OS waits 888
 
RW-shared spins 665, rounds 19950, OS waits 664
 
RW-excl spins 1, rounds 330, OS waits 11
 
Spin rounds per wait: 18.16 mutex, 30.00 RW-shared, 330.00 RW-excl
 
------------
 
TRANSACTIONS
 
------------
 
Trx id counter 2075
 
Purge done for trx's n:o < 2071 undo n:o < 0 state: running but idle
 
History list length 27
 
LIST OF TRANSACTIONS FOR EACH SESSION:
 
---TRANSACTION 2071, not started
 
MySQL thread id 1747, OS thread handle 0x7f7b9de05b00, query id 184936 localhost 127.0.0.1 root Unlocking tables
 
DROP TABLE IF EXISTS tt_xx_7, nt_xx_7
 
---TRANSACTION 2072, ACTIVE 257 sec dropping table
 
18 lock struct(s), heap size 2936, 19 row lock(s), undo log entries 9
 
MySQL thread id 1747, OS thread handle 0x7f7b9de05b00, query id 184936 localhost 127.0.0.1 root Unlocking tables
 
DROP TABLE IF EXISTS tt_xx_7, nt_xx_7
 
Trx read view will not see trx with id >= 2075, sees < 2075
 
Trx #rec lock waits 0 #table lock waits 0
 
Trx total rec lock wait time 0 SEC
 
Trx total table lock wait time 0 SEC
 
--------
 
FILE I/O
 
--------
 
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
 
I/O thread 1 state: waiting for completed aio requests (log thread)
 
I/O thread 2 state: waiting for completed aio requests (read thread)
 
I/O thread 3 state: waiting for completed aio requests (read thread)
 
I/O thread 4 state: waiting for completed aio requests (write thread)
 
I/O thread 5 state: waiting for completed aio requests (write thread)
 
Pending normal aio reads: 0 [0, 0] , aio writes: 0 [0, 0] ,
 
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
 
Pending flushes (fsync) log: 0; buffer pool: 0
 
212 OS file reads, 6386 OS file writes, 4806 OS fsyncs
 
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
 
-------------------------------------
 
INSERT BUFFER AND ADAPTIVE HASH INDEX
 
-------------------------------------
 
Ibuf: size 1, free list len 0, seg size 2, 0 merges
 
merged operations:
 
 insert 0, delete mark 0, delete 0
 
discarded operations:
 
 insert 0, delete mark 0, delete 0
 
0.00 hash searches/s, 0.00 non-hash searches/s
 
---
 
LOG
 
---
 
Log sequence number 2242348
 
Log flushed up to   2242348
 
Pages flushed up to 2242348
 
Last checkpoint at  2221348
 
Max checkpoint age    7782360
 
Checkpoint age target 7539162
 
Modified age          0
 
Checkpoint age        21000
 
0 pending log writes, 0 pending chkp writes
 
2051 log i/o's done, 0.00 log i/o's/second
 
----------------------
 
BUFFER POOL AND MEMORY
 
----------------------
 
Total memory allocated 8798208; in additional pool allocated 0
 
Total memory allocated by read views 376
 
InnoDB: Error: Waited for 255 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 260 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 265 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: ###### Diagnostic info printed to the standard error stream
 
InnoDB: Warning: a long semaphore wait:
 
--Thread 140168992282368 has waited at srv0srv.cc line 2841 for 272.00 seconds the semaphore:
 
X-lock on RW-latch at 0x55dcf8a76220 '&dict_operation_lock'
 
a writer (thread id 140168906431232) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: Warning: semaphore wait:
 
--Thread 140168992282368 has waited at srv0srv.cc line 2841 for 272.00 seconds the semaphore:
 
X-lock on RW-latch at 0x55dcf8a76220 '&dict_operation_lock'
 
a writer (thread id 140168906431232) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: Warning: semaphore wait:
 
--Thread 140169026578176 has waited at dict0dict.cc line 7278 for 16.000 seconds the semaphore:
 
Mutex at 0x61600000b4e8 '&dict_sys->mutex', lock var 1
 
Last time reserved by thread 140168906431232 in file not yet reserved line 0, waiters flag 1
 
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
 
InnoDB: Pending reads 0, writes 0
 
InnoDB: Error: Waited for 270 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 275 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 280 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 285 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 290 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 295 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: ###### Diagnostic info printed to the standard error stream
 
InnoDB: Warning: a long semaphore wait:
 
--Thread 140168992282368 has waited at srv0srv.cc line 2841 for 303.00 seconds the semaphore:
 
X-lock on RW-latch at 0x55dcf8a76220 '&dict_operation_lock'
 
a writer (thread id 140168906431232) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: Warning: semaphore wait:
 
--Thread 140168992282368 has waited at srv0srv.cc line 2841 for 303.00 seconds the semaphore:
 
X-lock on RW-latch at 0x55dcf8a76220 '&dict_operation_lock'
 
a writer (thread id 140168906431232) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: Warning: semaphore wait:
 
--Thread 140169026578176 has waited at dict0dict.cc line 7278 for 47.000 seconds the semaphore:
 
Mutex at 0x61600000b4e8 '&dict_sys->mutex', lock var 1
 
Last time reserved by thread 140168906431232 in file not yet reserved line 0, waiters flag 1
 
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
 
InnoDB: Pending reads 0, writes 0
 
InnoDB: Error: Waited for 300 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 305 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 310 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 315 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 320 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 325 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: ###### Diagnostic info printed to the standard error stream
 
InnoDB: Error: Waited for 330 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 335 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 340 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 345 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 350 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 355 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 360 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 365 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 370 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 375 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 380 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 385 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 390 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 395 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 400 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 405 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 410 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 415 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 420 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 425 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 430 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 435 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 440 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 445 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 450 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 455 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 460 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 465 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 470 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 475 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 480 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 485 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 490 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 495 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 500 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 505 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 510 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 515 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 520 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 525 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 530 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 535 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 540 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 545 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 550 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 555 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 560 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 565 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 570 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 575 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 580 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 585 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 590 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 595 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 600 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
2017-11-18 12:57:10 7f7b9de05b00  InnoDB: Assertion failure in thread 140168906431232 in file dict0dict.cc line 2756
 
InnoDB: We intentionally generate a memory trap.
 
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
 
InnoDB: If you get repeated assertion failures or crashes, even
 
InnoDB: immediately after the mysqld startup, there may be
 
InnoDB: corruption in the InnoDB tablespace. Please refer to
 
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
 
InnoDB: about forcing recovery.
 
171118 12:57:10 [ERROR] mysqld got signal 6 ;
 
This could be because you hit a bug. It is also possible that this binary
 
or one of the libraries it was linked against is corrupt, improperly built,
 
or misconfigured. This error can also be caused by malfunctioning hardware.
 
 
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
 
 
We will try our best to scrape up some info that will hopefully help
 
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
 
 
Server version: 10.1.30-MariaDB
 
key_buffer_size=1048576
 
read_buffer_size=131072
 
max_used_connections=7
 
max_threads=153
 
thread_count=6
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 62938 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x62a00078c208
 
Attempting backtrace. You can use the following information to find out
 
where mysqld died. If you see no messages after this, something went
 
terribly wrong...
 
stack_bottom = 0x7f7b9de05030 thread_stack 0x48400
 
/usr/lib/x86_64-linux-gnu/libasan.so.2(+0x4a077)[0x7f7bb4262077]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(my_print_stacktrace+0xdc)[0x55dcf75f6ca6]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(handle_fatal_signal+0x766)[0x55dcf6aa3d11]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f7bb3109390]
 
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x38)[0x7f7bb26d9428]
 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7f7bb26db02a]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0x14150eb)[0x55dcf738d0eb]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0x1429d10)[0x55dcf73a1d10]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0x142a60c)[0x55dcf73a260c]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0x125dfe2)[0x55dcf71d5fe2]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0x10a8394)[0x55dcf7020394]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_ZN7handler15ha_delete_tableEPKc+0x161)[0x55dcf6abab55]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z15ha_delete_tableP3THDP10handlertonPKcS4_S4_b+0x209)[0x55dcf6abad63]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z23mysql_rm_table_no_locksP3THDP10TABLE_LISTbbbbb+0x1203)[0x55dcf67e459c]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z14mysql_rm_tableP3THDP10TABLE_LISTcc+0x5c0)[0x55dcf67e6160]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z21mysql_execute_commandP3THD+0xdfc2)[0x55dcf6680804]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x6a1)[0x55dcf668bb0a]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x29d2)[0x55dcf66916a7]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z10do_commandP3THD+0x135f)[0x55dcf66972d7]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z24do_handle_one_connectionP3THD+0x42b)[0x55dcf68d0253]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(handle_one_connection+0xd3)[0x55dcf68d0730]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0xf36591)[0x55dcf6eae591]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7f7bb30ff6ba]
 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f7bb27aa82d]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x62b000bc9220): DROP TABLE IF EXISTS tt_xx_7, nt_xx_7
 
Connection ID (thread ID): 1747
 
Status: NOT_KILLED
 
 
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=off
 
 
 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
 
information that should help you find out what is causing the crash.
 
Writing a core file
 
----------SERVER LOG END-------------
 
 
 
 
 
 - saving '/mnt/buildbot/build/mariadb-10.1.30/mysql-test/var/1/log/rpl.rpl_row_mixing_engines-row,xtradb/' to '/mnt/buildbot/build/mariadb-10.1.30/mysql-test/var/log/rpl.rpl_row_mixing_engines-row,xtradb/'
 
worker[1] > Restart  - not started
 
worker[1] > Restart  - not started
 
***Warnings generated in error logs during shutdown after running tests: rpl.rpl_row_mixing_engines rpl.rpl_non_direct_row_mixing_engines
 
 
 
InnoDB: Error: Waited for 5 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 10 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 15 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 20 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 25 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 30 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 35 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 40 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 45 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 50 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 55 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 60 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 65 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 70 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 75 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 80 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 85 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 90 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 95 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 100 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 105 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 110 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 115 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 120 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 125 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 130 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 135 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 140 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 145 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 150 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 155 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 160 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 165 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 170 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 175 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 180 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 185 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 190 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 195 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 200 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 205 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 210 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 215 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 220 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 225 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 230 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 235 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Warning: semaphore wait:
 
InnoDB: Error: Waited for 240 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 245 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 250 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 255 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 260 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 265 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Warning: semaphore wait:
 
InnoDB: Warning: semaphore wait:
 
InnoDB: Error: Waited for 270 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 275 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 280 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 285 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 290 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 295 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Warning: semaphore wait:
 
InnoDB: Warning: semaphore wait:
 
InnoDB: Error: Waited for 300 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 305 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 310 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 315 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 320 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 325 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 330 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 335 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 340 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 345 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 350 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 355 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 360 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 365 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 370 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 375 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 380 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 385 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 390 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 395 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 400 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 405 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 410 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 415 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 420 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 425 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 430 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 435 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 440 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 445 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 450 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 455 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 460 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 465 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 470 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 475 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 480 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 485 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 490 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 495 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 500 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 505 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 510 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 515 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 520 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 525 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 530 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 535 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 540 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 545 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 550 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 555 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 560 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 565 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 570 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 575 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 580 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 585 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 590 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 595 secs for hash index ref_count (1) to drop to 0.
 
InnoDB: Error: Waited for 600 secs for hash index ref_count (1) to drop to 0.
 
Attempting backtrace. You can use the following information to find out



 Comments   
Comment by Elena Stepanova [ 2017-12-20 ]

rpl.rpl_non_direct_row_mixing_engines
http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1401/steps/mtr_nm/logs/stdio

rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w1 [ pass ]  787481
 
worker[2] Test still running: rpl.rpl_non_direct_row_mixing_engines
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w2 [ fail ]
 
        Test ended at 2017-12-07 21:25:16
 
 
 
CURRENT_TEST: rpl.rpl_non_direct_row_mixing_engines
 
mysqltest: In included file "./extra/rpl_tests/rpl_mixing_engines.inc": 
included from ./extra/rpl_tests/rpl_mixing_engines.test at line 1666:
 
included from /mnt/buildbot/build/mariadb-10.1.30/mysql-test/suite/rpl/t/rpl_non_direct_row_mixing_engines.test at line 15:
 
At line 562: query 'DROP TABLE IF EXISTS tt_xx_$tb_id, nt_xx_$tb_id' failed: 2013: Lost connection to MySQL server during query
 
 
 
The result from queries just before the failure was:
 
< snip >
 
Log_name	Pos	Event_type	Server_id	End_log_pos	Info
 
master-bin.000001	#	Gtid	#	#	BEGIN GTID #-#-#
 
master-bin.000001	#	Table_map	#	#	table_id: # (test.tt_1)
 
master-bin.000001	#	Write_rows_v1	#	#	table_id: # flags: STMT_END_F
 
master-bin.000001	#	Xid	#	#	COMMIT /* XID */
 
-e-e-e-e-e-e-e-e-e-e-e- >> C << -e-e-e-e-e-e-e-e-e-e-e-
 
-b-b-b-b-b-b-b-b-b-b-b- >> trunc-CS-T B ISe-T<-N T C << -b-b-b-b-b-b-b-b-b-b-b-
 
include/show_binlog_events.inc
 
Log_name	Pos	Event_type	Server_id	End_log_pos	Info
 
master-bin.000001	#	Gtid	#	#	GTID #-#-#
 
master-bin.000001	#	Query	#	#	use `test`; TRUNCATE TABLE tt_xx_7
 
master-bin.000001	#	Gtid	#	#	BEGIN GTID #-#-#
 
master-bin.000001	#	Table_map	#	#	table_id: # (test.tt_1)
 
master-bin.000001	#	Write_rows_v1	#	#	table_id: # flags: STMT_END_F
 
master-bin.000001	#	Xid	#	#	COMMIT /* XID */
 
-e-e-e-e-e-e-e-e-e-e-e- >> trunc-CS-T B ISe-T<-N T C << -e-e-e-e-e-e-e-e-e-e-e-
 
 
 
rpl_mixing_engines.inc [commands=drop-CS]
 
-b-b-b-b-b-b-b-b-b-b-b- >> drop-CS << -b-b-b-b-b-b-b-b-b-b-b-
 
DROP TABLE IF EXISTS tt_xx_7, nt_xx_7;
 
 
 
More results from queries before failure can be found in /mnt/buildbot/build/mariadb-10.1.30/mysql-test/var/2/log/rpl_non_direct_row_mixing_engines.log
 
 
 
 
 
Server [mysqld.1 - pid: 27842, winpid: 27842, exit: 256] failed during test run
 
Server log from this test:
 
----------SERVER LOG START-----------
 
2017-12-07 21:03:17 139746729646336 [Note] /mnt/buildbot/build/mariadb-10.1.30/sql/mysqld (mysqld 10.1.30-MariaDB) starting as process 27844 ...
 
2017-12-07 21:03:17 139746729646336 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
 
2017-12-07 21:03:17 139746729646336 [Warning] setrlimit could not change the size of core files to 'infinity';  We may not be able to generate a core file on signals
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'SEQUENCE' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'partition' is disabled.
 
innodb_open_files should not be greater than the open_files_limit.
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.
 
 
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: The InnoDB memory heap is disabled
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: Compressed tables use zlib 1.2.3
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: Using Linux native AIO
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: Using generic crc32 instructions
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: Initializing buffer pool, size = 8.0M
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: Completed initialization of buffer pool
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: Highest supported file format is Barracuda.
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: 128 rollback segment(s) are active.
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB: Waiting for purge to start
 
2017-12-07 21:03:18 139746729646336 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.2 started; log sequence number 1629415
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'XTRADB_RSEG' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'CHANGED_PAGE_BITMAPS' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'XTRADB_INTERNAL_HASH_TABLES' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'FEEDBACK' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_CMP' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_MUTEXES' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'XTRADB_READ_VIEW' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_CHANGED_PAGES' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
 
2017-12-07 21:03:18 139746729646336 [Warning] /mnt/buildbot/build/mariadb-10.1.30/sql/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
 
2017-12-07 21:03:18 139746729646336 [Warning] /mnt/buildbot/build/mariadb-10.1.30/sql/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
 
2017-12-07 21:03:18 139746729646336 [Warning] /mnt/buildbot/build/mariadb-10.1.30/sql/mysqld: unknown variable 'loose-feedback-debug-interval=60'
 
2017-12-07 21:03:18 139746729646336 [Warning] /mnt/buildbot/build/mariadb-10.1.30/sql/mysqld: unknown option '--loose-pam-debug'
 
2017-12-07 21:03:18 139746729646336 [Warning] /mnt/buildbot/build/mariadb-10.1.30/sql/mysqld: unknown variable 'loose-debug-sync-timeout=300'
 
2017-12-07 21:03:18 139746381506304 [Note] InnoDB: Dumping buffer pool(s) not yet started
 
2017-12-07 21:03:18 139746729646336 [Note] Server socket created on IP: '127.0.0.1'.
 
2017-12-07 21:03:18 139746729646336 [Note] /mnt/buildbot/build/mariadb-10.1.30/sql/mysqld: ready for connections.
 
Version: '10.1.30-MariaDB'  socket: '/mnt/buildbot/build/mariadb-10.1.30/mysql-test/var/tmp/2/mysqld.1.sock'  port: 16020  MariaDB Server
 
InnoDB: Error: Waited for 5 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 10 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 15 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 20 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 25 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 30 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 35 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 40 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 45 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 50 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 55 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 60 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 65 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 70 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 75 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 80 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 85 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 90 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 95 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 100 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 105 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 110 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 115 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 120 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 125 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 130 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 135 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 140 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 145 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 150 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 155 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 160 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 165 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 170 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 175 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 180 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 185 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 190 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 195 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 200 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 205 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 210 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 215 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 220 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 225 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 230 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 235 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Warning: a long semaphore wait:
 
--Thread 139746424354560 has waited at srv0srv.cc line 2841 for 241.00 seconds the semaphore:
 
X-lock on RW-latch at 0x556470569220 '&dict_operation_lock'
 
a writer (thread id 139746337905408) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: Warning: semaphore wait:
 
--Thread 139746424354560 has waited at srv0srv.cc line 2841 for 241.00 seconds the semaphore:
 
X-lock on RW-latch at 0x556470569220 '&dict_operation_lock'
 
a writer (thread id 139746337905408) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
 
InnoDB: Pending reads 0, writes 0
 
InnoDB: Error: Waited for 240 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 245 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
 
 
=====================================
 
2017-12-07 21:19:18 7f194206d700 INNODB MONITOR OUTPUT
 
=====================================
 
Per second averages calculated from the last 45 seconds
 
-----------------
 
BACKGROUND THREAD
 
-----------------
 
srv_master_thread loops: 331 srv_active, 0 srv_shutdown, 368 srv_idle
 
srv_master_thread log flush and writes: 698
 
----------
 
SEMAPHORES
 
----------
 
OS WAIT ARRAY INFO: reservation count 610
 
--Thread 139746424354560 has waited at srv0srv.cc line 2841 for 251.00 seconds the semaphore:
 
X-lock on RW-latch at 0x556470569220 '&dict_operation_lock'
 
a writer (thread id 139746337905408) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
OS WAIT ARRAY INFO: signal count 601
 
Mutex spin waits 1107, rounds 23078, OS waits 318
 
RW-shared spins 262, rounds 7860, OS waits 261
 
RW-excl spins 1, rounds 330, OS waits 11
 
Spin rounds per wait: 20.85 mutex, 30.00 RW-shared, 330.00 RW-excl
 
------------
 
TRANSACTIONS
 
------------
 
Trx id counter 1633
 
Purge done for trx's n:o < 1629 undo n:o < 0 state: running but idle
 
History list length 32
 
LIST OF TRANSACTIONS FOR EACH SESSION:
 
---TRANSACTION 1629, not started
 
MySQL thread id 8, OS thread handle 0x7f193ad45b00, query id 86041 localhost 127.0.0.1 root Unlocking tables
 
DROP TABLE IF EXISTS tt_xx_7, nt_xx_7
 
---TRANSACTION 1630, ACTIVE 252 sec dropping table
 
18 lock struct(s), heap size 2936, 19 row lock(s), undo log entries 9
 
MySQL thread id 8, OS thread handle 0x7f193ad45b00, query id 86041 localhost 127.0.0.1 root Unlocking tables
 
DROP TABLE IF EXISTS tt_xx_7, nt_xx_7
 
Trx read view will not see trx with id >= 1633, sees < 1633
 
Trx #rec lock waits 0 #table lock waits 0
 
Trx total rec lock wait time 0 SEC
 
Trx total table lock wait time 0 SEC
 
--------
 
FILE I/O
 
--------
 
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
 
I/O thread 1 state: waiting for completed aio requests (log thread)
 
I/O thread 2 state: waiting for completed aio requests (read thread)
 
I/O thread 3 state: waiting for completed aio requests (read thread)
 
I/O thread 4 state: waiting for completed aio requests (write thread)
 
I/O thread 5 state: waiting for completed aio requests (write thread)
 
Pending normal aio reads: 0 [0, 0] , aio writes: 0 [0, 0] ,
 
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
 
Pending flushes (fsync) log: 0; buffer pool: 0
 
181 OS file reads, 2866 OS file writes, 2077 OS fsyncs
 
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
 
-------------------------------------
 
INSERT BUFFER AND ADAPTIVE HASH INDEX
 
-------------------------------------
 
Ibuf: size 1, free list len 0, seg size 2, 0 merges
 
merged operations:
 
 insert 0, delete mark 0, delete 0
 
discarded operations:
 
 insert 0, delete mark 0, delete 0
 
0.00 hash searches/s, 0.00 non-hash searches/s
 
---
 
LOG
 
---
 
Log sequence number 1936121
 
Log flushed up to   1936121
 
Pages flushed up to 1936121
 
Last checkpoint at  1911375
 
Max checkpoint age    7782360
 
Checkpoint age target 7539162
 
Modified age          0
 
Checkpoint age        24746
 
0 pending log writes, 0 pending chkp writes
 
903 log i/o's done, 0.00 log i/o's/second
 
----------------------
 
BUFFER POOL AND MEMORY
 
----------------------
 
Total memory allocated 8798208; in additional pool allocated 0
 
Total memory allocated by read views 376
 
InnoDB: Error: Waited for 250 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 255 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 260 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 265 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: ###### Diagnostic info printed to the standard error stream
 
InnoDB: Warning: a long semaphore wait:
 
--Thread 139746424354560 has waited at srv0srv.cc line 2841 for 272.00 seconds the semaphore:
 
X-lock on RW-latch at 0x556470569220 '&dict_operation_lock'
 
a writer (thread id 139746337905408) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: Warning: semaphore wait:
 
--Thread 139746424354560 has waited at srv0srv.cc line 2841 for 272.00 seconds the semaphore:
 
X-lock on RW-latch at 0x556470569220 '&dict_operation_lock'
 
a writer (thread id 139746337905408) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: Warning: semaphore wait:
 
--Thread 139746458654464 has waited at dict0dict.cc line 7278 for 21.000 seconds the semaphore:
 
Mutex at 0x61600000b4e8 '&dict_sys->mutex', lock var 1
 
Last time reserved by thread 139746337905408 in file not yet reserved line 0, waiters flag 1
 
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
 
InnoDB: Pending reads 0, writes 0
 
InnoDB: Error: Waited for 270 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 275 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 280 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 285 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 290 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 295 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: ###### Diagnostic info printed to the standard error stream
 
InnoDB: Error: Waited for 300 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Warning: a long semaphore wait:
 
--Thread 139746424354560 has waited at srv0srv.cc line 2841 for 303.00 seconds the semaphore:
 
X-lock on RW-latch at 0x556470569220 '&dict_operation_lock'
 
a writer (thread id 139746337905408) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: Warning: semaphore wait:
 
--Thread 139746424354560 has waited at srv0srv.cc line 2841 for 303.00 seconds the semaphore:
 
X-lock on RW-latch at 0x556470569220 '&dict_operation_lock'
 
a writer (thread id 139746337905408) has reserved it in mode  exclusive
 
number of readers 0, waiters flag 1, lock_word: 0
 
Last time read locked in file row0undo.cc line 299
 
Last time write locked in file row0mysql.cc line 4006
 
Holder thread 0 file not yet reserved line 0
 
InnoDB: Warning: semaphore wait:
 
--Thread 139746458654464 has waited at dict0dict.cc line 7278 for 52.000 seconds the semaphore:
 
Mutex at 0x61600000b4e8 '&dict_sys->mutex', lock var 1
 
Last time reserved by thread 139746337905408 in file not yet reserved line 0, waiters flag 1
 
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
 
InnoDB: Pending reads 0, writes 0
 
InnoDB: Error: Waited for 305 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 310 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 315 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 320 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 325 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: ###### Diagnostic info printed to the standard error stream
 
InnoDB: Error: Waited for 330 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 335 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 340 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 345 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 350 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 355 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 360 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 365 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 370 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 375 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 380 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 385 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 390 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 395 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 400 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 405 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 410 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 415 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 420 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 425 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 430 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 435 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 440 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 445 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 450 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 455 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 460 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 465 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 470 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 475 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 480 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 485 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 490 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 495 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 500 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 505 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 510 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 515 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 520 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 525 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 530 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 535 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 540 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 545 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 550 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 555 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 560 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 565 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 570 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 575 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 580 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 585 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 590 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 595 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
InnoDB: Error: Waited for 600 secs for hash index ref_count (1) to drop to 0.
 
index: "PRIMARY" table: "test/tt_xx_7"
 
2017-12-07 21:25:14 7f193ad45b00  InnoDB: Assertion failure in thread 139746337905408 in file dict0dict.cc line 2756
 
InnoDB: We intentionally generate a memory trap.
 
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
 
InnoDB: If you get repeated assertion failures or crashes, even
 
InnoDB: immediately after the mysqld startup, there may be
 
InnoDB: corruption in the InnoDB tablespace. Please refer to
 
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
 
InnoDB: about forcing recovery.
 
171207 21:25:14 [ERROR] mysqld got signal 6 ;
 
This could be because you hit a bug. It is also possible that this binary
 
or one of the libraries it was linked against is corrupt, improperly built,
 
or misconfigured. This error can also be caused by malfunctioning hardware.
 
 
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
 
 
We will try our best to scrape up some info that will hopefully help
 
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
 
 
Server version: 10.1.30-MariaDB
 
key_buffer_size=1048576
 
read_buffer_size=131072
 
max_used_connections=7
 
max_threads=153
 
thread_count=6
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 62938 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x62a00007e208
 
Attempting backtrace. You can use the following information to find out
 
where mysqld died. If you see no messages after this, something went
 
terribly wrong...
 
stack_bottom = 0x7f193ad45030 thread_stack 0x48400
 
/usr/lib/x86_64-linux-gnu/libasan.so.2(+0x4a077)[0x7f1951235077]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(my_print_stacktrace+0xdc)[0x55646f0e9b5c]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(handle_fatal_signal+0x766)[0x55646e596d11]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f19500dc390]
 
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x38)[0x7f194f6ac428]
 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7f194f6ae02a]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0x14150eb)[0x55646ee800eb]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0x1429d10)[0x55646ee94d10]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0x142a60c)[0x55646ee9560c]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0x125dfe2)[0x55646ecc8fe2]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0x10a8394)[0x55646eb13394]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_ZN7handler15ha_delete_tableEPKc+0x161)[0x55646e5adb55]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z15ha_delete_tableP3THDP10handlertonPKcS4_S4_b+0x209)[0x55646e5add63]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z23mysql_rm_table_no_locksP3THDP10TABLE_LISTbbbbb+0x1203)[0x55646e2d759c]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z14mysql_rm_tableP3THDP10TABLE_LISTcc+0x5c0)[0x55646e2d9160]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z21mysql_execute_commandP3THD+0xdfc2)[0x55646e173804]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x6a1)[0x55646e17eb0a]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x29d2)[0x55646e1846a7]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z10do_commandP3THD+0x135f)[0x55646e18a2d7]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(_Z24do_handle_one_connectionP3THD+0x42b)[0x55646e3c3253]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(handle_one_connection+0xd3)[0x55646e3c3730]
 
/mnt/buildbot/build/mariadb-10.1.30/sql/mysqld(+0xf36591)[0x55646e9a1591]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7f19500d26ba]
 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f194f77d82d]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x62b000046220): DROP TABLE IF EXISTS tt_xx_7, nt_xx_7
 
Connection ID (thread ID): 8
 
Status: NOT_KILLED

Comment by Marko Mäkelä [ 2018-03-16 ]

I was not able to repeat this locally:

./mtr --mem --parallel=auto --repeat=10 rpl_row_mixing_engines rpl.rpl_non_direct_row_mixing_engines

10.1 0a534348c75cf435d2017959855de2efa798fd0b Debug -DWITH_ASAN=1

 
worker[3] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
worker[2] Using MTR_BUILD_THREAD 301, with reserved ports 16020..16039
 
worker[4] Using MTR_BUILD_THREAD 302, with reserved ports 16040..16059
 
worker[1] Using MTR_BUILD_THREAD 303, with reserved ports 16060..16079
 
rpl.rpl_row_mixing_engines 'innodb_plugin,row' w2 [ pass ]  349342
 
rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w3 [ pass ]  351769
 
rpl.rpl_row_mixing_engines 'row,xtradb'  w4 [ pass ]  352062
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w1 [ pass ]  352125
 
rpl.rpl_row_mixing_engines 'innodb_plugin,row' w2 [ pass ]  353247
 
rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w3 [ pass ]  354111
 
rpl.rpl_row_mixing_engines 'row,xtradb'  w4 [ pass ]  353077
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w1 [ pass ]  353737
 
rpl.rpl_row_mixing_engines 'innodb_plugin,row' w2 [ pass ]  387183
 
rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w3 [ pass ]  387071
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w1 [ pass ]  387667
 
rpl.rpl_row_mixing_engines 'row,xtradb'  w4 [ pass ]  388246
 
rpl.rpl_row_mixing_engines 'innodb_plugin,row' w2 [ pass ]  371570
 
rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w3 [ pass ]  370127
 
rpl.rpl_row_mixing_engines 'row,xtradb'  w4 [ pass ]  370745
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w1 [ pass ]  371569
 
rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w3 [ pass ]  368808
 
rpl.rpl_row_mixing_engines 'innodb_plugin,row' w2 [ pass ]  370530
 
rpl.rpl_row_mixing_engines 'row,xtradb'  w4 [ pass ]  369630
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w1 [ pass ]  370384
 
rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w3 [ pass ]  372221
 
rpl.rpl_row_mixing_engines 'innodb_plugin,row' w2 [ pass ]  372123
 
rpl.rpl_row_mixing_engines 'row,xtradb'  w4 [ pass ]  370254
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w1 [ pass ]  370333
 
rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w3 [ pass ]  370740
 
rpl.rpl_row_mixing_engines 'innodb_plugin,row' w2 [ pass ]  371270
 
rpl.rpl_row_mixing_engines 'row,xtradb'  w4 [ pass ]  370915
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w1 [ pass ]  371129
 
rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w3 [ pass ]  376476
 
rpl.rpl_row_mixing_engines 'innodb_plugin,row' w2 [ pass ]  375260
 
rpl.rpl_row_mixing_engines 'row,xtradb'  w4 [ pass ]  375881
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w1 [ pass ]  375525
 
rpl.rpl_row_mixing_engines 'innodb_plugin,row' w2 [ pass ]  383433
 
rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w3 [ pass ]  386081
 
rpl.rpl_row_mixing_engines 'row,xtradb'  w4 [ pass ]  385311
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w1 [ pass ]  384721
 
rpl.rpl_row_mixing_engines 'innodb_plugin,row' w2 [ pass ]  379674
 
rpl.rpl_non_direct_row_mixing_engines 'innodb_plugin,row' w3 [ pass ]  377989
 
rpl.rpl_row_mixing_engines 'row,xtradb'  w4 [ pass ]  378175
 
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w1 [ pass ]  378676

The cause ought to be a corruption of the innodb_adaptive_hash_index which is ON by default.
The test case uses multiple nested source files, and it is hard to follow the history of table tt_xx_7. The hanging statement

DROP TABLE IF EXISTS tt_xx_7, nt_xx_7;

is line 13,897 of both the files rpl_non_direct_row_mixing_engines.result and rpl_row_mixing_engines.result.
The logic for adding or updating entries in the adaptive hash index is highly nondeterministic, but any entries must be dropped when tables or indexes are dropped.
For some reason, the reference counter for the index does not reach zero. If I could analyze a core dump of this, I could determine if there really is a block->index that is pointing to an index of the to-be-dropped table, or if the reference counter is corrupted (should have been 0).

Comment by Marko Mäkelä [ 2018-05-29 ]

As part of the MDEV-16283 fix, I replaced the flawed logic with one that actively evicts the adaptive hash index. My understanding is that the wait while holding the InnoDB data dictionary lock could essentially lock the whole InnoDB instance. When the InnoDB buffer pool is idle, nothing can possibly evict pages, which would be the only way how adaptive hash index entries for a to-be-dropped index could be removed.

Generated at Thu Feb 08 08:14:00 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.