3

My site is very slow sometimes, so I activated the php-slowlog to find out whats wrong. It is full of mysql-functions like mysql_query. So I activated the mysql-slowlog and found out that some querys took up to 35 (!) seconds like the following:

# Thread_id: 4866  Schema: mytable  QC_hit: No
# Query_time: 35.803294  Lock_time: 0.000042  Rows_sent: 0  Rows_examined: 1
SET timestamp=1393847628;
UPDATE cache
     SET locktime = 1393847592
     WHERE cacheid = 'cms_priv_user_23459';

Others are faster, but for such a MySQL-Query stil very slow:

# Thread_id: 4137  Schema: mytable  QC_hit: No
# Query_time: 1.119290  Lock_time: 0.000047  Rows_sent: 0  Rows_examined: 1
SET timestamp=1393846824;
UPDATE session
     SET lastactivity = 1393846818, badlocation = 0
     WHERE sessionhash = 'mysessionhash';

Its not a single problem, I get one slow query every 10-50 seconds (long_query_time is set to 1). Most of the querys are a kind of INSERT (for example UPDATE-Querys as you can see above), but there are also some selects.

From 418 slow querys

$ cat mysql-slow.log | grep Query_time | wc -l
418

there were 5 SELECTs

$ cat mysql-slow.log | grep SELECT | wc -l
22

By writing an addon that integrates SHOW PROFILE in my CMS I found out that the database-server is spending most of the time to wait for locks

Array
(
    [Query_ID] => 227
    [Duration] => 5.74142869
    [Query] => SELECT
        user.username, (user.options & 512) AS invisible, user.usergroupid, user.lastvisit,
        session.userid, session.inforum, session.lastactivity, session.badlocation,
        IF(displaygroupid=0, user.usergroupid, displaygroupid) AS displaygroupid, infractiongroupid

    FROM session AS session

)


Duration    Status
0.000030    starting
0.000011    Waiting for query cache lock
0.000076    checking query cache for query
0.000012    checking permissions
0.000011    checking permissions
0.000027    Opening tables
0.000012    System lock
0.000010    Table lock
5.126086    Waiting for table level lock
0.000020    Table lock
0.613440    Waiting for table level lock
0.000066    Table lock
0.000151    Waiting for query cache lock
0.000121    init
0.000108    optimizing
0.000066    statistics
0.000050    preparing
0.000074    executing
0.000115    Creating tmp table
0.000427    Copying to tmp table
0.000119    Sorting result
0.000116    Sending data
0.000064    end
0.000044    removing tmp table
0.000020    end
0.000019    query end
0.000027    closing tables
0.000025    freeing items
0.000056    updating status
0.000024    cleaning up

Thats strange, because in the slow-log mysql told me that Lock_time is very low and so I thought this can't be responsible for the long query time.

And why are tables locked on SELECT-Statements? What can I do to reduce the waiting here? The status variables tell me that this affects about 2% of the querys (About 3000k querys have to wait for a table lock out of 125000k). This is similar to my personal experience: Sometimes my page is loading very fast, sometimes it take about 4-5 seconds, other times about 15 seconds and in some cases I even get timeouts.

EDIT1:

I take a look at about 3 hours of slow query logs and it seems that the session-table is one of the main issues for slow querys. From about 550 querys are alone 160 UPDATE-querys to the session-table. But I really can't understand why just this table causes slowlogs, because It's a memory table. The table is also very small (currently about 200 rows, at peak maybe up to 400). So even with bad indexes there such a small query shouldn't nearly take 30 seconds and more. I thought a memory table should be optimal for performance in this case, but because it looks like it isn't I converted them to MyISAM for testing. The server is running now for only 20 minutes but it looks like this make nothing better: 53 slow 'UPDATE session' querys of 173 total slow querys. That's a factor of 0,30 and nearly even a little bit more than before with the memory tables (0,29). 0,3063583815028902

Edit2: A lot of opened tables

