Re: Slow Query - Postgres 9.2 - Mailing list pgsql-general

From Vitaly Burovoy
Subject Re: Slow Query - Postgres 9.2
Date
Msg-id CAKOSWNk8hhdPj=C05U7GoDLbvFJHGTpCc8Vu6e7_1nqc-HDDKQ@mail.gmail.com
Whole thread Raw
In response to Re: Slow Query - Postgres 9.2  ("drum.lucas@gmail.com" <drum.lucas@gmail.com>)
List pgsql-general
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


pgsql-general by date:

Previous
From: "Premsun Choltanwanich"
Date:
Subject: Re: could not migrate 8.0.13 database with large object data to 9.5.1
Next
From: Rémi Cura
Date:
Subject: Re: PLPythonu for production server