2015-03-16T22:51:21.667184Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2015-03-16T22:51:21.667242Z 0 [Warning] Insecure configuration for --secure-file-priv: Current value does not restrict location of generated files. Consider setting it to a valid, non-empty path. 2015-03-16T22:51:21.667281Z 0 [Note] /sda/MS-mysql-5.7.6-m16-linux-x86_64-debug/bin/mysqld (mysqld 5.7.6-m16-debug) starting as process 29027 ... 2015-03-16T22:51:21.670896Z 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!! 2015-03-16T22:51:21.670914Z 0 [Note] InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!! 2015-03-16T22:51:21.670920Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2015-03-16T22:51:21.670925Z 0 [Note] InnoDB: Uses event mutexes 2015-03-16T22:51:21.670929Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 2015-03-16T22:51:21.670933Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3 2015-03-16T22:51:21.670936Z 0 [Note] InnoDB: Using Linux native AIO 2015-03-16T22:51:21.671242Z 0 [Note] InnoDB: Number of pools: 1 2015-03-16T22:51:21.671334Z 0 [Note] InnoDB: Using CPU crc32 instructions 2015-03-16T22:51:21.671861Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M 2015-03-16T22:51:21.721906Z 0 [Note] InnoDB: Completed initialization of buffer pool 2015-03-16T22:51:21.723567Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 2015-03-16T22:51:21.724988Z 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB 2015-03-16T22:51:21.734058Z 0 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB 2015-03-16T22:51:21.743636Z 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0 2015-03-16T22:51:21.743686Z 0 [Warning] InnoDB: New log files created, LSN=2321946 2015-03-16T22:51:21.744281Z 0 [Note] InnoDB: Highest supported file format is Barracuda. 2015-03-16T22:51:21.745144Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 2322444 2015-03-16T22:51:21.745152Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 2322453 2015-03-16T22:51:21.745298Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 2322453 2015-03-16T22:51:21.745306Z 0 [Note] InnoDB: Database was not shutdown normally! 2015-03-16T22:51:21.745310Z 0 [Note] InnoDB: Starting crash recovery. 2015-03-16T22:51:22.006749Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2015-03-16T22:51:22.006850Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 2015-03-16T22:51:22.009235Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2015-03-16T22:51:22.037671Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active. 2015-03-16T22:51:22.037680Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active. 2015-03-16T22:51:22.038416Z 0 [Note] InnoDB: Waiting for purge to start 2015-03-16T22:51:22.089896Z 0 [Note] InnoDB: 5.7.6 started; log sequence number 2322453 2015-03-16T22:51:22.090351Z 0 [Note] Plugin 'FEDERATED' is disabled. 2015-03-16T22:51:22.092525Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: f780ae59-cc2e-11e4-bba3-902b34625689. 2015-03-16T22:51:22.095955Z 0 [Warning] Failed to setup SSL 2015-03-16T22:51:22.095962Z 0 [Warning] SSL error: SSL context is not usable without certificate and private key 2015-03-16T22:51:22.095969Z 0 [Note] Server hostname (bind-address): '*'; port: 53413 2015-03-16T22:51:22.096004Z 0 [Note] IPv6 is available. 2015-03-16T22:51:22.096013Z 0 [Note] - '::' resolves to '::'; 2015-03-16T22:51:22.096024Z 0 [Note] Server socket created on IP: '::'. 2015-03-16T22:51:22.117765Z 0 [Note] Event Scheduler: Loaded 0 events 2015-03-16T22:51:22.117911Z 0 [Note] /sda/MS-mysql-5.7.6-m16-linux-x86_64-debug/bin/mysqld: ready for connections. Version: '5.7.6-m16-debug' socket: '/dev/shm/352307/3/socket.sock' port: 53413 MySQL Community Server (GPL) 2015-03-16T22:51:22.117931Z 1 [Note] Event Scheduler: scheduler thread started with id 1 2015-03-16T22:51:23.032174Z 6 [Note] InnoDB: Saving InnoDB page number: 1 2015-03-16T22:51:23.074214Z 6 [Warning] Did not write failed 'GRANT ALL ON test.t1 TO user1@localhost' into binary log while storing table level and column level grants in the privilege tables. 2015-03-16T22:51:23.245031Z 6 [ERROR] Slave: Cannot create new master info structure when repositories are of type FILE. Convert slave repositories to TABLE to replicate from multiple sources. 2015-03-16T22:51:23.382479Z 6 [Note] Event Scheduler: Killing the scheduler thread, thread id 1 2015-03-16T22:51:23.382495Z 6 [Note] Event Scheduler: Waiting for the scheduler thread to reply 2015-03-16T22:51:23.382574Z 6 [Note] Event Scheduler: Stopped 2015-03-16T22:51:23.638137Z 6 [Note] InnoDB: The file format in the system tablespace is now set to Barracuda. 2015-03-16T22:51:23.768351Z 6 [ERROR] InnoDB: User stopword table Salmon does not exist. 2015-03-16T22:51:23.850951Z 6 [ERROR] Invalid (old?) table or database name 'mysqltest-2' 2015-03-16T22:51:23.947915Z 7 [Note] Event Scheduler: scheduler thread started with id 7 2015-03-16T22:51:24.048884Z 9 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:24.048892Z 9 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:24.139048Z 6 [Note] InnoDB: The file format in the system tablespace is now set to Antelope. 2015-03-16T22:51:24.561919Z 6 [ERROR] Invalid (old?) table or database name 'mysqltest-2' 2015-03-16T22:51:24.658532Z 6 [ERROR] Invalid (old?) table or database name 'mysqltest-2' 2015-03-16T22:51:24.889993Z 6 [ERROR] Invalid (old?) table or database name 'mysqltest-2' 2015-03-16T22:51:25.945152Z 11 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:25.945160Z 11 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:26.945432Z 12 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:26.945441Z 12 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:27.945669Z 13 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:27.945678Z 13 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:28.946046Z 14 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:28.946057Z 14 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:29.946343Z 15 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:29.946352Z 15 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:30.946570Z 16 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:30.946579Z 16 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:31.946828Z 17 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:31.946836Z 17 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:32.947089Z 18 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:32.947098Z 18 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:33.947365Z 19 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:33.947374Z 19 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:34.947636Z 20 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:34.947645Z 20 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:35.947991Z 21 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:35.948000Z 21 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:36.948206Z 22 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:36.948215Z 22 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:37.948408Z 23 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:37.948417Z 23 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:38.948693Z 24 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:38.948701Z 24 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:39.948918Z 25 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:39.948926Z 25 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:40.949170Z 26 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:40.949179Z 26 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:41.949448Z 27 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:41.949457Z 27 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:42.949668Z 28 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:42.949677Z 28 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:43.949942Z 29 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:43.949951Z 29 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:44.950167Z 30 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:44.950175Z 30 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:45.950402Z 31 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:45.950411Z 31 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:46.950716Z 32 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:46.950725Z 32 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:47.950930Z 33 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:47.950939Z 33 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:48.951149Z 34 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:48.951158Z 34 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:49.951420Z 35 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:49.951429Z 35 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:50.951653Z 36 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:50.951662Z 36 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:51.951883Z 37 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:51.951892Z 37 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:52.952109Z 38 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:52.952118Z 38 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:53.952389Z 39 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:53.952398Z 39 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:54.952539Z 40 [ERROR] Event Scheduler: [root@localhost][test.e2] Can't drop database 'BUG52792'; database doesn't exist 2015-03-16T22:51:54.952547Z 40 [Note] Event Scheduler: [root@localhost].[test.e2] event execution failed. 2015-03-16T22:51:55.845687Z 0 [Note] Giving 2 client threads a chance to die gracefully 2015-03-16T22:51:55.845703Z 0 [Note] Shutting down slave threads 2015-03-16T22:51:57.845772Z 0 [Note] Forcefully disconnecting 2 remaining clients 2015-03-16T22:51:57.845783Z 0 [Warning] /sda/MS-mysql-5.7.6-m16-linux-x86_64-debug/bin/mysqld: Forcing close of thread 6 user: 'root' 2015-03-16T22:51:57.845806Z 0 [Note] Event Scheduler: Killing the scheduler thread, thread id 7 2015-03-16T22:51:57.845813Z 0 [Note] Event Scheduler: Waiting for the scheduler thread to reply 2015-03-16T22:51:57.845869Z 0 [Note] Event Scheduler: Stopped 2015-03-16T22:51:57.845878Z 0 [Note] Event Scheduler: Purging the queue. 3 events 2015-03-16T23:02:36.908074Z 0 [Warning] InnoDB: A long semaphore wait: --Thread 140046824883968 has waited at trx0purge.cc line 153 for 324.00 seconds the semaphore: Mutex at 0x7f5f3f67b7a0 created file trx0rseg.cc line 211, lock var 1 Last time reserved in file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/trx/trx0trx.cc line 1528 InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info: InnoDB: Pending preads 0, pwrites 0 ===================================== 2015-03-17 10:02:45 0x7f5f323fe700 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 9 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 3 srv_active, 0 srv_shutdown, 2 srv_idle srv_master_thread log flush and writes: 4 ---------- SEMAPHORES ---------- ------------- RW-LATCH INFO ------------- RW-LOCK: 0x25b4da0 Waiters for the lock exist Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/dict/dict0stats.cc line 2366 X-LOCK RW-LOCK: 0x7f5f3fdbb0f0 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0undo.ic line 171 S-LOCK RW-LOCK: 0x7f5f3fdbafd8 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0undo.ic line 171 X-LOCK RW-LOCK: 0x7f5f3fda4718 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9dbd8 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9d898 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9cb98 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9c858 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9c518 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd92a30 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0rseg.ic line 48 S-LOCK RW-LOCK: 0x7f5f3fd92918 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0rseg.ic line 48 X-LOCK RW-LOCK: 0x7f5f3fd80e58 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd80158 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x25b4ca0 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0buf.cc line 3588 S-LOCK Total number of rw-locks 16639 OS WAIT ARRAY INFO: reservation count 799 --Thread 140046824883968 has waited at trx0purge.cc line 153 for 333.00 seconds the semaphore: Mutex at 0x7f5f3f67b7a0 created file trx0rseg.cc line 211, lock var 1 Last time reserved in file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/trx/trx0trx.cc line 1528 --Thread 140046833276672 has waited at srv0srv.cc line 1915 for 203.00 seconds the semaphore: X-lock on RW-latch at 0x25b4da0 created in file dict0dict.cc line 1038 a writer (thread id 140046795532032) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file row0purge.cc line 811 Last time write locked in file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/dict/dict0stats.cc line 2366 OS WAIT ARRAY INFO: signal count 677 Mutex spin waits 0, rounds 0, OS waits 0 RW-shared spins 54, rounds 102, OS waits 48 RW-excl spins 6, rounds 24564, OS waits 16 RW-sx spins 5, rounds 41, OS waits 3 Spin rounds per wait: 0.00 mutex, 1.89 RW-shared, 4094.00 RW-excl, 8.20 RW-sx ------------ TRANSACTIONS ------------ Trx id counter 1972 Purge done for trx's n:o < 1946 undo n:o < 0 state: running History list length 103 Total number of lock structs in row lock hash table 1 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 421522187488592, not started 0 lock struct(s), heap size 1160, 0 row lock(s) ---TRANSACTION 1970, ACTIVE 671 sec committing 2 lock struct(s), heap size 1160, 2 row lock(s), undo log entries 2 ---TRANSACTION 1968, ACTIVE 680 sec mysql tables in use 1, locked 1 0 lock struct(s), heap size 1160, 0 row lock(s) MySQL thread id 6, OS thread handle 140047447013120, query id 8005 localhost root altering table ALTER TABLE t1 ADD c2 MEDIUMTEXT NULL FIRST Trx read view will not see trx with id >= 1970, sees < 1969 -------- 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 (read thread) I/O thread 5 state: waiting for completed aio requests (read thread) I/O thread 6 state: complete io for buf page (write thread) I/O thread 7 state: waiting for completed aio requests (write thread) I/O thread 8 state: waiting for completed aio requests (write thread) I/O thread 9 state: waiting for completed aio requests (write thread) Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 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 323 OS file reads, 1611 OS file writes, 714 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 Hash table size 276707, used cells 0, node heap has 0 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 2804647 Log flushed up to 2804421 Pages flushed up to 2726652 Last checkpoint at 2726652 0 pending log flushes, 0 pending chkp writes 418 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total large memory allocated 141033472 Dictionary memory allocated 884529 Buffer pool size 8192 Free buffers 7464 Database pages 728 Old database pages 54 Modified db pages 114 Pending reads 0 Pending writes: LRU 0, flush list 9, single page 0 Pages made young 0, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 233, created 495, written 851 0.00 reads/s, 0.00 creates/s, 0.00 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 728, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue 1 read views open inside InnoDB Process ID=29027, Main thread ID=140046833276672, state: enforcing dict cache limit Number of rows inserted 1491, updated 1, deleted 4, read 1477 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ ===================================== 2015-03-17 10:03:05 0x7f5f323fe700 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 20 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 3 srv_active, 0 srv_shutdown, 2 srv_idle srv_master_thread log flush and writes: 4 ---------- SEMAPHORES ---------- ------------- RW-LATCH INFO ------------- RW-LOCK: 0x25b4da0 Waiters for the lock exist Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/dict/dict0stats.cc line 2366 X-LOCK RW-LOCK: 0x7f5f3fdbb0f0 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0undo.ic line 171 S-LOCK RW-LOCK: 0x7f5f3fdbafd8 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0undo.ic line 171 X-LOCK RW-LOCK: 0x7f5f3fda4718 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9dbd8 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9d898 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9cb98 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9c858 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9c518 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd92a30 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0rseg.ic line 48 S-LOCK RW-LOCK: 0x7f5f3fd92918 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0rseg.ic line 48 X-LOCK RW-LOCK: 0x7f5f3fd80e58 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd80158 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x25b4ca0 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0buf.cc line 3588 S-LOCK Total number of rw-locks 16639 OS WAIT ARRAY INFO: reservation count 799 --Thread 140046824883968 has waited at trx0purge.cc line 153 for 353.00 seconds the semaphore: Mutex at 0x7f5f3f67b7a0 created file trx0rseg.cc line 211, lock var 1 Last time reserved in file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/trx/trx0trx.cc line 1528 --Thread 140046833276672 has waited at srv0srv.cc line 1915 for 223.00 seconds the semaphore: X-lock on RW-latch at 0x25b4da0 created in file dict0dict.cc line 1038 a writer (thread id 140046795532032) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file row0purge.cc line 811 Last time write locked in file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/dict/dict0stats.cc line 2366 OS WAIT ARRAY INFO: signal count 677 Mutex spin waits 0, rounds 0, OS waits 0 RW-shared spins 54, rounds 102, OS waits 48 RW-excl spins 6, rounds 24566, OS waits 16 RW-sx spins 5, rounds 41, OS waits 3 Spin rounds per wait: 0.00 mutex, 1.89 RW-shared, 4094.33 RW-excl, 8.20 RW-sx ------------ TRANSACTIONS ------------ Trx id counter 1972 Purge done for trx's n:o < 1946 undo n:o < 0 state: running History list length 103 Total number of lock structs in row lock hash table 1 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 421522187488592, not started 0 lock struct(s), heap size 1160, 0 row lock(s) ---TRANSACTION 1970, ACTIVE 691 sec committing 2 lock struct(s), heap size 1160, 2 row lock(s), undo log entries 2 ---TRANSACTION 1968, ACTIVE 700 sec mysql tables in use 1, locked 1 0 lock struct(s), heap size 1160, 0 row lock(s) MySQL thread id 6, OS thread handle 140047447013120, query id 8005 localhost root altering table ALTER TABLE t1 ADD c2 MEDIUMTEXT NULL FIRST Trx read view will not see trx with id >= 1970, sees < 1969 -------- 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 (read thread) I/O thread 5 state: waiting for completed aio requests (read thread) I/O thread 6 state: complete io for buf page (write thread) I/O thread 7 state: waiting for completed aio requests (write thread) I/O thread 8 state: waiting for completed aio requests (write thread) I/O thread 9 state: waiting for completed aio requests (write thread) Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 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 323 OS file reads, 1611 OS file writes, 714 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 Hash table size 276707, used cells 0, node heap has 0 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 2804647 Log flushed up to 2804421 Pages flushed up to 2726652 Last checkpoint at 2726652 0 pending log flushes, 0 pending chkp writes 418 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total large memory allocated 141033472 Dictionary memory allocated 884529 Buffer pool size 8192 Free buffers 7464 Database pages 728 Old database pages 54 Modified db pages 114 Pending reads 0 Pending writes: LRU 0, flush list 9, single page 0 Pages made young 0, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 233, created 495, written 851 0.00 reads/s, 0.00 creates/s, 0.00 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 728, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue 1 read views open inside InnoDB Process ID=29027, Main thread ID=140046833276672, state: enforcing dict cache limit Number of rows inserted 1491, updated 1, deleted 4, read 1477 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ InnoDB: ###### Diagnostic info printed to the standard error stream 2015-03-16T23:03:07.908287Z 0 [Warning] InnoDB: A long semaphore wait: --Thread 140046824883968 has waited at trx0purge.cc line 153 for 355.00 seconds the semaphore: Mutex at 0x7f5f3f67b7a0 created file trx0rseg.cc line 211, lock var 1 Last time reserved in file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/trx/trx0trx.cc line 1528 InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info: InnoDB: Pending preads 0, pwrites 0 ===================================== 2015-03-17 10:03:25 0x7f5f323fe700 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 20 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 3 srv_active, 0 srv_shutdown, 2 srv_idle srv_master_thread log flush and writes: 4 ---------- SEMAPHORES ---------- ------------- RW-LATCH INFO ------------- RW-LOCK: 0x25b4da0 Waiters for the lock exist Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/dict/dict0stats.cc line 2366 X-LOCK RW-LOCK: 0x7f5f3fdbb0f0 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0undo.ic line 171 S-LOCK RW-LOCK: 0x7f5f3fdbafd8 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0undo.ic line 171 X-LOCK RW-LOCK: 0x7f5f3fda4718 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9dbd8 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9cb98 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9c858 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd9c518 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd92a30 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0rseg.ic line 48 S-LOCK RW-LOCK: 0x7f5f3fd92918 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/include/trx0rseg.ic line 48 X-LOCK RW-LOCK: 0x7f5f3fd80e58 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x7f5f3fd80158 Locked: thread 140047447013120 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0flu.cc line 1107 SX-LOCK pass value 2 RW-LOCK: 0x25b4ca0 Locked: thread 140046795532032 file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/buf/buf0buf.cc line 3588 S-LOCK Total number of rw-locks 16639 OS WAIT ARRAY INFO: reservation count 800 --Thread 140046824883968 has waited at trx0purge.cc line 153 for 373.00 seconds the semaphore: Mutex at 0x7f5f3f67b7a0 created file trx0rseg.cc line 211, lock var 1 Last time reserved in file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/trx/trx0trx.cc line 1528 --Thread 140046833276672 has waited at srv0srv.cc line 1915 for 243.00 seconds the semaphore: X-lock on RW-latch at 0x25b4da0 created in file dict0dict.cc line 1038 a writer (thread id 140046795532032) has reserved it in mode exclusive number of readers 0, waiters flag 1, lock_word: 0 Last time read locked in file row0purge.cc line 811 Last time write locked in file /bzr/mysql-5.7.6-m16_dbg/storage/innobase/dict/dict0stats.cc line 2366 OS WAIT ARRAY INFO: signal count 678 Mutex spin waits 0, rounds 0, OS waits 0 RW-shared spins 54, rounds 102, OS waits 48 RW-excl spins 6, rounds 24568, OS waits 16 RW-sx spins 5, rounds 41, OS waits 3 Spin rounds per wait: 0.00 mutex, 1.89 RW-shared, 4094.67 RW-excl, 8.20 RW-sx ------------ TRANSACTIONS ------------ Trx id counter 1972 Purge done for trx's n:o < 1946 undo n:o < 0 state: running History list length 103 Total number of lock structs in row lock hash table 1 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 421522187488592, not started 0 lock struct(s), heap size 1160, 0 row lock(s) ---TRANSACTION 1970, ACTIVE 711 sec committing 2 lock struct(s), heap size 1160, 2 row lock(s), undo log entries 2 ---TRANSACTION 1968, ACTIVE 720 sec mysql tables in use 1, locked 1 0 lock struct(s), heap size 1160, 0 row lock(s) MySQL thread id 6, OS thread handle 140047447013120, query id 8005 localhost root altering table ALTER TABLE t1 ADD c2 MEDIUMTEXT NULL FIRST Trx read view will not see trx with id >= 1970, sees < 1969 -------- 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 (read thread) I/O thread 5 state: waiting for completed aio requests (read thread) I/O thread 6 state: waiting for completed aio requests (write thread) I/O thread 7 state: waiting for completed aio requests (write thread) I/O thread 8 state: waiting for completed aio requests (write thread) I/O thread 9 state: waiting for completed aio requests (write thread) Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 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 323 OS file reads, 1611 OS file writes, 714 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 Hash table size 276707, used cells 0, node heap has 0 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 2804647 Log flushed up to 2804421 Pages flushed up to 2726652 Last checkpoint at 2726652 0 pending log flushes, 0 pending chkp writes 418 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total large memory allocated 141033472 Dictionary memory allocated 884529 Buffer pool size 8192 Free buffers 7464 Database pages 728 Old database pages 54 Modified db pages 113 Pending reads 0 Pending writes: LRU 0, flush list 8, single page 0 Pages made young 0, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 233, created 495, written 852 0.00 reads/s, 0.00 creates/s, 0.05 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 728, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue 1 read views open inside InnoDB Process ID=29027, Main thread ID=140046833276672, state: enforcing dict cache limit Number of rows inserted 1491, updated 1, deleted 4, read 1477 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ InnoDB: ###### Diagnostic info printed to the standard error stream