I see that I've a lot of opened tables, currently about 21,000, and the server is only running for about 6 hours. I have set table_open_cache to 6000. Would it make sense to increase this to lets say 25,000? Enough RAM is avaliable, I've currently 4-6GB which can be used for this.

migrated from serverfault.com Mar 5 '14 at 20:24

This question came from our site for system and network administrators.

  • Dumb questions : do you have good indexing policy ? Are the disk i/o saturated with writes ? (iostat -k 1 ) – Kwaio Mar 3 '14 at 13:45
  • I used our command when the site is hanging and there is not much i/o, at peak 3MB/s writing and much less reading (about 90% of my querys are read-querys). But i/o waiting time is mostly about 15-30%, sometimes shortly up to 40%. Indexing policy is a good question which I have to check, because I'm using vBulletin. – Lion Mar 3 '14 at 13:52
  • As @Kwaio said, maybe your indexing policy isn't good. Search in your logs for slow queries and see what tables are affected. Have in mind that INSERT and UPDATE commands require locking to populate the indexes. If your tables have more fields indexed than those you need, it may be slowing your site. BTW, how many rows have those tables? Have a lokk at this guy's post forums.digitalpoint.com/threads/optimize-vbulletin-4.1767626, it seems that you should clear the cache table from time to time. – ojovirtual Mar 3 '14 at 15:12
  • The table is very small, thats the strange thing (see EDIT1 below). But there are also other tables in the slowlog. Strangely I have much bigger tables (300,000 rows) which are only very rarely in the slowlog. I'm using vBulletin 2.2, in this version the cache-table is purged automatically. Currently are only 12 rows in the caching-table. – Lion Mar 3 '14 at 16:16
  • 2
    Try converting your tables to use InnoDB engine. InnoDB has row-level locking instead of MyISAM's table level locks, therefore the locking should not cause slowdowns like this. – Tero Kilkanen Mar 3 '14 at 17:45
1

I would have put it in a comment but do not have enough reputation to do so...
So here some advice I find useful when looking for performance issues like these. Use the -- MYSQL PERFORMANCE TUNING PRIMER -- - By: Matthew Montgomery - to check if your system in healthy, if you can improve parameter, do it first, since it will allow you to better test other options.
The entries in the slow_log help you but they can be misleading, e.g. when a connection explicitly or implicitly locks tables. I have seen it many times that the statements showing up in the slow_log are the victims, not the culprits.
You already got a very valuable suggestion with switching to InnoDB, MyISAM tables are notorious for locking the whole table for changes, mostly blocking the whole table on any update with default settings.
There is however one database engine that has even worse locking than MyISAM and most people will not ever assume it: the memory table engine (HEAP)
If a memory table is very active, and you are running low on memory, I have seen ungodly high waiting/lock waiting times on these. If your are very daring you can mount a tempfs directory in your MySQL database directory and create a temporary InnoDB database/table, otherwise a regular InnoDB with a somewhat more relaxed write policy will do the trick as well. Regular memory tables do not allow for the use of indexes which sometimes leads to very bad optimization of complex queries involving them.
To narrow down what is really causing the queries to wait for a lock, or better to find out what is locking them, you can use SHOW PROCESSLIST or the nice mytop tool. The processes with the highest time values are you most likely culprits. It is also noteworthy that you might find processes that are running way longer than long_query_time but will never show up in your slowlog, because they consist of multiple statements, all of which may execute fast enough one by one...
If you see a number of processes piling up in mytop, you should investigate the list carefully, since this is an easy way of finding the culprit!
If locking is introduced trough transactions (implicit or explicit) you can try to optimize the performance by changing your transaction isolation level with [SET TRANSACTION][2]. One has to be careful with this since thses changes sometimes tend to break (poorly written) applications, or better said applications that rely on a certain behaviour.
So if your locked tables on SELECT statements are locked by design, because someone misused the database as a glorified process lock (I have seen that before) it might break that intended behaviour at the same time as fixing your performance issue... good luck!

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.