All of a sudden this morning I have a load spike on my server hitting up to 10. Which is unusual as it used to be below 1.
Below is what I figure, in innodb engine status. Any thoughts if anything looks bad in this?
mysql> show engine innodb status \G
*************************** 1. row ***************************
Status:
=====================================
121117 16:04:24 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 53 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 830893788, signal count 532132777
--Thread 1175492928 has waited at btr0sea.c line 773 for 0.00 seconds the semaphore:
S-lock on RW-latch at 0x2aaaeb1a50b8 created in file btr0sea.c line 139
number of readers 4, waiters flag 0
Last time read locked in file btr0sea.c line 773
Last time write locked in file btr0sea.c line 516
--Thread 1298495808 has waited at btr0sea.c line 773 for 0.00 seconds the semaphore:
S-lock on RW-latch at 0x2aaaeb1a50b8 created in file btr0sea.c line 139
a writer (thread id 1182681408) has reserved it in mode wait exclusive
number of readers 0, waiters flag 0
Last time read locked in file btr0sea.c line 773
Last time write locked in file btr0sea.c line 1267
Mutex spin waits 0, rounds 203550824060, OS waits 473478907
RW-shared spins 349053415, OS waits 78380817; RW-excl spins 514677483, OS waits 20821824
------------------------
LATEST DETECTED DEADLOCK
------------------------
121116 21:26:58
*** (1) TRANSACTION:
TRANSACTION 0 1780664112, ACTIVE 0 sec, process no 4145, OS thread id
1226877248 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1216, undo log entries 1
MySQL thread id 58254357, query id 564520818 108.68.9.18 crystalduuser Updating
UPDATE subscriptionhistory set `status` = 'processing' WHERE idhistory = 4846881
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 15492964 n bits 240 index `PRIMARY` of table `crystal_du_sm/subscriptionhistory` trx id 0 1780664112 lock_mode X locks rec but not gap waiting
Record lock, heap no 170 PHYSICAL RECORD: n_fields 18; compact format; info bits 0
0: len 8; hex 800000000049f521; asc I !;; 1: len 6; hex 00006a22c72e; asc j" .;; 2: len 7; hex 0000cac03e20f7; asc > ;; 3: len 8; hex 800000000001138e; asc ;; 4: len 4; hex 508a7246; asc P rF;; 5: len 4; hex 5093adb6; asc P ;; 6: len 4; hex 00004040; asc @@;; 7: len 8; hex 8000000000002760; asc '`;; 8: len 4; hex 508a7246; asc P rF;; 9: len 4; hex 5093acc6; asc P ;; 10: len 6; hex 616374697665; asc active;; 11: len 1; hex 02; asc ;; 12: len 4; hex 80000003; asc ;; 13: len 1; hex 01; asc ;; 14: len 1; hex 80; asc ;; 15: len 9; hex 73757370656e646564; asc suspended;; 16: len 1; hex 02; asc ;; 17: len 8; hex 8000000000000001; asc ;;
*** (2) TRANSACTION:
TRANSACTION 0 1780664110, ACTIVE 0 sec, process no 4145, OS thread id 1078765888 fetching rows, thread declared inside InnoDB 481
mysql tables in use 2, locked 2
9 lock struct(s), heap size 1216, undo log entries 1
MySQL thread id 58254375, query id 564520798 108.68.9.18 crystalduuser Sending data
UPDATE subscriptionhistory AS sh, renewalqueue AS rq SET sh.status='active' ,rq.status='failure'
WHERE sh.idhistory = rq.idhistory AND sh.status='processing' AND sh.idhistory=4846881
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 15492964 n bits 240 index `PRIMARY` of table `crystal_du_sm/subscriptionhistory` trx id 0 1780664110 lock_mode X locks rec but not gap
Record lock, heap no 170 PHYSICAL RECORD: n_fields 18; compact format; info bits 0
0: len 8; hex 800000000049f521; asc I !;; 1: len 6; hex 00006a22c72e; asc j" .;; 2: len 7; hex 0000cac03e20f7; asc > ;; 3: len 8; hex 800000000001138e; asc ;; 4: len 4; hex 508a7246; asc P rF;; 5: len 4; hex 5093adb6; asc P ;; 6: len 4; hex 00004040; asc @@;; 7: len 8; hex 8000000000002760; asc '`;; 8: len 4; hex 508a7246; asc P rF;; 9: len 4; hex 5093acc6; asc P ;; 10: len 6; hex 616374697665; asc active;; 11: len 1; hex 02; asc ;; 12: len 4; hex 80000003; asc ;; 13: len 1; hex 01; asc ;; 14: len 1; hex 80; asc ;; 15: len 9; hex 73757370656e646564; asc suspended;; 16: len 1; hex 02; asc ;; 17: len 8; hex 8000000000000001; asc ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 14456565 n bits 360 index
`idx_rq_history_transid` of table `crystal_du_sm/renewalqueue` trx id 0 1780664110 lock_mode X waiting
Record lock, heap no 59 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
0: len 8; hex 800000000049f521; asc
I !;; 1: len 30; hex
396464303766616434373135656136323836363439656433393337643365; asc
9dd07fad4715ea6286649ed3937d3e;...(truncated); 2: len 8; hex 000000000118a3cc; asc;;
*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 0 1787041889
Purge done for trx's n:o < 0 1779729277 undo n:o < 0 1
History list length 1749083
Total number of lock structs in row lock hash table 35
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
21710781 OS file reads, 336513222 OS file writes, 5594248 OS fsyncs
17.36 reads/s, 16651 avg bytes/read, 167.36 writes/s, 1.75 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 40175, free list len 23224, seg size 63400,
47274274 inserts, 41207331 merged recs, 10248524 merges
Hash table size 25499819, used cells 12836683, node heap has 26321 buffer(s)
522407.60 hash searches/s, 109824.10 non-hash searches/s
---
LOG
---
Log sequence number 240 1520989635
Log flushed up to 240 1520967362
Last checkpoint at 239 2777566435
0 pending log writes, 0 pending chkp writes
316135640 log i/o's done, 158.13 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 14330057522; in additional pool allocated 16029184
Buffer pool size 786432
Free buffers 0
Database pages 760111
Modified db pages 451626
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 32028848, created 7809334, written 41821350
18.04 reads/s, 2.62 creates/s, 18.58 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
10 queries inside InnoDB, 0 queries in queue
17 read views open inside InnoDB
Main thread process no. 4145, id 1165642048, state: sleeping
Number of rows inserted 241838205, updated 75023424, deleted 40, read 183252813758
49.96 inserts/s, 37.34 updates/s, 0.00 deletes/s, 1461310.64 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
1 row in set (0.06 sec)
MONyog latest version has Real-Time tab It tells you what’s happening on your MySQL server RIGHT NOW. It details key metrics like top 200 queries, slow queries, locked queries, locking queries, tables, databases, users, hosts and thread states, all of this in real-time as it happens. Information is retrieved from the server every one second. And the best part is that you can get started with real-time with just a click of a button without the overhead of enabling logs.
