GET 24/7 LIVE HELP NOW

Announcement

Announcement Module
Collapse
No announcement yet.

mysql 5.5 became unresponsive

Page Title Module
Move Remove Collapse
X
Conversation Detail Module
Collapse
  • Filter
  • Time
  • Show
Clear All
new posts

  • mysql 5.5 became unresponsive

    A couple of days ago, our production mysql 5.5.25a become incredibly slow and basically unresponsive. On Sunday, we moved to a faster server. I grabbed some stats before restarting:

    ----------SEMAPHORES----------OS WAIT ARRAY INFO: reservation count 8640502, signal count 65724365--Thread 139910991918848 has waited at btr0cur.c line 530 for 0.00 seconds the semaphore:S-lock on RW-latch at 0x7f4a400932a8 created in file dict0dict.c line 1725a writer (thread id 139905520744192) has reserved it in mode exclusivenumber of readers 0, waiters flag 1, lock_word: 0Last time read locked in file btr0cur.c line 530Last time write locked in file /pb2/build/sb_0-6211460-1340976390.39/rpm/BUILD/mysql-5.5.25a/mysql-5.5.25a/storage/innobase/btr/btr0cur.c line 523--Thread 139905521800960 has waited at btr0cur.c line 530 for 0.00 seconds the semaphore:S-lock on RW-latch at 0x7f4a400932a8 created in file dict0dict.c line 1725a writer (thread id 139905520744192) has reserved it in mode exclusivenumber of readers 0, waiters flag 1, lock_word: 0Last time read locked in file btr0cur.c line 530Last time write locked in file /pb2/build/sb_0-6211460-1340976390.39/rpm/BUILD/mysql-5.5.25a/mysql-5.5.25a/storage/innobase/btr/btr0cur.c line 523--Thread 139905504892672 has waited at btr0cur.c line 530 for 0.00 seconds the semaphore:S-lock on RW-latch at 0x7f4a400932a8 created in file dict0dict.c line 1725a writer (thread id 139905520744192) has reserved it in mode exclusivenumber of readers 0, waiters flag 1, lock_word: 0Last time read locked in file btr0cur.c line 530Last time write locked in file /pb2/build/sb_0-6211460-1340976390.39/rpm/BUILD/mysql-5.5.25a/mysql-5.5.25a/storage/innobase/btr/btr0cur.c line 523--Thread 139910982407936 has waited at btr0cur.c line 530 for 0.00 seconds the semaphore:S-lock on RW-latch at 0x7f4a400932a8 created in file dict0dict.c line 1725a writer (thread id 139905520744192) has reserved it in mode exclusivenumber of readers 0, waiters flag 1, lock_word: 0Last time read locked in file btr0cur.c line 530Last time write locked in file /pb2/build/sb_0-6211460-1340976390.39/rpm/BUILD/mysql-5.5.25a/mysql-5.5.25a/storage/innobase/btr/btr0cur.c line 523--Thread 139905495910144 has waited at btr0cur.c line 530 for 0.00 seconds the semaphore:S-lock on RW-latch at 0x7f4a400932a8 created in file dict0dict.c line 1725a writer (thread id 139905520744192) has reserved it in mode exclusivenumber of readers 0, waiters flag 1, lock_word: 0Last time read locked in file btr0cur.c line 530Last time write locked in file /pb2/build/sb_0-6211460-1340976390.39/rpm/BUILD/mysql-5.5.25a/mysql-5.5.25a/storage/innobase/btr/btr0cur.c line 523--Thread 139905059964672 has waited at btr0cur.c line 530 for 0.00 seconds the semaphore:S-lock on RW-latch at 0x7f4a400932a8 created in file dict0dict.c line 1725a writer (thread id 139905520744192) has reserved it in mode exclusivenumber of readers 0, waiters flag 1, lock_word: 0Last time read locked in file btr0cur.c line 530Last time write locked in file /pb2/build/sb_0-6211460-1340976390.39/rpm/BUILD/mysql-5.5.25a/mysql-5.5.25a/storage/innobase/btr/btr0cur.c line 523..Several hundred more lines like this..--Thread 139905043056384 has waited at btr0sea.c line 1268 for 0.00 seconds the semaphore:S-lock on RW-latch at 0x465ec3f8 created in file btr0sea.c line 178number of readers 2, waiters flag 0, lock_word: ffffeLast time read locked in file btr0sea.c line 882Last time write locked in file /pb2/build/sb_0-6211460-1340976390.39/rpm/BUILD/mysql-5.5.25a/mysql-5.5.25a/storage/innobase/btr/btr0sea.c line 633Mutex spin waits 2135381830, rounds 5049682179, OS waits 4091057RW-shared spins 16968062, rounds 66882873, OS waits 1072341RW-excl spins 3661986, rounds 89024882, OS waits 688394Spin rounds per wait: 2.36 mutex, 3.94 RW-shared, 24.31 RW-excl


    Also:
    Threads_running | 246 |

    (I have all variables/status and innodb status if that will help).

    We have heavy traffic, especially select, and we are all innodb.

    After doing some digging, I noticed that innodb_thread_concurrency wasn't set, so yesterday I set it to 32. so far so good, and I've started to collect "show engine innodb mutex." As of this morning, results are:


    +--------+------------------------+-----------------+| Type | Name | Status |+--------+------------------------+-----------------+| InnoDB | dict0mem.c:92 | os_waits=1 || InnoDB | dict0mem.c:92 | os_waits=40 || InnoDB | dict0mem.c:92 | os_waits=1 || InnoDB | dict0mem.c:92 | os_waits=1 || InnoDB | dict0mem.c:92 | os_waits=1 || InnoDB | dict0mem.c:92 | os_waits=4 || InnoDB | dict0mem.c:92 | os_waits=1 || InnoDB | dict0mem.c:92 | os_waits=1 || InnoDB | dict0mem.c:92 | os_waits=1 || InnoDB | dict0mem.c:92 | os_waits=1 || InnoDB | dict0mem.c:92 | os_waits=1 || InnoDB | dict0mem.c:92 | os_waits=2 || InnoDB | dict0mem.c:92 | os_waits=8 || InnoDB | dict0mem.c:92 | os_waits=2 || InnoDB | trx0purge.c:245 | os_waits=2 || InnoDB | trx0rseg.c:210 | os_waits=1 || InnoDB | trx0rseg.c:210 | os_waits=1 || InnoDB | trx0rseg.c:210 | os_waits=1 || InnoDB | ibuf0ibuf.c:534 | os_waits=3070 || InnoDB | ibuf0ibuf.c:531 | os_waits=2 || InnoDB | dict0dict.c:698 | os_waits=1599 || InnoDB | trx0sys.c:1327 | os_waits=3 || InnoDB | log0log.c:775 | os_waits=6386 || InnoDB | log0log.c:771 | os_waits=23999 || InnoDB | buf0buf.c:1166 | os_waits=581933 || InnoDB | fil0fil.c:1608 | os_waits=815 || InnoDB | srv0srv.c:1018 | os_waits=59154 || InnoDB | combined buf0buf.c:915 | os_waits=11921 || InnoDB | dict0dict.c:1725 | os_waits=7 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=106 || InnoDB | dict0dict.c:1725 | os_waits=5 || InnoDB | dict0dict.c:1725 | os_waits=9 || InnoDB | dict0dict.c:1725 | os_waits=17 || InnoDB | dict0dict.c:1725 | os_waits=263 || InnoDB | dict0dict.c:1725 | os_waits=132 || InnoDB | dict0dict.c:1725 | os_waits=127 || InnoDB | dict0dict.c:1725 | os_waits=1495 || InnoDB | dict0dict.c:1725 | os_waits=108 || InnoDB | dict0dict.c:1725 | os_waits=93 || InnoDB | dict0dict.c:1725 | os_waits=1869 || InnoDB | dict0dict.c:1725 | os_waits=3 || InnoDB | dict0dict.c:1725 | os_waits=43 || InnoDB | dict0dict.c:1725 | os_waits=6 || InnoDB | dict0dict.c:1725 | os_waits=5 || InnoDB | dict0dict.c:1725 | os_waits=5 || InnoDB | dict0dict.c:1725 | os_waits=108 || InnoDB | dict0dict.c:1725 | os_waits=19 || InnoDB | dict0dict.c:1725 | os_waits=212 || InnoDB | dict0dict.c:1725 | os_waits=139 || InnoDB | dict0dict.c:1725 | os_waits=114 || InnoDB | dict0dict.c:1725 | os_waits=53 || InnoDB | dict0dict.c:1725 | os_waits=444 || InnoDB | dict0dict.c:1725 | os_waits=38 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=3 || InnoDB | dict0dict.c:1725 | os_waits=88 || InnoDB | dict0dict.c:1725 | os_waits=6 || InnoDB | dict0dict.c:1725 | os_waits=3 || InnoDB | dict0dict.c:1725 | os_waits=120 || InnoDB | dict0dict.c:1725 | os_waits=4 || InnoDB | dict0dict.c:1725 | os_waits=2 || InnoDB | dict0dict.c:1725 | os_waits=89 || InnoDB | dict0dict.c:1725 | os_waits=2 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=364 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=3 || InnoDB | dict0dict.c:1725 | os_waits=3 || InnoDB | dict0dict.c:1725 | os_waits=5 || InnoDB | dict0dict.c:1725 | os_waits=2 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=55 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=6 || InnoDB | dict0dict.c:1725 | os_waits=138 || InnoDB | dict0dict.c:1725 | os_waits=3 || InnoDB | dict0dict.c:1725 | os_waits=17 || InnoDB | dict0dict.c:1725 | os_waits=12 || InnoDB | dict0dict.c:1725 | os_waits=208 || InnoDB | dict0dict.c:1725 | os_waits=4 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=2 || InnoDB | dict0dict.c:1725 | os_waits=30 || InnoDB | dict0dict.c:1725 | os_waits=2 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=15 || InnoDB | dict0dict.c:1725 | os_waits=2 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=40 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=16 || InnoDB | dict0dict.c:1725 | os_waits=2 || InnoDB | dict0dict.c:1725 | os_waits=162 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=2111 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=36 || InnoDB | dict0dict.c:1725 | os_waits=10 || InnoDB | dict0dict.c:1725 | os_waits=3 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=13 || InnoDB | dict0dict.c:1725 | os_waits=2 || InnoDB | dict0dict.c:1725 | os_waits=6033 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=13 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=9 || InnoDB | dict0dict.c:1725 | os_waits=144 || InnoDB | dict0dict.c:1725 | os_waits=220 || InnoDB | dict0dict.c:1725 | os_waits=174 || InnoDB | dict0dict.c:1725 | os_waits=80 || InnoDB | dict0dict.c:1725 | os_waits=582 || InnoDB | dict0dict.c:1725 | os_waits=10 || InnoDB | dict0dict.c:1725 | os_waits=22 || InnoDB | dict0dict.c:1725 | os_waits=62 || InnoDB | dict0dict.c:1725 | os_waits=7 || InnoDB | dict0dict.c:1725 | os_waits=1 || InnoDB | dict0dict.c:1725 | os_waits=9 || InnoDB | dict0dict.c:1725 | os_waits=5 || InnoDB | dict0dict.c:1725 | os_waits=2 || InnoDB | dict0dict.c:1725 | os_waits=13 || InnoDB | fil0fil.c:1300 | os_waits=32 || InnoDB | fil0fil.c:1300 | os_waits=11 || InnoDB | fil0fil.c:1300 | os_waits=3 || InnoDB | fil0fil.c:1300 | os_waits=4 || InnoDB | fil0fil.c:1300 | os_waits=8 || InnoDB | fil0fil.c:1300 | os_waits=1 || InnoDB | fil0fil.c:1300 | os_waits=1 || InnoDB | fil0fil.c:1300 | os_waits=1 || InnoDB | fil0fil.c:1300 | os_waits=1 || InnoDB | fil0fil.c:1300 | os_waits=217 || InnoDB | fil0fil.c:1300 | os_waits=24 || InnoDB | trx0purge.c:241 | os_waits=2 || InnoDB | dict0dict.c:1725 | os_waits=10357 || InnoDB | dict0dict.c:721 | os_waits=5 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=7 || InnoDB | dict0dict.c:721 | os_waits=12 || InnoDB | dict0dict.c:721 | os_waits=275 || InnoDB | dict0dict.c:721 | os_waits=108 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=5 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=9 || InnoDB | dict0dict.c:721 | os_waits=8 || InnoDB | dict0dict.c:721 | os_waits=3 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=3 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=5 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=2 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=12 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=3 || InnoDB | dict0dict.c:721 | os_waits=12 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=3 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=5 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=4 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | dict0dict.c:721 | os_waits=1 || InnoDB | fil0fil.c:1300 | os_waits=1 || InnoDB | log0log.c:832 | os_waits=15553 || InnoDB | btr0sea.c:178 | os_waits=297376 || InnoDB | combined buf0buf.c:916 | os_waits=23287 |+--------+------------------------+-----------------+


    So, did I do the right thing by setting innodb_thread_concurrency? Or will I still have issues? Should I be worried about the ouput of innodb mutext?

    Thank you....

  • #2
    Do you have SHOW PROCESSLIST output taken at the same time of the INNODB STATUS above? Looks like there was DDL operation running at the time.
    Our documentation has a lot of answers about common questions on Percona software, have you checked there before posting that question here? http://www.percona.com/forums/core/i...lies/smile.png

    Join us at the annual Percona Live MySQL Users Conference - http://www.percona.com/live/mysql-conference-2014/

    Comment


    • #3
      I have it -- no DDL running, mostly it's all select statements.

      Comment


      • #4
        It may not be on the PROCESSLIST, it's also possible it happened on multi statement transaction - you should be able to tie up the thread IDs from the semaphore to the processlist and transactions.
        Our documentation has a lot of answers about common questions on Percona software, have you checked there before posting that question here? http://www.percona.com/forums/core/i...lies/smile.png

        Join us at the annual Percona Live MySQL Users Conference - http://www.percona.com/live/mysql-conference-2014/

        Comment


        • #5
          I don't understand that. The thread id's appear in the semaphore section and no where else, so there's nothing to match them to. Transaction section has mostly selects, a few inserts, all stuff normal to the app. There are more there than usual, because everything was taking a long time. I don't see anything that indicates a single query created all of these semaphore waits.

          Comment


          • #6
            Just checking back to seee if anyone has any ideas?

            Comment

            Working...
            X