1. This site uses cookies. By continuing to use this site, you are agreeing to our use of cookies. Learn More.

XF 1.4 Double Posts, MySQL Lock Timeout errors

Discussion in 'Troubleshooting and Problems' started by Denny Crane, Feb 22, 2015.

  1. Denny Crane

    Denny Crane Member

    I've been getting a lot of both on my site lately.

    http://www.sportstwo.com.

    What I think is going on is users are clicking on the submit post button two or more times because they're on mobile and there's a lot of lag.

    I just read a thread where one guy submitted the same post 4 times in a row.

    I'm seeing only a handful (like 12-15) per day of these MySQL Lock Timeout errors in the server log.

    Any suggestions?
     
  2. Denny Crane

    Denny Crane Member

    I already bumped the innodb_lock_timeout variable as suggested in an older thread I found on this site.

    I think that's a mistake, but I'm hoping someone will set that straight. I've not ever seen a message board take 50 seconds (the lock timeout default) to render a page.
     
  3. Mike

    Mike XenForo Developer Staff Member

    Can you post the actual errors and backtraces? Do the errors roughly correspond to when you're seeing double posts?
     
  4. Denny Crane

    Denny Crane Member

    Server Error Log
    Error Info
    Zend_Db_Statement_Mysqli_Exception: Mysqli statement execute error : Lock wait timeout exceeded; try restarting transaction - library/Zend/Db/Statement/Mysqli.php:214
    Generated By: BlayZa, 31 minutes ago
    Stack Trace
    #0 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/Zend/Db/Statement.php(297): Zend_Db_Statement_Mysqli->_execute(Array)
    #1 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/Zend/Db/Adapter/Abstract.php(479): Zend_Db_Statement->execute(Array)
    #2 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter/DiscussionMessage.php(928): Zend_Db_Adapter_Abstract->query('?????UPDATE xf_...', 20938)
    #3 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter/DiscussionMessage/Post.php(200): XenForo_DataWriter_DiscussionMessage->_updateUserMessageCount(false)
    #4 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter/DiscussionMessage.php(560): XenForo_DataWriter_DiscussionMessage_Post->_updateUserMessageCount()
    #5 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter.php(1409): XenForo_DataWriter_DiscussionMessage->_postSave()
    #6 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/ControllerPublic/Thread.php(555): XenForo_DataWriter->save()
    #7 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/FrontController.php(347): XenForo_ControllerPublic_Thread->actionAddReply()
    #8 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/FrontController.php(134): XenForo_FrontController->dispatch(Object(XenForo_RouteMatch))
    #9 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/index.php(13): XenForo_FrontController->run()
    #10 {main}
    Request State
    array(3) {
    ["url"] => string(90) "http://www.sportstwo.com/threads/official-around-the-nba-february-edition.279290/add-reply"
    ["_GET"] => array(0) {
    }
    ["_POST"] => array(9) {
    ["message_html"] => string(92) "<p>so Claver is exploring options outside the NBA</p><p><br></p><p>anyone surprised?<br></p>"
    ["_xfRelativeResolver"] => string(88) "http://www.sportstwo.com/threads/official-around-the-nba-february-edition.279290/page-27"
    ["attachment_hash"] => string(32) "74909a4696e516604e5b189890d19aea"
    ["last_date"] => string(10) "1424653759"
    ["last_known_date"] => string(10) "1424653759"
    ["_xfToken"] => string(8) "********"
    ["_xfRequestUri"] => string(64) "/threads/official-around-the-nba-february-edition.279290/page-27"
    ["_xfNoRedirect"] => string(1) "1"
    ["_xfResponseType"] => string(4) "json"
    }
    }
     
  5. Denny Crane

    Denny Crane Member

    And another:

    Server Error Log
    Error Info
    Zend_Db_Statement_Mysqli_Exception: Mysqli statement execute error : Lock wait timeout exceeded; try restarting transaction - library/Zend/Db/Statement/Mysqli.php:214
    Generated By: Strenuus, Today at 4:39 PM
    Stack Trace
    #0 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/Zend/Db/Statement.php(297): Zend_Db_Statement_Mysqli->_execute(Array)
    #1 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/Zend/Db/Adapter/Abstract.php(479): Zend_Db_Statement->execute(Array)
    #2 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter/Alert.php(99): Zend_Db_Adapter_Abstract->query('????UPDATE xf_u...', 27997)
    #3 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter.php(1409): XenForo_DataWriter_Alert->_postSave()
    #4 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/Model/Alert.php(452): XenForo_DataWriter->save()
    #5 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/Model/Alert.php(426): XenForo_Model_Alert->alertUser(27997, 27918, 'Strenuus', 'post', 3559884, 'insert', NULL)
    #6 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/Model/ThreadWatch.php(279): XenForo_Model_Alert::alert(27997, 27918, 'Strenuus', 'post', 3559884, 'insert')
    #7 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter/DiscussionMessage/Post.php(164): XenForo_Model_ThreadWatch->sendNotificationToWatchUsersOnReply(Array, NULL, Array)
    #8 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/WidgetFramework/XenForo/DataWriter/DiscussionMessage/Post.php(7): XenForo_DataWriter_DiscussionMessage_Post->_postSaveAfterTransaction()
    #9 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter.php(1423): WidgetFramework_XenForo_DataWriter_DiscussionMessage_Post->_postSaveAfterTransaction()
    #10 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/ControllerPublic/Thread.php(555): XenForo_DataWriter->save()
    #11 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/FrontController.php(347): XenForo_ControllerPublic_Thread->actionAddReply()
    #12 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/FrontController.php(134): XenForo_FrontController->dispatch(Object(XenForo_RouteMatch))
    #13 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/index.php(13): XenForo_FrontController->run()
    #14 {main}
    Request State
    array(3) {
    ["url"] => string(117) "http://www.sportstwo.com/threads/ga...015-sunday-6-00-pm-pst-csnnw.280179/add-reply"
    ["_GET"] => array(0) {
    }
    ["_POST"] => array(9) {
    ["message_html"] => string(99) "<p>This is cool</p><p><br></p><p>https://twitter.com/trailblazers/status/569654311535255552<br></p>"
    ["_xfRelativeResolver"] => string(108) "http://www.sportstwo.com/threads/ga...uary-22-2015-sunday-6-00-pm-pst-csnnw.280179/"
    ["attachment_hash"] => string(32) "f437c0494b4e7bb009f0718d2c5e3138"
    ["last_date"] => string(10) "1424649169"
    ["last_known_date"] => string(10) "1424649169"
    ["_xfToken"] => string(8) "********"
    ["_xfRequestUri"] => string(84) "/threads/game-55-grizzlies-blazers-february-22-2015-sunday-6-00-pm-pst-csnnw.280179/"
    ["_xfNoRedirect"] => string(1) "1"
    ["_xfResponseType"] => string(4) "json"
    }
    }
     
  6. Denny Crane

    Denny Crane Member

    I think it is almost certainly coincidental with double posts.

    The user clicks "submit" for his post and it does nothing while the lock timeout occurs. So he hits "submit" again.
     
  7. Denny Crane

    Denny Crane Member

  8. Denny Crane

    Denny Crane Member

    It definitely added a few to the log just now and I have two users: 1) created duplicate thread (first post duplicate), 2) created 3-4 duplicate posts in a row in a thread
     
  9. Denny Crane

    Denny Crane Member

    This one's different:

    Server Error Log
    Error Info
    Zend_Db_Statement_Mysqli_Exception: Mysqli statement execute error : Duplicate entry '28021-280179' for key 'PRIMARY' - library/Zend/Db/Statement/Mysqli.php:214
    Generated By: honkicracker, 55 minutes ago
    Stack Trace
    #0 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/Zend/Db/Statement.php(297): Zend_Db_Statement_Mysqli->_execute(Array)
    #1 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/Zend/Db/Adapter/Abstract.php(479): Zend_Db_Statement->execute(Array)
    #2 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/Zend/Db/Adapter/Abstract.php(574): Zend_Db_Adapter_Abstract->query('INSERT INTO `xf...', Array)
    #3 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter.php(1624): Zend_Db_Adapter_Abstract->insert('xf_thread_watch', Array)
    #4 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter.php(1613): XenForo_DataWriter->_insert()
    #5 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/DataWriter.php(1405): XenForo_DataWriter->_save()
    #6 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/Model/ThreadWatch.php(506): XenForo_DataWriter->save()
    #7 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/Model/ThreadWatch.php(549): XenForo_Model_ThreadWatch->setThreadWatchStateWithUserDefault(28021, 280179, 'watch_email')
    #8 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/ControllerPublic/Thread.php(562): XenForo_Model_ThreadWatch->setVisitorThreadWatchStateFromInput(280179, Array)
    #9 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/FrontController.php(347): XenForo_ControllerPublic_Thread->actionAddReply()
    #10 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/library/XenForo/FrontController.php(134): XenForo_FrontController->dispatch(Object(XenForo_RouteMatch))
    #11 /home/mschwartz/github/mschwartz/sportstwo-xenforo/htdocs/index.php(13): XenForo_FrontController->run()
    #12 {main}
    Request State
    array(3) {
    ["url"] => string(117) "http://www.sportstwo.com/threads/ga...015-sunday-6-00-pm-pst-csnnw.280179/add-reply"
    ["_GET"] => array(0) {
    }
    ["_POST"] => array(9) {
    ["message_html"] => string(258) "<p>hate to say it but... after dropping the Utah game... And the Thunder starting to play better... This Memphis game.. being at home is sort of a must win..... But without Aldridge I just don't see the Blazers having a chance...<br><br>I pray I'm wrong.</p>"
    ["_xfRelativeResolver"] => string(114) "http://www.sportstwo.com/threads/ga...2-2015-sunday-6-00-pm-pst-csnnw.280179/page-2"
    ["attachment_hash"] => string(32) "36f7497e81355035bf9bf0caf43f03cb"
    ["last_date"] => string(10) "1424655494"
    ["last_known_date"] => string(10) "1424655494"
    ["_xfToken"] => string(8) "********"
    ["_xfRequestUri"] => string(90) "/threads/game-55-grizzlies-blazers-february-22-2015-sunday-6-00-pm-pst-csnnw.280179/page-2"
    ["_xfNoRedirect"] => string(1) "1"
    ["_xfResponseType"] => string(4) "json"
    }
    }
     
  10. Denny Crane

    Denny Crane Member

    Some more info.

    The site is doing about 30 pages a minute while the errors are happening. Lots of race conditions as people are posting like crazy in one thread.

    No, I can't drive them to different threads, they're discussing the NBA basketball game as it's being played.
     
  11. Brogan

    Brogan XenForo Moderator Staff Member

    What hosting package are you on and what are your server specs?
    Tuning the server may help.

    Threads aren't the best medium for real time discussion - have you considered a chat add-on of some sort?
     
  12. Mike

    Mike XenForo Developer Staff Member

    The 2 lock wait issues are on the xf_user table. This almost looks like a general load issue as it's simply waiting for another transaction to free that row (or page actually); normally these transactions should be quick.

    What does this query output?
    Code:
    SHOW ENGINE INNODB STATUS;
    Have you gone through your InnoDB settings to ensure they're fully optimized for your usage? See: http://www.percona.com/blog/2013/09/20/innodb-performance-optimization-basics-updated/
     
  13. Denny Crane

    Denny Crane Member

    ====================================
    2015-02-23 09:45:32 7f9c93594700 INNODB MONITOR OUTPUT
    =====================================
    Per second averages calculated from the last 15 seconds
    -----------------
    BACKGROUND THREAD
    -----------------
    srv_master_thread loops: 3752728 srv_active, 0 srv_shutdown, 551763 srv_idle
    srv_master_thread log flush and writes: 4303899
    ----------
    SEMAPHORES
    ----------
    OS WAIT ARRAY INFO: reservation count 4516342
    OS WAIT ARRAY INFO: signal count 4677420
    Mutex spin waits 5250178, rounds 88754970, OS waits 2880839
    RW-shared spins 1702525, rounds 48518223, OS waits 1569819
    RW-excl spins 117345, rounds 3240862, OS waits 51261
    Spin rounds per wait: 16.91 mutex, 28.50 RW-shared, 27.62 RW-excl
    ------------
    TRANSACTIONS
    ------------
    Trx id counter 40415194
    Purge done for trx's n:eek: < 40415194 undo n:eek: < 0 state: running but idle
    History list length 1883
    LIST OF TRANSACTIONS FOR EACH SESSION:
    ---TRANSACTION 0, not started
    MySQL thread id 16484479, OS thread handle 0x7f9c93594700, query id 342060715 localhost mschwartz init
    SHOW ENGINE INNODB STATUS
    ---TRANSACTION 40415192, not started
    MySQL thread id 16484562, OS thread handle 0x7f9c8a22f700, query id 342060718 www1.local 10.132.142.156 apache cleaning up
    ---TRANSACTION 40294476, not started
    MySQL thread id 2, OS thread handle 0x7f9c938c3700, query id 341020989 Slave has read all relay log; waiting for the slave I/O thread to update it
    --------
    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
    33742703 OS file reads, 34634129 OS file writes, 13387658 OS fsyncs
    14.27 reads/s, 16384 avg bytes/read, 15.07 writes/s, 4.33 fsyncs/s
    -------------------------------------
    INSERT BUFFER AND ADAPTIVE HASH INDEX
    -------------------------------------
    Ibuf: size 1, free list len 3077, seg size 3079, 1014753 merges
    merged operations:
    insert 1624831, delete mark 5849690, delete 3447754
    discarded operations:
    insert 0, delete mark 0, delete 0
    Hash table size 276671, node heap has 568 buffer(s)
    60.73 hash searches/s, 197.25 non-hash searches/s
    ---
    LOG
    ---
    Log sequence number 32854782961
    Log flushed up to 32854782845
    Pages flushed up to 32854735385
    Last checkpoint at 32854673043
    0 pending log writes, 0 pending chkp writes
    11134187 log i/o's done, 3.73 log i/o's/second
    ----------------------
    BUFFER POOL AND MEMORY
    ----------------------
    Total memory allocated 137363456; in additional pool allocated 0
    Dictionary memory allocated 1349698
    Buffer pool size 8191
    Free buffers 1023
    Database pages 6600
    Old database pages 2416
    Modified db pages 100
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 19844255, not young 557767527
    1.80 youngs/s, 121.26 non-youngs/s
    Pages read 33742219, created 422922, written 22892745
    14.27 reads/s, 0.13 creates/s, 11.13 writes/s
    Buffer pool hit rate 987 / 1000, young-making rate 1 / 1000 not 111 / 1000
    Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
    LRU len: 6600, unzip_LRU len: 0
    I/O sum[919]:cur[1], unzip sum[0]:cur[0]
    --------------
    ROW OPERATIONS
    --------------
    0 queries inside InnoDB, 0 queries in queue
    0 read views open inside InnoDB
    Main thread process no. 30394, id 140310435165952, state: sleeping
    Number of rows inserted 7001024, updated 7628939, deleted 2631031, read 48827526387
    0.13 inserts/s, 3.00 updates/s, 0.07 deletes/s, 188.45 reads/s
    ----------------------------
    END OF INNODB MONITOR OUTPUT
     
  14. Denny Crane

    Denny Crane Member

    Using a chat program is not an option.

    Switching back to vBulletin is. We never ever had this kind of problem using vb4 or ipBoard prior.

    The site setup is described here:
    http://moduscreate.com/scaling-xenforo-on-digital-oceans-iaas/

    I have monitored the vps systems under load and we're not even using 5% of any of the CPUs. All are 95%+ idle.

    It's not for lack of computing power. It appears to be a race condition BUG in xenforo where two HTTP requests cause the PHP to issue.

    I cannot imagine why the software would hold a lock on a row or rows in the users table for over a minute at a time if it is not a bug.
     
  15. Denny Crane

    Denny Crane Member

    [​IMG]

    Those are my innodb settings in my.cnf.


    db1:~$ free
    total used free shared buffers cached
    Mem: 8176824 1810012 6366812 340 16288 261464
    -/+ buffers/cache: 1532260 6644564
    Swap: 0 0
     
  16. Mike

    Mike XenForo Developer Staff Member

    Note that XenForo does not use the same MySQL configuration as vBulletin. If you setup your MySQL server for MyISAM primarily, the server is likely setup totally the wrong way for XenForo.

    This part is making me think that InnoDB hasn't been hugely configured:

    This would seem to imply the innodb_buffer_pool_size variable is something like 128M. It should ideally be set as large as possible. If you can fit your entire data set in it, all the better.

    There are also things that can be done to speed up writes specifically (innodb_flush_log_at_trx_commit and innodb_flush_method) that, if not tuned, may cause significant overhead if you have a lot of writes happening.

    XenForo certainly shouldn't be holding on to a transaction while posting for any significant amount of time. When you make a post, you're seeing the transaction in question and much more happen. All told, it should probably take no longer than a second for the entire request to run. Individual transactions within should be less than that. That's what made me suggest that there's some general load/resource contention issue within MySQL that's causing issues.

    Note that a lock wait timeout isn't a race condition or a deadlock. It's just waiting for another transaction to release. The question is why that other transaction is taking so long. This is very often a load issue. It could potentially also happen if there are things being done in the transaction that are taking a long time. The only thing done within the post insert transaction that doesn't depend on MySQL would be Elasticsearch indexing (assuming you're using that). If there's some issue there that would take a huge amount of time, that could be related; ES is usually significantly faster at indexing than MySQL fulltext itself though.
     
  17. Mike

    Mike XenForo Developer Staff Member

    I see you posted some InnoDB settings while I was posting. Can you confirm those are the variables in use? The total memory allocated doesn't seem to correspond to 6G (testing here, it does correspond to what we have in my.cnf, though slightly larger than what's set there).
     
  18. Denny Crane

    Denny Crane Member

    =====================================
    2015-02-23 10:26:32 7fbd0fd32700 INNODB MONITOR OUTPUT
    =====================================
    Per second averages calculated from the last 13 seconds
    -----------------
    BACKGROUND THREAD
    -----------------
    srv_master_thread loops: 285 srv_active, 0 srv_shutdown, 32 srv_idle
    srv_master_thread log flush and writes: 317
    ----------
    SEMAPHORES
    ----------
    OS WAIT ARRAY INFO: reservation count 642
    OS WAIT ARRAY INFO: signal count 650
    Mutex spin waits 496, rounds 12180, OS waits 397
    RW-shared spins 245, rounds 7270, OS waits 239
    RW-excl spins 2, rounds 307, OS waits 4
    Spin rounds per wait: 24.56 mutex, 29.67 RW-shared, 153.50 RW-excl
    ------------
    TRANSACTIONS
    ------------
    Trx id counter 40441013
    Purge done for trx's n:eek: < 40441007 undo n:eek: < 0 state: running but idle
    History list length 1454
    LIST OF TRANSACTIONS FOR EACH SESSION:
    ---TRANSACTION 0, not started
    MySQL thread id 1305, OS thread handle 0x7fbd0fd32700, query id 27074 localhost mschwartz init
    SHOW ENGINE INNODB STATUS
    ---TRANSACTION 40437755, not started
    MySQL thread id 1, OS thread handle 0x7fbd0fdb6700, query id 262 Slave has read all relay log; waiting for the slave I/O thread to update it
    --------
    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
    8475 OS file reads, 3816 OS file writes, 1162 OS fsyncs
    6.92 reads/s, 16384 avg bytes/read, 3.77 writes/s, 0.46 fsyncs/s
    -------------------------------------
    INSERT BUFFER AND ADAPTIVE HASH INDEX
    -------------------------------------
    Ibuf: size 1, free list len 3077, seg size 3079, 105 merges
    merged operations:
    insert 394, delete mark 80, delete 34
    discarded operations:
    insert 0, delete mark 0, delete 0
    Hash table size 12749447, node heap has 573 buffer(s)
    244.67 hash searches/s, 154.45 non-hash searches/s
    ---
    LOG
    ---
    Log sequence number 32863462053
    Log flushed up to 32863462053
    Pages flushed up to 32863354953
    Last checkpoint at 32863354953
    0 pending log writes, 0 pending chkp writes
    886 log i/o's done, 3.77 log i/o's/second
    ----------------------
    BUFFER POOL AND MEMORY
    ----------------------
    Total memory allocated 6593445888; in additional pool allocated 0
    Dictionary memory allocated 1349698
    Buffer pool size 393200
    Free buffers 384263
    Database pages 8364
    Old database pages 1664
    Modified db pages 317
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 8334, created 30, written 2591
    6.92 reads/s, 0.08 creates/s, 0.00 writes/s
    Buffer pool hit rate 995 / 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: 8364, 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 24575
    Free buffers 24037
    Database pages 502
    Old database pages 0
    Modified db pages 51
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 502, created 0, written 443
    0.85 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 996 / 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: 502, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 1
    Buffer pool size 24575
    Free buffers 24058
    Database pages 481
    Old database pages 0
    Modified db pages 10
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 481, created 0, written 46
    0.31 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 971 / 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: 481, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 2
    Buffer pool size 24575
    Free buffers 24072
    Database pages 467
    Old database pages 0
    Modified db pages 12
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 467, created 0, written 50
    1.15 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 971 / 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: 467, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 3
    Buffer pool size 24575
    Free buffers 23980
    Database pages 559
    Old database pages 226
    Modified db pages 29
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 559, created 0, written 341
    0.54 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 995 / 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: 559, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 4
    Buffer pool size 24575
    Free buffers 23841
    Database pages 698
    Old database pages 277
    Modified db pages 52
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 698, created 0, written 470
    0.15 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 999 / 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: 698, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 5
    Buffer pool size 24575
    Free buffers 23982
    Database pages 557
    Old database pages 225
    Modified db pages 23
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 548, created 9, written 199
    0.77 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 962 / 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: 557, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 6
    Buffer pool size 24575
    Free buffers 23982
    Database pages 557
    Old database pages 225
    Modified db pages 10
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 552, created 5, written 95
    0.69 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 973 / 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: 557, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 7
    Buffer pool size 24575
    Free buffers 24002
    Database pages 537
    Old database pages 218
    Modified db pages 14
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 537, created 0, written 122
    0.38 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 970 / 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: 537, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 8
    Buffer pool size 24575
    Free buffers 23854
    Database pages 685
    Old database pages 272
    Modified db pages 25
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 671, created 14, written 183
    0.38 reads/s, 0.08 creates/s, 0.00 writes/s
    Buffer pool hit rate 997 / 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: 685, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 9
    Buffer pool size 24575
    Free buffers 24107
    Database pages 432
    Old database pages 0
    Modified db pages 20
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 432, created 0, written 215
    0.23 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 994 / 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: 432, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 10
    Buffer pool size 24575
    Free buffers 24076
    Database pages 463
    Old database pages 0
    Modified db pages 6
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 463, created 0, written 36
    0.31 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 999 / 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: 463, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 11
    Buffer pool size 24575
    Free buffers 24035
    Database pages 504
    Old database pages 0
    Modified db pages 7
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 504, created 0, written 20
    0.23 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 997 / 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: 504, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 12
    Buffer pool size 24575
    Free buffers 23994
    Database pages 545
    Old database pages 221
    Modified db pages 25
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 543, created 2, written 143
    0.54 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 996 / 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: 545, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 13
    Buffer pool size 24575
    Free buffers 24097
    Database pages 443
    Old database pages 0
    Modified db pages 13
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 443, created 0, written 119
    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: 443, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 14
    Buffer pool size 24575
    Free buffers 24068
    Database pages 472
    Old database pages 0
    Modified db pages 12
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 472, created 0, written 63
    0.23 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 995 / 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: 472, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    ---BUFFER POOL 15
    Buffer pool size 24575
    Free buffers 24078
    Database pages 462
    Old database pages 0
    Modified db pages 8
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 462, created 0, written 46
    0.15 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 997 / 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: 462, 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
    0 read views open inside InnoDB
    Main thread process no. 1254, id 140450042210048, state: sleeping
    Number of rows inserted 199, updated 743, deleted 16, read 3662284
    1.23 inserts/s, 1.92 updates/s, 0.00 deletes/s, 486.65 reads/s
    ----------------------------
    END OF INNODB MONITOR OUTPUT
     
  19. Denny Crane

    Denny Crane Member

    I made adjustments according to the persona document you linked.

    The section of my.cnf I posted are the new values.

    If you think I have set anything wrong, please let me know.

    In the mean time, I can monitor the site for any continued issues.
     
  20. Mike

    Mike XenForo Developer Staff Member

    Please let me know how that goes. If you see the site slow down/give lock timeout errors, run a few more InnoDB status checks -- we'd be looking for the open transactions at the time to hopefully see if anything can be gleaned from that.

    Are you running Elasticsearch? If so, please have a look to make sure that's running well and that it has memory allocated to handle its indexes. (If you're running MySQL full text search, that could potentially be a bottleneck I suppose; it may be slow to update the index with 3.5 million posts. That's also a MyISAM table so some memory would still need to be allocated to MyISAM and its key cache to handle that table.)

    I assume you are pulling sessions for Memcached as well (cache has to be enabled in config.php and you have to explicitly opt in to using it for sessions). That will remove a read and a write to the DB server on each page.
     

Share This Page