1

我有一个在 mysql 5.6 上运行的 Rails 应用程序。每天 1-2 次应用程序挂起并重新启动服务器使事情恢复运行。

在我的日志中,看起来我得到了 LOCK WAIT TIMEOUTS,问题看起来像是在 MySQL 中,在 SHOW ENGINE INNODB STATUS\G 中,这通常是我们看到的:

---TRANSACTION 13339315173, ACTIVE 1339 sec
17 lock struct(s), heap size 3112, 28 row lock(s), undo log entries 236
MySQL thread id 28, OS thread handle 0x1a68, query id 37763097 localhost 127.0.0
.1 root cleaning up
Trx read view will not see trx with id >= 13339315174, sees < 13339315174

所有其他挂起的查询在状态输出中都有查询字符串,但我认为导致挂起的这个过程只显示此信息。

如果我稍等片刻并再次运行状态,我会看到相同类型的事务有一些细微差别

---TRANSACTION 13339315173, ACTIVE 1572 sec
17 lock struct(s), heap size 3112, 28 row lock(s), undo log entries 265
MySQL thread id 28, OS thread handle 0x1a68, query id 38154939 localhost 127.0.0
.1 root cleaning up
Trx read view will not see trx with id >= 13339315174, sees < 13339315174
--------

我对 MySQL 不是很有经验,但我从这个输出推断事务 13339315173 正在阻止一切。任何人都可以阐明可能发生的事情吗?

我的 Rails 应用程序不使用事务块,而且数据库本身相当小 - 不到 200 mb。

从一些分析工具来看,我每秒大约有 2,000 次读取和 30 次写入/秒,平均有 40-50 个连接。

完整显示 innodb 状态如下:

