BUG #18074: After enabling JIT, the query runtime increased by over a thousand times.

From: PG Bug reporting form <noreply(at)postgresql(dot)org>
To: pgsql-bugs(at)lists(dot)postgresql(dot)org
Cc: sdqdfcd(at)126(dot)com
Subject: BUG #18074: After enabling JIT, the query runtime increased by over a thousand times.
Date: 2023-08-29 06:42:16
Message-ID: 18074-9f187d80c23e0fd9@postgresql.org
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

The following bug has been logged on the website:

Bug reference: 18074
Logged by: CunDi Fang
Email address: sdqdfcd(at)126(dot)com
PostgreSQL version: 14.9
Operating system: Ubuntu 20.04 x64
Description:

This is a bug I found using my fuzzer tool. I created a table and inserted
data using the following commands:
```
CREATE TABLE t4(c0 float);
INSERT INTO t4(c0) VALUES(0.6079624182999142), (0.9022437185484834),
(0.2325958017979053);
```

Then I tried the following query
```
SELECT t4.c0 FROM t4 WHERE (((reverse('') COLLATE "C"))LIKE((((('Nu' COLLATE
"C.utf8"))||(CAST(1.27347917E9 AS MONEY))) COLLATE "C")));
```
and recorded the time using explain analyze.

When I did not enable JIT, the execution result was as follows:
```
postgres=# set jit = off;
SET
postgres=# set jit_above_cost = 100000;
SET
postgres=# set jit_inline_above_cost = 500000;
SET
postgres=# set jit_optimize_above_cost = 500000;
SET
postgres=# explain analyze SELECT t4.c0 FROM t4 WHERE (((reverse('') COLLATE
"C"))LIKE((((('Nu' COLLATE "C.utf8"))||(CAST(1.27347917E9 AS MONEY)))
COLLATE "C")));
QUERY PLAN

------------------------------------------------------------------------------------------------------------------------------
Result (cost=0.01..32.61 rows=2260 width=8) (actual time=0.010..0.010
rows=0 loops=1)
One-Time Filter: (''::text COLLATE "C" ~~ (('Nu'::text COLLATE "C.utf8"
|| (('1273479170'::numeric)::money)::text))::text)
-> Seq Scan on t4 (cost=0.01..32.61 rows=2260 width=8) (never
executed)
Planning Time: 0.123 ms
Execution Time: 0.025 ms
(5 rows)
```

When I enabled JIT, the execution result was as follows:
```
postgres=# set jit = on;
SET
postgres=# set jit_above_cost = 0;
SET
postgres=# set jit_inline_above_cost = 0;
SET
postgres=# set jit_optimize_above_cost = 0;
SET
postgres=# explain analyze SELECT t4.c0 FROM t4 WHERE (((reverse('') COLLATE
"C"))LIKE((((('Nu' COLLATE "C.utf8"))||(CAST(1.27347917E9 AS MONEY)))
COLLATE "C")));
QUERY PLAN

------------------------------------------------------------------------------------------------------------------------------
Result (cost=0.01..32.61 rows=2260 width=8) (actual time=56.490..56.491
rows=0 loops=1)
One-Time Filter: (''::text COLLATE "C" ~~ (('Nu'::text COLLATE "C.utf8"
|| (('1273479170'::numeric)::money)::text))::text)
-> Seq Scan on t4 (cost=0.01..32.61 rows=2260 width=8) (never
executed)
Planning Time: 0.093 ms
JIT:
Functions: 3
Options: Inlining true, Optimization true, Expressions true, Deforming
true
Timing: Generation 0.296 ms, Inlining 10.589 ms, Optimization 33.214 ms,
Emission 12.665 ms, Total 56.764 ms
Execution Time: 56.841 ms
(9 rows)
```

As you can see, the time increased from 0.025ms to 56.841ms. InteWHERE
clause's condition isthe WHERE clause is actually empty. When I simplified
the condition in the WHERE clause and tested it again, I found:
```
postgres=# explain analyze SELECT t4.c0 FROM t4 where null;
QUERY PLAN

------------------------------------------------------------------------------------
Result (cost=0.00..0.00 rows=0 width=0) (actual time=0.002..0.002 rows=0
loops=1)
One-Time Filter: false
Planning Time: 0.044 ms
Execution Time: 0.015 ms
(4 rows)
```

This shows that empty functions (useless functions) can greatly slow down
the runtime of JIT, hindering its performance.

Browse pgsql-bugs by date

  From Date Subject
Next Message torikoshia 2023-08-29 13:15:51 Re: pg_rewind WAL segments deletion pitfall
Previous Message John Naylor 2023-08-29 06:39:32 Re: group by true now errors with non-integer constant in GROUP BY