Why MySQL sat for 2 minutes doing nothing?
- by Alex R
This was a one-time thing, not reproducible... But I saved the show innodb status output. Can anybody tell what's going on here? The simple insert took almost 3 minutes to complete.
| InnoDB | |
=====================================
110201 15:58:10 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 34 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 11963, signal count 11766
--Thread 1824 has waited at .\btr\btr0cur.c line 443 for 118.00 seconds the sema
phore:
S-lock on RW-latch at 09D6453C created in file .\buf\buf0buf.c line 550
a writer (thread id 1824) has reserved it in mode wait exclusive
number of readers 1, waiters flag 1
Last time read locked in file .\buf\buf0flu.c line 599
Last time write locked in file .\btr\btr0cur.c line 443
Mutex spin waits 0, rounds 527817, OS waits 7133
RW-shared spins 2532, OS waits 1226; RW-excl spins 1652, OS waits 1118
------------
TRANSACTIONS
------------
Trx id counter 0 95830
Purge done for trx's n:o < 0 95814 undo n:o < 0 0
History list length 11
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, OS thread id 3704
MySQL thread id 551, query id 2702112 localhost 127.0.0.1 root
show innodb status
---TRANSACTION 0 95829, not started, OS thread id 3132
MySQL thread id 534, query id 2702020 localhost 127.0.0.1 root
---TRANSACTION 0 95828, not started, OS thread id 3152
MySQL thread id 527, query id 2701973 localhost 127.0.0.1 root
---TRANSACTION 0 95827, ACTIVE 118 sec, OS thread id 1824 inserting, thread decl
ared inside InnoDB 500
mysql tables in use 1, locked 1
1 lock struct(s), heap size 320, 0 row lock(s)
MySQL thread id 526, query id 2701972 localhost 127.0.0.1 root update
INSERT INTO log_searchcriteria (userid,search_criteria,date,search_type) VALUES
( NAME_CONST('userid',NULL), NAME_CONST('search_criteria',_latin1' SELECT SQL_C
ALC_FOUND_ROWS idx_search.CTCX_LATITUDE, idx_search.CTCX_LONGITUDE, idx_search.b
uilding_id, idx_search.LN_LIST_NUMBER, idx_search.LP_LIST_PRICE, idx_search.HSN_
ADRESS_HOUSE_NUMBER, idx_search.STR_ADDRESS_STREET, idx_search.CP_ADDRESS_COMPAS
S_POINT, idx_search.UN_UNIT, idx_search.CIT_CITY, idx_search.ZP_ZIP_CODE, idx_se
arch.AR_AREA_NAME, idx_search.BR_BEDROOMS, idx_search.BTH_BATHS, idx_search.ST_S
TATUS, idx_search.CTCX_STYLE_TYPE, idx_s
--------
FILE I/O
--------
I/O thread 0 state: wait Windows aio (insert buffer thread)
I/O thread 1 state: wait Windows aio (log thread)
I/O thread 2 state: wait Windows aio (read thread)
I/O thread 3 state: wait Windows aio (write thread)
Pending normal aio reads: 0, aio writes: 1,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
151006 OS file reads, 120758 OS file writes, 6844 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 5, seg size 7,
24664 inserts, 24664 merged recs, 4612 merges
Hash table size 553253, node heap has 629 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 5 2318193115
Log flushed up to 5 2318193115
Last checkpoint at 5 2318129891
0 pending log writes, 0 pending chkp writes
3036 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 213459462; in additional pool allocated 1720192
Dictionary memory allocated 240416
Buffer pool size 8192
Free buffers 0
Database pages 7563
Modified db pages 18
Pending reads 0
Pending writes: LRU 0, flush list 18, single page 0
Pages read 150973, created 28788, written 115137
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
--------------
ROW OPERATIONS
--------------
1 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread id 2992, state: flushing buffer pool pages
Number of rows inserted 794294, updated 89203, deleted 13698, read 1453084305
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
Thanks
