query sqlexplain interpretation
A user posted an EXPLAIN/query-statistics output asking why a three-table join (adatos/avalor/pruebas) took ~35 seconds. Art Kagel pointed out the optimizer estimated 1 row per table while the scans actually produced ~1.4M rows, a sign of stale or missing data distributions leading to a bad join order (table 'a' should have been scanned first); he recommended proper UPDATE STATISTICS (per the Performance Guide or his dostats utility). Fernando Nunes suggested the same, plus testing with the ORDERED hint. The user reported that updating statistics solved it. A side discussion clarified that AUTO_STAT_MODE/STATCHANGE only make statistics gathering selective, they don't run it automatically.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Hello: CAn someone helps me to understand why this query takes 35 seconds? Thank you. QUERY: (OPTIMIZATION TIMESTAMP: 11-05-2014 10:32:41) ------ select c.items,b.muestra,b.prueba,b.valor,b.comentario,a.fecha,a.sid,a.pid,a.demo4,a.de mo9 from adatos a,avalor b, pruebas c where a.sid=b.sid and a.fecha=b.fecha and a.baja=b.baja and a.baja=c.baja and a.baja='3000-01-01 00:00:00' and b.status in ('V','v','I','i') and b.prueba=c.codigo and c.clase='1' and a.fecha between '20140530' and '20140930' and pid='1055052' Estimated Cost: 5 Estimated # of Rows Returned: 1 1) informix.b: INDEX PATH Filters: informix.b.status IN ('V' , 'v' , 'I' , 'i' ) (1) Index Name: root. 104_24 Index Keys: fecha sid baja muestra prueba (Key-First) (Serial, fragments: ALL) Lower Index Filter: informix.b.fecha >= 20140530 Upper Index Filter: informix.b.fecha <= 20140930 Index Key Filters: (informix.b.baja = datetime(3000-01-01 00:00:00) year to second ) 2) informix.c: INDEX PATH Filters: informix.c.clase = '1' (1) Index Name: informix. 298_990 Index Keys: codigo baja (Serial, fragments: ALL) Lower Index Filter: (informix.b.prueba = informix.c.codigo AND informix.b.baja = informix.c.baja ) NESTED LOOP JOIN 3) informix.a: INDEX PATH Filters: informix.a.pid = '1055052' (1) Index Name: root. 183_710 Index Keys: fecha sid baja (Serial, fragments: ALL) Lower Index Filter: ((informix.a.baja = informix.b.baja AND informix.a.sid = informix.b.sid ) AND informix.a.fecha = informix.b.fecha ) NESTED LOOP JOIN Query statistics: ----------------- Table map : ---------------------------- Internal name Table name ---------------------------- t1 b t2 c t3 a type table rows_prod est_rows rows_scan time est_cost ------------------------------------------------------------------- scan t1 1422778 1 1640606 00:13.55 1 type table rows_prod est_rows rows_scan time est_cost ------------------------------------------------------------------- scan t2 1422337 1 1422337 00:22.01 0 type rows_prod est_rows time est_cost ------------------------------------------------- nljoin 1422337 1 00:36.10 3 type table rows_prod est_rows rows_scan time est_cost ------------------------------------------------------------------- scan t3 40 1 1422337 00:20.91 0 type rows_prod est_rows time est_cost ------------------------------------------------- nljoin 40 1 00:57.47 5 --001a1140e2c86c5f7005071e7926
Your data distributions are stale or non-existent. Look at the detail for the first table (t1) in the timing section. The optimizer estimated that this phase would return one row. However, it read through 1,640,606 rows and actually returned 1,422,778 rows. The second table (t2) is estimated to return one row as well, but it actually scanned 1,422,337 rows that matched the rows from t1 and selected all of them to join. The third table (t3) again estimated one row but matches 1,422,337 row in the join to t1+t2 and filtering removed all but 40 rows which were actually returned not the one row the optimizer estimated. All this means that the optimizer got bad information from your data distributions and so probably chose the wrong indexes and the wrong join order. It probably should have searched t3 first. Fix? Update statistics using the recommended protocols described in the Performance Guide or as they are implemented using my dostats_ng.ec utility. Dostats is included in the utils2_ak package which you can download from the IIUG Software Repository (www.iiug.org/software) for free. If you have not disabled AUS, then it is not configure properly to maintain stats for you. I maintain that dostats does a better job than AUS, but even up-to-date AUS, correctly configured, distributions are better than what you have now. Art --089e0160b9ca0db21505071f4d74
Thnank you. I'll try 2014-11-05 16:45 GMT+00:00 Art Kagel <art.kagel@gmail.com>: > Your data distributions are stale or non-existent. Look at the detail for > the first table (t1) in the timing section. The optimizer estimated that > this phase would return one row. However, it read through 1,640,606 rows > and actually returned 1,422,778 rows. > > The second table (t2) is estimated to return one row as well, but it > actually scanned 1,422,337 rows that matched the rows from t1 and selected > all of them to join. > > The third table (t3) again estimated one row but matches 1,422,337 row in > the join to t1+t2 and filtering removed all but 40 rows which were actually > returned not the one row the optimizer estimated. > > All this means that the optimizer got bad information from your data > distributions and so probably chose the wrong indexes and the wrong join > order. It probably should have searched t3 first. > > Fix? Update statistics using the recommended protocols described in the > Performance Guide or as they are implemented using my dostats_ng.ec > utility. Dostats is included in the utils2_ak package which you can > download from the IIUG Software Repository (www.iiug.org/software) for > free. > > If you have not disabled AUS, then it is not configure properly to maintain > stats for you. I maintain that dostats does a better job than AUS, but > even up-to-date AUS, correctly configured, distributions are better than > what you have now. > > Art > > --089e0160b9ca0db21505071f4d74 > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --089e01184afec2db1605071f9f9d
Just a side note, it is possible that you are missing other indexes that would have worked better, I'm assuming that this is not the case as the indexes chosen look reasonable. I think it is just a matter of the optimizer choosing the wrong table to scan first because the stale distributions implied that only one row would match the filter on that table and each of the others, so it didn't really matter which table was used first. Art Art S. Kagel, President and Principal Consultant ASK Database Management www.askdbmgt.com Blog: http://informix-myview.blogspot.com/ Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Wed, Nov 5, 2014 at 12:08 PM, Juan Francisco González Navarro < jfrancisco.navarro@gmail.com> wrote: > Thnank you. I'll try > > 2014-11-05 16:45 GMT+00:00 Art Kagel <art.kagel@gmail.com>: > > > Your data distributions are stale or non-existent. Look at the detail for > > the first table (t1) in the timing section. The optimizer estimated that > > this phase would return one row. However, it read through 1,640,606 rows > > and actually returned 1,422,778 rows. > > > > The second table (t2) is estimated to return one row as well, but it > > actually scanned 1,422,337 rows that matched the rows from t1 and > selected > > all of them to join. > > > > The third table (t3) again estimated one row but matches 1,422,337 row in > > the join to t1+t2 and filtering removed all but 40 rows which were > actually > > returned not the one row the optimizer estimated. > > > > All this means that the optimizer got bad information from your data > > distributions and so probably chose the wrong indexes and the wrong join > > order. It probably should have searched t3 first. > > > > Fix? Update statistics using the recommended protocols described in the > > Performance Guide or as they are implemented using my dostats_ng.ec > > utility. Dostats is included in the utils2_ak package which you can > > download from the IIUG Software Repository (www.iiug.org/software) for > > free. > > > > If you have not disabled AUS, then it is not configure properly to > maintain > > stats for you. I maintain that dostats does a better job than AUS, but > > even up-to-date AUS, correctly configured, distributions are better than > > what you have now. > > > > Art > > > > --089e0160b9ca0db21505071f4d74 > > > > > > > > > > ******************************************************************************* > > Forum Note: Use "Reply" to post a response in the discussion forum. > > > > > > --089e01184afec2db1605071f9f9d > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --089e0160b9ca79c73205071fc435
It's a bit harder for us to explain why it takes that time vs for you to say with why you think it shouldn't... We can see from the query plan that the starting point brings a lot of records... 1.4M... It's possible that if it started from another table it would bring less... is that your point? Or do you think it should work faster even considering the number of rows that match the conditions and the joins? We could start by obtaining counts of the several tables involved using the conditions (consider that if you're doing tabA.col1 = tabB.col1 AND tabB.col1 BETWEEN X and Y we would need the counts for tabA and tabB). That could give us a clue where to start the query... We can see that the 1.4 M rows are "transported" acrross the first join but it is drastically dropped to 40 rows on the last one... so it could be better to do thequery the other way round... and easy way to test this could be writing the tables in different order and use the hint ORDERED... Besides that and as Obnoxio would answer: Have you tried UPDATE STATISTICS? :) On Wed, Nov 5, 2014 at 3:45 PM, Juan Francisco González Navarro < jfrancisco.navarro@gmail.com> wrote: > Hello: > > CAn someone helps me to understand why this query takes 35 seconds? > > Thank you. > > QUERY: (OPTIMIZATION TIMESTAMP: 11-05-2014 10:32:41) > ------ > select > > > c.items,b.muestra,b.prueba,b.valor,b.comentario,a.fecha,a.sid,a.pid,a.demo4,a.de mo9 > from adatos a,avalor b, pruebas c where a.sid=b.sid and a.fecha=b.fecha and > a.baja=b.baja and a.baja=c.baja and a.baja='3000-01-01 00:00:00' and > b.status in ('V','v','I','i') and b.prueba=c.codigo and c.clase='1' and > a.fecha between '20140530' and '20140930' and pid='1055052' > > Estimated Cost: 5 > Estimated # of Rows Returned: 1 > > 1) informix.b: INDEX PATH > > Filters: informix.b.status IN ('V' , 'v' , 'I' , 'i' ) > > (1) Index Name: root. 104_24 > > Index Keys: fecha sid baja muestra prueba (Key-First) (Serial, > fragments: ALL) > > Lower Index Filter: informix.b.fecha >= 20140530 > > Upper Index Filter: informix.b.fecha <= 20140930 > > Index Key Filters: (informix.b.baja = datetime(3000-01-01 > 00:00:00) year to second ) > > 2) informix.c: INDEX PATH > > Filters: informix.c.clase = '1' > > (1) Index Name: informix. 298_990 > > Index Keys: codigo baja (Serial, fragments: ALL) > > Lower Index Filter: (informix.b.prueba = informix.c.codigo AND > informix.b.baja = informix.c.baja ) > NESTED LOOP JOIN > > 3) informix.a: INDEX PATH > > Filters: informix.a.pid = '1055052' > > (1) Index Name: root. 183_710 > > Index Keys: fecha sid baja (Serial, fragments: ALL) > > Lower Index Filter: ((informix.a.baja = informix.b.baja AND > informix.a.sid = informix.b.sid ) AND informix.a.fecha = informix.b.fecha ) > NESTED LOOP JOIN > > Query statistics: > ----------------- > > Table map : > ---------------------------- > Internal name Table name > ---------------------------- > t1 b > t2 c > t3 a > > type table rows_prod est_rows rows_scan time est_cost > ------------------------------------------------------------------- > scan t1 1422778 1 1640606 00:13.55 1 > > type table rows_prod est_rows rows_scan time est_cost > ------------------------------------------------------------------- > scan t2 1422337 1 1422337 00:22.01 0 > > type rows_prod est_rows time est_cost > ------------------------------------------------- > nljoin 1422337 1 00:36.10 3 > > type table rows_prod est_rows rows_scan time est_cost > ------------------------------------------------------------------- > scan t3 40 1 1422337 00:20.91 0 > > type rows_prod est_rows time est_cost > ------------------------------------------------- > nljoin 40 1 00:57.47 5 > > --001a1140e2c86c5f7005071e7926 > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > -- Fernando Nunes Portugal http://informix-technology.blogspot.com My email works... but I don't check it frequently... --001a11c2ffb6d9353b05071feab9
Hello Updating statistics works. Thank you. El nov 5, 2014 10:46 AM, "Juan Francisco González Navarro" < jfrancisco.navarro@gmail.com> escribió: > Hello: > > CAn someone helps me to understand why this query takes 35 seconds? > > Thank you. > > QUERY: (OPTIMIZATION TIMESTAMP: 11-05-2014 10:32:41) > ------ > select > > > c.items,b.muestra,b.prueba,b.valor,b.comentario,a.fecha,a.sid,a.pid,a.demo4,a.de mo9 > from adatos a,avalor b, pruebas c where a.sid=b.sid and a.fecha=b.fecha and > a.baja=b.baja and a.baja=c.baja and a.baja='3000-01-01 00:00:00' and > b.status in ('V','v','I','i') and b.prueba=c.codigo and c.clase='1' and > a.fecha between '20140530' and '20140930' and pid='1055052' > > Estimated Cost: 5 > Estimated # of Rows Returned: 1 > > 1) informix.b: INDEX PATH > > Filters: informix.b.status IN ('V' , 'v' , 'I' , 'i' ) > > (1) Index Name: root. 104_24 > > Index Keys: fecha sid baja muestra prueba (Key-First) (Serial, > fragments: ALL) > > Lower Index Filter: informix.b.fecha >= 20140530 > > Upper Index Filter: informix.b.fecha <= 20140930 > > Index Key Filters: (informix.b.baja = datetime(3000-01-01 > 00:00:00) year to second ) > > 2) informix.c: INDEX PATH > > Filters: informix.c.clase = '1' > > (1) Index Name: informix. 298_990 > > Index Keys: codigo baja (Serial, fragments: ALL) > > Lower Index Filter: (informix.b.prueba = informix.c.codigo AND > informix.b.baja = informix.c.baja ) > NESTED LOOP JOIN > > 3) informix.a: INDEX PATH > > Filters: informix.a.pid = '1055052' > > (1) Index Name: root. 183_710 > > Index Keys: fecha sid baja (Serial, fragments: ALL) > > Lower Index Filter: ((informix.a.baja = informix.b.baja AND > informix.a.sid = informix.b.sid ) AND informix.a.fecha = informix.b.fecha ) > NESTED LOOP JOIN > > Query statistics: > ----------------- > > Table map : > ---------------------------- > Internal name Table name > ---------------------------- > t1 b > t2 c > t3 a > > type table rows_prod est_rows rows_scan time est_cost > ------------------------------------------------------------------- > scan t1 1422778 1 1640606 00:13.55 1 > > type table rows_prod est_rows rows_scan time est_cost > ------------------------------------------------------------------- > scan t2 1422337 1 1422337 00:22.01 0 > > type rows_prod est_rows time est_cost > ------------------------------------------------- > nljoin 1422337 1 00:36.10 3 > > type table rows_prod est_rows rows_scan time est_cost > ------------------------------------------------------------------- > scan t3 40 1 1422337 00:20.91 0 > > type rows_prod est_rows time est_cost > ------------------------------------------------- > nljoin 40 1 00:57.47 5 > > --001a1140e2c86c5f7005071e7926 > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001a113ebb0e11a7d1050731467f
Obnoxio was right! Actually it works most of the times.... that's why our optimizer is considered very good. Fuel it with the right information and it makes good choices most of the times. Not all, but most of the times... Regards On Thu, Nov 6, 2014 at 2:11 PM, Juan Francisco González Navarro < jfrancisco.navarro@gmail.com> wrote: > Hello > > Updating statistics works. > > Thank you. > El nov 5, 2014 10:46 AM, "Juan Francisco González Navarro" < > jfrancisco.navarro@gmail.com> escribió: > > > Hello: > > > > CAn someone helps me to understand why this query takes 35 seconds? > > > > Thank you. > > > > QUERY: (OPTIMIZATION TIMESTAMP: 11-05-2014 10:32:41) > > ------ > > select > > > > > > > > c.items,b.muestra,b.prueba,b.valor,b.comentario,a.fecha,a.sid,a.pid,a.demo4,a.de mo9 > > from adatos a,avalor b, pruebas c where a.sid=b.sid and a.fecha=b.fecha > and > > a.baja=b.baja and a.baja=c.baja and a.baja='3000-01-01 00:00:00' and > > b.status in ('V','v','I','i') and b.prueba=c.codigo and c.clase='1' and > > a.fecha between '20140530' and '20140930' and pid='1055052' > > > > Estimated Cost: 5 > > Estimated # of Rows Returned: 1 > > > > 1) informix.b: INDEX PATH > > > > Filters: informix.b.status IN ('V' , 'v' , 'I' , 'i' ) > > > > (1) Index Name: root. 104_24 > > > > Index Keys: fecha sid baja muestra prueba (Key-First) (Serial, > > fragments: ALL) > > > > Lower Index Filter: informix.b.fecha >= 20140530 > > > > Upper Index Filter: informix.b.fecha <= 20140930 > > > > Index Key Filters: (informix.b.baja = datetime(3000-01-01 > > 00:00:00) year to second ) > > > > 2) informix.c: INDEX PATH > > > > Filters: informix.c.clase = '1' > > > > (1) Index Name: informix. 298_990 > > > > Index Keys: codigo baja (Serial, fragments: ALL) > > > > Lower Index Filter: (informix.b.prueba = informix.c.codigo AND > > informix.b.baja = informix.c.baja ) > > NESTED LOOP JOIN > > > > 3) informix.a: INDEX PATH > > > > Filters: informix.a.pid = '1055052' > > > > (1) Index Name: root. 183_710 > > > > Index Keys: fecha sid baja (Serial, fragments: ALL) > > > > Lower Index Filter: ((informix.a.baja = informix.b.baja AND > > informix.a.sid = informix.b.sid ) AND informix.a.fecha = > informix.b.fecha ) > > NESTED LOOP JOIN > > > > Query statistics: > > ----------------- > > > > Table map : > > ---------------------------- > > Internal name Table name > > ---------------------------- > > t1 b > > t2 c > > t3 a > > > > type table rows_prod est_rows rows_scan time est_cost > > ------------------------------------------------------------------- > > scan t1 1422778 1 1640606 00:13.55 1 > > > > type table rows_prod est_rows rows_scan time est_cost > > ------------------------------------------------------------------- > > scan t2 1422337 1 1422337 00:22.01 0 > > > > type rows_prod est_rows time est_cost > > ------------------------------------------------- > > nljoin 1422337 1 00:36.10 3 > > > > type table rows_prod est_rows rows_scan time est_cost > > ------------------------------------------------------------------- > > scan t3 40 1 1422337 00:20.91 0 > > > > type rows_prod est_rows time est_cost > > ------------------------------------------------- > > nljoin 40 1 00:57.47 5 > > > > --001a1140e2c86c5f7005071e7926 > > > > > > > > > > ******************************************************************************* > > Forum Note: Use "Reply" to post a response in the discussion forum. > > > > > > --001a113ebb0e11a7d1050731467f > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > -- Fernando Nunes Portugal http://informix-technology.blogspot.com My email works... but I don't check it frequently... --047d7bd6b8561470f1050731a81f
Hi Juan. Have you tried automatic statistics collection? Just 2 parameters in your onconfig file: AUTO_STAT_MODE 1 - Enables it STATCHANGE 10 - (i.e) Rebuild stastistics if 10% of table/fragment/index changed. It's an usefull feature and make DBAs sleep better ;)
I'm very sorry to bring the bad news, but AUTO_STAT_MODE does NOT activate automatic statistics gathering.... It activates SELECTIVE statistics gathering which is totally different. It means that whenever and however you run update statistics, the engine may decide to ignore you if there were no significant (STATCHANGE) canges in the tables. In order to gather the statistics you need to use the automatics task or a script or a tool like Art's dostats. And be careful with these parameters, because sometimes 9% changes can make a difference... Regards. On Thu, Nov 6, 2014 at 3:25 PM, RAFAEL GOMEZ <rgomezs@gmail.com> wrote: > Hi Juan. > > Have you tried automatic statistics collection? > > Just 2 parameters in your onconfig file: > > AUTO_STAT_MODE 1 - Enables it > STATCHANGE 10 - (i.e) Rebuild stastistics if 10% of table/fragment/index > changed. > > It's an usefull feature and make DBAs sleep better ;) > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > -- Fernando Nunes Portugal http://informix-technology.blogspot.com My email works... but I don't check it frequently... --001a11c2ffb6aec255050732ad94
Hi Fernando. You're right, thanks for explain it, and sorry by my mistake. I was confused because "Auto Update Statistics Evaluation" and "Auto Update Statistics Refresh" tasks in sysadmin:ph_task are activated by default in all my servers. Greetings.