Re: Slow SQL query (14-15 seconds)

From: Bruno Baguette <bruno(dot)baguette(at)gmail(dot)com>
To: Matthew Wakeling <matthew(at)flymine(dot)org>
Subject: Re: Slow SQL query (14-15 seconds)
Date: 2008-11-13 14:39:20
Message-ID: 491C3C18.6030901@gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Le 13/11/08 14:28, Matthew Wakeling a écrit :
> On Thu, 13 Nov 2008, Bruno Baguette wrote:
>> I'm having a problem with this query (below) that takes between 14 and
>> 15 seconds to run, which is too long for the end-user.
>>
>> I've done a EXPLAIN ANALYZE (below below) but I'm having difficulties
>> to see which part of that query is taking so many times.

Hello Matthew !

> As a general tip, if you're trying to work out which part of a query is
> taking time, and the query is fairly obviously made up of several parts,
> it would make sense to try them individually.

I did a try separately for each LEFT JOIN and EXISTS, but I didn't
understood that the EXISTS was guilty, since it was fast to me (indeed,
I did't saw that it was runned 818 times !).

With Tomasz, Tom and your suggest, I've changed the EXISTS subquery to a
IN subquery (cf. my answer to Tom). The query time was going from 14-15
seconds to ~5 seconds.

I just found an faster way by moving the "AND societe.is_deleted = FALSE
"from the main query to the IN subquery. The query is now running in 165
ms !!! :-)

Here's the current SQL query :

####################################
SELECT pk_societe_id,
denomination_commerciale,
denomination_sociale,
numero_client,
COALESCE(stats_commandes.nombre, 0) AS societe_nbre_commandes,
COALESCE(stats_adresses_livraison.nombre, 0) AS
societe_adresses_livraison_quantite,
COALESCE(stats_adresses_facturation.nombre, 0) AS
societe_adresses_facturation_quantite,
COALESCE(NULLIF(admin_email,''), NULLIF(admin_bis_email,''),
NULLIF(admin_ter_email,''), 'n/a') AS email,
COALESCE(NULLIF(admin_tel,''), NULLIF(admin_bis_tel,''),
NULLIF(admin_ter_tel,''), 'n/a') AS telephone,
remise_permanente,
is_horeca
FROM societes
LEFT JOIN (
SELECT societes.pk_societe_id AS societe_id,
COUNT(commandes.pk_commande_id) AS nombre
FROM commandes
INNER JOIN clients ON commandes.fk_client_id =
clients.pk_client_id
INNER JOIN societes ON clients.fk_societe_id =
societes.pk_societe_id
GROUP BY societes.pk_societe_id
) AS stats_commandes ON stats_commandes.societe_id =
societes.pk_societe_id
LEFT JOIN (
SELECT fk_societe_id AS societe_id,
COUNT(pk_adresse_livraison_id) AS nombre
FROM societes_adresses_livraison
WHERE is_deleted = FALSE
GROUP BY fk_societe_id
) AS stats_adresses_livraison ON
stats_adresses_livraison.societe_id = societes.pk_societe_id
LEFT JOIN (
SELECT fk_societe_id AS societe_id,
COUNT(pk_adresse_facturation_id) AS nombre
FROM societes_adresses_facturation
WHERE is_deleted = FALSE
GROUP BY fk_societe_id
) AS stats_adresses_facturation ON
stats_adresses_facturation.societe_id = societes.pk_societe_id
WHERE societes.pk_societe_id IN (
SELECT societe_client.pk_societe_id
FROM commandes
INNER JOIN clients ON
commandes.fk_client_id = clients.pk_client_id
INNER JOIN societes AS societe_client
ON clients.fk_societe_id = societe_client.pk_societe_id
WHERE delivery_date_livraison BETWEEN
(NOW() - '1 year'::interval) AND NOW()
AND societe_client.is_deleted = FALSE
)
ORDER BY LOWER(denomination_commerciale);
####################################

and the query plan :

####################################

QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=1311.74..1313.79 rows=821 width=147) (actual
time=162.924..163.400 rows=285 loops=1)
Sort Key: lower((societes.denomination_commerciale)::text)
-> Hash IN Join (cost=1196.61..1272.00 rows=821 width=147) (actual
time=137.164..160.354 rows=285 loops=1)
Hash Cond: ("outer".pk_societe_id = "inner".pk_societe_id)
-> Merge Left Join (cost=788.60..837.19 rows=903 width=147)
(actual time=95.140..116.124 rows=903 loops=1)
Merge Cond: ("outer".pk_societe_id = "inner".societe_id)
-> Merge Left Join (cost=695.31..728.65 rows=903
width=139) (actual time=83.413..97.585 rows=903 loops=1)
Merge Cond: ("outer".pk_societe_id =
"inner".societe_id)
-> Merge Left Join (cost=602.27..620.33 rows=903
width=131) (actual time=71.751..79.176 rows=903 loops=1)
Merge Cond: ("outer".pk_societe_id =
"inner".societe_id)
-> Sort (cost=89.36..91.62 rows=903
width=123) (actual time=5.966..7.494 rows=903 loops=1)
Sort Key: societes.pk_societe_id
-> Seq Scan on societes
(cost=0.00..45.03 rows=903 width=123) (actual time=0.007..2.775 rows=903
loops=1)
-> Sort (cost=512.91..515.17 rows=903
width=16) (actual time=65.773..66.726 rows=563 loops=1)
Sort Key: stats_commandes.societe_id
-> Subquery Scan stats_commandes
(cost=448.26..468.58 rows=903 width=16) (actual time=61.278..64.345
rows=563 loops=1)
-> HashAggregate
(cost=448.26..459.55 rows=903 width=16) (actual time=61.273..62.413
rows=563 loops=1)
-> Hash Join
(cost=132.44..423.38 rows=4977 width=16) (actual time=13.740..48.912
rows=5972 loops=1)
Hash Cond:
("outer".fk_client_id = "inner".pk_client_id)
-> Seq Scan on
commandes (cost=0.00..211.11 rows=6011 width=16) (actual
time=0.004..11.882 rows=5972 loops=1)
-> Hash
(cost=129.74..129.74 rows=1083 width=16) (actual time=13.711..13.711
rows=1082 loops=1)
-> Hash Join
(cost=47.29..129.74 rows=1083 width=16) (actual time=3.882..11.315
rows=1082 loops=1)
Hash
Cond: ("outer".fk_societe_id = "inner".pk_societe_id)
-> Seq
Scan on clients (cost=0.00..65.08 rows=1308 width=16) (actual
time=0.003..2.652 rows=1308 loops=1)
-> Hash
(cost=45.03..45.03 rows=903 width=8) (actual time=3.846..3.846
rows=903 loops=1)
->
Seq Scan on societes (cost=0.00..45.03 rows=903 width=8) (actual
time=0.004..1.897 rows=903 loops=1)
-> Sort (cost=93.04..95.21 rows=868 width=16)
(actual time=11.651..13.149 rows=885 loops=1)
Sort Key: stats_adresses_livraison.societe_id
-> Subquery Scan stats_adresses_livraison
(cost=31.14..50.67 rows=868 width=16) (actual time=4.602..9.398 rows=885
loops=1)
-> HashAggregate (cost=31.14..41.99
rows=868 width=16) (actual time=4.598..6.370 rows=885 loops=1)
-> Seq Scan on
societes_adresses_livraison (cost=0.00..26.19 rows=990 width=16)
(actual time=0.006..2.225 rows=991 loops=1)
Filter: (NOT is_deleted)
-> Sort (cost=93.29..95.46 rows=866 width=16) (actual
time=11.718..13.221 rows=903 loops=1)
Sort Key: stats_adresses_facturation.societe_id
-> Subquery Scan stats_adresses_facturation
(cost=31.55..51.04 rows=866 width=16) (actual time=4.502..9.424 rows=903
loops=1)
-> HashAggregate (cost=31.55..42.38
rows=866 width=16) (actual time=4.498..6.311 rows=903 loops=1)
-> Seq Scan on
societes_adresses_facturation (cost=0.00..26.84 rows=943 width=16)
(actual time=0.006..2.180 rows=943 loops=1)
Filter: (NOT is_deleted)
-> Hash (cost=403.31..403.31 rows=1877 width=16) (actual
time=41.623..41.623 rows=2677 loops=1)
-> Hash Join (cost=164.98..403.31 rows=1877 width=16)
(actual time=19.522..35.816 rows=2677 loops=1)
Hash Cond: ("outer".fk_client_id =
"inner".pk_client_id)
-> Bitmap Heap Scan on commandes
(cost=33.97..241.06 rows=2493 width=8) (actual time=6.043..11.625
rows=2774 loops=1)
Recheck Cond: ((delivery_date_livraison >=
(now() - '1 year'::interval)) AND (delivery_date_livraison <= now()))
-> Bitmap Index Scan on idx_date_livraison
(cost=0.00..33.97 rows=2493 width=0) (actual time=6.018..6.018
rows=2774 loops=1)
Index Cond: ((delivery_date_livraison
>= (now() - '1 year'::interval)) AND (delivery_date_livraison <= now()))
-> Hash (cost=128.55..128.55 rows=985 width=24)
(actual time=13.465..13.465 rows=1016 loops=1)
-> Hash Join (cost=47.08..128.55 rows=985
width=24) (actual time=4.062..11.293 rows=1016 loops=1)
Hash Cond: ("outer".fk_societe_id =
"inner".pk_societe_id)
-> Seq Scan on clients
(cost=0.00..65.08 rows=1308 width=16) (actual time=0.003..2.635
rows=1308 loops=1)
-> Hash (cost=45.03..45.03 rows=821
width=8) (actual time=4.002..4.002 rows=818 loops=1)
-> Seq Scan on societes
societe_client (cost=0.00..45.03 rows=821 width=8) (actual
time=0.006..2.363 rows=818 loops=1)
Filter: (NOT is_deleted)
Total runtime: 164.639 ms
(53 lignes)

####################################

To keep the reading easy, I've put a copy on pastebin :
<http://pastebin.com/m33388d93>

Many thanks everybody for your help !

King regards,

--
Bruno Baguette

In response to

Browse pgsql-performance by date

  From Date Subject
Next Message Bruno Baguette 2008-11-13 15:22:47 Re: Slow SQL query (14-15 seconds)
Previous Message Tom Lane 2008-11-13 14:30:08 Re: Slow SQL query (14-15 seconds)