Hello
Recently I noticed extremely suspicious behavior from queries under JIT.
A query (details for which sadly I cannot disclose) had an EXPLAIN
looking like this:
JIT:
Functions: 743
Options: Inlining true, Optimization true, Expressions true, Deforming true
Timing: Generation 47.013 ms, Inlining 20.277 ms, Optimization 3269.381 ms, Emission 2392.115 ms, Total 5728.786 ms
Execution Time: 5735.552 ms
Disabling JIT, the query takes a few tens of milliseconds, so of course
the typical recommendation is to disable JIT. But I noted that the
average time to optimize, per function, is 4.7ms. I didn't know what to
make of this -- is it a reasonable to to take to optimize a single
function?
I put that thought aside. But then I spotted a couple of minor things
in the query that could be made better; so I did some of that, and
noticed that the number of functions was reduced from 743 to 671, and
the JIT details in the explain looked like this:
Planning Time: 15.060 ms
JIT:
Functions: 671
Options: Inlining false, Optimization true, Expressions true, Deforming true
Timing: Generation 75.205 ms, Inlining 0.000 ms, Optimization 1387.741 ms, Emission 1110.807 ms, Total 2573.753 ms
Execution Time: 2587.776 ms
But what really surprised me is that the the average time to optimize
per function is now 2.06ms ... less than half of the previous
measurement. It emits 10% less functions than before, but the time to
both optimize and emit is reduced by 50%. How does that make sense?
I don't know how to approach an investigation into this, but I thought
that maybe we're doing quadratic effort in the optimization / emission
phase or something like that.
--
Álvaro Herrera
