Bug #26339 Query hangs / State: statistics
Submitted: 13 Feb 2007 19:45 Modified: 16 Feb 2013 22:47
Reporter: Dimitri Roschkowski Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S2 (Serious)
Version:5.0.26, 5.0.41 OS:Any (2.6.19.2-grsec Linux)
Assigned to: CPU Architecture:Any
Triage: Triaged: D2 (Serious) / R5 (Severe) / E4 (High)

[13 Feb 2007 19:45] Dimitri Roschkowski
Description:
Sometimes Querys with multiple inner join parts hangs during/after the execution. The normal execution time of that qry is about 0.2 sec

This Bug appears every 3 or 4 days. "During the Bug" the server load is verry high, the bug stays about 1-2h, after that everything work normal.

How to repeat:
mysql> SHOW FULL PROCESSLIST\G
*************************** 1. row ***************************
     Id: 54905
   User: shop
   Host: localhost
     db: shop
Command: Query
   Time: 1150
  State: statistics
   Info: SELECT a.artikel_id as artikel_id,a.titel as titel,a.preis as preis,d.wert as bild1,e.wert as uebersicht_text,bestell_f.wert as bestellnr,g.wert as tech_det,h.wert as zielgruppe,i.wert as meinung,j.wert as groesse,bild2.wert as bild2 ,bild3.wert as bild3,bild4.wert as bild4,bild5.wert as bild5,bild6.wert as bild6,bild7.wert as bild7,bild8.wert as bild8,bild9.wert as bild9,bild10.wert as bild10,altpreis.wert as alt_preis FROM artikel a INNER JOIN objektgruppenzuordnung b ON a.artikel_id = b.artikel_id inner join features d on d.vorlage_item_id=58 and a.artikel_id = d.artikel_id inner join features e on e.vorlage_item_id=52 and a.artikel_id = e.artikel_id inner join features bestell_f on bestell_f.vorlage_item_id=57 and a.artikel_id = bestell_f.artikel_id inner join features g on g.vorlage_item_id=53 and a.artikel_id = g.artikel_id inner join features h on h.vorlage_item_id=55 and a.artikel_id = h.artikel_id inner join features i on i.vorlage_item_id=56 and a.artikel_id = i.artikel_id inner join features j on j.vorlage_item_id=63 and a.artikel_id = j.artikel_id inner join features bild2 on bild2.vorlage_item_id=59 and a.artikel_id = bild2.artikel_id inner join features bild3 on bild3.vorlage_item_id=60 and a.artikel_id = bild3.artikel_id  inner join features bild4 on bild4.vorlage_item_id=61 and a.artikel_id = bild4.artikel_id  inner join features bild5 on bild5.vorlage_item_id=62 and a.artikel_id = bild5.artikel_id  inner join features bild6 on bild6.vorlage_item_id=65 and a.artikel_id = bild6.artikel_id  inner join features bild7 on bild7.vorlage_item_id=66 and a.artikel_id = bild7.artikel_id  inner join features bild8 on bild8.vorlage_item_id=67 and a.artikel_id = bild8.artikel_id  inner join features bild9 on bild9.vorlage_item_id=68 and a.artikel_id = bild9.artikel_id  inner join features bild10 on bild10.vorlage_item_id=69 and a.artikel_id = bild10.artikel_id left join features altpreis on altpreis.vorlage_item_id=70 and a.artikel_id = altpreis.artikel_id where shop_id='6' and a.artikel_id='132'
[14 Feb 2007 6:51] Valeriy Kravchuk
Thank you for a problem report. It looks like a duplicate of a known bug #20932. Please, check.
[15 Feb 2007 17:46] Martin Friebe
Some Comments. But since from the data supplied only guesses can be taken, it will still be to the original bug reporter, to work out if this is the same bug or not.

It doesn't look to me like the original book:

1) bug #20932 is about the time it takes mysql do estimate a range of several 1000 values in a list (every combination of the 2 "column IN ()" clauses).
There are only 2 possible query plans, and both take a lot of time to estimate.

