Re: Strange behaviour with a query - Mailing list pgsql-admin

Hi everybody again.

Deleting rel_dis_can_fk index has solved the problem! But.... why??


-----Original Message-----
From: Iñigo Martinez Lasala <imartinez@vectorsf.com>
To: pgsql-admin <pgsql-admin@postgresql.org>
Cc: Jaume Sabater <jsabater@gmail.com>, Sergio Chavarria <sergio.chavarria@gmail.com>
Subject: Strange behaviour with a query
Date: Fri, 17 Apr 2009 10:44:29 +0200

In a production enviroment over Postgresql 8.2.13, we have found some queries take forever without finish until statement_timeout enters in play.
These queries are like this one:

SELECT ART.ART_ID, DIS.DIS_HORAS, ART.TIP_ID FROM ARTICULO ART,DISPONIBILIDAD DIS, ENTE ENT, PARTICIPACION PAR,CANCION C WHERE (ART.ART_APROBADO = 1) 
AND ((ART.ART_SHOW_ANYWAY = 1) OR (ART.ART_STOCK_ALMACEN_CENTRAL >=1) OR (ART.ART_STOCK_LOCAL  >=1) OR (ART.ART_STOCK_LOCAL_2 >= 1)  OR (ART.ART_STOCK >= 1)) 
AND (ART_DESCATALOGADO != 1) AND (ART_BUYABLE = 1) AND (NVL(ART.ART_PRECIO_FNAC_WEB,0) > 0) AND (ART.ART_PMP is not null) AND ART.TIP_ID =1  AND 
( (ENT.ent_nombre_search_string % 'COS') ) AND PAR.ROL_ID = 100004  AND PAR.ENT_ID = ENT.ENT_ID AND PAR.ART_ID = ART.ART_ID  AND ( (c.can_nombre_search_string % 'WHAT') ) 
AND C.ART_ID = ART.ART_ID  AND DIS.DIS_ID = ART.DIS_ID  AND ART.PRE_ID = 5  ORDER BY DIS.DIS_HORAS, ART_FECHA_UP DESC LIMIT 100;

Explain:
"Limit  (cost=2213.67..2213.67 rows=1 width=40)"
"  ->  Sort  (cost=2213.67..2213.67 rows=1 width=40)"
"        Sort Key: dis.dis_horas, art.art_fecha_up"
"        ->  Nested Loop  (cost=47.44..2213.66 rows=1 width=40)"
"              Join Filter: (dis.dis_id = art.dis_id)"
"              ->  Nested Loop  (cost=47.44..2212.39 rows=1 width=40)"
"                    ->  Nested Loop  (cost=47.44..2211.89 rows=1 width=52)"
"                          ->  Nested Loop  (cost=0.00..2160.43 rows=1 width=64)"
"                                ->  Index Scan using ix_pre_id on articulo art  (cost=0.00..2134.34 rows=3 width=40)"
"                                      Index Cond: (pre_id = 5::numeric)"
"                                      Filter: ((art_aprobado = 1::numeric) AND ((art_show_anyway = 1::numeric) OR (art_stock_almacen_central >= 1::numeric) OR (art_stock_local >= 1::numeric) OR (art_stock_local_2 >= 1::numeric) OR (art_stock >= 1::numeric)) AND (art_descatalogado <> 1::numeric) AND (art_buyable = 1::numeric) AND (nvl(art_precio_fnac_web, 0::numeric) > 0::numeric) AND (art_pmp IS NOT NULL) AND (tip_id = 1::numeric))"
"                                ->  Index Scan using rel_participacion_articulo_fk on participacion par  (cost=0.00..8.68 rows=1 width=24)"
"                                      Index Cond: (par.art_id = art.art_id)"
"                                      Filter: (rol_id = 100004::numeric)"
"                          ->  Bitmap Heap Scan on cancion c  (cost=47.44..51.45 rows=1 width=12)"
"                                Recheck Cond: ((c.art_id = art.art_id) AND ((c.can_nombre_search_string)::text % 'NOMBRE'::text))"
"                                ->  BitmapAnd  (cost=47.44..47.44 rows=1 width=0)"
"                                      ->  Bitmap Index Scan on rel_dis_can_fk  (cost=0.00..5.56 rows=163 width=0)"
"                                            Index Cond: (c.art_id = art.art_id)"
"                                      ->  Bitmap Index Scan on cancion_nombre_search_string_trgm  (cost=0.00..41.47 rows=650 width=0)"
"                                            Index Cond: ((can_nombre_search_string)::text % 'NOMBRE'::text)"
"                    ->  Index Scan using ix_ent_id on ente ent  (cost=0.00..0.48 rows=1 width=12)"
"                          Index Cond: (par.ent_id = ent.ent_id)"
"                          Filter: ((ent_nombre_search_string)::text % 'COS'::text)"
"              ->  Seq Scan on disponibilidad dis  (cost=0.00..1.12 rows=12 width=20)"



