[MDEV-9687] Waiting for table level lock that isn't there.... Created: 2016-03-04  Updated: 2016-04-04  Resolved: 2016-04-04

Status: Closed
Project: MariaDB Server
Component/s: Locking
Affects Version/s: 10.1.12
Fix Version/s: N/A

Type: Bug Priority: Minor
Reporter: Sander Pilon Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: need_feedback


 Description   

This might or might not be related to MDEV-9674. We ran a lot of 5M record-transactions to duplicate the crash in that issue.

The server didn't crash, but during the day our server became very slow and quite unusable. A lot of trivial queries were waiting for a table level lock, when only using the primary key of the table involved. Queries stalling for 30 seconds and then timing out. Never seen that before. And, as far as I'm concerned, no reason why a table level lock should have to be involved.

A restart of the server fixed all this. I don't know exactly what to think of this.

Below the output of SHOW ENGINE INNODB STATUS. You can see that there are a lot of "Waiting for table level lock" entries, and I can't figure out why.
All those entries update some InnoDB table using the primary key.

my.cnf settings are in MDEV-9674

=====================================
 
2016-03-04 13:59:14 7f056a901700 INNODB MONITOR OUTPUT
 
=====================================
 
Per second averages calculated from the last 5 seconds
 
-----------------
 
BACKGROUND THREAD
 
-----------------
 
srv_master_thread loops: 8277 srv_active, 0 srv_shutdown, 21 srv_idle
 
srv_master_thread log flush and writes: 8298
 
----------
 
SEMAPHORES
 
----------
 
OS WAIT ARRAY INFO: reservation count 1188926
 
OS WAIT ARRAY INFO: signal count 23114187
 
Mutex spin waits 29575445, rounds 26144519, OS waits 34856
 
RW-shared spins 14081769, rounds 52545202, OS waits 830385
 
RW-excl spins 2234662, rounds 34283440, OS waits 128962
 
Spin rounds per wait: 0.88 mutex, 3.73 RW-shared, 15.34 RW-excl
 
------------------------
 
LATEST FOREIGN KEY ERROR
 
------------------------
 
2016-03-04 12:28:27 7ef72627c700 Transaction:
 
TRANSACTION 29344937053, ACTIVE 0 sec updating or deleting
 
mysql tables in use 101, locked 101
 
10 lock struct(s), heap size 2936, 7 row lock(s), undo log entries 1
 
MySQL thread id 43879, OS thread handle 0x7ef72627c700, query id 86915581 kantoor 217.77.139.43 site
 
UPDATE Managementboek_Klanten.Bestellingen SET `RegelKostenplaatsId`='' WHERE BackorderOrigineel = '50642993'
 
Foreign key constraint fails for table `Managementboek_Klanten`.`Bestellingen`:
 
,
 
  CONSTRAINT `Bestellingen_ibfk_1` FOREIGN KEY (`RegelKostenplaatsID`) REFERENCES `KostenplaatsLijstRegels` (`KostenplaatsId`)
 
Trying to add in child table, in index `RegelKostenplaatsID` tuple:
 
DATA TUPLE: 2 fields;
 
 0: len 4; hex 80000000; asc     ;;
 
 1: len 4; hex 8305c97f; asc     ;;
 
 
 
But in parent table `Managementboek_Klanten`.`KostenplaatsLijstRegels`, in index `PRIMARY`,
 
the closest match we can find is record:
 
PHYSICAL RECORD: n_fields 7; compact format; info bits 0
 
 0: len 4; hex 80000033; asc    3;;
 
 1: len 6; hex 0006be07bec7; asc       ;;
 
 2: len 7; hex 4a0063002d0590; asc J c -  ;;
 
 3: len 4; hex 80000004; asc     ;;
 
 4: len 30; hex 323130323030202f20313330313731202d204c465320636f72706f726174; asc 210200 / 130171 - LFS corporat; (total 31 bytes);
 
 5: len 4; hex 00000000; asc     ;;
 
 6: len 1; hex 80; asc  ;;
 
 
 
------------------------
 
LATEST DETECTED DEADLOCK
 
------------------------
 
2016-03-04 13:55:16 7ef71b4f1700
 
*** (1) TRANSACTION:
 
