Re: what's the slowest part in the SQL

On Tue, Aug 9, 2016 at 9:34 PM, Suya Huang <shuang@connexity.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=526loops=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.216rows=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.022rows=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.026rows=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.