Re: Slow Query - Postgres 9.2

From: Vitaly Burovoy <vitaly(dot)burovoy(at)gmail(dot)com>
To: "drum(dot)lucas(at)gmail(dot)com" <drum(dot)lucas(at)gmail(dot)com>
Cc: Postgres General <pgsql-general(at)postgresql(dot)org>
Subject: Re: Slow Query - Postgres 9.2
Date: 2016-03-04 06:42:33
Message-ID: CAKOSWNk8hhdPj=C05U7GoDLbvFJHGTpCc8Vu6e7_1nqc-HDDKQ@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

On 3/2/16, drum(dot)lucas(at)gmail(dot)com <drum(dot)lucas(at)gmail(dot)com> wrote:
> On 3 March 2016 at 10:33, Vitaly Burovoy <vitaly(dot)burovoy(at)gmail(dot)com> wrote:
>> On 3/2/16, drum(dot)lucas(at)gmail(dot)com <drum(dot)lucas(at)gmail(dot)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

In response to

Browse pgsql-general by date

  From Date Subject
Next Message Rémi Cura 2016-03-04 09:46:52 Re: PLPythonu for production server
Previous Message Premsun Choltanwanich 2016-03-04 02:22:06 Re: could not migrate 8.0.13 database with large object data to 9.5.1