Which Files In My Application that Make Slow Mysql Query Log Entries

Question

I have been struggling for 2 days for this problem and have not found a solution.

I log mysql slow query with 10 seconds period. In the log file there are a huge entries with this statement:

# Thread_id: 222244  Schema: user  QC_hit: No
# Query_time: 51.019708  Lock_time: 0.000119  Rows_sent: 1  Rows_examined: 13295012
# Rows_affected: 0
SET timestamp=1559388099;
SELECT (COUNT(*)) AS `count` 
FROM statistics Statistics WHERE (id >= 1 AND ad_type <> 3);

Which is associated with a surge in apache requests. The query_time is up to one minute or more completed and causes my server to be overloaded. The problem is I can't find which file in my php script that causes the slow queries.

Is there any command line to find the associated file. Or any fast way?

CREATE TABLE statistics` (
    id bigint(20) unsigned NOT NULL AUTO_INCREMENT, 
    ... , 
    PRIMARY KEY (id), 
    KEY idx_uid (uid), 
    KEY idx_ip (ip), 
    KEY idx_cnid_uid (cid,uid), 
    KEY idx_rlid (rid), 
    KEY idx_created_uid (created,uid)
) ENGINE=InnoDB AUTO_INCREMENT=34015 DEFAULT CHARSET=utf8

i have try this line, still no good: grep -HIi -rnw "Statistics" './public_html' | cut -d: -f1 — Drunken M, Jun 01 '19 at 12:32
Why are you aliasing your `statistics` table as `Statistics` — zanderwar, Jun 01 '19 at 12:36
Personally I'd hook up a proper PHP profiler, and then simply inspect where in the code the time is spent. But if you want to search for it manually, try for example `'id >='`, `'ad_type <>'`, `Statstic->find`, `Statistics->find`, `Statstic->find('count'`, `Statstics->find('count'`, `paginate('Statstic'`, `paginate('Statstics'`, `paginate($this->Statistic`, `paginate($this->Statistics`... and generally `find('count'` and `->count()`, as there's also count queries issued by the CakePHP core in various places, for example when saving data. Also try it with double quotes instead of single ones. — ndm, Jun 01 '19 at 13:25
And make sure that your columns are properly indexed, such a simple query shouldn't take any significant amount of time, even with millions of rows. — ndm, Jun 01 '19 at 13:26
@ndm I have id as primary key and 5 other columns indexed in that table. I think it suppose to be enough. And can you recommend me which php profiler to use? Thanks. — Drunken M, Jun 01 '19 at 14:05
Can you test sql query from terminal? How much you have memory? Test your app on other server setup,.. — Salines, Jun 01 '19 at 16:47
@RickJames `| statistics | CREATE TABLE `statistics` ( `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT, ... , PRIMARY KEY (`id`), KEY `idx_uid` (`uid`), KEY `idx_ip` (`ip`), KEY `idx_cnid_uid` (`cid`,`uid`), KEY `idx_rlid` (`rid`), KEY `idx_created_uid` (`created`,`uid`) ) ENGINE=InnoDB AUTO_INCREMENT=34015 DEFAULT CHARSET=utf8 |` — Drunken M, Jun 01 '19 at 16:55
@Salines Yes, all works fine. I just need to find the file and limit the associated query line. 8GB 4cpu — Drunken M, Jun 01 '19 at 16:59
Personally I'm usually using Xdebug for profiling. Anyways, according to the `CREATE TABLE` statement, there's no index on `ad_type`. — ndm, Jun 01 '19 at 22:04
@ndm I barely know about php profiler especially xdebug. I still need your help on it. I have create new question on that topic at https://stackoverflow.com/questions/56412381/how-to-trace-mysql-slow-query-log-file-entries-using-php-profiler . Please take a look. Thanks! — Drunken M, Jun 02 '19 at 05:18

score 1 · Accepted Answer · answered Jun 01 '19 at 22:27

1

If there is no reason for checking id >= 1, get rid of it -- it inhibits certain optimizations.

Then add INDEX(ad_type)

Still, I see no good reason for COUNT(*) on a 34K-row(?) table to take 51 seconds. Something else must be involved.

answered Jun 01 '19 at 22:27

Rick James

135,179
13
127
222

As I mention in the question, it's only happen when there's a spike on apache requests. My mpm prefork ``` StartServers 5 MinSpareServers 5 MaxSpareServers 10 MaxRequestWorkers 512 ServerLimit 512 MaxConnectionsPerChild 5000 ``` apache config ```Timeout 30 KeepAlive On MaxKeepAliveRequests 500 KeepAliveTimeout 5``` – Drunken M Jun 02 '19 at 03:49
I'm sorry, the previous create table values was from my debugging database, the real db shows this ```ENGINE=InnoDB AUTO_INCREMENT=13437433 DEFAULT CHARSET=latin1``` – Drunken M Jun 02 '19 at 03:56
I hope you can pinpoint to my problem. It's more about finding a bug in the application itself and eliminating it rather than optimizing a query statement. With the growth of around 5 million new rows weekly, it will soon become my big concern. I need to find out the related file in the script. As a temporary solution I have added index for ad_type. ```CREATE TABLE `statistics` (`id` bigint(20) unsigned NOT NULL AUTO_INCREMENT, ... , PRIMARY KEY (id), ..., KEY idx_created_uid (created,uid), KEY idx_adtype (ad_type)) ENGINE=InnoDB AUTO_INCREMENT=13455056 DEFAULT CHARSET=latin1``` – Drunken M Jun 02 '19 at 07:51
How much RAM? What are the settings of `innodb_buffer_pool_size` and `max_connections`? What datatype is `uid`? Please elaborate on why you need to run that count(*); my goal will be to avoid running it, or find a way to avoid running it during busy times. – Rick James Jun 02 '19 at 17:32
It's a bug! I eventually found it by grepping all possible keywords. Thanks for your help anyway. – Drunken M Jun 03 '19 at 01:26

Which Files In My Application that Make Slow Mysql Query Log Entries

1 Answers1