I was checking the slow-query-log of MySQL, and found out an entry as below:
# Time: 131108 4:16:34
# Query_time: 14.726425 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 1
SET timestamp=1383884194;
UPDATE `Artist` SET ImageFilename = NULL, Title = 'Elton John', PopularityRating = 657, UniqueID = NULL, Description = NULL, IsFeatured = 0, FeaturedText = '', MetaDescription = '', MetaTitle = NULL, _Temporary_LastUpdOn = '2013-11-08 04:15:58 ', _Temporary_Flag = 0, _Deleted = 0, _DeletedOn = NULL, Priority = 0 WHERE ID = 3449748;
As you can see, it took a staggering 14.72sec to perform this query, when it is a simple update with just a WHERE
by primary key. I've tried re-executing the query, but now it executing in 0.095sec which is much more reasonable.
Any ideas how I can debug why at that specific time it took so long?
Edit 1: query_cache% variables
mysql> SHOW variables where variable_name like 'query_cache%';
+------------------------------+-----------+
| Variable_name | Value |
+------------------------------+-----------+
| query_cache_limit | 1048576 |
| query_cache_min_res_unit | 4096 |
| query_cache_size | 210763776 |
| query_cache_type | ON |
| query_cache_wlock_invalidate | OFF |
+------------------------------+-----------+
Edit 2: Artist table info
CREATE TABLE `artist` (
`ID` bigint(20) NOT NULL,
`ImageFilename` mediumtext,
`Title` varchar(1000) DEFAULT NULL,
`PopularityRating` int(11) DEFAULT '0',
`UniqueID` mediumtext,
`Description` mediumtext,
`IsFeatured` tinyint(1) DEFAULT '0',
`FeaturedText` mediumtext,
`_Temporary_LastUpdOn` datetime DEFAULT '0001-01-01 00:00:00',
`_Temporary_Flag` tinyint(1) DEFAULT '0',
`_Deleted` tinyint(1) DEFAULT '0',
`_DeletedOn` datetime DEFAULT NULL,
`Priority` int(11) DEFAULT '0',
`MetaDescription` varchar(2000) DEFAULT NULL,
`MetaTitle` mediumtext,
PRIMARY KEY (`ID`),
KEY `_Temporary_Flag` (`_Temporary_Flag`),
KEY `_Deleted` (`_Deleted`),
KEY `Priority` (`Priority`),
KEY `PopularityRating` (`PopularityRating`),
KEY `Title` (`Title`(255)),
KEY `IsFeatured` (`IsFeatured`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8
Given the output you have provided, my suggestion here would be to minimize your cache size. Its is ofcourse only my best assumption that this caused the update time to span over 15 seconds because the query itself is optimal using WHERE
on PRIMARY KEY
.
Since you havent been able to reproduced the problem its hard to determine.
I was reading the cache documentation again to get some info.
When tables are modified, any relevant entries in the query cache are flushed. This could be a reason for the update you did that it had to flush cached data.
Another part of the docmentation
Be cautious about sizing the query cache excessively large, which increases the overhead required to maintain the cache, possibly beyond the benefit of enabling it. Sizes in tens of megabytes are usually beneficial. Sizes in the hundreds of megabytes might not be.
Either way, since you have the query cache enabled, i think thats a good starting point.
To set a new query cache while in production
SET GLOBAL query_cache_size = 1000000;
Mysql will automatically set the size to be aligned to the nearest 1024 byte block.
Read this documentation well, its very helpful to understand. Query cache can at the same time be your best and your worst setting.
http://dev.mysql.com/doc/refman/5.1/en/query-cache.html
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With