We have a search engine on one of our sites, which is very slow. I turned on the slow query log and logged all requests that take longer than 10 seconds. Only requests from this search engine are recorded. Here is one example log:
# Time: 120801 9:21:42
As you can see, it took about 22 seconds to complete the query, if you execute the same query directly in MySQL, it takes about 4 seconds.
I did EXPLAIN in the same query, and uotput looks like this:
id select_type table type possible_keys key key_len ref rows Extra 1 PRIMARY <derived2> ALL NULL NULL NULL NULL 33 Using filesort 2 DERIVED search_people ALL NULL NULL NULL NULL 323 Using where; Using temporary 2 DERIVED search_people_branches ALL NULL NULL NULL NULL 2013 Distinct 2 DERIVED search_people_specialismen ALL NULL NULL NULL NULL 1013 Distinct 2 DERIVED wpu ref user_id user_id 8 wordpress.search_people.ForeignId 84 Using index; Distinct 3 DEPENDENT SUBQUERY search_hasarticles ALL NULL NULL NULL NULL 101 Using where 4 UNION search_branches ALL NULL NULL NULL NULL 19 Using where; Using temporary 4 UNION search_people ALL NULL NULL NULL NULL 323 Using where; Using join buffer 4 UNION search_people_specialismen ALL NULL NULL NULL NULL 1013 Distinct 4 UNION search_people_branches ALL NULL NULL NULL NULL 2013 Using where; Distinct; Using join buffer 5 DEPENDENT SUBQUERY search_hasarticles ALL NULL NULL NULL NULL 101 Using where 6 UNION search_specialties ALL NULL NULL NULL NULL 73 Using where; Using temporary 6 UNION search_people ALL NULL NULL NULL NULL 323 Using where; Using join buffer 6 UNION search_people_specialismen ALL NULL NULL NULL NULL 1013 Using where; Distinct; Using join buffer 6 UNION search_people_branches ALL NULL NULL NULL NULL 2013 Distinct 7 DEPENDENT SUBQUERY search_hasarticles ALL NULL NULL NULL NULL 101 Using where 8 UNION search_posts ALL NULL NULL NULL NULL 15860 Using where; Using temporary 8 UNION search_posts_branches ALL NULL NULL NULL NULL 149 Distinct 8 UNION search_branches ALL NULL NULL NULL NULL 19 Distinct 8 UNION search_people_specialismen ALL NULL NULL NULL NULL 1013 Distinct 8 UNION search_specialties ALL NULL NULL NULL NULL 73 Using where; Distinct 8 UNION search_people ALL NULL NULL NULL NULL 323 Using where; Distinct; Using join buffer UNION RESULT <union2,4,6,8> ALL NULL NULL NULL NULL NULL
Can someone explain why the same query is much slower on my website and then directly to MySQL? Or, more importantly, is there a way to make this request faster on this website?
If you need more troubleshooting information, give a shout and I will try to provide them.
Thanks a lot in advance, January
This is the request PROFILE:
+----------------------+----------+ | Status | Duration | +----------------------+----------+ | starting | 0.000431 | | Opening tables | 0.002004 | | System lock | 0.000012 | | Table lock | 0.000502 | | optimizing | 0.000033 | | statistics | 0.000042 | | preparing | 0.000034 | | Creating tmp table | 0.000085 | | executing | 0.000004 | | Copying to tmp table | 0.001957 | | Sending data | 0.000006 | | optimizing | 0.000025 | | statistics | 0.000027 | | preparing | 0.000041 | | Creating tmp table | 0.000114 | | executing | 0.000001 | | Copying to tmp table | 0.000058 | | Sending data | 0.000004 | | optimizing | 0.000021 | | statistics | 0.000027 | | preparing | 0.000037 | | Creating tmp table | 0.000095 | | executing | 0.000003 | | Copying to tmp table | 0.007376 | | optimizing | 0.000013 | | statistics | 0.000017 | | preparing | 0.000011 | | executing | 0.000005 | | Sending data | 0.001248 | | executing | 0.000014 | | Sending data | 0.001894 | | executing | 0.000007 | | Sending data | 0.003249 | | executing | 0.000004 | | Sending data | 0.001487 | | executing | 0.000001 | | Sending data | 0.000433 | | executing | 0.000001 | | Sending data | 0.012100 | | executing | 0.000006 | | Sending data | 0.000713 | | executing | 0.000002 | | Sending data | 0.000681 | | executing | 0.000001 | | Sending data | 0.015382 | | executing | 0.000005 | | Sending data | 0.001048 | | executing | 0.000002 | | Sending data | 0.000916 | | executing | 0.000004 | | Sending data | 0.000421 | | executing | 0.000001 | | Sending data | 0.000561 | | executing | 0.000001 | | Sending data | 0.005126 | | executing | 0.000008 | | Sending data | 0.014534 | | executing | 0.000004 | | Sending data | 0.001666 | | executing | 0.000006 | | Sending data | 0.001641 | | Sending data | 0.000203 | | optimizing | 0.000045 | | statistics | 0.000050 | | preparing | 0.000049 | | Creating tmp table | 0.000182 | | executing | 0.000002 | | Copying to tmp table | 5.101209 | | Sending data | 0.000226 | | optimizing | 0.000007 | | statistics | 0.000008 | | preparing | 0.000007 | | executing | 0.000001 | | Sending data | 0.000217 | | removing tmp table | 0.000044 | | Sending data | 0.000007 | | removing tmp table | 0.000012 | | Sending data | 0.000017 | | removing tmp table | 0.000011 | | Sending data | 0.000005 | | removing tmp table | 0.000033 | | Sending data | 0.000008 | | removing tmp table | 0.000030 | | Sending data | 0.000009 | | init | 0.000044 | | optimizing | 0.000005 | | statistics | 0.000004 | | preparing | 0.000007 | | executing | 0.000002 | | Sorting result | 0.000074 | | Sending data | 0.000164 | | end | 0.000003 | | query end | 0.000005 | | freeing items | 0.000210 | | removing tmp table | 0.000061 | | closing tables | 0.000051 | | logging slow query | 0.000003 | | cleaning up | 0.000026 | +----------------------+----------+
source share