TRANSACTION 29346772847, ACTIVE 1 sec starting index read
 
mysql tables in use 1, locked 1
 
LOCK WAIT 7 lock struct(s), heap size 1184, 4 row lock(s)
 
MySQL thread id 114955, OS thread handle 0x7ef71b878700, query id 293616804 kantoor 217.77.139.43 site updating
 
DELETE FROM OrderschermRegels WHERE Gewist=1 AND BestellingId =  NAME_CONST('_orderid',12920407)
 
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
 
RECORD LOCKS space id 12534235 page no 32 n bits 1616 index `Gewist` of table `Managementboek_Klanten`.`OrderschermRegels` trx table locks 3 total table locks 3  trx id 29346772847 lock_mode X waiting lock hold time 0 wait time before grant 0 
*** (2) TRANSACTION:
 
TRANSACTION 29346772958, ACTIVE 1 sec starting index read
 
mysql tables in use 1, locked 1
 
41 lock struct(s), heap size 6544, 24 row lock(s), undo log entries 1
 
MySQL thread id 115218, OS thread handle 0x7ef71b4f1700, query id 293616846 kantoor 217.77.139.43 site updating
 
DELETE FROM OrderschermRegels WHERE Gewist=1 AND BestellingId =  NAME_CONST('_orderid',12919603)
 
*** (2) HOLDS THE LOCK(S):
 
RECORD LOCKS space id 12534235 page no 32 n bits 1616 index `Gewist` of table `Managementboek_Klanten`.`OrderschermRegels` trx table locks 17 total table locks 3  trx id 29346772958 lock_mode X locks rec but not gap lock hold time 0 wait time before grant 0 
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
 
RECORD LOCKS space id 12534235 page no 32 n bits 1616 index `Gewist` of table `Managementboek_Klanten`.`OrderschermRegels` trx table locks 17 total table locks 3  trx id 29346772958 lock_mode X waiting lock hold time 0 wait time before grant 0 
*** WE ROLL BACK TRANSACTION (1)
 
------------
 
TRANSACTIONS
 
------------
 
Trx id counter 29346863136
 
Purge done for trx's n:o < 29346845160 undo n:o < 0 state: running but idle
 
History list length 1160
 
LIST OF TRANSACTIONS FOR EACH SESSION:
 
---TRANSACTION 29346863135, not started
 
MySQL thread id 121082, OS thread handle 0x7ef725cf1700, query id 299431724 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346861951, not started
 
mysql tables in use 138, locked 138
 
MySQL thread id 121047, OS thread handle 0x7ef71b6f5700, query id 299243329 solrhost 188.66.17.13 site Waiting for table level lock
 
INSERT INTO Managementboek_Klanten.Bestellingen SET Bestellingid = '12844866', Aantal = 1, Omschrijving = '1163910vkuu', Ean = 'BONG', Prijs = 0
 
---TRANSACTION 29346861690, not started
 
MySQL thread id 121042, OS thread handle 0x7ef707a34700, query id 299188733 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346858999, not started
 
mysql tables in use 157, locked 157
 
MySQL thread id 120837, OS thread handle 0x7ef709264700, query id 299072547 solrhost 188.66.17.13 site Waiting for table level lock
 
UPDATE Managementboek_Klanten.BestellingAll SET ProspectId = '967054179' WHERE BestellingId = '12920420'
 
---TRANSACTION 29346856346, not started
 
mysql tables in use 157, locked 44
 
MySQL thread id 120563, OS thread handle 0x7ef70956a700, query id 298948867 solrhost 188.66.17.13 site Waiting for table level lock
 
UPDATE Managementboek_Klanten.BestellingAll SET IdealOpen = 0 WHERE BestellingId = '12920358'
 
---TRANSACTION 29346855195, not started
 
mysql tables in use 157, locked 44
 
MySQL thread id 120520, OS thread handle 0x7ef7de4ef700, query id 298755849 solrhost 188.66.17.13 site Waiting for table level lock
 
