Обсуждение: Slow Query - Postgres 9.2

Поиск
Список
Период
Сортировка

Slow Query - Postgres 9.2

От
"drum.lucas@gmail.com"
Дата:
Hi all...

I'm working on a Slow Query. It's faster now (It was 20sec before) but still not good.

Can you have a look and see if you can find something?
Cheers

Query:

WITH jobs AS (   SELECT       job.id,       job.clientid,       CONCAT(customer.company, ' ', customer.name_first, ' ', customer.name_last) AS "identity",       job.gps_lat,       job.gps_long   FROM public.ja_jobs AS job   JOIN public.ja_customers AS customer ON customer.id = job.customerid   WHERE       job.clientid = 22       AND job.time_job >= 1422702000       AND job.time_job <= 1456743540
       AND NOT job.deleted       AND NOT job.templated
), items AS (   SELECT       job.identity,       COALESCE(bill_item.unit_cost, billable.unit_cost, 0) * bill_item.quantity AS cost,       COALESCE(bill_item.unit_price, billable.unit_price, 0) * bill_item.quantity AS revenue,       bill_item.quantity AS quantity,       note.n_quote_status,       bill_item.for_invoicing   FROM       jobs AS job   JOIN       public.ja_notes AS note       ON           note.jobid = job.id           AND note.note_type IN ('time', 'part')   JOIN       dm.bill_items AS bill_item       ON           bill_item.bill_item_id = note.bill_item_id           AND bill_item.for_invoicing   LEFT JOIN       dm.billables AS billable       ON           billable.billable_id = note.billable_id   JOIN       public.ja_mobiusers AS user_creator       ON           user_creator.id = note.mobiuserid           AND (               user_creator.name_first ilike 'Alan'               OR user_creator.name_last ilike 'Alan'           )
)
SELECT   item.identity,   SUM(CASE WHEN item.for_invoicing THEN item.revenue ELSE 0 END) AS revenue,   SUM(CASE WHEN item.for_invoicing THEN item.quantity ELSE 0 END) AS quantity,   SUM(CASE WHEN item.for_invoicing THEN item.cost ELSE 0 END) AS cost
FROM   items AS item
GROUP BY   item.identity
ORDER BY   revenue DESC,   item.identity ASC

Explain analyze link: http://explain.depesz.com/s/IIDj


Re: Slow Query - Postgres 9.2

