Re: [RFC] Add jit deform_counter

> On 15 Apr 2023, at 16:40, Dmitry Dolgov <9erthalion6(at)gmail(dot)com> wrote:
>> On Fri, Mar 31, 2023 at 07:39:27PM +0200, Dmitry Dolgov wrote:
>>> On Wed, Mar 29, 2023 at 01:50:37PM +1300, David Rowley wrote:

I had a look at this patch today and I agree that it would be good to give the
user an easier way to gain insights into this since we make it configurable.

>>> If we add this deform time, then that's no longer going to be true as
>>> the "Generation" time includes the newly added deform time.
>>>
>>> master:
>>> JIT:
>>> Functions: 600
>>> Options: Inlining false, Optimization false, Expressions true, Deforming true
>>> Timing: Generation 37.758 ms, Inlining 0.000 ms, Optimization 6.736
>>> ms, Emission 172.244 ms, Total 216.738 ms
>>>
>>> 37.758 + 6.736 + 172.244 = 216.738
>>>
>>> I think if I was a DBA wondering why JIT was taking so long, I'd
>>> probably either be very astonished or I'd report a bug if I noticed
>>> that all the individual component JIT times didn't add up to the total
>>> time.

While true, the current EXPLAIN output for JIT isn't without confusing details
as it is. The example above has "Optimization false" and "Optimization 6.736",
and it takes reading the very last line on a docs page commenting on an example
to understand why.

>>> I don't think the solution is to subtract the deform time from the
>>> generation time either.

Agreed.

>> I agree about adding up to the total time though. What about changing
>> the format to something like this?
>>
>> Options: Inlining false, Optimization false, Expressions true, Deforming true
>> Timing: Generation 37.758 ms (Deforming 1.234 ms), Inlining 0.000 ms, Optimization 6.736 ms, Emission 172.244 ms, Total 216.738 ms
>>
>> This way it doesn't look like deforming timing is in the same category
>> as others, but rather a part of another value.

I think this is a good trade-off, but the wording "deforming" makes it sound
like it's the act of tuple deforming and not that of compiling tuple deforming
code. I don't have too many better suggestions, but maybe "Deform" is enough
to differentiate it?

> Here is the patch with the proposed variation.

This version still leaves non-text EXPLAIN formats with timing which doesn't
add up. Below are JSON and XML examples:

"Timing": { +
"Generation": 0.564, +
"Deforming": 0.111, +
"Inlining": 0.000, +
"Optimization": 0.358, +
"Emission": 6.505, +
"Total": 7.426 +
} +

<Timing> +
<Generation>0.598</Generation> +
<Deforming>0.117</Deforming> +
<Inlining>0.000</Inlining> +
<Optimization>0.367</Optimization> +
<Emission>6.400</Emission> +
<Total>7.365</Total> +
</Timing> +

It's less obvious how the additional level of details should be represented
here.

+ int64 jit_deform_count; /* number of times deform time has been >
+ * 0 */
While not a new problem with this patch, the comments on this struct yields
pretty awkward reflows by pgindent. I wonder if we should make a separate pass
over this at some point to clean it up?

The patch also fails to update doc/src/sgml/jit.sgml with the new EXPLAIN
output.

--
Daniel Gustafsson