/* save_order 12920420*/ UPDATE Managementboek_Klanten.BestellingAll  SET
 
        SiteBestelling   = 1,
 
        Siteid           = '1005',
 
        Affiliateid      = '0',
 
        Klantid          = '2747250',
 
        Achternaam       = 'Heithuis',
 
        Bedrijfsnaam     = '',
 
        BetalingsTermijn = '14',
 
        IP               = '77.167.57.164',
 
        IsOmzet          = 1,
 
        ReferrerDomain   = NULL,
 
        DT               = now(),
 
        SessionId        = '60758219' /* save_order */ WHERE Bestellingid = '12920420'
 
---TRANSACTION 29346854388, not started
 
mysql tables in use 157, locked 157
 
MySQL thread id 120510, OS thread handle 0x7ef7076ad700, query id 298725677 solrhost 188.66.17.13 site Waiting for table level lock
 
UPDATE Managementboek_Klanten.BestellingAll
 
            SET Betaalmethode = 'D'
 
            WHERE BestellingId = '12844866'
 
---TRANSACTION 29346853398, not started
 
MySQL thread id 120457, OS thread handle 0x7ef71bbff700, query id 298554954 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346862937, not started
 
MySQL thread id 120458, OS thread handle 0x7ef7083c7700, query id 299372928 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346852275, not started
 
MySQL thread id 120416, OS thread handle 0x7ef7260f9700, query id 298419718 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346862357, not started
 
MySQL thread id 120417, OS thread handle 0x7f055d97b700, query id 299349987 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346850929, not started
 
MySQL thread id 120368, OS thread handle 0x7ef703ebe700, query id 298236107 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346862682, not started
 
MySQL thread id 120293, OS thread handle 0x7ef725e74700, query id 299363194 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346844355, not started
 
MySQL thread id 120165, OS thread handle 0x7ef709cf9700, query id 297399072 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346843292, not started
 
MySQL thread id 120135, OS thread handle 0x7ef725ef5700, query id 297291991 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 0, not started
 
MySQL thread id 120126, OS thread handle 0x7ef7082c5700, query id 299408060 localhost percona cleaning up
 
---TRANSACTION 29346863067, not started
 
MySQL thread id 118619, OS thread handle 0x7ef707cb9700, query id 299420613 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346844435, not started
 
MySQL thread id 117766, OS thread handle 0x7ef706a95700, query id 297409425 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346750811, not started
 
MySQL thread id 116680, OS thread handle 0x7ef7749fb700, query id 291522499 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346863111, not started
 
MySQL thread id 115634, OS thread handle 0x7f056857a700, query id 299427616 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346732482, not started
 
MySQL thread id 115633, OS thread handle 0x7ef7074a9700, query id 289282218 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346728483, not started
 
MySQL thread id 115336, OS thread handle 0x7ef725ff7700, query id 289087065 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346844610, not started
 
MySQL thread id 115218, OS thread handle 0x7ef71b4f1700, query id 297459320 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346767003, not started
 
MySQL thread id 115192, OS thread handle 0x7ef7261fb700, query id 293202170 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346863066, not started
 
MySQL thread id 115157, OS thread handle 0x7ef742fff700, query id 299420211 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346722477, not started
 
MySQL thread id 115156, OS thread handle 0x7ef795d46700, query id 288358897 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346863007, not started
 
MySQL thread id 115108, OS thread handle 0x7ef7874f9700, query id 299387417 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346842211, not started
 
MySQL thread id 115093, OS thread handle 0x7ef774afd700, query id 297224284 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346850952, not started
 
MySQL thread id 115086, OS thread handle 0x7ef706d9b700, query id 298237688 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346716876, not started
 
MySQL thread id 115020, OS thread handle 0x7ef7aa4f8700, query id 287659408 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346707368, not started
 
MySQL thread id 114484, OS thread handle 0x7ef7098f1700, query id 286848864 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346702366, not started
 
MySQL thread id 114376, OS thread handle 0x7ef795f4a700, query id 286293484 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346700038, not started
 
MySQL thread id 114312, OS thread handle 0x7ef742f7e700, query id 285942302 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346695580, not started
 
MySQL thread id 114215, OS thread handle 0x7ef708ad5700, query id 285447255 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346863133, not started
 
MySQL thread id 102487, OS thread handle 0x7ef708448700, query id 299429555 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346862995, not started
 
MySQL thread id 102286, OS thread handle 0x7ef709dfb700, query id 299385839 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 0, not started
 
