Re: Reducing the log spam
On Thu, 25 Jul 2024 at 18:03, Laurenz Albe wrote:
> Thanks for the review!
>
> On Wed, 2024-07-24 at 15:27 +0200, Rafia Sabih wrote:
> > I liked the idea for this patch. I will also go for the default being
> > an empty string.
> > I went through this patch and have some comments on the code,
> >
> > 1. In general, I don't like the idea of goto, maybe we can have a
> > free_something function to call here.
>
> The PostgreSQL code base has over 3000 goto's...
>
> Sure, that can be factored out to a function (except the final "return"),
> but I feel that a function for three "free" calls is code bloat.
>
> On a detailed look over this, you are right Laurenz about this.
> Do you think that avoiding the goto and using a function would make the
> code simpler and clearer?
>
> > 2.
> > if (!SplitIdentifierString(new_copy, ',', &states))
> > {
> > GUC_check_errdetail("List syntax is invalid.");
> > goto failed;
> > }
> > Here, we don't need all that free-ing, we can just return false here.
>
> I am OK with changing that; I had thought it was more clearer and more
> foolproof to use the same pattern everywhere.
>
> > 3.
> > /*
> > * Check the the values are alphanumeric and convert them to upper case
> > * (SplitIdentifierString converted them to lower case).
> > */
> > for (p = state; *p != '\0'; p++)
> > if (*p >= 'a' && *p <= 'z')
> > *p += 'A' - 'a';
> > else if (*p < '0' || *p > '9')
> > {
> > GUC_check_errdetail("error codes can only contain digits and ASCII
> letters.");
> > goto failed;
> > }
> > I was thinking, maybe we can use tolower() function here.
>
> That is a good idea, but these C library respect the current locale.
> I would have to explicitly specify the C locale or switch the locale
> temporarily.
>
Hmm. actually I don't have any good answers to this locale issue.
>
> Switching the locale seems clumsy, and I have no idea what I would have
> to feed as second argument to toupper_l() or isalnum_l().
> Do you have an idea?
>
> > 4.
> > list_free(states);
> > pfree(new_copy);
> >
> > *extra = statelist;
> > return true;
> >
> > failed:
> > list_free(states);
> > pfree(new_copy);
> > guc_free(statelist);
> > return false;
> >
> > This looks like duplication that can be easily avoided.
> > You may have free_somthing function to do all free-ing stuff only and
> > its callee can then have a return statement.
> > e.g for here,
> > free_states(states, new_copy, statelist);
> > return true;
>
> That free_states() function would just contain two function calls.
> I think that defining a special function for that is somewhat out of
> proportion.
>
> > 5. Also, for alphanumeric check, maybe we can have something like,
> > if (isalnum(*state) == 0)
> > {
> > GUC_check_errdetail("error codes can only contain digits and ASCII
> letters.");
> > goto failed;
> > }
> > and we can do this in the beginning after the len check.
>
> isalnum() operates on a single character and depends on the current locale.
> See my comments to 3. above.
>
>
> Please let me know what you think, particularly about the locale problem.
>
> Yours,
> Laurenz Albe
>
--
Regards,
Rafia Sabih
Re: Reducing the log spam
Thanks for the review!
On Wed, 2024-07-24 at 15:27 +0200, Rafia Sabih wrote:
> I liked the idea for this patch. I will also go for the default being
> an empty string.
> I went through this patch and have some comments on the code,
>
> 1. In general, I don't like the idea of goto, maybe we can have a
> free_something function to call here.
The PostgreSQL code base has over 3000 goto's...
Sure, that can be factored out to a function (except the final "return"),
but I feel that a function for three "free" calls is code bloat.
Do you think that avoiding the goto and using a function would make the
code simpler and clearer?
> 2.
> if (!SplitIdentifierString(new_copy, ',', &states))
> {
> GUC_check_errdetail("List syntax is invalid.");
> goto failed;
> }
> Here, we don't need all that free-ing, we can just return false here.
I am OK with changing that; I had thought it was more clearer and more
foolproof to use the same pattern everywhere.
> 3.
> /*
> * Check the the values are alphanumeric and convert them to upper case
> * (SplitIdentifierString converted them to lower case).
> */
> for (p = state; *p != '\0'; p++)
> if (*p >= 'a' && *p <= 'z')
> *p += 'A' - 'a';
> else if (*p < '0' || *p > '9')
> {
> GUC_check_errdetail("error codes can only contain digits and ASCII letters.");
> goto failed;
> }
> I was thinking, maybe we can use tolower() function here.
That is a good idea, but these C library respect the current locale.
I would have to explicitly specify the C locale or switch the locale
temporarily.
Switching the locale seems clumsy, and I have no idea what I would have
to feed as second argument to toupper_l() or isalnum_l().
Do you have an idea?
> 4.
> list_free(states);
> pfree(new_copy);
>
> *extra = statelist;
> return true;
>
> failed:
> list_free(states);
> pfree(new_copy);
> guc_free(statelist);
> return false;
>
> This looks like duplication that can be easily avoided.
> You may have free_somthing function to do all free-ing stuff only and
> its callee can then have a return statement.
> e.g for here,
> free_states(states, new_copy, statelist);
> return true;
That free_states() function would just contain two function calls.
I think that defining a special function for that is somewhat out of
proportion.
> 5. Also, for alphanumeric check, maybe we can have something like,
> if (isalnum(*state) == 0)
> {
> GUC_check_errdetail("error codes can only contain digits and ASCII letters.");
> goto failed;
> }
> and we can do this in the beginning after the len check.
isalnum() operates on a single character and depends on the current locale.
See my comments to 3. above.
Please let me know what you think, particularly about the locale problem.
Yours,
Laurenz Albe
Re: Reducing the log spam
Hello Laurenz,
I liked the idea for this patch. I will also go for the default being
an empty string.
I went through this patch and have some comments on the code,
1. In general, I don't like the idea of goto, maybe we can have a
free_something function to call here.
2.
if (!SplitIdentifierString(new_copy, ',', &states))
{
GUC_check_errdetail("List syntax is invalid.");
goto failed;
}
Here, we don't need all that free-ing, we can just return false here.
3.
/*
* Check the the values are alphanumeric and convert them to upper case
* (SplitIdentifierString converted them to lower case).
*/
for (p = state; *p != '\0'; p++)
if (*p >= 'a' && *p <= 'z')
*p += 'A' - 'a';
else if (*p < '0' || *p > '9')
{
GUC_check_errdetail("error codes can only contain digits and ASCII letters.");
goto failed;
}
I was thinking, maybe we can use tolower() function here.
4.
list_free(states);
pfree(new_copy);
*extra = statelist;
return true;
failed:
list_free(states);
pfree(new_copy);
guc_free(statelist);
return false;
This looks like duplication that can be easily avoided.
You may have free_somthing function to do all free-ing stuff only and
its callee can then have a return statement.
e.g for here,
free_states(states, new_copy, statelist);
return true;
5. Also, for alphanumeric check, maybe we can have something like,
if (isalnum(*state) == 0)
{
GUC_check_errdetail("error codes can only contain digits and ASCII letters.");
goto failed;
}
and we can do this in the beginning after the len check.
On Tue, 18 Jun 2024 at 18:49, Laurenz Albe wrote:
>
> On Mon, 2024-06-17 at 16:40 -0500, Justin Pryzby wrote:
> > > The feature will become much less useful if unique voilations keep
> > > getting logged.
> >
> > Uh, to be clear, your patch is changing the *defaults*, which I found
> > surprising, even after reaading the thread. Evidently, the current
> > behavior is not what you want, and you want to change it, but I'm *sure*
> > that whatever default you want to use at your site/with your application
> > is going to make someone else unhappy. I surely want unique violations
> > to be logged, for example.
>
> I was afraid that setting the default non-empty would cause objections.
>
> > > +
> > > +This setting is useful to exclude error messages from the log
> > > that are
> > > +frequent but irrelevant.
> >
> > I think you should phrase the feature as ".. *allow* skipping error
> > logging for messages ... that are frequent but irrelevant for a given
> > site/role/DB/etc."
>
> I have reworded that part.
>
> > I suggest that this patch should not change the default behavior at all:
> > its default should be empty. That you, personally, would plan to
> > exclude this or that error code is pretty uninteresting. I think the
> > idea of changing the default behavior will kill the patch, and even if
> > you want to propose to do that, it should be a separate discussion.
> > Maybe you should make it an 002 patch.
>
> I have attached a new version that leaves the parameter empty by default.
>
> The patch is not motivated by my personal dislike of certain error messages.
> A well-written application would not need that parameter at all.
> The motivation for me is based on my dealing with customers' log files,
> which are often full of messages that are only distracting from serious
> problems and fill up the disk.
>
> But you are probably right that it would be hard to find a default setting
> that nobody has quibbles with, and the default can always be changed with
> a future patch.
>
> Yours,
> Laurenz Albe
--
Regards,
Rafia Sabih
Re: Reducing the log spam
On Mon, 2024-06-17 at 16:40 -0500, Justin Pryzby wrote: > > The feature will become much less useful if unique voilations keep getting > > logged. > > Uh, to be clear, your patch is changing the *defaults*, which I found > surprising, even after reaading the thread. Evidently, the current > behavior is not what you want, and you want to change it, but I'm *sure* > that whatever default you want to use at your site/with your application > is going to make someone else unhappy. I surely want unique violations > to be logged, for example. I was afraid that setting the default non-empty would cause objections. > > + > > +This setting is useful to exclude error messages from the log that > > are > > +frequent but irrelevant. > > I think you should phrase the feature as ".. *allow* skipping error > logging for messages ... that are frequent but irrelevant for a given > site/role/DB/etc." I have reworded that part. > I suggest that this patch should not change the default behavior at all: > its default should be empty. That you, personally, would plan to > exclude this or that error code is pretty uninteresting. I think the > idea of changing the default behavior will kill the patch, and even if > you want to propose to do that, it should be a separate discussion. > Maybe you should make it an 002 patch. I have attached a new version that leaves the parameter empty by default. The patch is not motivated by my personal dislike of certain error messages. A well-written application would not need that parameter at all. The motivation for me is based on my dealing with customers' log files, which are often full of messages that are only distracting from serious problems and fill up the disk. But you are probably right that it would be hard to find a default setting that nobody has quibbles with, and the default can always be changed with a future patch. Yours, Laurenz Albe From 8e1eeb9cbcb94d9b15eb9ee97956cc4044ff7964 Mon Sep 17 00:00:00 2001 From: Laurenz Albe Date: Tue, 18 Jun 2024 18:39:05 +0200 Subject: [PATCH v4] Add parameter log_suppress_errcodes The parameter contains a list of SQLSTATEs for which FATAL and ERROR messages are not logged. This is to suppress messages that are of little interest to the database administrator, but tend to clutter the log. Author: Laurenz Albe Discussion: https://postgr.es/m/408f399e7de1416c47bab7e260327ed5ad92838c.camel%40cybertec.at --- doc/src/sgml/config.sgml | 35 ++ src/backend/utils/error/elog.c| 119 ++ src/backend/utils/misc/guc_tables.c | 11 ++ src/backend/utils/misc/postgresql.conf.sample | 3 + src/include/pg_config_manual.h| 10 ++ src/include/utils/guc.h | 1 + src/include/utils/guc_hooks.h | 2 + 7 files changed, 181 insertions(+) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 698169afdb..a58b43bceb 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -6883,6 +6883,41 @@ local0.*/var/log/postgresql + + log_suppress_errcodes (string) + + log_suppress_errcodes configuration parameter + + + + +Causes ERROR and FATAL messages +from client backend processes with certain error codes to be excluded +from the log. +The value is a comma-separated list of five-character error codes as +listed in . An error code that +represents a class of errors (ends with three zeros) suppresses logging +of all error codes within that class. For example, the entry +08000 (connection_exception) +would suppress an error with code 08P01 +(protocol_violation). The default setting is +empty, that is, all error codes get logged. +Only superusers and users with the appropriate SET +privilege can change this setting. + + + +This setting allows you to skip error logging for messages that are +frequent but irrelevant. Supressing such messages makes it easier to +spot relevant messages in the log and keeps log files from growing too +big. For example, if you have a monitoring system that regularly +establishes a TCP connection to the server without sending a correct +startup packet, you could suppress the protocol violation errors by +adding the error code 08P01 to the list. + + + + log_min_duration_statement (integer) diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index d91a85cb2d..0b2506e07a 100644 --- a/src/backend/utils/error/elog.c +++ b/src/backend/utils/error/elog.c @@ -111,12 +111,16 @@ int Log_error_verbosity = PGERROR_DEFAULT; char *Log_line_prefix = NULL; /* format for extra log line info */ int Log_destination = LOG_DESTINATION_STDERR; char *Log_desti
Re: Reducing the log spam
On Thu, May 02, 2024 at 12:47:45PM +0200, Laurenz Albe wrote:
> On Mon, 2024-03-11 at 09:33 +0100, Jelte Fennema-Nio wrote:
> > - the subscriber's server log.
> > + the subscriber's server log if you remove 23505 from
> > + .
> >
> > This seems like a pretty big regression. Being able to know why your
> > replication got closed seems pretty critical.
>
> Yes. But I'd argue that that is a shortcoming of logical replication:
> there should be a ways to get this information via SQL. Having to look into
> the log file is not a very useful option.
>
> The feature will become much less useful if unique voilations keep getting
> logged.
Uh, to be clear, your patch is changing the *defaults*, which I found
surprising, even after reaading the thread. Evidently, the current
behavior is not what you want, and you want to change it, but I'm *sure*
that whatever default you want to use at your site/with your application
is going to make someone else unhappy. I surely want unique violations
to be logged, for example.
> @@ -6892,6 +6892,41 @@ local0.*/var/log/postgresql
>
>
>
> + xreflabel="log_suppress_errcodes">
> + log_suppress_errcodes (string)
> +
> + log_suppress_errcodes configuration
> parameter
> +
> +
> +
> +
> +Causes ERROR and FATAL messages
> +from client backend processes with certain error codes to be excluded
> +from the log.
> +The value is a comma-separated list of five-character error codes as
> +listed in . An error code that
> +represents a class of errors (ends with three zeros) suppresses
> logging
> +of all error codes within that class. For example, the entry
> +08000 (connection_exception)
> +would suppress an error with code 08P01
> +(protocol_violation). The default setting is
> +23505,3D000,3F000,42601,42704,42883,42P01,57P03.
> +Only superusers and users with the appropriate SET
> +privilege can change this setting.
> +
> +
> +
> +This setting is useful to exclude error messages from the log that
> are
> +frequent but irrelevant.
I think you should phrase the feature as ".. *allow* skipping error
logging for messages ... that are frequent but irrelevant for a given
site/role/DB/etc."
I suggest that this patch should not change the default behavior at all:
its default should be empty. That you, personally, would plan to
exclude this or that error code is pretty uninteresting. I think the
idea of changing the default behavior will kill the patch, and even if
you want to propose to do that, it should be a separate discussion.
Maybe you should make it an 002 patch.
> + {"log_suppress_errcodes", PGC_SUSET, LOGGING_WHEN,
> + gettext_noop("ERROR and FATAL messages with these error
> codes don't get logged."),
> + NULL,
> + GUC_LIST_INPUT
> + },
> + &log_suppress_errcodes,
> + DEFAULT_LOG_SUPPRESS_ERRCODES,
> + check_log_suppress_errcodes, assign_log_suppress_errcodes, NULL
> +/*
> + * Default value for log_suppress_errcodes. ERROR or FATAL messages with
> + * these error codes are never logged. Error classes (error codes ending
> with
> + * three zeros) match all error codes in the class. The idea is to suppress
> + * messages that usually don't indicate a serious problem but tend to pollute
> + * the log file.
> + */
> +
> +#define DEFAULT_LOG_SUPPRESS_ERRCODES
> "23505,3D000,3F000,42601,42704,42883,42P01,57P03"
> +
../src/backend/utils/errcodes.txt:23505EERRCODE_UNIQUE_VIOLATION
unique_violation
../src/backend/utils/errcodes.txt:3D000EERRCODE_INVALID_CATALOG_NAME
invalid_catalog_name
../src/backend/utils/errcodes.txt:3F000EERRCODE_INVALID_SCHEMA_NAME
invalid_schema_name
../src/backend/utils/errcodes.txt:42601EERRCODE_SYNTAX_ERROR
syntax_error
../src/backend/utils/errcodes.txt:3D000EERRCODE_UNDEFINED_DATABASE
../src/backend/utils/errcodes.txt:42883EERRCODE_UNDEFINED_FUNCTION
undefined_function
../src/backend/utils/errcodes.txt:3F000EERRCODE_UNDEFINED_SCHEMA
../src/backend/utils/errcodes.txt:42P01EERRCODE_UNDEFINED_TABLE
undefined_table
../src/backend/utils/errcodes.txt:42704EERRCODE_UNDEFINED_OBJECT
undefined_object
../src/backend/utils/errcodes.txt:57P03EERRCODE_CANNOT_CONNECT_NOW
cannot_connect_now
--
Justin
Re: Reducing the log spam
On Thu, 2024-05-02 at 13:11 +0200, Jelte Fennema-Nio wrote:
> On Thu, 2 May 2024 at 13:08, Jelte Fennema-Nio wrote:
> > 2. Change the newly added check in errcode() to only set
> > output_to_server to false when IsLogicalWorker() returns false.
>
> Actually a third, and probably even better solution would be to only
> apply this new GUC to non-backgroundworker processes. That seems quite
> reasonable, since often the only way to access background worker
> errors is often through the logs.
That is a good idea. This version only suppresses error messages
in ordinary backend processes.
Yours,
Laurenz Albe
From 3fe19a7df69d588d6a915450064094ca2066ae33 Mon Sep 17 00:00:00 2001
From: Laurenz Albe
Date: Fri, 3 May 2024 14:47:03 +0200
Subject: [PATCH v3] Add parameter log_suppress_errcodes
The parameter contains a list of SQLSTATEs for which
FATAL and ERROR messages are not logged. This is to
suppress messages that are of little interest to the
database administrator, but tend to clutter the log.
Author: Laurenz Albe
Discussion: https://postgr.es/m/408f399e7de1416c47bab7e260327ed5ad92838c.camel%40cybertec.at
---
doc/src/sgml/config.sgml | 35 ++
src/backend/utils/error/elog.c| 119 ++
src/backend/utils/misc/guc_tables.c | 11 ++
src/backend/utils/misc/postgresql.conf.sample | 4 +
src/bin/pg_ctl/t/004_logrotate.pl | 1 +
src/include/pg_config_manual.h| 10 ++
src/include/utils/guc.h | 1 +
src/include/utils/guc_hooks.h | 2 +
src/test/subscription/t/029_on_error.pl | 1 +
9 files changed, 184 insertions(+)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index ffb6b023fd..614e37b951 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -6892,6 +6892,41 @@ local0.*/var/log/postgresql
+
+ log_suppress_errcodes (string)
+
+ log_suppress_errcodes configuration parameter
+
+
+
+
+Causes ERROR and FATAL messages
+from client backend processes with certain error codes to be excluded
+from the log.
+The value is a comma-separated list of five-character error codes as
+listed in . An error code that
+represents a class of errors (ends with three zeros) suppresses logging
+of all error codes within that class. For example, the entry
+08000 (connection_exception)
+would suppress an error with code 08P01
+(protocol_violation). The default setting is
+23505,3D000,3F000,42601,42704,42883,42P01,57P03.
+Only superusers and users with the appropriate SET
+privilege can change this setting.
+
+
+
+This setting is useful to exclude error messages from the log that are
+frequent but irrelevant. Supressing such messages makes it easier to
+spot relevant messages in the log and keeps log files from growing too
+big. For example, if you have a monitoring system that regularly
+establishes a TCP connection to the server without sending a correct
+startup packet, you could suppress the protocol violation errors by
+adding the error code 08P01 to the list.
+
+
+
+
log_min_duration_statement (integer)
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index d91a85cb2d..0b2506e07a 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -111,12 +111,16 @@ int Log_error_verbosity = PGERROR_DEFAULT;
char *Log_line_prefix = NULL; /* format for extra log line info */
int Log_destination = LOG_DESTINATION_STDERR;
char *Log_destination_string = NULL;
+char *log_suppress_errcodes = NULL;
bool syslog_sequence_numbers = true;
bool syslog_split_messages = true;
/* Processed form of backtrace_functions GUC */
static char *backtrace_function_list;
+/* Processed form form of log_suppress_errcodes (zero-terminated array) */
+static int *suppressed_errcodes;
+
#ifdef HAVE_SYSLOG
/*
@@ -863,6 +867,30 @@ errcode(int sqlerrcode)
edata->sqlerrcode = sqlerrcode;
+ /*
+ * ERROR and FATAL messages with codes in log_suppress_errcodes don't get
+ * logged. We only want to suppress error messages from ordinary backend
+ * processes.
+ */
+ if ((MyBackendType == B_BACKEND ||
+ MyBackendType == B_STANDALONE_BACKEND) &&
+ (edata->elevel == ERROR ||
+ edata->elevel == FATAL) &&
+ suppressed_errcodes != NULL)
+ {
+ int *state;
+
+ for (state = suppressed_errcodes; *state != 0; state++)
+ /* error categories match all error codes in the category */
+ if (sqlerrcode == *state ||
+(ERRCODE_IS_CATEGORY(*state) &&
+ ERRCODE_TO_CATEGORY(sqlerrcode) == *state))
+ {
+edata->output_to_server = false;
+break;
+ }
+ }
+
return 0; /* return value does not matter */
}
@@ -2263
Re: Reducing the log spam
On Thu, 2 May 2024 at 13:08, Jelte Fennema-Nio wrote: > 2. Change the newly added check in errcode() to only set > output_to_server to false when IsLogicalWorker() returns false. Actually a third, and probably even better solution would be to only apply this new GUC to non-backgroundworker processes. That seems quite reasonable, since often the only way to access background worker errors is often through the logs.
Re: Reducing the log spam
On Thu, 2 May 2024 at 12:47, Laurenz Albe wrote: > Yes. But I'd argue that that is a shortcoming of logical replication: > there should be a ways to get this information via SQL. Having to look into > the log file is not a very useful option. Definitely agreed that accessing the error details using SQL would be much better. But having no way at all (by default) to find the cause of the failure is clearly much worse. > The feature will become much less useful if unique voilations keep getting > logged. Agreed. How about changing the patch so that the GUC is not applied to logical replication apply workers (and document that accordingly). I can think of two ways of achieving that (but there might be other/better ones): 1. Set the GUC to empty string when an apply worker is started. 2. Change the newly added check in errcode() to only set output_to_server to false when IsLogicalWorker() returns false.
Re: Reducing the log spam
On Mon, 2024-03-11 at 09:33 +0100, Jelte Fennema-Nio wrote: > - the subscriber's server log. > + the subscriber's server log if you remove 23505 from > + . > > This seems like a pretty big regression. Being able to know why your > replication got closed seems pretty critical. Yes. But I'd argue that that is a shortcoming of logical replication: there should be a ways to get this information via SQL. Having to look into the log file is not a very useful option. The feature will become much less useful if unique voilations keep getting logged. Yours, Laurenz Albe
Re: Reducing the log spam
On Mon, 2024-03-11 at 09:33 +0100, Jelte Fennema-Nio wrote: > - the subscriber's server log. > + the subscriber's server log if you remove 23505 from > + . > > This seems like a pretty big regression. Being able to know why your > replication got closed seems pretty critical. The actual SQLSTATEs that get suppressed are subject to discussion (an I have a gut feeling that some people will want the list empty). As far as this specific functionality is concerned, I think that the actual problem is a deficiency in PostgreSQL. The problem is that the log is the *only* place where you can get this information. That will be a problem for many people, even without "log_suppress_errcodes". I think that this isformation should be available in some statistics view. Yours, Laurenz Albe
Re: Reducing the log spam
- the subscriber's server log. + the subscriber's server log if you remove 23505 from + . This seems like a pretty big regression. Being able to know why your replication got closed seems pretty critical. On Mon, 11 Mar 2024 at 03:44, Laurenz Albe wrote: > > On Sat, 2024-03-09 at 14:03 +0100, Laurenz Albe wrote: > > Here is a patch that implements this. > > And here is patch v2 that fixes a bug and passes the regression tests. > > Yours, > Laurenz Albe
Re: Reducing the log spam
On Sat, 2024-03-09 at 14:03 +0100, Laurenz Albe wrote:
> Here is a patch that implements this.
And here is patch v2 that fixes a bug and passes the regression tests.
Yours,
Laurenz Albe
From 6c72ea7d0aa1df569a4e53f54fcb1a11542ac0ef Mon Sep 17 00:00:00 2001
From: Laurenz Albe
Date: Mon, 11 Mar 2024 03:41:49 +0100
Subject: [PATCH v2] Add parameter log_suppress_errcodes
The parameter contains a list of SQLSTATEs for which
FATAL and ERROR messages are not logged. This is to
suppress messages that are of little interest to the
database administrator, but tend to clutter the log.
Author: Laurenz Albe
Discussion: https://postgr.es/m/408f399e7de1416c47bab7e260327ed5ad92838c.camel%40cybertec.at
---
doc/src/sgml/config.sgml | 34 +
doc/src/sgml/logical-replication.sgml | 3 +-
src/backend/utils/error/elog.c| 116 ++
src/backend/utils/misc/guc_tables.c | 11 ++
src/backend/utils/misc/postgresql.conf.sample | 4 +
src/bin/pg_ctl/t/004_logrotate.pl | 1 +
src/include/pg_config_manual.h| 10 ++
src/include/utils/guc.h | 1 +
src/include/utils/guc_hooks.h | 2 +
src/test/subscription/t/014_binary.pl | 5 +
src/test/subscription/t/029_on_error.pl | 1 +
11 files changed, 187 insertions(+), 1 deletion(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 43b1a132a2..89a698c7b6 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -6850,6 +6850,40 @@ local0.*/var/log/postgresql
+
+ log_suppress_errcodes (string)
+
+ log_suppress_errcodes configuration parameter
+
+
+
+
+Causes ERROR and FATAL messages
+with certain error codes to be excluded from the log.
+The value is a comma-separated list of five-character error codes as
+listed in . An error code that
+represents a class of errors (ends with three zeros) suppresses logging
+of all error codes within that class. For example, the entry
+08000 (connection_exception)
+would suppress an error with code 08P01
+(protocol_violation). The default setting is
+23505,3D000,3F000,42601,42704,42883,42P01,57P03.
+Only superusers and users with the appropriate SET
+privilege can change this setting.
+
+
+
+This setting is useful to exclude error messages from the log that are
+frequent but irrelevant. That makes it easier to spot relevant
+messages in the log and keeps log files from growing too big. For
+example, if you have a monitoring system that regularly establishes a
+TCP connection to the server without sending a correct startup packet,
+you could suppress the protocol violation errors by adding the error
+code 08P01 to the list.
+
+
+
+
log_min_duration_statement (integer)
diff --git a/doc/src/sgml/logical-replication.sgml b/doc/src/sgml/logical-replication.sgml
index ec2130669e..6c647a8782 100644
--- a/doc/src/sgml/logical-replication.sgml
+++ b/doc/src/sgml/logical-replication.sgml
@@ -1490,7 +1490,8 @@ test_sub=# SELECT * FROM t1 ORDER BY id;
A conflict will produce an error and will stop the replication; it must be
resolved manually by the user. Details about the conflict can be found in
- the subscriber's server log.
+ the subscriber's server log if you remove 23505 from
+ .
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index c9719f358b..01eb00e870 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -112,12 +112,16 @@ int Log_error_verbosity = PGERROR_DEFAULT;
char *Log_line_prefix = NULL; /* format for extra log line info */
int Log_destination = LOG_DESTINATION_STDERR;
char *Log_destination_string = NULL;
+char *log_suppress_errcodes = NULL;
bool syslog_sequence_numbers = true;
bool syslog_split_messages = true;
/* Processed form of backtrace_functions GUC */
static char *backtrace_function_list;
+/* Processed form form of log_suppress_errcodes (zero-terminated array) */
+static int *suppressed_errcodes;
+
#ifdef HAVE_SYSLOG
/*
@@ -866,6 +870,27 @@ errcode(int sqlerrcode)
edata->sqlerrcode = sqlerrcode;
+ /*
+ * ERROR and FATAL messages with codes in log_suppress_errcodes don't get
+ * logged.
+ */
+ if ((edata->elevel == ERROR ||
+ edata->elevel == FATAL) &&
+ suppressed_errcodes != NULL)
+ {
+ int *state;
+
+ for (state = suppressed_errcodes; *state != 0; state++)
+ /* error categories match all error codes in the category */
+ if (sqlerrcode == *state ||
+(ERRCODE_IS_CATEGORY(*state) &&
+ ERRCODE_TO_CATEGORY(sqlerrcode) == *state))
+ {
+edata->output_to_server = false;
+break;
+ }
+ }
+
return 0; /* return value does
Re: Reducing the log spam
On Thu, 2024-03-07 at 08:30 +0100, Laurenz Albe wrote: > On Wed, 2024-03-06 at 17:33 -0500, Isaac Morland wrote: > > I have two questions about this: > > > > First, can it be done per role? If I have a particular application which is > > constantly throwing some particular error, I might want to suppress it, but > > not suppress the same error occasionally coming from another application. > > I see ALTER DATABASE name SET configuration_parameter … as being useful > > here, > > but often multiple applications share a database. > > > > Second, where can this setting be adjusted? Can any session turn off logging > > of arbitrary sets of sqlstates resulting from its queries? It feels to me > > like that might allow security problems to be hidden. Specifically, the > > first > > thing an SQL injection might do would be to turn off logging of important > > error states, then proceed to try various nefarious things. > > I was envisioning the parameter to be like other logging parameters, for > example "log_statement": only superusers can set the parameter or GRANT > that privilege to others. Also, a superuser could use ALTER ROLE to set > the parameter for all sessions by that role. > > > It seems to me the above questions interact; an answer to the first might be > > "ALTER ROLE role_specification SET configuration_parameter", but I think > > that > > would allow roles to change their own settings, contrary to the concern > > raised by the second question. > > If a superuser sets "log_statement" on a role, that role cannot undo or change > the setting. That's just how I plan to implement the new parameter. Here is a patch that implements this. I went with "log_suppress_errcodes", since the term "error code" is used throughout our documentation. The initial value is 23505,3D000,3F000,42601,42704,42883,42P01,57P03 Yours, Laurenz Albe From 26465dafe4bcd2aea3889360987d2a863b66 Mon Sep 17 00:00:00 2001 From: Laurenz Albe Date: Sat, 9 Mar 2024 13:59:55 +0100 Subject: [PATCH v1] Add parameter log_suppress_errcodes The parameter contains a list of SQLSTATEs for which FATAL and ERROR messages are not logged. This is to suppress messages that are of little interest to the database administrator, but tend to clutter the log. Author: Laurenz Albe Discussion: https://postgr.es/m/408f399e7de1416c47bab7e260327ed5ad92838c.camel%40cybertec.at --- doc/src/sgml/config.sgml | 34 + src/backend/utils/error/elog.c| 118 ++ src/backend/utils/misc/guc_tables.c | 11 ++ src/backend/utils/misc/postgresql.conf.sample | 4 + src/include/pg_config_manual.h| 10 ++ src/include/utils/guc.h | 1 + src/include/utils/guc_hooks.h | 2 + 7 files changed, 180 insertions(+) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 43b1a132a2..f9487de06f 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -6850,6 +6850,40 @@ local0.*/var/log/postgresql + + log_suppress_errcodes (string) + + log_suppress_errcodes configuration parameter + + + + +Causes ERROR and FATAL messages +with certain error codes to be excluded from the log. +The value is a comma-separated list of five-character error codes as +listed in . An error code that +represents a class of errors (ends with three zeros) suppresses logging +of all error codes within that class. For example, the entry +08000 (connection_exception) +would suppress an error with code 08P01 +(protocol_violation). The default setting is +23505,3D000,3F000,42601,42704,42883,42P01,57P03. +Only superusers and users with the appropriate SET +privilege can change this setting. + + + +This setting is useful to exclude error messages from the log that are +frequent but irrelevant. That makes it easier to spot relevant +messages in the log and keeps log files from growing too big. For +example, if you have a monitoring system that regularly establishes a +TCP connection to the server without sending a correct startup packet, +you could suppress the protocol violation errors by adding error code +08P01 to the list. + + + + log_min_duration_statement (integer) diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index c9719f358b..4b38adfd4d 100644 --- a/src/backend/utils/error/elog.c +++ b/src/backend/utils/error/elog.c @@ -112,12 +112,16 @@ int Log_error_verbosity = PGERROR_DEFAULT; char *Log_line_prefix = NULL; /* format for extra log line info */ int Log_destination = LOG_DESTINATION_STDERR; char *Log_destination_string = NULL; +char *log_suppress_errcodes = NULL; bool syslog_sequence_numbers = true; bool syslog_spl
Re: Reducing the log spam
On Wed, 2024-03-06 at 17:33 -0500, Isaac Morland wrote: > I have two questions about this: > > First, can it be done per role? If I have a particular application which is > constantly throwing some particular error, I might want to suppress it, but > not suppress the same error occasionally coming from another application. > I see ALTER DATABASE name SET configuration_parameter … as being useful here, > but often multiple applications share a database. > > Second, where can this setting be adjusted? Can any session turn off logging > of arbitrary sets of sqlstates resulting from its queries? It feels to me > like that might allow security problems to be hidden. Specifically, the first > thing an SQL injection might do would be to turn off logging of important > error states, then proceed to try various nefarious things. I was envisioning the parameter to be like other logging parameters, for example "log_statement": only superusers can set the parameter or GRANT that privilege to others. Also, a superuser could use ALTER ROLE to set the parameter for all sessions by that role. > It seems to me the above questions interact; an answer to the first might be > "ALTER ROLE role_specification SET configuration_parameter", but I think that > would allow roles to change their own settings, contrary to the concern > raised by the second question. If a superuser sets "log_statement" on a role, that role cannot undo or change the setting. That's just how I plan to implement the new parameter. Yours, Laurenz Albe
Re: Reducing the log spam
On Tue, 5 Mar 2024 at 07:55, Laurenz Albe wrote: > Inspired by feedback to [1], I thought about how to reduce log spam. > > My experience from the field is that a lot of log spam looks like > > database/table/... "xy" does not exist > duplicate key value violates unique constraint "xy" > > So what about a parameter "log_suppress_sqlstates" that suppresses > logging ERROR and FATAL messages with the enumerated SQL states? > > My idea for a default setting would be something like > > log_suppress_sqlstates = '23505,3D000,3F000,42601,42704,42883,42P01' > > but that's of course bikeshedding territory. > I like the basic idea and the way of specifying states seems likely to cover a lot of typical use cases. Of course in principle the application should be fixed, but in practice we can't always control that. I have two questions about this: First, can it be done per role? If I have a particular application which is constantly throwing some particular error, I might want to suppress it, but not suppress the same error occasionally coming from another application. I see ALTER DATABASE name SET configuration_parameter … as being useful here, but often multiple applications share a database. Second, where can this setting be adjusted? Can any session turn off logging of arbitrary sets of sqlstates resulting from its queries? It feels to me like that might allow security problems to be hidden. Specifically, the first thing an SQL injection might do would be to turn off logging of important error states, then proceed to try various nefarious things. It seems to me the above questions interact; an answer to the first might be "ALTER ROLE role_specification SET configuration_parameter", but I think that would allow roles to change their own settings, contrary to the concern raised by the second question.
Re: Reducing the log spam
On Wed, 2024-03-06 at 10:50 -0500, Greg Sabino Mullane wrote: > On Tue, Mar 5, 2024 at 7:55 AM Laurenz Albe wrote: > > My experience from the field is that a lot of log spam looks like > > > > database/table/... "xy" does not exist > > duplicate key value violates unique constraint "xy" > > Forcibly hiding those at the Postgres level seems a heavy hammer for what is > ultimately an application problem. Yes... or no. Lots of applications violate constraints routinely. As long as the error is caught and handled, that's not a problem. Whoever cares about the log messages can enable them. My impression is that most people don't care about them. But thanks for your opinion. Yours, Laurenz Albe
Re: Reducing the log spam
On Wed, 2024-03-06 at 17:09 +0300, Aleksander Alekseev wrote: > I like the idea of suppressing certain log messages in general, but > the particular user interface doesn't strike me as an especially > convenient one. > > Firstly I don't think many people remember sqlstates and what 3F000 > stands for. IMO most users don't know such a thing exists. Secondly, > whether we should list sqlstates to suppress or the opposite - list > the states that shouldn't be suppressed, is a debatable question. Last > but not least, it's not quite clear whether PostgreSQL core is the > right place for implementing this functionality. For instance, one > could argue that the log message should just contain sqlstate and be > directed to |grep instead. > > I suspect this could be one of "there is no one size fits all" > situations. The typical solution in such cases is to form a structure > containing the log message and its attributes and submit this > structure to a registered hook of a pluggable logging subsystem. This > would be the most flexible approach. It will allow not only filtering > the messages but also using binary logging, JSON logging, logging to > external systems like Loki instead of a given text file, etc. > > I don't think we currently have this in the core, but maybe I just missed it. The target would not primarily be installations where people configure nifty logging software to filter logs (those people know how to deal with log spam), but installations where people don't even know enough to configure "shared_buffers". So I'd like something that is part of core and reduces spam without the user needing to configure anything. I am somewhat worried that people will come up with all kinds of justified but complicated wishes for such a feature: - an option to choose whether to include or to exclude certain errors - be able to configure that certain errors be logged on FATAL, but not on ERROR - allow exception names in addition to SQL states - have wildcards for exception names - ... I would like to write a simple patch that covers the basic functionality I described, provided enough people find it useful. That does not exclude the option for future extensions for this feature. Yours, Laurenz Albe
Re: Reducing the log spam
On Tue, Mar 5, 2024 at 7:55 AM Laurenz Albe wrote: > My experience from the field is that a lot of log spam looks like > > database/table/... "xy" does not exist > duplicate key value violates unique constraint "xy" Forcibly hiding those at the Postgres level seems a heavy hammer for what is ultimately an application problem. Tell me about a system that logs different classes of errors to different log files, and I'm interested again. Cheers, Greg
Re: Reducing the log spam
Hi, > So what about a parameter "log_suppress_sqlstates" that suppresses > logging ERROR and FATAL messages with the enumerated SQL states? > > My idea for a default setting would be something like > > log_suppress_sqlstates = '23505,3D000,3F000,42601,42704,42883,42P01' > > but that's of course bikeshedding territory. I like the idea of suppressing certain log messages in general, but the particular user interface doesn't strike me as an especially convenient one. Firstly I don't think many people remember sqlstates and what 3F000 stands for. IMO most users don't know such a thing exists. Secondly, whether we should list sqlstates to suppress or the opposite - list the states that shouldn't be suppressed, is a debatable question. Last but not least, it's not quite clear whether PostgreSQL core is the right place for implementing this functionality. For instance, one could argue that the log message should just contain sqlstate and be directed to |grep instead. I suspect this could be one of "there is no one size fits all" situations. The typical solution in such cases is to form a structure containing the log message and its attributes and submit this structure to a registered hook of a pluggable logging subsystem. This would be the most flexible approach. It will allow not only filtering the messages but also using binary logging, JSON logging, logging to external systems like Loki instead of a given text file, etc. I don't think we currently have this in the core, but maybe I just missed it. -- Best regards, Aleksander Alekseev
Re: Reducing the log spam
On Tue, 5 Mar 2024 at 14:55, Jim Jones wrote: > > So what about a parameter "log_suppress_sqlstates" that suppresses > > logging ERROR and FATAL messages with the enumerated SQL states? Big +1 from me for this idea.
Re: Reducing the log spam
Hi út 5. 3. 2024 v 14:55 odesílatel Jim Jones napsal: > Hi Laurenz > > On 05.03.24 13:55, Laurenz Albe wrote: > > Inspired by feedback to [1], I thought about how to reduce log spam. > > > > My experience from the field is that a lot of log spam looks like > > > >database/table/... "xy" does not exist > >duplicate key value violates unique constraint "xy" > > > > So what about a parameter "log_suppress_sqlstates" that suppresses > > logging ERROR and FATAL messages with the enumerated SQL states? > > > > My idea for a default setting would be something like > > > >log_suppress_sqlstates = '23505,3D000,3F000,42601,42704,42883,42P01' > > > > but that's of course bikeshedding territory. > > > > Yours, > > Laurenz Albe > > > > > > > > [1]: > https://postgr.es/m/b8b8502915e50f44deb111bc0b43a99e2733e117.camel%40cybertec.at > > I like this idea, and I could see myself using it a lot in some projects. > > Additionally, it would be nice to also have the possibility suppress a > whole class instead of single SQL states, e.g. > > log_suppress_sqlstates = 'class_08' to suppress these all at once: > > 08000 connection_exception > 08003 connection_does_not_exist > 08006 connection_failure > 08001 sqlclient_unable_to_establish_sqlconnection > 08004 sqlserver_rejected_establishment_of_sqlconnection > 08007 transaction_resolution_unknown > 08P01 protocol_violation > > It can take code from PLpgSQL. Regards Pavel > Best regards, > Jim > > > >
Re: Reducing the log spam
Hi Laurenz On 05.03.24 13:55, Laurenz Albe wrote: Inspired by feedback to [1], I thought about how to reduce log spam. My experience from the field is that a lot of log spam looks like database/table/... "xy" does not exist duplicate key value violates unique constraint "xy" So what about a parameter "log_suppress_sqlstates" that suppresses logging ERROR and FATAL messages with the enumerated SQL states? My idea for a default setting would be something like log_suppress_sqlstates = '23505,3D000,3F000,42601,42704,42883,42P01' but that's of course bikeshedding territory. Yours, Laurenz Albe [1]: https://postgr.es/m/b8b8502915e50f44deb111bc0b43a99e2733e117.camel%40cybertec.at I like this idea, and I could see myself using it a lot in some projects. Additionally, it would be nice to also have the possibility suppress a whole class instead of single SQL states, e.g. log_suppress_sqlstates = 'class_08' to suppress these all at once: 08000 connection_exception 08003 connection_does_not_exist 08006 connection_failure 08001 sqlclient_unable_to_establish_sqlconnection 08004 sqlserver_rejected_establishment_of_sqlconnection 08007 transaction_resolution_unknown 08P01 protocol_violation Best regards, Jim
Re: Reducing the log spam
Hi út 5. 3. 2024 v 13:55 odesílatel Laurenz Albe napsal: > Inspired by feedback to [1], I thought about how to reduce log spam. > > My experience from the field is that a lot of log spam looks like > > database/table/... "xy" does not exist > duplicate key value violates unique constraint "xy" > > So what about a parameter "log_suppress_sqlstates" that suppresses > logging ERROR and FATAL messages with the enumerated SQL states? > > My idea for a default setting would be something like > > log_suppress_sqlstates = '23505,3D000,3F000,42601,42704,42883,42P01' > +1 in this form the overhead of this implementation should be small Regards Pavel > but that's of course bikeshedding territory. > > Yours, > Laurenz Albe > > > > [1]: > https://postgr.es/m/b8b8502915e50f44deb111bc0b43a99e2733e117.camel%40cybertec.at > > >
Reducing the log spam
Inspired by feedback to [1], I thought about how to reduce log spam. My experience from the field is that a lot of log spam looks like database/table/... "xy" does not exist duplicate key value violates unique constraint "xy" So what about a parameter "log_suppress_sqlstates" that suppresses logging ERROR and FATAL messages with the enumerated SQL states? My idea for a default setting would be something like log_suppress_sqlstates = '23505,3D000,3F000,42601,42704,42883,42P01' but that's of course bikeshedding territory. Yours, Laurenz Albe [1]: https://postgr.es/m/b8b8502915e50f44deb111bc0b43a99e2733e117.camel%40cybertec.at
