Re: Add parameter jit_warn_above_fraction

On Fri, Feb 25, 2022 at 5:23 PM Justin Pryzby <pryzby@telsasoft.com> wrote:
>
> On Fri, Feb 25, 2022 at 04:16:01PM +0100, Magnus Hagander wrote:
> > +     {
> > +             {"jit_warn_above_fraction", PGC_SUSET, LOGGING_WHEN,
> > +                     gettext_noop("Sets the fraction of query time spent on JIT before writing"
> > +                                              "a warning to the log."),
> > +                     gettext_noop("Write a message tot he server log if more than this"
> > +                                              "fraction of the query runtime is spent on JIT."
> > +                                              "Zero turns off the warning.")
> > +             },
> > +             &jit_warn_above_fraction,
> > +             0.0, 0.0, 1.0,
> > +             NULL, NULL, NULL
> > +     },
>
> Should be PGC_USERSET ?

Yes. Definitely. Copy/paste thinko.


> +                       gettext_noop("Write a message tot he server log if more than this"
>
> to the

Yup.


> +       if (jit_enabled && jit_warn_above_fraction > 0)
> +       {
> +               int64 jit_time =
> +                       INSTR_TIME_GET_MILLISEC(portal->queryDesc->estate->es_jit->instr.generation_counter) +
> +                       INSTR_TIME_GET_MILLISEC(portal->queryDesc->estate->es_jit->instr.inlining_counter) +
> +                       INSTR_TIME_GET_MILLISEC(portal->queryDesc->estate->es_jit->instr.optimization_counter) +
> +                       INSTR_TIME_GET_MILLISEC(portal->queryDesc->estate->es_jit->instr.emission_counter);
> +
> +               if (jit_time > msecs * jit_warn_above_fraction)
> +               {
> +                       ereport(WARNING,
> +                                       (errmsg("JIT time was %ld ms of %d ms",
> +                                                       jit_time, msecs)));
> +               }
> +       }
>
>
> I think it should be a NOTICE (or less?)

Hmm. I'm not so sure.

Other similar parameters often use LOG, but the downside of that is
that it won't be sent to the client.

The problem with using NOTICE is that it won't go to the log by
default. It needs to be at least warning to do that.


> Is it more useful if this is applied combined with log_min_duration_statement ?
>
> It's easy to imagine a query for which the planner computes a high cost, but
> actually runs quickly.  You might get a bunch of WARNINGs that the query took
> 10 MS and JIT was 75% of that, even if you don't care about queries that take
> less than 10 SEC.

Yeah, that's definitely a problem. But which way would you want to tie
it to log_min_duration_statement?  That a statement would both have to
take longer than log_min_duration_statement *and* have JIT above a
certain percentage? In my experience that is instead likely to miss
most of the interesting times. Maybe it would need a separate guc for
the timing, but I'd like to avoid that, I'm not sure it's a function
worth *that* much...


> I should say that this is already available by processing the output of
> autoexplain.

True. You just can't trigger it based on it. (and it can be somewhat
of a PITA to parse things out of auto_explain on busy systems, but it
does give a lot of very useful details)


Meanwhile here is an updated based on your other comments above, as
well as those from Julien.

-- 
 Magnus Hagander
 Me: https://www.hagander.net/
 Work: https://www.redpill-linpro.com/