MySQL thread id 99016, OS thread handle 0x7f056cbf7700, query id 299429514 localhost percona cleaning up
 
---TRANSACTION 29346863039, not started
 
MySQL thread id 96733, OS thread handle 0x7ef705cfa700, query id 299410296 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 29346863044, not started
 
MySQL thread id 95145, OS thread handle 0x7ef795cc5700, query id 299410453 kantoor 217.77.139.43 site cleaning up
 
---TRANSACTION 0, not started
 
MySQL thread id 74053, OS thread handle 0x7ef70752a700, query id 299250834 localhost percona cleaning up
 
---TRANSACTION 0, not started
 
MySQL thread id 64205, OS thread handle 0x7ef769ef5700, query id 297258228 kantoor 217.77.139.43 sander cleaning up
 
---TRANSACTION 29346842105, not started
 
MySQL thread id 1987, OS thread handle 0x7f056a901700, query id 299431885 kantoor 217.77.139.43 sander init
 
SHOW ENGINE INNODB STATUS
 
---TRANSACTION 29345120183, not started
 
MySQL thread id 28429, OS thread handle 0x7ef76a27c700, query id 145452710 kantoor 217.77.139.43 sander cleaning up
 
---TRANSACTION 29346496292, not started
 
MySQL thread id 28080, OS thread handle 0x7ef76a078700, query id 262888562 localhost 127.0.0.1 site cleaning up
 
---TRANSACTION 29346767011, not started
 
MySQL thread id 1841, OS thread handle 0x7ef7967f4700, query id 293202183 localhost 127.0.0.1 site cleaning up
 
---TRANSACTION 29346767811, not started
 
MySQL thread id 1840, OS thread handle 0x7ef796352700, query id 293222354 localhost 127.0.0.1 site cleaning up
 
---TRANSACTION 29346863071, not started
 
MySQL thread id 586, OS thread handle 0x7f056a880700, query id 299422232 localhost 127.0.0.1 site cleaning up
 
---TRANSACTION 29346841045, not started
 
MySQL thread id 405, OS thread handle 0x7f05685fb700, query id 298237635 localhost 127.0.0.1 site cleaning up
 
---TRANSACTION 29346844421, not started
 
MySQL thread id 404, OS thread handle 0x7f056994c700, query id 297405774 localhost 127.0.0.1 site cleaning up
 
---TRANSACTION 29343842307, not started
 
MySQL thread id 1, OS thread handle 0x7f056dd01700, query id 0 Waiting for background binlog tasks
 
---TRANSACTION 29346863134, ACTIVE 0 sec starting index read
 
mysql tables in use 14, locked 0
 
MySQL thread id 120369, OS thread handle 0x7ef72637e700, query id 299431421 kantoor 217.77.139.43 site
 
/* tellingen */ SELECT
 
                Managementboek_Klanten.order_volgnummer( R.BestellingID ) as order_volgnummer,
 
                Betaalmethode,
 
                R.`Bakje`,
 
                R.MagONE,
 
                B.`Gebruiker`,
 
                N.Id, R.BestellingId, B.OrigineelBestellingId, B.DT, B.Klantid, K.`Achternaam`,BA.FactuurBedrijfsnaam,
 
                BA.FactuurLand,
 
                FactuurAchternaam,
 
                N.ispromo,
 
                R.Ean,
 
                R.`Aantal`, R.`Geleverd`,
 
                R.`Leverbaar`,
 
                R.`DeelLeverbaar`,
 
                R.`CBLeverbaar`,
 
                N.`Auteurnaam`, N.`Omschrijving`,
 
                R.`BoekStatus`,
 
                ACC.`Geaccepteerd`,
 
                R.`CB24Leverbaar`,
 
                R.`FysiekeVoorraad`,
 
                R.GeprinteVoorraad,
 
                
Trx read view will not see trx with id >= 29346863135, sees < 29346844914
 
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
 
---TRANSACTION 29346862153, ACTIVE 4 sec
 
mysql tables in use 33, locked 33
 
4 lock struct(s), heap size 1184, 5 row lock(s), undo log entries 2
 
MySQL thread id 121054, OS thread handle 0x7ef708346700, query id 299282240 kantoor 217.77.139.43 site Waiting for table level lock
 
