Re: what's the slowest part in the SQL

From: Claudio Freire <klaussfreire(at)gmail(dot)com>
To: Suya Huang <shuang(at)connexity(dot)com>
Cc: "pgsql-performance(at)postgresql(dot)org" <pgsql-performance(at)postgresql(dot)org>
Subject: Re: what's the slowest part in the SQL
Date: 2016-08-10 00:49:38
Message-ID: CAGTBQpY+DGBzQe-mWpAPovxKjcx+Lx_J0p+HEUxOiyTwu1YC9A@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

On Tue, Aug 9, 2016 at 9:46 PM, Claudio Freire <klaussfreire(at)gmail(dot)com> wrote:
> On Tue, Aug 9, 2016 at 9:34 PM, Suya Huang <shuang(at)connexity(dot)com> wrote:
>> dev=# explain analyze
>> SELECT COALESCE(w.displayname, o.name) FROM order o INNER JOIN data w
>> ON w.name = o.name WHERE (w.name LIKE '%dog%' OR w.displayname LIKE '%dog%') AND (NOT w.categories && ARRAY[1, 6, 10, 1337])
>> ORDER BY o.cnt DESC LIMIT 100;
>> QUERY PLAN
>> ----------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> Limit (cost=1761.35..1761.60 rows=100 width=50) (actual time=21.938..21.980 rows=100 loops=1)
>> -> Sort (cost=1761.35..1761.69 rows=138 width=50) (actual time=21.937..21.953 rows=100 loops=1)
>> Sort Key: o.cnt
>> Sort Method: quicksort Memory: 32kB
>> -> Nested Loop (cost=53.66..1756.44 rows=138 width=50) (actual time=3.791..21.818 rows=101 loops=1)
>> -> Bitmap Heap Scan on data w (cost=53.11..571.37 rows=138 width=40) (actual time=3.467..7.802 rows=526 loops=1)
>> Recheck Cond: (((name)::text ~~ '%dog%'::text) OR ((displayname)::text ~~ '%dog%'::text))
>> Rows Removed by Index Recheck: 7
>> Filter: (NOT (categories && '{1,6,10,1337}'::integer[]))
>> Rows Removed by Filter: 1249
>> -> BitmapOr (cost=53.11..53.11 rows=138 width=0) (actual time=3.241..3.241 rows=0 loops=1)
>> -> Bitmap Index Scan on idx_data_3 (cost=0.00..32.98 rows=131 width=0) (actual time=3.216..3.216 rows=1782 loops=1)
>> Index Cond: ((name)::text ~~ '%dog%'::text)
>> -> Bitmap Index Scan on idx_data_4 (cost=0.00..20.05 rows=7 width=0) (actual time=0.022..0.022 rows=3 loops=1)
>> Index Cond: ((displayname)::text ~~ '%dog%'::text)
>> -> Index Scan using idx_order_1_us on order o (cost=0.56..8.58 rows=1 width=30) (actual time=0.025..0.026 rows=0 loops=526)
>> Index Cond: (name = (w.name)::text)
>> Total runtime: 22.069 ms
>> (18 rows)
>
> Maybe I misunderstood your question, but dog here seems to behave just like cat.
>
> Are you expecting that running first "cat" and then "dog" should make
> "dog" go fast?
>
> That's not how it works, the rows for cat and dog may not reside on
> the same pages, so what's cached for "cat" doesn't work for "dog" and
> viceversa. It could even be the other way around, if by chance they
> resided on the same page, so... it still looks normal.
>
> Clearly your bottleneck is the I/O subsystem.

Btw, what kind of index are idx_data_3 and idx_data_4?

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Suya Huang 2016-08-10 01:43:54 Re: what's the slowest part in the SQL
Previous Message Claudio Freire 2016-08-10 00:46:42 Re: what's the slowest part in the SQL