Subject: Re: Add parameter jit_warn_above_fraction

From: Justin Pryzby <[email-masked]>
Date: Sat, 12 Mar 2022 09:24:11 -0600

On Mon, Mar 07, 2022 at 04:02:16PM +0100, Magnus Hagander wrote:
> On Mon, Mar 7, 2022 at 2:09 PM Justin Pryzby <[email-masked]> wrote:
> > On Mon, Mar 07, 2022 at 01:10:32PM +0100, Magnus Hagander wrote:
> > > On Fri, Feb 25, 2022 at 5:23 PM Justin Pryzby <[email-masked]> wrote:
> > > >
> > > > 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.
> >
> > Anyone who uses this parameter is aleady going to be changing GUCs, so it
> > doesn't need to work by default.  The people who are likely to enable this
> > already monitor their logs and have probably customized their logging
> > configuration.
> 
> Sure, but if you set log_min_messagse to NOTICE you are likely going
> to flood your logs beyond usefulness. And the whole idea of this
> parameter is you can keep it on during "normal times" to catch
> outliers.

I do set log_min_messages - not to NOTICE, but to INFO ;)

Would NOTICEs really flood most people's logs ?  From what ?  They're aren't
that many, and most seem to be for DDL and utility commands.  We do, uh, more
of that than most people would say is reasonable.

I see a couple hundred of these per day:
| PostGIS: Unable to compute statistics for...
And during deployment, a few hundred more for IF NOT EXIST commands.
That's it.

I still think this GUC should not be WARNING.  If it's a warning, then *this*
will cause previously-quiet logs to be flooded - the opposite problem.  Which
is not desirable for a new guc.

https://www.postgresql.org/docs/current/runtime-config-logging.html

INFO 	Provides information implicitly requested by the user, e.g., output from VACUUM VERBOSE. 	INFO 	INFORMATION
NOTICE 	Provides information that might be helpful to users, e.g., notice of truncation of long identifiers. 	NOTICE 	INFORMATION
WARNING Provides warnings of likely problems, e.g., COMMIT outside a transaction block. 	NOTICE 	WARNING

> > I don't understand - why doesn't it combine trivially with
> > log_min_duration_statement?  Are you saying that the default / pre-existing min
> > duration may not log all of the intended queries ?  I think that just means the
> > configuration needs to be changed.  The GUC needs to allow/help finding these
> > JIT issues, but going to require an admin's interaction in any case.  Avoiding
> > false positives may be important for it to be useful at all.
> >
> > Hmm .. should it also combine with min_sample_rate ?  Maybe that addresses your
> > concern.
> 
> For one, what if I don't want to log any queries unless this is the
> case? I leave log_min_duration_statement at -1...

Then you will conclude that our logging is inadequate for your case.
You need to filter the lines which don't interest you.

> Or what if I want to log say only queries taking more than 60 seconds.
> Now I will miss all queries taking 30 seconds where 99.9% of the time
> is spent on JIT which I definitely *would* want.

If you're unwilling to deal with log entries which are uninteresting, then
clearly you'll need a separate GUC just for log_min_duration_jit_above_fraction
(and maybe another one for jit_above_duration_log_level).  Or implement generic
log filtering based on file/severity/message.

As I see it: most people won't set this GUC at all.  Those who do might enable
it with a high threshold value of log_min_duration_statement (probably a
pre-existing, configured value) to see what there is to see - the worst issues.

A small fraction of people will enable it with a low threshold value for
log_min_duration_statement - maybe only temporarily or per-session.  They'll be
willing to sift through the logs to look for interesting things, like queries
that take 10ms, 75% of which is in JIT, but run hundreds of times per second.

This feature intends to make it easier to identify queries affected by this
problem, but it doesn't need to be possible to do that without logging anything
else.

-- 
Justin