Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-11342

OQGRAPH should acquire meta-data locks on "backing" tables

    XMLWordPrintable

    Details

      Description

      After attempting to upgrade Mariadb from 10.0.x to 10.1.x we ran into a "drop database" issue that was not present in 10.0.x. The issue is reproducible at will. If a database has an Innodb table that has an OQGRAPH table referencing it and you drop the entire database, Innodb goes into a meltdown.

      Test case on empty database: create an empty table and then an OQGRAPH table referencing it:

      CREATE TABLE `routes` (
        `orig_node_id` int(10) unsigned NOT NULL,
        `dest_node_id` int(10) unsigned NOT NULL,
        `weight` double NOT NULL,
        PRIMARY KEY (`orig_node_id`,`dest_node_id`),
        KEY `dest_node_id` (`dest_node_id`)
      ) ENGINE=InnoDB;
       
      CREATE TABLE `routing` (
        `latch` varchar(32) DEFAULT NULL,
        `origid` bigint(20) unsigned DEFAULT NULL,
        `destid` bigint(20) unsigned DEFAULT NULL,
        `weight` double DEFAULT NULL,
        `seq` bigint(20) unsigned DEFAULT NULL,
        `linkid` bigint(20) unsigned DEFAULT NULL,
        KEY `latch` (`latch`,`origid`,`destid`) USING HASH,
        KEY `latch_2` (`latch`,`destid`,`origid`) USING HASH
      ) ENGINE=OQGRAPH `data_table`='routes' `origid`='orig_node_id' `destid`='dest_node_id' `weight`='weight';
      
      

      Then do below and watch the MariaDB logs:

      echo "drop database test" | mysql
      
      

      Nov 23 22:55:20 ip-30-7-0-23 mysqld: 2016-11-23 22:55:20 139686369522432 [Warning] InnoDB: Waited 30 seconds for ref-count on table: axon/routes space: 28
      Nov 23 22:55:50 ip-30-7-0-23 mysqld: 2016-11-23 22:55:50 139686369522432 [Warning] InnoDB: Waited 60 seconds for ref-count on table: axon/routes space: 28
      Nov 23 22:56:20 ip-30-7-0-23 mysqld: 2016-11-23 22:56:20 139686369522432 [Warning] InnoDB: Waited 90 seconds for ref-count on table: axon/routes space: 28
      Nov 23 22:56:50 ip-30-7-0-23 mysqld: 2016-11-23 22:56:50 139686369522432 [Warning] InnoDB: Waited 120 seconds for ref-count on table: axon/routes space: 28
      Nov 23 22:57:20 ip-30-7-0-23 mysqld: 2016-11-23 22:57:20 139686369522432 [Warning] InnoDB: Waited 150 seconds for ref-count on table: axon/routes space: 28
      Nov 23 22:57:50 ip-30-7-0-23 mysqld: 2016-11-23 22:57:50 139686369522432 [Warning] InnoDB: Waited 180 seconds for ref-count on table: axon/routes space: 28
      Nov 23 22:58:20 ip-30-7-0-23 mysqld: 2016-11-23 22:58:20 139686369522432 [Warning] InnoDB: Waited 210 seconds for ref-count on table: axon/routes space: 28
      Nov 23 22:58:50 ip-30-7-0-23 mysqld: 2016-11-23 22:58:50 139686369522432 [Warning] InnoDB: Waited 240 seconds for ref-count on table: axon/routes space: 28
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: 2016-11-23 22:58:51 139685468825344 [Warning] InnoDB: A long semaphore wait:
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: --Thread 139685435254528 has waited at row0purge.cc line 861 for 241.00 seconds the semaphore:
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: S-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: 2016-11-23 22:58:51 139685468825344 [Note] InnoDB: A semaphore wait:
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: --Thread 139685435254528 has waited at row0purge.cc line 861 for 241.00 seconds the semaphore:
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: S-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: 2016-11-23 22:58:51 139685468825344 [Note] InnoDB: A semaphore wait:
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: --Thread 139685452039936 has waited at srv0srv.cc line 2243 for 240.00 seconds the semaphore:
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: X-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
      Nov 23 22:58:51 ip-30-7-0-23 mysqld: InnoDB: Pending preads 0, pwrites 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: =====================================
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 2016-11-23 22:58:53 0x7f0b0e3fd700 INNODB MONITOR OUTPUT
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: =====================================
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Per second averages calculated from the last 8 seconds
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: -----------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: BACKGROUND THREAD
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: -----------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: srv_master_thread loops: 2 srv_active, 0 srv_shutdown, 496 srv_idle
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: srv_master_thread log flush and writes: 497
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ----------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: SEMAPHORES
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ----------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: OS WAIT ARRAY INFO: reservation count 6
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: --Thread 139685435254528 has waited at row0purge.cc line 861 for 243.00 seconds the semaphore:
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: S-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: --Thread 139685452039936 has waited at srv0srv.cc line 2243 for 242.00 seconds the semaphore:
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: X-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: OS WAIT ARRAY INFO: signal count 4
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: RW-shared spins 0, rounds 8, OS waits 4
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: RW-excl spins 0, rounds 0, OS waits 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: RW-sx spins 0, rounds 0, OS waits 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Spin rounds per wait: 8.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: TRANSACTIONS
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Trx id counter 8974
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Purge done for trx's n:o < 8972 undo n:o < 0 state: running
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: History list length 81
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: LIST OF TRANSACTIONS FOR EACH SESSION:
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ---TRANSACTION 421161104051016, not started
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0 lock struct(s), heap size 1136, 0 row lock(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ---TRANSACTION 421161104050056, not started
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0 lock struct(s), heap size 1136, 0 row lock(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ---TRANSACTION 8969, ACTIVE 243 sec dropping table
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0 lock struct(s), heap size 1136, 0 row lock(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: MySQL thread id 7, OS thread handle 0x7f0b446f7300, query id 118 localhost root Unlocking tables
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: drop database axon
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: --------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: FILE I/O
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: --------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O thread 1 state: waiting for completed aio requests (log thread)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O thread 2 state: waiting for completed aio requests (read thread)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O thread 3 state: waiting for completed aio requests (read thread)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O thread 4 state: waiting for completed aio requests (read thread)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O thread 5 state: waiting for completed aio requests (read thread)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O thread 6 state: waiting for completed aio requests (write thread)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O thread 7 state: waiting for completed aio requests (write thread)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O thread 8 state: waiting for completed aio requests (write thread)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O thread 9 state: waiting for completed aio requests (write thread)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ibuf aio reads:, log i/o's:, sync i/o's:
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Pending flushes (fsync) log: 0; buffer pool: 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 313 OS file reads, 95 OS file writes, 30 OS fsyncs
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: -------------------------------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: INSERT BUFFER AND ADAPTIVE HASH INDEX
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: -------------------------------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Ibuf: size 1, free list len 0, seg size 2, 0 merges
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: merged operations:
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: insert 0, delete mark 0, delete 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: discarded operations:
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: insert 0, delete mark 0, delete 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 1 buffer(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 1 buffer(s)
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0.00 hash searches/s, 0.00 non-hash searches/s
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ---
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: LOG
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ---
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Log sequence number 1759389
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Log flushed up to   1759389
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Pages flushed up to 1759389
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Last checkpoint at  1757801
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0 pending log flushes, 0 pending chkp writes
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 20 log i/o's done, 0.00 log i/o's/second
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ----------------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: BUFFER POOL AND MEMORY
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ----------------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Total large memory allocated 138215424
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Dictionary memory allocated 251473
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Buffer pool size   8192
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Free buffers       7867
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Database pages     323
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Old database pages 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Modified db pages  0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Percent of dirty pages(LRU & free pages): 0.000
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Max dirty pages percent: 75.000
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Pending reads 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Pending writes: LRU 0, flush list 0, single page 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Pages made young 0, not young 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0.00 youngs/s, 0.00 non-youngs/s
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Pages read 284, created 39, written 62
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0.00 reads/s, 0.00 creates/s, 0.00 writes/s
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: No buffer pool page gets since the last printout
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: LRU len: 323, unzip_LRU len: 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: I/O sum[0]:cur[0], unzip sum[0]:cur[0]
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: --------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ROW OPERATIONS
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: --------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0 queries inside InnoDB, 0 queries in queue
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0 read views open inside InnoDB
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Process ID=4049, Main thread ID=139685452039936, state: enforcing dict cache limit
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Number of rows inserted 0, updated 0, deleted 0, read 259
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: Number of system rows inserted 0, updated 0, deleted 0, read 0
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ----------------------------
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: END OF INNODB MONITOR OUTPUT
      Nov 23 22:58:53 ip-30-7-0-23 mysqld: ============================
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: =====================================
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 2016-11-23 22:59:13 0x7f0b0e3fd700 INNODB MONITOR OUTPUT
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: =====================================
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Per second averages calculated from the last 20 seconds
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: -----------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: BACKGROUND THREAD
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: -----------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: srv_master_thread loops: 2 srv_active, 0 srv_shutdown, 496 srv_idle
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: srv_master_thread log flush and writes: 497
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ----------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: SEMAPHORES
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ----------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: OS WAIT ARRAY INFO: reservation count 6
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: --Thread 139685435254528 has waited at row0purge.cc line 861 for 263.00 seconds the semaphore:
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: S-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: --Thread 139685452039936 has waited at srv0srv.cc line 2243 for 262.00 seconds the semaphore:
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: X-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: OS WAIT ARRAY INFO: signal count 4
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: RW-shared spins 0, rounds 8, OS waits 4
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: RW-excl spins 0, rounds 0, OS waits 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: RW-sx spins 0, rounds 0, OS waits 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Spin rounds per wait: 8.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: TRANSACTIONS
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Trx id counter 8974
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Purge done for trx's n:o < 8972 undo n:o < 0 state: running
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: History list length 81
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: LIST OF TRANSACTIONS FOR EACH SESSION:
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ---TRANSACTION 421161104051016, not started
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0 lock struct(s), heap size 1136, 0 row lock(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ---TRANSACTION 421161104050056, not started
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0 lock struct(s), heap size 1136, 0 row lock(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ---TRANSACTION 8969, ACTIVE 263 sec dropping table
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0 lock struct(s), heap size 1136, 0 row lock(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: MySQL thread id 7, OS thread handle 0x7f0b446f7300, query id 118 localhost root Unlocking tables
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: drop database axon
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: --------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: FILE I/O
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: --------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O thread 1 state: waiting for completed aio requests (log thread)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O thread 2 state: waiting for completed aio requests (read thread)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O thread 3 state: waiting for completed aio requests (read thread)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O thread 4 state: waiting for completed aio requests (read thread)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O thread 5 state: waiting for completed aio requests (read thread)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O thread 6 state: waiting for completed aio requests (write thread)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O thread 7 state: waiting for completed aio requests (write thread)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O thread 8 state: waiting for completed aio requests (write thread)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O thread 9 state: waiting for completed aio requests (write thread)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ibuf aio reads:, log i/o's:, sync i/o's:
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Pending flushes (fsync) log: 0; buffer pool: 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 313 OS file reads, 95 OS file writes, 30 OS fsyncs
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: -------------------------------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: INSERT BUFFER AND ADAPTIVE HASH INDEX
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: -------------------------------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Ibuf: size 1, free list len 0, seg size 2, 0 merges
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: merged operations:
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: insert 0, delete mark 0, delete 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: discarded operations:
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: insert 0, delete mark 0, delete 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 1 buffer(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 1 buffer(s)
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0.00 hash searches/s, 0.00 non-hash searches/s
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ---
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: LOG
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ---
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Log sequence number 1759389
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Log flushed up to   1759389
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Pages flushed up to 1759389
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Last checkpoint at  1757801
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0 pending log flushes, 0 pending chkp writes
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 20 log i/o's done, 0.00 log i/o's/second
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ----------------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: BUFFER POOL AND MEMORY
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ----------------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Total large memory allocated 138215424
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Dictionary memory allocated 251473
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Buffer pool size   8192
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Free buffers       7867
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Database pages     323
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Old database pages 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Modified db pages  0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Percent of dirty pages(LRU & free pages): 0.000
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Max dirty pages percent: 75.000
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Pending reads 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Pending writes: LRU 0, flush list 0, single page 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Pages made young 0, not young 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0.00 youngs/s, 0.00 non-youngs/s
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Pages read 284, created 39, written 62
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0.00 reads/s, 0.00 creates/s, 0.00 writes/s
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: No buffer pool page gets since the last printout
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: LRU len: 323, unzip_LRU len: 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: I/O sum[0]:cur[0], unzip sum[0]:cur[0]
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: --------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ROW OPERATIONS
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: --------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0 queries inside InnoDB, 0 queries in queue
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0 read views open inside InnoDB
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Process ID=4049, Main thread ID=139685452039936, state: enforcing dict cache limit
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Number of rows inserted 0, updated 0, deleted 0, read 259
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: Number of system rows inserted 0, updated 0, deleted 0, read 0
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ----------------------------
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: END OF INNODB MONITOR OUTPUT
      Nov 23 22:59:13 ip-30-7-0-23 mysqld: ============================
      Nov 23 22:59:20 ip-30-7-0-23 mysqld: 2016-11-23 22:59:20 139686369522432 [Warning] InnoDB: Waited 270 seconds for ref-count on table: axon/routes space: 28
      Nov 23 22:59:21 ip-30-7-0-23 mysqld: InnoDB: ###### Diagnostic info printed to the standard error stream
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: 2016-11-23 22:59:22 139685468825344 [Warning] InnoDB: A long semaphore wait:
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: --Thread 139685435254528 has waited at row0purge.cc line 861 for 272.00 seconds the semaphore:
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: S-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: 2016-11-23 22:59:22 139685468825344 [Warning] InnoDB: A long semaphore wait:
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: --Thread 139685452039936 has waited at srv0srv.cc line 2243 for 271.00 seconds the semaphore:
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: X-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: 2016-11-23 22:59:22 139685468825344 [Note] InnoDB: A semaphore wait:
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: --Thread 139685435254528 has waited at row0purge.cc line 861 for 272.00 seconds the semaphore:
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: S-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: 2016-11-23 22:59:22 139685468825344 [Note] InnoDB: A semaphore wait:
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: --Thread 139685452039936 has waited at srv0srv.cc line 2243 for 271.00 seconds the semaphore:
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: X-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
      Nov 23 22:59:22 ip-30-7-0-23 mysqld: InnoDB: Pending preads 0, pwrites 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: =====================================
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 2016-11-23 22:59:33 0x7f0b0e3fd700 INNODB MONITOR OUTPUT
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: =====================================
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Per second averages calculated from the last 20 seconds
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: -----------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: BACKGROUND THREAD
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: -----------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: srv_master_thread loops: 2 srv_active, 0 srv_shutdown, 496 srv_idle
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: srv_master_thread log flush and writes: 497
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ----------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: SEMAPHORES
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ----------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: OS WAIT ARRAY INFO: reservation count 6
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: --Thread 139685435254528 has waited at row0purge.cc line 861 for 283.00 seconds the semaphore:
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: S-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: --Thread 139685452039936 has waited at srv0srv.cc line 2243 for 282.00 seconds the semaphore:
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: X-lock on RW-latch at 0x7f0b3f83c920 created in file dict0dict.cc line 1248
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: a writer (thread id 139686369522432) has reserved it in mode  exclusive
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: number of readers 0, waiters flag 1, lock_word: 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Last time read locked in file row0purge.cc line 861
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Last time write locked in file /home/buildbot/buildbot/build/mariadb-10.2.2/storage/innobase/row/row0mysql.cc line 4400
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: OS WAIT ARRAY INFO: signal count 4
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: RW-shared spins 0, rounds 8, OS waits 4
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: RW-excl spins 0, rounds 0, OS waits 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: RW-sx spins 0, rounds 0, OS waits 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Spin rounds per wait: 8.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: TRANSACTIONS
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Trx id counter 8974
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Purge done for trx's n:o < 8972 undo n:o < 0 state: running
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: History list length 81
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: LIST OF TRANSACTIONS FOR EACH SESSION:
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ---TRANSACTION 421161104051016, not started
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0 lock struct(s), heap size 1136, 0 row lock(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ---TRANSACTION 421161104050056, not started
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0 lock struct(s), heap size 1136, 0 row lock(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ---TRANSACTION 8969, ACTIVE 283 sec dropping table
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0 lock struct(s), heap size 1136, 0 row lock(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: MySQL thread id 7, OS thread handle 0x7f0b446f7300, query id 118 localhost root Unlocking tables
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: drop database axon
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: --------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: FILE I/O
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: --------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O thread 1 state: waiting for completed aio requests (log thread)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O thread 2 state: waiting for completed aio requests (read thread)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O thread 3 state: waiting for completed aio requests (read thread)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O thread 4 state: waiting for completed aio requests (read thread)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O thread 5 state: waiting for completed aio requests (read thread)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O thread 6 state: waiting for completed aio requests (write thread)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O thread 7 state: waiting for completed aio requests (write thread)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O thread 8 state: waiting for completed aio requests (write thread)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O thread 9 state: waiting for completed aio requests (write thread)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ibuf aio reads:, log i/o's:, sync i/o's:
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Pending flushes (fsync) log: 0; buffer pool: 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 313 OS file reads, 95 OS file writes, 30 OS fsyncs
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: -------------------------------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: INSERT BUFFER AND ADAPTIVE HASH INDEX
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: -------------------------------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Ibuf: size 1, free list len 0, seg size 2, 0 merges
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: merged operations:
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: insert 0, delete mark 0, delete 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: discarded operations:
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: insert 0, delete mark 0, delete 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 1 buffer(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 0 buffer(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Hash table size 34679, node heap has 1 buffer(s)
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0.00 hash searches/s, 0.00 non-hash searches/s
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ---
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: LOG
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ---
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Log sequence number 1759389
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Log flushed up to   1759389
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Pages flushed up to 1759389
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Last checkpoint at  1757801
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0 pending log flushes, 0 pending chkp writes
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 20 log i/o's done, 0.00 log i/o's/second
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ----------------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: BUFFER POOL AND MEMORY
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ----------------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Total large memory allocated 138215424
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Dictionary memory allocated 251473
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Buffer pool size   8192
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Free buffers       7867
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Database pages     323
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Old database pages 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Modified db pages  0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Percent of dirty pages(LRU & free pages): 0.000
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Max dirty pages percent: 75.000
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Pending reads 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Pending writes: LRU 0, flush list 0, single page 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Pages made young 0, not young 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0.00 youngs/s, 0.00 non-youngs/s
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Pages read 284, created 39, written 62
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0.00 reads/s, 0.00 creates/s, 0.00 writes/s
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: No buffer pool page gets since the last printout
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: LRU len: 323, unzip_LRU len: 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: I/O sum[0]:cur[0], unzip sum[0]:cur[0]
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: --------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ROW OPERATIONS
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: --------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0 queries inside InnoDB, 0 queries in queue
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0 read views open inside InnoDB
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Process ID=4049, Main thread ID=139685452039936, state: enforcing dict cache limit
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Number of rows inserted 0, updated 0, deleted 0, read 259
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: Number of system rows inserted 0, updated 0, deleted 0, read 0
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ----------------------------
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: END OF INNODB MONITOR OUTPUT
      Nov 23 22:59:33 ip-30-7-0-23 mysqld: ============================
      Nov 23 22:59:50 ip-30-7-0-23 mysqld: 2016-11-23 22:59:50 139686369522432 [Warning] InnoDB: Waited 300 seconds for ref-count on table: axon/routes space: 28
      Nov 23 22:59:50 ip-30-7-0-23 mysqld: 2016-11-23 22:59:50 139686369522432 [Warning] InnoDB: After 300 seconds, gave up waiting for ref-count on table: axon/routes space: 28
      Nov 23 22:59:50 ip-30-7-0-23 mysqld: 2016-11-23 22:59:50 139686369522432 [Note] InnoDB: MySQL is trying to drop table `axon`.`routes` though there are still open handles to it. Adding the table to the background drop queue.
      Nov 23 22:59:51 ip-30-7-0-23 mysqld: 2016-11-23 22:59:51 139685452039936 [Note] InnoDB: Dropped table `axon`.`routes` in background drop queue.
      Nov 23 22:59:52 ip-30-7-0-23 mysqld: InnoDB: ###### Diagnostic info printed to the standard error stream
      
      

      Observations:

      The issue was not there in 10.0.x
      OQGRAPH code has not changed between 10.0, 10.1 and 10.2
      The issue only occurs on database drop. If I just drop the Innodb table then the issue does not occur. If I drop the OQGRAPH table first and then drop the database, the issue does not occur.

        Attachments

          Activity

            People

            Assignee:
            cvicentiu Vicențiu Ciorbaru
            Reporter:
            Ellerbrockr richardeaxon
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

              Dates

              Created:
              Updated: