Re: 15x slower PreparedStatement vs raw query

On Mon, May 03, 2021 at 03:18:11PM -0500, Justin Pryzby wrote:
> On Sun, May 02, 2021 at 07:45:26PM +0000, Alex wrote:
> > PreparedStatement: 15s
> > Raw query with embedded params: 1s
> > See issue on github with query and explain analyze:
> > https://github.com/pgjdbc/pgjdbc/issues/2145
>
> | ..PostgreSQL Version? 12
> |Prepared statement
> |...
> |Planning Time: 11.596 ms
> |Execution Time: 14799.266 ms
> |
> |Raw statement
> |Planning Time: 22.685 ms
> |Execution Time: 1012.992 ms
>
> The prepared statemnt has 2x faster planning time, which is what it's meant to
> improve.
>
> The execution time is slower, and I think you can improve it with this.
> https://www.postgresql.org/docs/12/runtime-config-query.html#GUC-PLAN-CACHE_MODE

Also, the rowcount estimates are way off starting with the scan nodes.

-> Bitmap Heap Scan on category_property_name cpn_limits (cost=32.13..53.55 rows=14 width=29) (actual time=0.665..8.822 rows=2650 loops=1)
Recheck Cond: ((lexeme = ANY ('{''rata'',""''polling'' ''rata'' ''ratez''"",""''polling'' ''rata''"",""''rata'' ''ratez'' ''semnal'' ''usb-ul''""}'::tsvector[])) OR (lexeme = '''frecventa'' ''frecventez'''::tsvector) OR (lexeme = '''raportare'' ''rata'' ''ratez'''::tsvector) OR (lexeme = ANY ('{''latime'',""''latime'' ''placi''"",""''compatibila'' ''latime'' ''telefon''""}'::tsvector[])) OR (lexeme = '''lungime'''::tsvector) OR (lexeme = '''cablu'' ''lungime'''::tsvector) OR (lexeme = '''inaltime'''::tsvector) OR (lexeme = '''rezolutie'''::tsvector) OR (lexeme = '''greutate'''::tsvector))
Heap Blocks: exact=85
-> BitmapOr (cost=32.13..32.13 rows=14 width=0) (actual time=0.574..0.577 rows=0 loops=1)
-> Bitmap Index Scan on category_property_name_lexeme_idx (cost=0.00..9.17 rows=4 width=0) (actual time=0.088..0.089 rows=10 loops=1)
Index Cond: (lexeme = ANY ('{''rata'',""''polling'' ''rata'' ''ratez''"",""''polling'' ''rata''"",""''rata'' ''ratez'' ''semnal'' ''usb-ul''""}'::tsvector[]))
-> Bitmap Index Scan on category_property_name_lexeme_idx (cost=0.00..2.29 rows=1 width=0) (actual time=0.047..0.047 rows=171 loops=1)
Index Cond: (lexeme = '''frecventa'' ''frecventez'''::tsvector) -> Bitmap Index Scan on category_property_name_lexeme_idx (cost=0.00..2.29 rows=1 width=0) (actual time=0.015..0.015 rows=1 loops=1) Index Cond: (lexeme = '''raportare'' ''rata'' ''ratez'''::tsvector)
-> Bitmap Index Scan on category_property_name_lexeme_idx (cost=0.00..6.88 rows=3 width=0) (actual time=0.097..0.097 rows=547 loops=1) Index Cond: (lexeme = ANY ('{''latime'',""''latime'' ''placi''"",""''compatibila'' ''latime'' ''telefon''""}'::tsvector[]))
-> Bitmap Index Scan on category_property_name_lexeme_idx (cost=0.00..2.29 rows=1 width=0) (actual time=0.107..0.107 rows=604 loops=1) Index Cond: (lexeme = '''lungime'''::tsvector)
-> Bitmap Index Scan on category_property_name_lexeme_idx (cost=0.00..2.29 rows=1 width=0) (actual time=0.030..0.030 rows=137 loops=1)
Index Cond: (lexeme = '''cablu'' ''lungime'''::tsvector)
-> Bitmap Index Scan on category_property_name_lexeme_idx (cost=0.00..2.29 rows=1 width=0) (actual time=0.079..0.079 rows=479 loops=1) Index Cond: (lexeme = '''inaltime'''::tsvector)
-> Bitmap Index Scan on category_property_name_lexeme_idx (cost=0.00..2.29 rows=1 width=0) (actual time=0.020..0.020 rows=40 loops=1)
Index Cond: (lexeme = '''rezolutie'''::tsvector) -> Bitmap Index Scan on category_property_name_lexeme_idx (cost=0.00..2.29 rows=1 width=0) (actual time=0.088..0.088 rows=661 loops=1) Index Cond: (lexeme = '''greutate'''::tsvector)