With those sizes, the gin index will probably be naturally kept mostly
in the file-system cache, if it is used regularly. So the original
slowness of your first query is likely just a cold-cache problem. Can
you generate a stream of realistic queries and see what it stabilizes
at?
> I just wanted to understand why the GIN index is not working, but it works
> here: https://www.depesz.com/2011/02/19/waiting-for-9-1-faster-likeilike/
In your first email, the gin index did "work", according to the
execution plan. It just wasn't as fast as you wanted. In general,
the longer the query string is between the %%, the worse it will
perform (until version 9.6, and to a smaller degree even with 9.6).
But it still seems oddly slow to me, unless you have a cold-cache and
really bad (or overloaded) IO.
>
>>
>>
>> It would be interesting to see the output of explain (analyze,
>> buffers) with track_io_timing turned on.
>
>
> explain analyze buffer with track_io_timing turned on:
...
That is the wrong query. The CTE (i.e. the WITH part) is an
optimization fence, so it can't use the gin index, simply because of
the way you query is written. (I think Melvin suggested it because he
noticed that using the gin index actually slowed down the query, so he
wanted to force it to not be used.)
Oh ok.
- Here is the explain analyze buffer with the original query I posted here with the gin index:
Query:
explain (analyze, buffers)
SELECT title
FROM ja_jobs WHERE title ILIKE '%RYAN WER%'
and clientid = 31239 AND time_job > 1457826264
order BY title
limit 10
Explain analyze:
Limit (cost=390.07..390.08 rows=1 width=20) (actual time=3945.263..3945.280 rows=4 loops=1)
Buffers: shared hit=5956 read=10
I/O Timings: read=60.323
-> Sort (cost=390.07..390.08 rows=1 width=20) (actual time=3945.256..3945.260 rows=4 loops=1)
Sort Key: "title"
Sort Method: quicksort Memory: 25kB
Buffers: shared hit=5956 read=10
I/O Timings: read=60.323
-> Bitmap Heap Scan on "ja_jobs" (cost=386.05..390.06 rows=1 width=20) (actual time=3944.857..3945.127 rows=4 loops=1)
Recheck Cond: (("clientid" = 31239) AND ("time_job" > 1457826264) AND (("title")::"text" ~~* '% WER%'::"text"))
Buffers: shared hit=5951 read=10
I/O Timings: read=60.323
-> BitmapAnd (cost=386.05..386.05 rows=1 width=0) (actual time=3929.540..3929.540 rows=0 loops=1)
Buffers: shared hit=5950 read=7
I/O Timings: read=45.021
-> Bitmap Index Scan on "ix_jobs_client_times" (cost=0.00..50.16 rows=1660 width=0) (actual time=45.536..45.536 rows=795 loops=1)
Index Cond: (("clientid" = 31239) AND ("time_job" > 1457826264))
Buffers: shared hit=5 read=7
I/O Timings: read=45.021
-> Bitmap Index Scan on "ix_jobs_trgm_gin" (cost=0.00..335.64 rows=485 width=0) (actual time=3883.886..3883.886 rows=32 loops=1)
Index Cond: (("title")::"text" ~~* '%RYAN WER%'::"text")
Buffers: shared hit=5945
Total runtime: 3945.554 ms