If I slightly change it by removing one of the conditions for CANCION table, it works an finish in miliseconds:

SELECT ART.ART_ID, DIS.DIS_HORAS, ART.TIP_ID FROM ARTICULO ART,DISPONIBILIDAD DIS, ENTE ENT, PARTICIPACION PAR,CANCION C WHERE (ART.ART_APROBADO = 1) 
AND ((ART.ART_SHOW_ANYWAY = 1) OR (ART.ART_STOCK_ALMACEN_CENTRAL >=1) OR (ART.ART_STOCK_LOCAL  >=1) OR (ART.ART_STOCK_LOCAL_2 >= 1)  OR (ART.ART_STOCK >= 1)) 
AND (ART_DESCATALOGADO != 1) AND (ART_BUYABLE = 1) AND (NVL(ART.ART_PRECIO_FNAC_WEB,0) > 0) AND (ART.ART_PMP is not null) AND ART.TIP_ID =1  AND 
( (ENT.ent_nombre_search_string % 'COS') ) AND PAR.ROL_ID = 100004  AND PAR.ENT_ID = ENT.ENT_ID AND PAR.ART_ID = ART.ART_ID  AND ( (c.can_nombre_search_string % 'WHAT') ) 
AND C.ART_ID = ART.ART_ID AND DIS.DIS_ID = ART.DIS_ID  AND ART.PRE_ID = 5  ORDER BY DIS.DIS_HORAS, ART_FECHA_UP DESC LIMIT 100;

SELECT ART.ART_ID, DIS.DIS_HORAS, ART.TIP_ID FROM ARTICULO ART,DISPONIBILIDAD DIS, ENTE ENT, PARTICIPACION PAR,CANCION C WHERE (ART.ART_APROBADO = 1) 
AND ((ART.ART_SHOW_ANYWAY = 1) OR (ART.ART_STOCK_ALMACEN_CENTRAL >=1) OR (ART.ART_STOCK_LOCAL  >=1) OR (ART.ART_STOCK_LOCAL_2 >= 1)  OR (ART.ART_STOCK >= 1)) 
AND (ART_DESCATALOGADO != 1) AND (ART_BUYABLE = 1) AND (NVL(ART.ART_PRECIO_FNAC_WEB,0) > 0) AND (ART.ART_PMP is not null) AND ART.TIP_ID =1  AND 
( (ENT.ent_nombre_search_string % 'COS') ) AND PAR.ROL_ID = 100004  AND PAR.ENT_ID = ENT.ENT_ID AND PAR.ART_ID = ART.ART_ID  AND ( (c.can_nombre_search_string % 'WHAT') ) 
AND C.ART_ID = ART.ART_ID AND DIS.DIS_ID = ART.DIS_ID  AND ART.PRE_ID = 5  ORDER BY DIS.DIS_HORAS, ART_FECHA_UP DESC LIMIT 100;


I have tried to VACUUM / ANALYZE and RECREATE indexes, change search string, but problem remains. If I launch a single select I also works:
SELECT * FROM CANCION C WHERE ( (c.can_nombre_search_string % 'WHAT') ) and ART_ID=223212;

Does anybody have an idea about what could be happening? With postgres 8.1.15 there was no problem with this query...

Thanks in advance.