MySQL query, 2 similar servers, 2 minute difference in execution times
- by mr12086
I had a similar question on stack overflow, but it seems to be more server/mysql setup related than coding.
The queries below all execute instantly on our development server where as they can take upto 2 minutes 20 seconds.
The query execution time seems to be affected by home ambiguous the LIKE string's are. If they closely match a country that has few matches it will take less time, and if you use something like 'ge' for germany - it will take longer to execute. But this doesn't always work out like that, at times its quite erratic.
Sending data appears to be the culprit but why and what does that mean. Also memory on production looks to be quite low (free memory)?
Production:
Intel Quad Xeon E3-1220 3.1GHz
4GB DDR3
2x 1TB SATA in RAID1
Network speed 100Mb
Ubuntu
Development
Intel Core i3-2100, 2C/4T, 3.10GHz
500 GB SATA - No RAID
4GB DDR3
UPDATE 2 :
mysqltuner output:
[prod]
-------- General Statistics --------------------------------------------------
[--] Skipped version check for MySQLTuner script
[OK] Currently running supported MySQL version 5.1.61-0ubuntu0.10.04.1
[OK] Operating on 64-bit architecture
-------- Storage Engine Statistics -------------------------------------------
[--] Status: +Archive -BDB -Federated +InnoDB -ISAM -NDBCluster
[--] Data in MyISAM tables: 103M (Tables: 180)
[--] Data in InnoDB tables: 491M (Tables: 19)
[!!] Total fragmented tables: 38
-------- Security Recommendations -------------------------------------------
[OK] All database users have passwords assigned
-------- Performance Metrics -------------------------------------------------
[--] Up for: 77d 4h 6m 1s (53M q [7.968 qps], 14M conn, TX: 87B, RX: 12B)
[--] Reads / Writes: 98% / 2%
[--] Total buffers: 58.0M global + 2.7M per thread (151 max threads)
[OK] Maximum possible memory usage: 463.8M (11% of installed RAM)
[OK] Slow queries: 0% (12K/53M)
[OK] Highest usage of available connections: 22% (34/151)
[OK] Key buffer size / total MyISAM indexes: 16.0M/10.6M
[OK] Key buffer hit rate: 98.7% (162M cached / 2M reads)
[OK] Query cache efficiency: 20.7% (7M cached / 36M selects)
[!!] Query cache prunes per day: 3934
[OK] Sorts requiring temporary tables: 1% (3K temp sorts / 230K sorts)
[!!] Joins performed without indexes: 71068
[OK] Temporary tables created on disk: 24% (3M on disk / 13M total)
[OK] Thread cache hit rate: 99% (690 created / 14M connections)
[!!] Table cache hit rate: 0% (64 open / 85M opened)
[OK] Open file limit used: 12% (128/1K)
[OK] Table locks acquired immediately: 99% (16M immediate / 16M locks)
[!!] InnoDB data size / buffer pool: 491.9M/8.0M
-------- Recommendations -----------------------------------------------------
General recommendations:
Run OPTIMIZE TABLE to defragment tables for better performance
Enable the slow query log to troubleshoot bad queries
Adjust your join queries to always utilize indexes
Increase table_cache gradually to avoid file descriptor limits
Variables to adjust:
query_cache_size (> 16M)
join_buffer_size (> 128.0K, or always use indexes with joins)
table_cache (> 64)
innodb_buffer_pool_size (>= 491M)
[dev]
-------- General Statistics --------------------------------------------------
[--] Skipped version check for MySQLTuner script
[OK] Currently running supported MySQL version 5.1.62-0ubuntu0.11.10.1
[!!] Switch to 64-bit OS - MySQL cannot currently use all of your RAM
-------- Storage Engine Statistics -------------------------------------------
[--] Status: +Archive -BDB -Federated +InnoDB -ISAM -NDBCluster
[--] Data in MyISAM tables: 185M (Tables: 632)
[--] Data in InnoDB tables: 967M (Tables: 38)
[!!] Total fragmented tables: 73
-------- Security Recommendations -------------------------------------------
[OK] All database users have passwords assigned
-------- Performance Metrics -------------------------------------------------
[--] Up for: 1d 2h 26m 9s (5K q [0.058 qps], 1K conn, TX: 4M, RX: 1M)
[--] Reads / Writes: 99% / 1%
[--] Total buffers: 58.0M global + 2.7M per thread (151 max threads)
[OK] Maximum possible memory usage: 463.8M (11% of installed RAM)
[OK] Slow queries: 0% (0/5K)
[OK] Highest usage of available connections: 1% (2/151)
[OK] Key buffer size / total MyISAM indexes: 16.0M/18.6M
[OK] Key buffer hit rate: 99.9% (60K cached / 36 reads)
[OK] Query cache efficiency: 44.5% (1K cached / 2K selects)
[OK] Query cache prunes per day: 0
[OK] Sorts requiring temporary tables: 0% (0 temp sorts / 44 sorts)
[OK] Temporary tables created on disk: 24% (162 on disk / 666 total)
[OK] Thread cache hit rate: 99% (2 created / 1K connections)
[!!] Table cache hit rate: 1% (64 open / 4K opened)
[OK] Open file limit used: 8% (88/1K)
[OK] Table locks acquired immediately: 100% (1K immediate / 1K locks)
[!!] InnoDB data size / buffer pool: 967.7M/8.0M
-------- Recommendations -----------------------------------------------------
General recommendations:
Run OPTIMIZE TABLE to defragment tables for better performance
Enable the slow query log to troubleshoot bad queries
Increase table_cache gradually to avoid file descriptor limits
Variables to adjust:
table_cache (> 64)
innodb_buffer_pool_size (>= 967M)
UPDATE 1:
When testing the queries listed here there is usually no more than one other query taking place, and usually none.
Because production is actually handling apache requests that development gets very few of as it's only myself and 1 other who accesses it - could the 4GB of RAM be getting exhausted by using the single machine for both apache and mysql server?
Production:
sudo hdparm -tT /dev/sda
/dev/sda:
Timing cached reads: 24872 MB in 2.00 seconds = 12450.72 MB/sec
Timing buffered disk reads: 368 MB in 3.00 seconds = 122.49 MB/sec
sudo hdparm -tT /dev/sdb
/dev/sdb:
Timing cached reads: 24786 MB in 2.00 seconds = 12407.22 MB/sec
Timing buffered disk reads: 350 MB in 3.00 seconds = 116.53 MB/sec
Server version(mysql + ubuntu versions): 5.1.61-0ubuntu0.10.04.1
Development:
sudo hdparm -tT /dev/sda
/dev/sda:
Timing cached reads: 10632 MB in 2.00 seconds = 5319.40 MB/sec
Timing buffered disk reads: 400 MB in 3.01 seconds = 132.85 MB/sec
Server version(mysql + ubuntu versions): 5.1.62-0ubuntu0.11.10.1
ORIGINAL DATA :
This query is NOT the query in question but is related so ill post it.
SELECT
f.form_question_has_answer_id
FROM
form_question_has_answer f
INNER JOIN
project_company_has_user p ON f.form_question_has_answer_user_id = p.project_company_has_user_user_id
INNER JOIN
company c ON p.project_company_has_user_company_id = c.company_id
INNER JOIN
project p2 ON p.project_company_has_user_project_id = p2.project_id
INNER JOIN
user u ON p.project_company_has_user_user_id = u.user_id
INNER JOIN
form f2 ON p.project_company_has_user_project_id = f2.form_project_id
WHERE
(f2.form_template_name = 'custom' AND p.project_company_has_user_garbage_collection = 0 AND p.project_company_has_user_project_id = '29') AND (LCASE(c.company_country) LIKE '%ge%' OR LCASE(c.company_country) LIKE '%abcde%') AND f.form_question_has_answer_form_id = '174'
And the explain plan for the above query is, run on both dev and production produce the same plan.
+----+-------------+-------+--------+----------------------------------------------------------------------------------------------------------------------------------------------+----------------------------------+---------+----------------------------------------------------+------+-------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+-------+--------+----------------------------------------------------------------------------------------------------------------------------------------------+----------------------------------+---------+----------------------------------------------------+------+-------------+
| 1 | SIMPLE | p2 | const | PRIMARY | PRIMARY | 4 | const | 1 | Using index |
| 1 | SIMPLE | f | ref | form_question_has_answer_form_id,form_question_has_answer_user_id | form_question_has_answer_form_id | 4 | const | 796 | Using where |
| 1 | SIMPLE | u | eq_ref | PRIMARY | PRIMARY | 4 | new_klarents.f.form_question_has_answer_user_id | 1 | Using index |
| 1 | SIMPLE | p | ref | project_company_has_user_unique_key,project_company_has_user_user_id,project_company_has_user_company_id,project_company_has_user_project_id | project_company_has_user_user_id | 4 | new_klarents.f.form_question_has_answer_user_id | 1 | Using where |
| 1 | SIMPLE | f2 | ref | form_project_id | form_project_id | 4 | const | 15 | Using where |
| 1 | SIMPLE | c | eq_ref | PRIMARY | PRIMARY | 4 | new_klarents.p.project_company_has_user_company_id | 1 | Using where |
+----+-------------+-------+--------+----------------------------------------------------------------------------------------------------------------------------------------------+----------------------------------+---------+----------------------------------------------------+------+-------------+
This query takes 2 minutes ~20 seconds to execute.
The query that is ACTUALLY being run on the server is this one:
SELECT
COUNT(*) AS num_results
FROM (SELECT
f.form_question_has_answer_id
FROM
form_question_has_answer f
INNER JOIN
project_company_has_user p ON f.form_question_has_answer_user_id = p.project_company_has_user_user_id
INNER JOIN
company c ON p.project_company_has_user_company_id = c.company_id
INNER JOIN
project p2 ON p.project_company_has_user_project_id = p2.project_id
INNER JOIN
user u ON p.project_company_has_user_user_id = u.user_id
INNER JOIN
form f2 ON p.project_company_has_user_project_id = f2.form_project_id
WHERE
(f2.form_template_name = 'custom' AND p.project_company_has_user_garbage_collection = 0 AND p.project_company_has_user_project_id = '29') AND (LCASE(c.company_country) LIKE '%ge%' OR LCASE(c.company_country) LIKE '%abcde%') AND f.form_question_has_answer_form_id = '174'
GROUP BY
f.form_question_has_answer_id;) dctrn_count_query;
With explain plans (again same on dev and production):
+----+-------------+-------+--------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------------+---------+----------------------------------------------------+------+------------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+-------+--------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------------+---------+----------------------------------------------------+------+------------------------------+
| 1 | PRIMARY | NULL | NULL | NULL | NULL | NULL | NULL | NULL | Select tables optimized away |
| 2 | DERIVED | p2 | const | PRIMARY | PRIMARY | 4 | | 1 | Using index |
| 2 | DERIVED | f | ref | form_question_has_answer_form_id,form_question_has_answer_user_id | form_question_has_answer_form_id | 4 | | 797 | Using where |
| 2 | DERIVED | p | ref | project_company_has_user_unique_key,project_company_has_user_user_id,project_company_has_user_company_id,project_company_has_user_project_id,project_company_has_user_garbage_collection | project_company_has_user_user_id | 4 | new_klarents.f.form_question_has_answer_user_id | 1 | Using where |
| 2 | DERIVED | f2 | ref | form_project_id | form_project_id | 4 | | 15 | Using where |
| 2 | DERIVED | c | eq_ref | PRIMARY | PRIMARY | 4 | new_klarents.p.project_company_has_user_company_id | 1 | Using where |
| 2 | DERIVED | u | eq_ref | PRIMARY | PRIMARY | 4 | new_klarents.p.project_company_has_user_user_id | 1 | Using where; Using index |
+----+-------------+-------+--------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------------+---------+----------------------------------------------------+------+------------------------------+
On the production server the information I have is as follows.
Upon execution:
+-------------+
| num_results |
+-------------+
| 3 |
+-------------+
1 row in set (2 min 14.28 sec)
Show profile:
+--------------------------------+------------+
| Status | Duration |
+--------------------------------+------------+
| starting | 0.000016 |
| checking query cache for query | 0.000057 |
| Opening tables | 0.004388 |
| System lock | 0.000003 |
| Table lock | 0.000036 |
| init | 0.000030 |
| optimizing | 0.000016 |
| statistics | 0.000111 |
| preparing | 0.000022 |
| executing | 0.000004 |
| Sorting result | 0.000002 |
| Sending data | 136.213836 |
| end | 0.000007 |
| query end | 0.000002 |
| freeing items | 0.004273 |
| storing result in query cache | 0.000010 |
| logging slow query | 0.000001 |
| logging slow query | 0.000002 |
| cleaning up | 0.000002 |
+--------------------------------+------------+
On development the results are as follows.
+-------------+
| num_results |
+-------------+
| 3 |
+-------------+
1 row in set (0.08 sec)
Again the profile for this query:
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| starting | 0.000022 |
| checking query cache for query | 0.000148 |
| Opening tables | 0.000025 |
| System lock | 0.000008 |
| Table lock | 0.000101 |
| optimizing | 0.000035 |
| statistics | 0.001019 |
| preparing | 0.000047 |
| executing | 0.000008 |
| Sorting result | 0.000005 |
| Sending data | 0.086565 |
| init | 0.000015 |
| optimizing | 0.000006 |
| executing | 0.000020 |
| end | 0.000004 |
| query end | 0.000004 |
| freeing items | 0.000028 |
| storing result in query cache | 0.000005 |
| removing tmp table | 0.000008 |
| closing tables | 0.000008 |
| logging slow query | 0.000002 |
| cleaning up | 0.000005 |
+--------------------------------+----------+
If i remove user and/or project innerjoins the query is reduced to 30s.
Last bit of information I have:
Mysqlserver and Apache are on the same box, there is only one box for production.
Production output from top: before & after.
top - 15:43:25 up 78 days, 12:11, 4 users, load average: 1.42, 0.99, 0.78
Tasks: 162 total, 2 running, 160 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.1%us, 50.4%sy, 0.0%ni, 49.5%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 4037868k total, 3772580k used, 265288k free, 243704k buffers
Swap: 3905528k total, 265384k used, 3640144k free, 1207944k cached
top - 15:44:31 up 78 days, 12:13, 4 users, load average: 1.94, 1.23, 0.87
Tasks: 160 total, 2 running, 157 sleeping, 0 stopped, 1 zombie
Cpu(s): 0.2%us, 50.6%sy, 0.0%ni, 49.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 4037868k total, 3834300k used, 203568k free, 243736k buffers
Swap: 3905528k total, 265384k used, 3640144k free, 1207804k cached
But this isn't a good representation of production's normal status so here is a grab of it from today outside of executing the queries.
top - 11:04:58 up 79 days, 7:33, 4 users, load average: 0.39, 0.58, 0.76
Tasks: 156 total, 1 running, 155 sleeping, 0 stopped, 0 zombie
Cpu(s): 3.3%us, 2.8%sy, 0.0%ni, 93.9%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 4037868k total, 3676136k used, 361732k free, 271480k buffers
Swap: 3905528k total, 268736k used, 3636792k free, 1063432k cached
Development: This one doesn't change during or after.
top - 15:47:07 up 110 days, 22:11, 7 users, load average: 0.17, 0.07, 0.06
Tasks: 210 total, 2 running, 208 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.1%us, 0.2%sy, 0.0%ni, 99.7%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 4111972k total, 1821100k used, 2290872k free, 238860k buffers
Swap: 4183036k total, 66472k used, 4116564k free, 921072k cached
