hard readable explain due JIT

From: Pavel Stehule <pavel(dot)stehule(at)gmail(dot)com>
To: PostgreSQL Hackers <pgsql-hackers(at)postgresql(dot)org>
Subject: hard readable explain due JIT
Date: 2020-11-07 12:54:31
Message-ID: CAFj8pRCSUCxPovJQ_H+LbCLnKFMjDPgP7=3p4oosLCwKeYJyRA@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Hi

I had to solve a slow due very slow JIT preparing. I found very unpleased
situation where some subplan was strangely slow

-> Hash Anti Join (cost=11.35..19.41 rows=143 width=3011) (actual
time=5039.022..5039.105 rows=203 loops=1)
Hash Cond: (term_p.id_i = term_d_1.id_i)
-> Seq Scan on public.term_p (cost=0.00..6.03 rows=203 width=24)
(actual time=5038.980..5039.014 rows=203 loops=1)
Filter: (term_p.to_h IS NULL)
-> Hash (cost=10.60..10.60 rows=60 width=16) (actual
time=0.008..0.009 rows=0 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 8kB
-> Seq Scan on public.term_d term_d_1 (cost=0.00..10.60
rows=60 width=16) (actual time=0.008..0.008 rows=0 loops=1)

It looks very strange - why does a scan of 203 rows need 5 sec?

There is a overhead of JIT but on different place of EXPLAIN

JIT:
Functions: 416
Options: Inlining true, Optimization true, Expressions true, Deforming
true
Timing: Generation 61.002 ms, Inlining 67.897 ms, Optimization 2853.125
ms, Emission 2116.233 ms, Total 5098.258 ms

With some deduction we can detect so slow seq scan is probably JIT ??

But some tools like https://explain.depesz.com displays very strange
statistics then - so JIT overhead should be displayed in related plans too.

Regards

Pavel

Attachment Content-Type Size
explain_plan_q1.zip application/zip 10.5 KB

Browse pgsql-hackers by date

  From Date Subject
Next Message vignesh C 2020-11-07 13:31:34 Re: Parallel copy
Previous Message Jürgen Purtz 2020-11-07 12:24:53 Re: Additional Chapter for Tutorial