От
Vitaly Burovoy
Дата:
On 3/2/16, drum.lucas@gmail.com <drum.lucas@gmail.com> wrote:
> Hi all...
>
> I'm working on a Slow Query. It's faster now (It was 20sec before) but
> still not good.
>
> Can you have a look and see if you can find something?
> Cheers
>
> Query:
>
> WITH jobs AS (
>     ...
>     FROM
>         jobs AS job
>     JOIN
>         public.ja_notes AS note
>         ON
>             note.jobid = job.id
>             AND note.note_type IN ('time', 'part')
>     ...

It is the most long part. All query is 8.8sec.
SeqScan by CTE is 2.8sec! and index scan in ix_notes_jobid_per_type
500rows(loops) * 9.878ms!!! = 4.939sec.

Why does it take so long time?
For example, index scan in ja_customers_pkey is only 0.781 per row...
10 times faster!

What definition of the ix_notes_jobid_per_type? Is it bloated?

> Explain analyze link: http://explain.depesz.com/s/IIDj
>


--
Best regards,
Vitaly Burovoy


Re: Slow Query - Postgres 9.2

От
"drum.lucas@gmail.com"
Дата:


On 3 March 2016 at 10:33, Vitaly Burovoy <vitaly.burovoy@gmail.com> wrote:
On 3/2/16, drum.lucas@gmail.com <drum.lucas@gmail.com> wrote:
> Hi all...
>
> I'm working on a Slow Query. It's faster now (It was 20sec before) but
> still not good.
>
> Can you have a look and see if you can find something?
> Cheers
>
> Query:
>
> WITH jobs AS (
>     ...
>     FROM
>         jobs AS job
>     JOIN
>         public.ja_notes AS note
>         ON
>             note.jobid = job.id
>             AND note.note_type IN ('time', 'part')
>     ...

It is the most long part. All query is 8.8sec.
SeqScan by CTE is 2.8sec! and index scan in ix_notes_jobid_per_type
500rows(loops) * 9.878ms!!! = 4.939sec.

Why does it take so long time?
For example, index scan in ja_customers_pkey is only 0.781 per row...
10 times faster!

What definition of the ix_notes_jobid_per_type? Is it bloated?


Hi there!

CREATE INDEX
    ix_notes_jobid_per_type
ON
    ja_notes
    (
        "jobid",
        "note_type"
    ); 


\di+ ix_notes_jobid_per_type

                                   List of relations

 Schema |          Name           | Type  |  Owner   |  Table   |  Size  | Description 

--------+-------------------------+-------+----------+----------+--------+-------------

 public | ix_notes_jobid_per_type | index | postgres | ja_notes | 484 MB | 



it does not seem to be bloated... since the table is 2805 MB

Re: Slow Query - Postgres 9.2

От
Vitaly Burovoy
Дата:
On 3/2/16, drum.lucas@gmail.com <drum.lucas@gmail.com> wrote:
> On 3 March 2016 at 10:33, Vitaly Burovoy <vitaly.burovoy@gmail.com> wrote:
>> On 3/2/16, drum.lucas@gmail.com <drum.lucas@gmail.com> wrote:
>> > Hi all...
>> >
>> > I'm working on a Slow Query. It's faster now (It was 20sec before) but
>> > still not good.
>> >
>> > Can you have a look and see if you can find something?
>> > Cheers
>> >
>> > Query:
>> >
>> > WITH jobs AS (
>> >     ...
>> >     FROM
>> >         jobs AS job
>> >     JOIN
>> >         public.ja_notes AS note
>> >         ON
>> >             note.jobid = job.id
>> >             AND note.note_type IN ('time', 'part')
>> >     ...
>>
>> It is the most long part. All query is 8.8sec.
>> SeqScan by CTE is 2.8sec! and index scan in ix_notes_jobid_per_type
>> 500rows(loops) * 9.878ms!!! = 4.939sec.
>>
>> Why does it take so long time?
>> For example, index scan in ja_customers_pkey is only 0.781 per row...
>> 10 times faster!
>>
>> What definition of the ix_notes_jobid_per_type? Is it bloated?
>>
>>
>> Hi there!
>
> CREATE INDEX
>     ix_notes_jobid_per_type
> ON
>     ja_notes
>     (
>         "jobid",
>         "note_type"
>     );
>
>
> \di+ ix_notes_jobid_per_type
>
>                                    List of relations
>
>  Schema |          Name           | Type  |  Owner   |  Table   |  Size  |
> Description
>
> --------+-------------------------+-------+----------+----------+--------+-------------
>
>  public | ix_notes_jobid_per_type | index | postgres | ja_notes | 484 MB |
>
> it does not seem to be bloated... since the table is 2805 MB


I'm sorry for the late answer.

It doesn't seem there is something wrong, but in the row:
> Index Scan using "ix_notes_jobid_per_type" on "ja_notes" "note"
>   (cost=0.00..29.33 rows=6 width=34)
>      (actual time=8.530..9.878 rows=1 loops=500)

the first digit is the time when the first row was returned from. See
[1] for more details.

It looks very strange for me because IIUC it spends almost all time on
opening (reopening) the index.
For example, <Index Scan using "ja_customers_pkey"> has an "actual
time" with both values equal.

I'd try to reindex "ix_notes_jobid_per_type".


[1]http://www.depesz.com/2013/04/16/explaining-the-unexplainable/
--
Best regards,
Vitaly Burovoy