REPLACE INTO OrderschermRegels ( Id, BestellingId, OrigineelBestellingId, DT, Ean, BoekStatus, Aantal, Geleverd, FysiekeVoorraad, GeprinteVoorraad, NogNietGeprint, Bron, VerstuurCompleteOrder, CBLeverbaar, FeedLeverbaar, Bindwijze_voorraadartikel, Bindwijze_Evenement, Gereserveerd, NietReserveren, Magazijn, MagONE, AantalOnderweg, OnderwegSinds, PromoBoek, PromoReden, DTVerwacht, bakje_proto_magazijn, bakje_vink_open, Gewist, Adres_Geaccepteerd, Risico_Geaccepteerd )
 
    SELECT 
        Id, N.BestellingId, OrigineelBestellingId, A.DT, N.Ean, COALESCE( B.Boekstatus, C.Boekstatus, F.Boekstatus, IF( E.`Co
 
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
 
 
 
---TRANSACTION 29346854391, ACTIVE 19 sec starting index read
 
mysql tables in use 157, locked 44
 
LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)
 
MySQL thread id 120174, OS thread handle 0x7ef74a0f9700, query id 298723800 kantoor 217.77.139.43 site updating
 
UPDATE Managementboek_Klanten.BestellingAll SET BatchId = -999 WHERE BestellingId = '12920419'
 
Trx #rec lock waits 3 #table lock waits 0
 
Trx total rec lock wait time 0 SEC
 
Trx total table lock wait time 0 SEC
 
------- TRX HAS BEEN WAITING 19 SEC FOR THIS LOCK TO BE GRANTED:
 
RECORD LOCKS space id 13224952 page no 88711 n bits 136 index `PRIMARY` of table `Managementboek_Klanten`.`BestellingAll` trx table locks 1 total table locks 2  
trx id 29346854391 lock_mode X locks rec but not gap waiting lock hold time 19 wait time before grant 0 
 
 
 
 
------------------
 
---TRANSACTION 29346850949, ACTIVE 35 sec
 
2 lock struct(s), heap size 360, 1 row lock(s)
 
MySQL thread id 114956, OS thread handle 0x7ef78777e700, query id 298888368 kantoor 217.77.139.43 site cleaning up
 
Trx read view will not see trx with id >= 29346855871, sees < 29346844914
 
Trx #rec lock waits 9 #table lock waits 0
 
Trx total rec lock wait time 2 SEC
 
Trx total table lock wait time 0 SEC
 
---TRANSACTION 29346844914, ACTIVE 61 sec
 
52 lock struct(s), heap size 6544, 43 row lock(s), undo log entries 5
 
MySQL thread id 114955, OS thread handle 0x7ef71b878700, query id 298195931 kantoor 217.77.139.43 site cleaning up
 
Trx read view will not see trx with id >= 29346844917, sees < 29346842189
 
Trx #rec lock waits 8 #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 (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
 
1143426 OS file reads, 1538519 OS file writes, 97874 OS fsyncs
 
2.40 reads/s, 11605 avg bytes/read, 1.20 writes/s, 1.20 fsyncs/s
 
-------------------------------------
 
INSERT BUFFER AND ADAPTIVE HASH INDEX
 
-------------------------------------
 
Ibuf: size 1, free list len 16659, seg size 16661, 30848 merges
 
merged operations:
 
 insert 46660, delete mark 264795, delete 558
 
discarded operations:
 
 insert 0, delete mark 0, delete 0
 
192142.97 hash searches/s, 51595.08 non-hash searches/s
 
---
 
LOG
 
---
 
Log sequence number 59705600957523
 
Log flushed up to   59705600953500
 
Pages flushed up to 59705575361381
 
Last checkpoint at  59705575361381
 
Max checkpoint age    1738750649
 
Checkpoint age target 1684414692
 
Modified age          25596142
 
Checkpoint age        25596142
 
0 pending log writes, 0 pending chkp writes
 
17890 log i/o's done, 1.20 log i/o's/second
 
----------------------
 
BUFFER POOL AND MEMORY
 
----------------------
 
Total memory allocated 55364812800; in additional pool allocated 0
 
Total memory allocated by read views 9672
 
Internal hash tables (constant factor + variable factor)
 
    Adaptive hash index 3321896224  (849988792 + 2471907432)
 
    Page hash           5313416 (buffer pool 0 only)
 
    Dictionary cache    226199046   (212498672 + 13700374)
 
    File system         1749744     (812272 + 937472)
 
    Lock system         147864640   (147837832 + 26808)
 
    Recovery system     0   (0 + 0)
 
Dictionary memory allocated 13700374
 
Buffer pool size        3276790
 
Buffer pool size, bytes 53686927360
 
Free buffers            1481517
 
Database pages          1367935
 
Old database pages      505074
 
Modified db pages       6288
 
Percent of dirty pages(LRU & free pages): 0.221
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 123290, not young 176496
 
1.20 youngs/s, 0.00 non-youngs/s
 
Pages read 1135912, created 232109, written 1494365
 
2.40 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: 1367935, unzip_LRU len: 555640
 
I/O sum[4080]:cur[70], unzip sum[590]:cur[30]
 
----------------------
 
INDIVIDUAL BUFFER POOL INFO
 
----------------------
 
---BUFFER POOL 0
 
Buffer pool size        327679
 
Buffer pool size, bytes 5368692736
 
Free buffers            146810
 
Database pages          138165
 
Old database pages      51021
 
Modified db pages       587
 
Percent of dirty pages(LRU & free pages): 0.206
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 8915, not young 0
 
0.00 youngs/s, 0.00 non-youngs/s
 
Pages read 114364, created 23801, written 150939
 
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: 138165, unzip_LRU len: 55413
 
I/O sum[408]:cur[7], unzip sum[59]:cur[3]
 
---BUFFER POOL 1
 
Buffer pool size        327679
 
Buffer pool size, bytes 5368692736
 
Free buffers            149625
 
Database pages          135269
 
Old database pages      49953
 
Modified db pages       454
 
Percent of dirty pages(LRU & free pages): 0.159
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 9131, not young 0
 
0.00 youngs/s, 0.00 non-youngs/s
 
Pages read 112792, created 22477, written 145163
 
0.80 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: 135269, unzip_LRU len: 55689
 
I/O sum[408]:cur[7], unzip sum[59]:cur[3]
 
---BUFFER POOL 2
 
Buffer pool size        327679
 
Buffer pool size, bytes 5368692736
 
Free buffers            148051
 
Database pages          137278
 
Old database pages      50694
 
Modified db pages       694
 
Percent of dirty pages(LRU & free pages): 0.243
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 8713, not young 0
 
0.00 youngs/s, 0.00 non-youngs/s
 
Pages read 112864, created 24414, written 152591
 
0.20 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: 137278, unzip_LRU len: 54845
 
I/O sum[408]:cur[7], unzip sum[59]:cur[3]
 
---BUFFER POOL 3
 
Buffer pool size        327679
 
Buffer pool size, bytes 5368692736
 
Free buffers            147620
 
Database pages          136698
 
Old database pages      50480
 
Modified db pages       686
 
Percent of dirty pages(LRU & free pages): 0.241
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 8882, not young 0
 
0.00 youngs/s, 0.00 non-youngs/s
 
Pages read 114234, created 22464, written 149552
 
0.40 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: 136698, unzip_LRU len: 56614
 
I/O sum[408]:cur[7], unzip sum[59]:cur[3]
 
---BUFFER POOL 4
 
Buffer pool size        327679
 
Buffer pool size, bytes 5368692736
 
Free buffers            147850
 
Database pages          137603
 
Old database pages      50814
 
Modified db pages       675
 
Percent of dirty pages(LRU & free pages): 0.236
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 9608, not young 0
 
0.20 youngs/s, 0.00 non-youngs/s
 
Pages read 113876, created 23727, written 151372
 
0.20 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: 137603, unzip_LRU len: 54629
 
I/O sum[408]:cur[7], unzip sum[59]:cur[3]
 
---BUFFER POOL 5
 
Buffer pool size        327679
 
Buffer pool size, bytes 5368692736
 
Free buffers            146992
 
Database pages          137517
 
Old database pages      50783
 
Modified db pages       623
 
Percent of dirty pages(LRU & free pages): 0.219
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 9724, not young 0
 
0.00 youngs/s, 0.00 non-youngs/s
 
Pages read 115117, created 22400, written 152281
 
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: 137517, unzip_LRU len: 56535
 
I/O sum[408]:cur[7], unzip sum[59]:cur[3]
 
---BUFFER POOL 6
 
Buffer pool size        327679
 
Buffer pool size, bytes 5368692736
 
Free buffers            148241
 
Database pages          136777
 
Old database pages      50503
 
Modified db pages       884
 
Percent of dirty pages(LRU & free pages): 0.310
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 8680, not young 0
 
0.00 youngs/s, 0.00 non-youngs/s
 
Pages read 112521, created 24256, written 150597
 
0.40 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: 136777, unzip_LRU len: 55476
 
I/O sum[408]:cur[7], unzip sum[59]:cur[3]
 
---BUFFER POOL 7
 
Buffer pool size        327679
 
Buffer pool size, bytes 5368692736
 
Free buffers            149170
 
Database pages          135790
 
Old database pages      50145
 
Modified db pages       481
 
Percent of dirty pages(LRU & free pages): 0.169
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 8941, not young 0
 
0.00 youngs/s, 0.00 non-youngs/s
 
Pages read 113369, created 22421, written 146552
 
0.40 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: 135790, unzip_LRU len: 55500
 
I/O sum[408]:cur[7], unzip sum[59]:cur[3]
 
---BUFFER POOL 8
 
Buffer pool size        327679
 
Buffer pool size, bytes 5368692736
 
Free buffers            146947
 
Database pages          137678
 
Old database pages      50802
 
Modified db pages       742
 
Percent of dirty pages(LRU & free pages): 0.261
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 25510, not young 103899
 
0.60 youngs/s, 0.00 non-youngs/s
 
Pages read 114064, created 23662, written 153815
 
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: 137678, unzip_LRU len: 56211
 
I/O sum[408]:cur[7], unzip sum[59]:cur[3]
 
---BUFFER POOL 9
 
Buffer pool size        327679
 
Buffer pool size, bytes 5368692736
 
Free buffers            150211
 
Database pages          135160
 
Old database pages      49879
 
Modified db pages       462
 
Percent of dirty pages(LRU & free pages): 0.162
 
Max dirty pages percent: 75.000
 
Pending reads 0
 
Pending writes: LRU 0, flush list 0, single page 0
 
Pages made young 25186, not young 72597
 
0.40 youngs/s, 0.00 non-youngs/s
 
Pages read 112711, created 22487, written 141503
 
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: 135160, unzip_LRU len: 54728
 
I/O sum[408]:cur[7], unzip sum[59]:cur[3]
 
--------------
 
ROW OPERATIONS
 
--------------
 
0 queries inside InnoDB, 0 queries in queue
 
3 read views open inside InnoDB
 
5 RW transactions active inside InnoDB
 
0 RO transactions active inside InnoDB
 
5 out of 1000 descriptors used
 
---OLDEST VIEW---
 
Normal read view
 
Read view low limit trx n:o 29346844917
 
Read view up limit trx id 29346842189
 
Read view low limit trx id 29346844917
 
Read view individually stored trx ids:
 
Read view trx id 29346842189
 
Read view trx id 29346842206
 
Read view trx id 29346844916
 
-----------------
 
Main thread process no. 24302, id 139601914087168, state: sleeping
 
Number of rows inserted 13809807, updated 1102353, deleted 12538841, read 8038794606
 
3.00 inserts/s, 1.80 updates/s, 0.00 deletes/s, 338656.27 reads/s
 
Number of system rows inserted 0, updated 0, deleted 0, read 1
 
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
 
----------------------------
 
END OF INNODB MONITOR OUTPUT
 
============================



 Comments   
Comment by Elena Stepanova [ 2016-03-07 ]

For slowness upon commit which you mentioned earlier, my main suspect was binary logging – your REPLACE does produce a huge binary log event which might take a long time to be written. But if you are concerned with table locks, I suggest to install plugin metadata_lock_info and check what is shows when it happens:

INSTALL SONAME 'metadata_lock_info';
 
SELECT * FROM information_schema.metadata_lock_info;

Comment by Elena Stepanova [ 2016-04-04 ]

Please comment to re-open if you have more information on the issue.

Generated at Thu Feb 08 07:36:33 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.