mysql> show engine innodb status \G
    *************************** 1. row ***************************
      Type: InnoDB
      Name:
    Status:
    =====================================
    2013-10-15 06:09:53 478 INNODB MONITOR OUTPUT
    =====================================
    Per second averages calculated from the last 50 seconds
    -----------------
    BACKGROUND THREAD
    -----------------
    srv_master_thread loops: 26859 srv_active, 0 srv_shutdown, 588 srv_idle
    srv_master_thread log flush and writes: 27447
    ----------
    SEMAPHORES
    ----------
    OS WAIT ARRAY INFO: reservation count 13486
    OS WAIT ARRAY INFO: signal count 300223
    Mutex spin waits 546801, rounds 492861, OS waits 10564
    RW-shared spins 84659, rounds 148173, OS waits 2071
    RW-excl spins 4010, rounds 320222, OS waits 663
    Spin rounds per wait: 0.90 mutex, 1.75 RW-shared, 79.86 RW-excl
    ------------
    TRANSACTIONS
    ------------
    Trx id counter 13342016110
    Purge done for trx's n:o < 13339316411 undo n:o < 0 state: running but idle
    History list length 16262
    LIST OF TRANSACTIONS FOR EACH SESSION:
    ---TRANSACTION 0, not started
    MySQL thread id 71, OS thread handle 0x478, query id 38154940 localhost ::1 root
     init
    show engine innodb status
    ---TRANSACTION 13341449747, not started
    MySQL thread id 68, OS thread handle 0x16d4, query id 38052625 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13341994684, not started
    MySQL thread id 67, OS thread handle 0x870, query id 38131995 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13337736707, not started
    MySQL thread id 66, OS thread handle 0x52c, query id 33240858 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13341868667, not started
    MySQL thread id 63, OS thread handle 0x1f50, query id 37985312 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13342003108, not started
    MySQL thread id 62, OS thread handle 0xd64, query id 38140995 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13342015950, not started
    MySQL thread id 60, OS thread handle 0x104c, query id 38154776 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13342016109, not started
    MySQL thread id 59, OS thread handle 0x2338, query id 38154937 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13342015945, not started
    MySQL thread id 58, OS thread handle 0x13f0, query id 38154767 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13342015905, not started
    MySQL thread id 57, OS thread handle 0x1758, query id 38154727 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13341953997, not started
    MySQL thread id 56, OS thread handle 0x1e24, query id 38088539 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13341746417, not started
    MySQL thread id 43, OS thread handle 0xfd8, query id 37843480 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13311372513, not started
    MySQL thread id 44, OS thread handle 0x9d0, query id 3625660 localhost 127.0.0.1
     root cleaning up
    ---TRANSACTION 13341970398, not started
    MySQL thread id 32, OS thread handle 0x1980, query id 38106072 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13311367975, not started
    MySQL thread id 47, OS thread handle 0x2218, query id 3620225 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13311372514, not started
    MySQL thread id 45, OS thread handle 0x1c40, query id 3625666 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13342002623, not started
    MySQL thread id 31, OS thread handle 0x192c, query id 38140455 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13311367962, not started
    MySQL thread id 55, OS thread handle 0x1974, query id 3620144 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13311367957, not started
    MySQL thread id 54, OS thread handle 0x1aa4, query id 3620139 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13311367952, not started
    MySQL thread id 52, OS thread handle 0x2200, query id 3620116 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13311367948, not started
    MySQL thread id 51, OS thread handle 0x101c, query id 3620106 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13311367998, not started
    MySQL thread id 49, OS thread handle 0x23b4, query id 3620296 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13311367946, not started
    MySQL thread id 48, OS thread handle 0xbf8, query id 3620098 localhost 127.0.0.1
     root cleaning up
    ---TRANSACTION 13311372515, not started
    MySQL thread id 46, OS thread handle 0x2134, query id 3625651 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13341963034, not started
    MySQL thread id 42, OS thread handle 0x1730, query id 38098217 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13341962985, not started
    MySQL thread id 41, OS thread handle 0x2350, query id 38098156 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13342004558, not started
    MySQL thread id 30, OS thread handle 0x1f0c, query id 38142582 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13342014064, not started
    MySQL thread id 29, OS thread handle 0x1208, query id 38152727 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13342010470, not started
    MySQL thread id 26, OS thread handle 0xab4, query id 38148942 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13311363353, not started
    MySQL thread id 25, OS thread handle 0x1a38, query id 3614908 localhost 127.0.0.
    1 root cleaning up
    ---TRANSACTION 13342015247, not started
    MySQL thread id 24, OS thread handle 0x11ac, query id 38154020 localhost 127.0.0
    .1 root cleaning up
    ---TRANSACTION 13341673205, ACTIVE 235 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 39, OS thread handle 0x17b8, query id 37762645 localhost 127.0.0
    .1 root updating
    UPDATE `stafftrack_logins` SET `end_time` = '2013-10-15 06:05:58', `updated_at`
    = '2013-10-15 06:05:58' WHERE `id` = 140428
    ------- TRX HAS BEEN WAITING 235 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 245 page no 1355 n bits 216 index `PRIMARY` of table `rail
    pro_development`.`stafftrack_logins` trx id 13341673205 lock_mode X locks rec bu
    t not gap waiting
    Record lock, heap no 136 PHYSICAL RECORD: n_fields 12; compact format; info bits
     0
     0: len 4; hex 8002248c; asc   $ ;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c2877; asc b    (w;;
     3: len 4; hex 80000011; asc     ;;
     4: len 4; hex 80000143; asc    C;;
     5: len 5; hex 9990de3e64; asc    >d;;
     6: len 5; hex 9990de6115; asc    a ;;
     7: len 1; hex 80; asc  ;;
     8: len 5; hex 9990de3e64; asc    >d;;
     9: len 5; hex 9990de6115; asc    a ;;
     10: SQL NULL;
     11: SQL NULL;

    ------------------
    ---TRANSACTION 13341672862, ACTIVE 235 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 40, OS thread handle 0x20a8, query id 37762284 localhost 127.0.0
    .1 root updating
    UPDATE `rails` SET `stopped` = 1, `updated_at` = '2013-10-15 06:05:58' WHERE `id
    ` = 158
    ------- TRX HAS BEEN WAITING 235 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 225 page no 5 n bits 200 index `PRIMARY` of table `railpro
    _development`.`rails` trx id 13341672862 lock_mode X locks rec but not gap waiti
    ng
    Record lock, heap no 95 PHYSICAL RECORD: n_fields 38; compact format; info bits
    0
     0: len 4; hex 8000009e; asc     ;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c22f6; asc b    " ;;
     3: len 4; hex 8000009e; asc     ;;
     4: len 15; hex 436c65616e20507265205374672038; asc Clean Pre Stg 8;;
     5: len 1; hex 81; asc  ;;
     6: len 4; hex 80000005; asc     ;;
     7: len 4; hex 80000002; asc     ;;
     8: len 5; hex 998a973df8; asc    = ;;
     9: len 5; hex 9990de5b72; asc    [r;;
     10: len 4; hex 800224d9; asc   $ ;;
     11: len 4; hex 80000002; asc     ;;
     12: len 4; hex 8000005a; asc    Z;;
     13: len 1; hex 80; asc  ;;
     14: SQL NULL;
     15: SQL NULL;
     16: SQL NULL;
     17: SQL NULL;
     18: len 0; hex ; asc ;;
     19: len 4; hex 43505338; asc CPS8;;
     20: len 1; hex 81; asc  ;;
     21: len 4; hex 80000000; asc     ;;
     22: len 4; hex 80000000; asc     ;;
     23: SQL NULL;
     24: len 1; hex 80; asc  ;;
     25: len 0; hex ; asc ;;
     26: SQL NULL;
     27: len 4; hex 800003e7; asc     ;;
     28: len 4; hex 800003e7; asc     ;;
     29: len 4; hex 80000002; asc     ;;
     30: len 4; hex 80000001; asc     ;;
     31: SQL NULL;
     32: SQL NULL;
     33: SQL NULL;
     34: len 4; hex 80000005; asc     ;;
     35: len 1; hex 80; asc  ;;
     36: len 1; hex 80; asc  ;;
     37: len 1; hex 80; asc  ;;

    ------------------
    ---TRANSACTION 13341581093, ACTIVE 300 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 69, OS thread handle 0x1f08, query id 37654138 localhost 127.0.0
    .1 root updating
    UPDATE `slings` SET `updated_at` = '2013-10-15 06:04:53', `tag` = 173 WHERE `id`
     = 3760434
    ------- TRX HAS BEEN WAITING 300 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 237 page no 117 n bits 384 index `PRIMARY` of table `railp
    ro_development`.`slings` trx id 13341581093 lock_mode X locks rec but not gap wa
    iting
    Record lock, heap no 138 PHYSICAL RECORD: n_fields 13; compact format; info bits
     0
     0: len 4; hex 80396132; asc  9a2;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c26e6; asc b    & ;;
     3: len 4; hex 800000dc; asc     ;;
     4: len 5; hex 9990de59d8; asc    Y ;;
     5: len 5; hex 9990de6073; asc    `s;;
     6: SQL NULL;
     7: len 4; hex 80000009; asc     ;;
     8: len 4; hex 80000017; asc     ;;
     9: len 4; hex 800000b7; asc     ;;
     10: len 5; hex 9990de6073; asc    `s;;
     11: len 1; hex 30; asc 0;;
     12: SQL NULL;

    ------------------
    ---TRANSACTION 13341529477, ACTIVE 332 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 38, OS thread handle 0x1fb0, query id 37598517 localhost 127.0.0
    .1 root updating
    UPDATE `stafftrack_logins` SET `end_time` = '2013-10-15 06:04:21', `updated_at`
    = '2013-10-15 06:04:21' WHERE `id` = 140428
    ------- TRX HAS BEEN WAITING 332 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 245 page no 1355 n bits 208 index `PRIMARY` of table `rail
    pro_development`.`stafftrack_logins` trx id 13341529477 lock_mode X locks rec bu
    t not gap waiting
    Record lock, heap no 136 PHYSICAL RECORD: n_fields 12; compact format; info bits
     0
     0: len 4; hex 8002248c; asc   $ ;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c2877; asc b    (w;;
     3: len 4; hex 80000011; asc     ;;
     4: len 4; hex 80000143; asc    C;;
     5: len 5; hex 9990de3e64; asc    >d;;
     6: len 5; hex 9990de6115; asc    a ;;
     7: len 1; hex 80; asc  ;;
     8: len 5; hex 9990de3e64; asc    >d;;
     9: len 5; hex 9990de6115; asc    a ;;
     10: SQL NULL;
     11: SQL NULL;

    ------------------
    ---TRANSACTION 13341500243, ACTIVE 349 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 37, OS thread handle 0x1624, query id 37565181 localhost 127.0.0
    .1 root updating
    UPDATE `stafftrack_logins` SET `end_time` = '2013-10-15 06:04:04', `updated_at`
    = '2013-10-15 06:04:04' WHERE `id` = 140421
    ------- TRX HAS BEEN WAITING 349 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 245 page no 1355 n bits 200 index `PRIMARY` of table `rail
    pro_development`.`stafftrack_logins` trx id 13341500243 lock_mode X locks rec bu
    t not gap waiting
    Record lock, heap no 134 PHYSICAL RECORD: n_fields 12; compact format; info bits
     0
     0: len 4; hex 80022485; asc   $ ;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c2823; asc b    (#;;
     3: len 4; hex 8000003e; asc    >;;
     4: len 4; hex 800000d3; asc     ;;
     5: len 5; hex 9990de37d9; asc    7 ;;
     6: len 5; hex 9990de6103; asc    a ;;
     7: len 1; hex 80; asc  ;;
     8: len 5; hex 9990de37d9; asc    7 ;;
     9: len 5; hex 9990de6103; asc    a ;;
     10: SQL NULL;
     11: SQL NULL;

    ------------------
    ---TRANSACTION 13341499101, ACTIVE 350 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 36, OS thread handle 0x19a8, query id 37563945 localhost 127.0.0
    .1 root updating
    UPDATE `stafftrack_logins` SET `end_time` = '2013-10-15 06:04:03', `updated_at`
    = '2013-10-15 06:04:03' WHERE `id` = 140421
    ------- TRX HAS BEEN WAITING 350 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 245 page no 1355 n bits 200 index `PRIMARY` of table `rail
    pro_development`.`stafftrack_logins` trx id 13341499101 lock_mode X locks rec bu
    t not gap waiting
    Record lock, heap no 134 PHYSICAL RECORD: n_fields 12; compact format; info bits
     0
     0: len 4; hex 80022485; asc   $ ;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c2823; asc b    (#;;
     3: len 4; hex 8000003e; asc    >;;
     4: len 4; hex 800000d3; asc     ;;
     5: len 5; hex 9990de37d9; asc    7 ;;
     6: len 5; hex 9990de6103; asc    a ;;
     7: len 1; hex 80; asc  ;;
     8: len 5; hex 9990de37d9; asc    7 ;;
     9: len 5; hex 9990de6103; asc    a ;;
     10: SQL NULL;
     11: SQL NULL;

    ------------------
    ---TRANSACTION 13341486252, ACTIVE 360 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 35, OS thread handle 0x1538, query id 37550281 localhost 127.0.0
    .1 root updating
    UPDATE `stafftrack_logins` SET `end_time` = '2013-10-15 06:03:53', `updated_at`
    = '2013-10-15 06:03:53' WHERE `id` = 140433
    ------- TRX HAS BEEN WAITING 360 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 245 page no 1355 n bits 200 index `PRIMARY` of table `rail
    pro_development`.`stafftrack_logins` trx id 13341486252 lock_mode X locks rec bu
    t not gap waiting
    Record lock, heap no 133 PHYSICAL RECORD: n_fields 12; compact format; info bits
     0
     0: len 4; hex 80022491; asc   $ ;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c27f9; asc b    ' ;;
     3: len 4; hex 8000003e; asc    >;;
     4: len 4; hex 80000079; asc    y;;
     5: len 5; hex 9990de3eb3; asc    > ;;
     6: len 5; hex 9990de60ed; asc    ` ;;
     7: len 1; hex 80; asc  ;;
     8: len 5; hex 9990de3eb3; asc    > ;;
     9: len 5; hex 9990de60ed; asc    ` ;;
     10: SQL NULL;
     11: SQL NULL;

    ------------------
    ---TRANSACTION 13341476145, ACTIVE 368 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 27, OS thread handle 0x1794, query id 37539510 localhost 127.0.0
    .1 root updating
    UPDATE `stafftrack_logins` SET `end_time` = '2013-10-15 06:03:45', `updated_at`
    = '2013-10-15 06:03:45' WHERE `id` = 140433
    ------- TRX HAS BEEN WAITING 368 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 245 page no 1355 n bits 200 index `PRIMARY` of table `rail
    pro_development`.`stafftrack_logins` trx id 13341476145 lock_mode X locks rec bu
    t not gap waiting
    Record lock, heap no 133 PHYSICAL RECORD: n_fields 12; compact format; info bits
     0
     0: len 4; hex 80022491; asc   $ ;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c27f9; asc b    ' ;;
     3: len 4; hex 8000003e; asc    >;;
     4: len 4; hex 80000079; asc    y;;
     5: len 5; hex 9990de3eb3; asc    > ;;
     6: len 5; hex 9990de60ed; asc    ` ;;
     7: len 1; hex 80; asc  ;;
     8: len 5; hex 9990de3eb3; asc    > ;;
     9: len 5; hex 9990de60ed; asc    ` ;;
     10: SQL NULL;
     11: SQL NULL;

    ------------------
    ---TRANSACTION 13341210786, ACTIVE 561 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 61, OS thread handle 0xcc0, query id 37228004 localhost 127.0.0.
    1 root updating
    UPDATE `slings` SET `tag` = 221, `updated_at` = '2013-10-15 06:00:32' WHERE `id`
     = 3760256
    ------- TRX HAS BEEN WAITING 561 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 237 page no 113 n bits 408 index `PRIMARY` of table `railp
    ro_development`.`slings` trx id 13341210786 lock_mode X locks rec but not gap wa
    iting
    Record lock, heap no 240 PHYSICAL RECORD: n_fields 13; compact format; info bits
     0
     0: len 4; hex 80396080; asc  9` ;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c2365; asc b    #e;;
     3: len 4; hex 800000dc; asc     ;;
     4: len 5; hex 9990de5644; asc    VD;;
     5: len 5; hex 9990de5c11; asc    \ ;;
     6: SQL NULL;
     7: len 4; hex 80000008; asc     ;;
     8: len 4; hex 8000001f; asc     ;;
     9: len 4; hex 800000de; asc     ;;
     10: len 5; hex 9990de5c11; asc    \ ;;
     11: len 1; hex 30; asc 0;;
     12: SQL NULL;

    ------------------
    ---TRANSACTION 13340733149, ACTIVE 813 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 34, OS thread handle 0x1c74, query id 36686947 localhost 127.0.0
    .1 root updating
    UPDATE `slings` SET `tag` = 0, `updated_at` = '2013-10-15 05:56:20' WHERE `id` =
     3750500
    ------- TRX HAS BEEN WAITING 813 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 237 page no 103 n bits 368 index `PRIMARY` of table `railp
    ro_development`.`slings` trx id 13340733149 lock_mode X locks rec but not gap wa
    iting
    Record lock, heap no 299 PHYSICAL RECORD: n_fields 13; compact format; info bits
     0
     0: len 4; hex 80393a64; asc  9:d;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c258d; asc b    % ;;
     3: len 4; hex 800000dc; asc     ;;
     4: len 5; hex 9990d6ad21; asc     !;;
     5: len 5; hex 9990de5e09; asc    ^ ;;
     6: SQL NULL;
     7: len 4; hex 80000007; asc     ;;
     8: len 4; hex 8000001e; asc     ;;
     9: len 4; hex 800000d3; asc     ;;
     10: len 5; hex 9990de5e09; asc    ^ ;;
     11: len 1; hex 30; asc 0;;
     12: SQL NULL;

    ------------------
    ---TRANSACTION 13340568617, ACTIVE 903 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 33, OS thread handle 0xfd4, query id 36497676 localhost 127.0.0.
    1 root updating
    UPDATE `slings` SET `tag` = 183, `updated_at` = '2013-10-15 05:54:50' WHERE `id`
     = 3760434
    ------- TRX HAS BEEN WAITING 903 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 237 page no 117 n bits 328 index `PRIMARY` of table `railp
    ro_development`.`slings` trx id 13340568617 lock_mode X locks rec but not gap wa
    iting
    Record lock, heap no 138 PHYSICAL RECORD: n_fields 13; compact format; info bits
     0
     0: len 4; hex 80396132; asc  9a2;;
     1: len 6; hex 00031b15cbe5; asc       ;;
     2: len 7; hex 620000078c26e6; asc b    & ;;
     3: len 4; hex 800000dc; asc     ;;
     4: len 5; hex 9990de59d8; asc    Y ;;
     5: len 5; hex 9990de6073; asc    `s;;
     6: SQL NULL;
     7: len 4; hex 80000009; asc     ;;
     8: len 4; hex 80000017; asc     ;;
     9: len 4; hex 800000b7; asc     ;;
     10: len 5; hex 9990de6073; asc    `s;;
     11: len 1; hex 30; asc 0;;
     12: SQL NULL;

    ------------------
    ---TRANSACTION 13339315173, ACTIVE 1572 sec
    17 lock struct(s), heap size 3112, 28 row lock(s), undo log entries 265
    MySQL thread id 28, OS thread handle 0x1a68, query id 38154939 localhost 127.0.0
    .1 root cleaning up
    Trx read view will not see trx with id >= 13339315174, sees < 13339315174
    --------
    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 (read thread)
    I/O thread 4 state: wait Windows aio (read thread)
    I/O thread 5 state: wait Windows aio (read thread)
    I/O thread 6 state: wait Windows aio (write thread)
    I/O thread 7 state: wait Windows aio (write thread)
    I/O thread 8 state: wait Windows aio (write thread)
    I/O thread 9 state: wait Windows aio (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
    16009 OS file reads, 247119 OS file writes, 196868 OS fsyncs
    0.00 reads/s, 0 avg bytes/read, 4.14 writes/s, 4.14 fsyncs/s
    -------------------------------------
    INSERT BUFFER AND ADAPTIVE HASH INDEX
    -------------------------------------
    Ibuf: size 1, free list len 600, seg size 602, 461 merges
    merged operations:
     insert 234, delete mark 72731, delete 6105
    discarded operations:
     insert 0, delete mark 0, delete 0
    Hash table size 25499819, node heap has 1457 buffer(s)
    18360.79 hash searches/s, 6378.53 non-hash searches/s
    ---
    LOG
    ---
    Log sequence number 32913782367
    Log flushed up to   32913782357
    Pages flushed up to 32905803711
    Last checkpoint at  32905803711
    0 pending log writes, 0 pending chkp writes
    154012 log i/o's done, 4.14 log i/o's/second
    ----------------------
    BUFFER POOL AND MEMORY
    ----------------------
    Total memory allocated 13186891776; in additional pool allocated 0
    Dictionary memory allocated 704979
    Buffer pool size   786432
    Free buffers       768193
    Database pages     16782
    Old database pages 6349
    Modified db pages  1585
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 177, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 15892, created 890, written 74469
    0.00 reads/s, 0.02 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: 16782, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ----------------------
    INDIVIDUAL BUFFER POOL INFO
    ----------------------
    ---BUFFER POOL 0
    Buffer pool size   98304
    Free buffers       95915
    Database pages     2211
    Old database pages 836
    Modified db pages  191
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 34, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 2119, created 92, written 12239
    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: 2211, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 1
    Buffer pool size   98304
    Free buffers       96184
    Database pages     1931
    Old database pages 732
    Modified db pages  234
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 15, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 1831, created 100, written 5972
    0.00 reads/s, 0.02 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: 1931, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 2
    Buffer pool size   98304
    Free buffers       96026
    Database pages     2098
    Old database pages 794
    Modified db pages  104
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 28, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 2090, created 8, written 2450
    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: 2098, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 3
    Buffer pool size   98304
    Free buffers       95810
    Database pages     2311
    Old database pages 872
    Modified db pages  354
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 11, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 2012, created 299, written 20722
    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: 2311, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 4
    Buffer pool size   98304
    Free buffers       96204
    Database pages     1915
    Old database pages 726
    Modified db pages  128
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 24, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 1850, created 65, written 10904
    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: 1915, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 5
    Buffer pool size   98304
    Free buffers       95833
    Database pages     2288
    Old database pages 864
    Modified db pages  196
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 20, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 2201, created 87, written 6023
    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: 2288, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 6
    Buffer pool size   98304
    Free buffers       95952
    Database pages     2173
    Old database pages 821
    Modified db pages  224
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 23, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 2079, created 94, written 10846
    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: 2173, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 7
    Buffer pool size   98304
    Free buffers       96269
    Database pages     1855
    Old database pages 704
    Modified db pages  154
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 22, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 1710, created 145, written 5313
    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: 1855, 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
    Main thread id 7604, state: sleeping
    Number of rows inserted 12203, updated 144283, deleted 45540, read 8849139354
    0.36 inserts/s, 4.46 updates/s, 0.04 deletes/s, 119285.59 reads/s
    ----------------------------
    END OF INNODB MONITOR OUTPUT
    ============================

    1 row in set (0.00 sec)

    mysql>
4

1 回答 1

1

以防将来有人遇到这种情况。我们发现这个问题与多线程和 Rails 2.3.2 处理连接中的一个错误有关。

它的要点是在我们真正使用它之前释放了一个连接,所以有时在事务的中间,mysql线程被传递给不同的进程,并在整个应用程序中进入嵌套事务级联锁.

为了解决这个问题,我们更新到 rails 2.3.18,并向后移植了很多 Rails 3 ActiveRecord。

于 2014-02-28T18:33:32.037 回答