I don't see any big list in this bug, unless it is loaded from one of the tables?
However, the query here could potentially have a huge amount of possible QEP (Query Execution Plans)?

2) In bug #20932 the query always takes time in the optimizer. Apparently the query in this bug can run in normal time.

What both bugs may share, is that once a query is occupying the optimizer, any further query will be slowed down even more, as CPU resources need to be shared.
Thus if a lot of those queries hit together, a huge slow down can build up.

As a workaround playing with "force index" "STRAIGHT JOIN", optimizer_prune_level or optimizer_search_depth may help.
[15 Feb 2007 18:10] Dimitri Roschkowski
I don't think, this bug is a dupe of bug #20932. Bug #20932 describes a permanent problem. My Bug appears iregulary. And the query execution time variates from 0.2 sec to 2h!! (The task was killed by me after 2h)
[12 Mar 2007 11:44] Valeriy Kravchuk
Please, try to use newer version, 5.0.37. In case of the same problems, can you, please, upload dump of all the tables involved in the query?
[12 Apr 2007 23:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[13 Apr 2007 4:52] Valeriy Kravchuk
Feedback is still needed.
[13 May 2007 23:02] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[6 Nov 2007 21:40] Walter Hopgood
I have a user who wrote their own php/mysql story archive software package.  Since she moved her code onto my site, I'm seeing her code hang the mysql server with the same information listed here.  State is statistics, many left joins.  I'm wondering if there is a bug here.
[6 Nov 2007 22:03] Walter Hopgood
Forgot to mention - I am on 5.0.45.  The selection from "show full processlist" is as below.  I can provide tables if needed.

| 492815 | ncis | squidge.org:34737 | ncis_db | Query   | 1667 | statistics | SELECT ncis_series.id AS series_id, ncis_series.user_id, ncis_series.series_title, ncis_series.series_rating, ncis_series.series_summary, ncis_series.series_notes, DATE_FORMAT(ncis_series.series_date, '%d/%m/%Y') AS date_f, ncis_series.series_complete, 
                ncis_users.name, 
                ncis_ratings.name as rating_name
                , ncis_series_cats.series_id, ncis_series_cats.cat_id 
FROM ncis_series 
                 LEFT JOIN ncis_users ON ncis_users.id=ncis_series.user_id 
                 LEFT JOIN ncis_stories ON ncis_stories.series_id = ncis_series.id 
                LEFT JOIN ncis_ratings ON ncis_ratings.id = ncis_series.series_rating 
                 LEFT JOIN ncis_series_cats ON ncis_series_cats.series_id=ncis_series.id 
 LEFT JOIN ncis_stories_genres as t_genre_id1 ON ncis_stories.id = t_genre_id1.story_id LEFT JOIN ncis_stories_genres as t_genre_id2 ON t_genre_id1.story_id = t_genre_id2.story_id LEFT JOIN ncis_stories_genres as t_genre_id3 ON t_genre_id1.story_id = t_genre_id3.story_id LEFT JOIN ncis_stories_genres as t_genre_id4 ON t_genre_id1.story_id = t_genre_id4.story_id LEFT JOIN ncis_stories_genres as t_genre_id5 ON t_genre_id1.story_id = t_genre_id5.story_id LEFT JOIN ncis_stories_genres as t_genre_id6 ON t_genre_id1.story_id = t_genre_id6.story_id LEFT JOIN ncis_stories_genres as t_genre_id7 ON t_genre_id1.story_id = t_genre_id7.story_id LEFT JOIN ncis_stories_genres as t_genre_id8 ON t_genre_id1.story_id = t_genre_id8.story_id LEFT JOIN ncis_stories_genres as t_genre_id9 ON t_genre_id1.story_id = t_genre_id9.story_id LEFT JOIN ncis_stories_genres as t_genre_id10 ON t_genre_id1.story_id = t_genre_id10.story_id LEFT JOIN ncis_stories_genres as t_genre_id11 ON t_genre_id1.story_id = t_genre_id11.story_id LEFT JOIN ncis_stories_genres as t_genre_id12 ON t_genre_id1.story_id = t_genre_id12.story_id 
WHERE ncis_series_cats.cat_id = '00005' 
 AND (t_genre_id1.genre_id = '00012' AND t_genre_id2.genre_id = '00022' AND t_genre_id3.genre_id = '00004' AND t_genre_id4.genre_id = '00007' AND t_genre_id5.genre_id = '00002' AND t_genre_id6.genre_id = '00001' AND t_genre_id7.genre_id = '00015' AND t_genre_id8.genre_id = '00006' AND t_genre_id9.genre_id = '00017' AND t_genre_id10.genre_id = '00003' AND t_genre_id11.genre_id = '00005' AND t_genre_id12.genre_id = '00014') AND ncis_series.series_complete = 'Yes' AND ncis_stories.complete = 'Yes' ORDER BY name |
[19 Mar 2008 4:05] Doug Ferrier
I am running: 
Server version: 5.0.41-log MySQL Community Server (GPL)

On Linux 2.6.20-1.2312.fc5smp

I see very similar behavior to that described in this bug report.

I have a query which runs hundreds of times each minute. The query extracts the same 3 columns of information from the same table but uses a different value for the primary key in the where clause each time -->

SELECT id, colA, colB
FROM mytable
WHERE id = ?

? changes on each invocation of the query

id is the unique primary key for the table.

The query nominally returns the data in less than 0.1 seconds.

However on what appears to be a random basis it will stall in the Statistics state for long periods of time; typically 180 seconds to many thousands of seconds.

During these periods where the query gets stuck in the query optimizer all other transactions in the database get backed up and stalled in the statistics state.

At this point in time we have not been able to reliably reproduce the defect as our test case is only able to illicit the behavior from MySql about 10% of the time when it is run and we have not yet been able to trace what other Mysql activities may be interacting with the test case to induce the problem.
[20 Mar 2008 12:17] Susanne Ebrecht
MySQL 5.0.4x is very old.
Please can you try with newest version. MySQL 5.0.51a.

Also we need to now how we could reproduce this. If you still have this problems with newest version.
[20 Apr 2008 23:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[31 Mar 2009 0:04] Igor Babaev
Gleb, please analyze this bug.
[22 Apr 2009 15:51] charlie barkin
I have the same situation and  symptoms with Mysql ver. 5.0.67 (maked from sources on FreeBSD 6.3-STABLE amd64). 

Sometimes I see queries in "statistics" state. And other queries stay locked at this time.

Query   |  4516 | 
statistics | SELECT COUNT(DISTINCT BE.ID) as C FROM b_iblock BI..

Query   |  4364 | Locked 
| SELECT COUNT(DISTINCT BE.ID) as C FROM b_iblock BI..

(Bitrix's terible queries with multiple inner join parts).

 Tables in the database was in MyISAM format. After I convert them into InnoDB, problem seems to  disappear. But I'm not shure.. I'll watch for other mysql servers in my company.
[5 Mar 2010 11:49] Manyi Lu
No repeatable test case.
[7 Apr 2010 12:34] Chris Wilson
The following query takes 60-120 seconds to run, all of which is spent in the "statistics" state.

Removing some joins makes it much quicker, seemingly depending on the number of rows in the joined table. Therefore I think MySQL is doing a full scan of all joined tables while computing statistics. Therefore I think you will need the test data, uploaded to ftp.mysql.com (bug-data-26339.sql.bz2), to reproduce the problem.

mysql> select 1
from
    cust_order this_ 
inner join
    arrival_type arrivaltyp2_ 
        on this_.arrival_type_code=arrivaltyp2_.code 
left outer join
    location location3_ 
        on this_.destination_location_id=location3_.id 
        and this_.destination_location_site_id=location3_.location_site_id 
left outer join
    country country4_ 
        on location3_.country_id=country4_.id 
left outer join
    location_type locationty5_ 
        on location3_.location_type_code=locationty5_.code 
left outer join
    site site6_ 
        on location3_.parent_site_id=site6_.id 
left outer join
    port_type porttype7_ 
        on location3_.port_type_id=porttype7_.id 
left outer join
    project project8_ 
        on location3_.project_id=project8_.id 
left outer join
    contact contact9_ 
        on this_.invoice_site_id=contact9_.id 
        and this_.invoice_contact_id=contact9_.owner_site_id 
left outer join
    country country10_ 
        on contact9_.country_id=country10_.id 
left outer join
    org org11_ 
        on contact9_.org_id=org11_.id 
left outer join
    project project12_ 
        on contact9_.project_id=project12_.id 
left outer join
    project_site projectsit13_ 
        on contact9_.project_id=projectsit13_.project_id 
        and contact9_.owner_site_id=projectsit13_.site_id 
left outer join
    location location14_ 
        on this_.origin_location_id=location14_.id 
        and this_.origin_location_site_id=location14_.location_site_id 
left outer join
    product product15_ 
        on this_.product_id=product15_.id 
left outer join
    product_ltu productltu16_ 
        on product15_.dflt_ltu_id=productltu16_.id 
left outer join
    product_sku productsku17_ 
        on product15_.dflt_sku_id=productsku17_.id 
left outer join
    product product18_ 
        on product15_.productFamily_id=product18_.id 
inner join
    project project19_ 
        on this_.project_id=project19_.id 
left outer join
    country country20_ 
        on project19_.country_id=country20_.id 
left outer join
    org org21_ 
        on project19_.org_id=org21_.id 
left outer join
    project_purpose projectpur22_ 
        on project19_.purpose_id=projectpur22_.id 
left outer join
    region region23_ 
        on project19_.region_id=region23_.id 
left outer join
    subregion subregion24_ 
        on project19_.subregion_id=subregion24_.id 
inner join
    contact contact25_ 
        on this_.receiver_site_id=contact25_.id 
        and this_.receiver_contact_id=contact25_.owner_site_id 
inner join
    site site26_ 
        on this_.request_site_id=site26_.id 
left outer join
    building_type buildingty27_ 
        on site26_.site_bldg_type_id=buildingty27_.id 
left outer join
    distribution_type distributi28_ 
        on site26_.site_dstr_type_id=distributi28_.id 
left outer join
    org org29_ 
        on site26_.org_id=org29_.id 
left outer join
    site site30_ 
        on site26_.rptg_site_id=site30_.id 
inner join -- removing this join makes the query quite fast (6 seconds)
    contact contact31_ 
        on this_.sender_site_id=contact31_.id 
        and this_.sender_contact_id=contact31_.owner_site_id 
inner join -- removing this join makes the query quite fast (7 seconds)
    request_status requeststa32_ 
        on this_.status_code=requeststa32_.code 
inner join -- removing this join makes the query fast (<1 second)
    request_type requesttyp34_ 
        on this_.type_code=requesttyp34_.code 
where
    this_.id in (
        2917292, 2917390, 2917421
    )
    ;
Empty set (1 min 7.23 sec)
[2 Jul 2010 6:47] Shane Bester
Folks, anything more that say 5 or 6 joins and you should be tuning  optimizer_prune_level or optimizer_search_depth, as Martin said in his post.

Please see the mysql manual for those options descriptions.
[28 Oct 2010 16:53] Craig Adams
I am not sure that I can add more information to this thread.  I am running version 5.0.90 .  This is a public website and the problem occurs about once every two months.  I don't know the entire SQL statement because it is a dynamically created SQL based on user search criteria and only the first couple lines appear in the process list report.  (I will work on trying to identify a culprit by logging all the SQL).

The symptoms are similar to the above.  The statements gets hung up in the "statistics" state and all other requests are "locked" behind it.  In my case it does not resolve itself (after many hours), and I must restart the database server.
[16 Jan 2013 22:47] Sveta Smirnova
This could be potentially solved by new 5.6 feature: persistent InnoDB statistics. See http://dev.mysql.com/doc/refman/5.6/en/innodb-parameters.html#sysvar_innodb_stats_persiste...

In earlier version check if you run table maintenance commands and if issue can be solved if set innodb_stats_on_metadata to OFF
[17 Feb 2013 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".