Re: Slow join over three tables

2016-04-27 2:27 GMT+03:00 Tim van der Linden <tim(at)shisaa(dot)jp>:

> The plan:
>
> Sort (cost=105773.63..105774.46 rows=333 width=76) (actual
> time=5143.162..5143.185 rows=448 loops=1)
> Sort Key: r.created
> Sort Method: quicksort Memory: 60kB
> -> Nested Loop (cost=1.31..105759.68 rows=333 width=76) (actual
> time=54.784..5142.872 rows=448 loops=1)
> Join Filter: (d.rid = a.rid)
> -> Nested Loop (cost=0.87..94657.59 rows=14005 width=72) (actual
> time=0.822..2038.952 rows=14199 loops=1)
> -> Index Scan using report_drugs_drug_idx on report_drugs d
> (cost=0.44..500.28 rows=14005 width=31) (actual time=0.669..3.900
> rows=14199 loops=1)
> Index Cond: (drug = ANY
> ('{359,360,361,362,363}'::integer[]))
> -> Index Scan using reports_id_key on reports r
> (cost=0.43..6.71 rows=1 width=41) (actual time=0.143..0.143 rows=1
> loops=14199)
> Index Cond: (id = d.rid)
> -> Index Scan using report_adverses_rid_idx on report_adverses a
> (cost=0.44..0.78 rows=1 width=12) (actual time=0.218..0.218 rows=0
> loops=14199)
> Index Cond: (rid = r.id)
> Filter: (adverse = ANY ('{"back pain -
> nonspecific","nonspecific back pain","back pain"}'::text[]))
> Rows Removed by Filter: 5
> Planning time: 13.994 ms
> Execution time: 5143.235 ms
>

Can you post output of `EXPLAIN (analyze, buffers)`, please?
It'd be good to check how many buffers are hit/read during Index Scans.

I have had a somewhat similar case, when due to misconfigured autovacuum
(not aggressive enough for the increased volume)
I got bloat accumulated in the indexes. Perhaps, REINDEX can help here.

--
Victor Y. Yegorov