[PATCH] Filter error log statements by sqlstate
Allow the default log_min_error_statement to be overridden per sqlstate
to make it possible to filter out some error types while maintaining a
low log_min_error_statement or enable logging for some error types when
the default is to not log anything.
I've tried to do something like this using rsyslog filters, but that's
pretty awkward and doesn't work at all when the statement is split to
multiple syslog messages.
https://github.com/saaros/postgres/compare/log-by-sqlstate
src/backend/utils/error/elog.c | 183
++++++++++++++++++++++++++++++++++++++++-
src/backend/utils/misc/guc.c | 14 +++-
src/include/utils/guc.h | 4 +
src/include/utils/guc_tables.h | 1 +
4 files changed, 199 insertions(+), 3 deletions(-)
/ Oskari
Attachments:
0001-Filter-error-log-statements-by-sqlstate.patchtext/x-patch; name=0001-Filter-error-log-statements-by-sqlstate.patchDownload
>From 61fe332f35f49c59257e9dcd0b5e2ff80f1f4055 Mon Sep 17 00:00:00 2001
From: Oskari Saarenmaa <os@ohmu.fi>
Date: Thu, 9 Jan 2014 20:49:28 +0200
Subject: [PATCH] Filter error log statements by sqlstate
Allow the default log_min_error_statement to be overridden per sqlstate to
make it possible to filter out some error types while maintaining a low
log_min_error_statement or enable logging for some error types when the
default is to not log anything.
---
src/backend/utils/error/elog.c | 183 ++++++++++++++++++++++++++++++++++++++++-
src/backend/utils/misc/guc.c | 14 +++-
src/include/utils/guc.h | 4 +
src/include/utils/guc_tables.h | 1 +
4 files changed, 199 insertions(+), 3 deletions(-)
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index 3de162b..c843e1a 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -74,7 +74,9 @@
#include "storage/ipc.h"
#include "storage/proc.h"
#include "tcop/tcopprot.h"
+#include "utils/builtins.h"
#include "utils/guc.h"
+#include "utils/guc_tables.h"
#include "utils/memutils.h"
#include "utils/ps_status.h"
@@ -111,6 +113,11 @@ char *Log_line_prefix = NULL; /* format for extra log line info */
int Log_destination = LOG_DESTINATION_STDERR;
char *Log_destination_string = NULL;
+static uint64 *log_sqlstate_error_statement = NULL;
+static size_t log_sqlstate_error_statement_len = 0;
+
+static int get_sqlstate_error_level(int sqlstate);
+
#ifdef HAVE_SYSLOG
/*
@@ -2475,6 +2482,7 @@ static void
write_csvlog(ErrorData *edata)
{
StringInfoData buf;
+ int requested_log_level;
bool print_stmt = false;
/* static counter for line numbers */
@@ -2618,7 +2626,10 @@ write_csvlog(ErrorData *edata)
appendStringInfoChar(&buf, ',');
/* user query --- only reported if not disabled by the caller */
- if (is_log_level_output(edata->elevel, log_min_error_statement) &&
+ requested_log_level = get_sqlstate_error_level(edata->sqlerrcode);
+ if (requested_log_level < 0)
+ requested_log_level = log_min_error_statement;
+ if (is_log_level_output(edata->elevel, requested_log_level) &&
debug_query_string != NULL &&
!edata->hide_stmt)
print_stmt = true;
@@ -2691,6 +2702,7 @@ static void
send_message_to_server_log(ErrorData *edata)
{
StringInfoData buf;
+ int requested_log_level;
initStringInfo(&buf);
@@ -2775,7 +2787,10 @@ send_message_to_server_log(ErrorData *edata)
/*
* If the user wants the query that generated this error logged, do it.
*/
- if (is_log_level_output(edata->elevel, log_min_error_statement) &&
+ requested_log_level = get_sqlstate_error_level(edata->sqlerrcode);
+ if (requested_log_level < 0)
+ requested_log_level = log_min_error_statement;
+ if (is_log_level_output(edata->elevel, requested_log_level) &&
debug_query_string != NULL &&
!edata->hide_stmt)
{
@@ -3577,3 +3592,167 @@ trace_recovery(int trace_level)
return trace_level;
}
+
+
+/*
+*/
+static int
+get_sqlstate_error_level(int sqlstate)
+{
+ uint64 left = 0, right = log_sqlstate_error_statement_len;
+ while (left < right)
+ {
+ uint64 middle = left + (right - left) / 2;
+ int m_sqlstate = log_sqlstate_error_statement[middle] >> 32;
+
+ if (m_sqlstate == sqlstate)
+ return log_sqlstate_error_statement[middle] & 0xFFFFFFFF;
+ else if (m_sqlstate < sqlstate)
+ left = middle + 1;
+ else
+ right = middle;
+ }
+ return -1;
+}
+
+bool
+check_log_sqlstate_error(char **newval, void **extra, GucSource source)
+{
+ const struct config_enum_entry *enum_entry;
+ char *rawstring, *new_newval, *rp;
+ List *elemlist;
+ ListCell *l;
+ uint64 *new_array = NULL;
+ int i, new_array_len = 0;
+
+ /* Need a modifiable copy of string */
+ rawstring = pstrdup(*newval);
+
+ /* Parse string into list of identifiers */
+ if (!SplitIdentifierString(rawstring, ',', &elemlist))
+ {
+ /* syntax error in list */
+ GUC_check_errdetail("List syntax is invalid.");
+ pfree(rawstring);
+ list_free(elemlist);
+ return false;
+ }
+
+ /* GUC wants malloced results, allocate room for as many elements on
+ * the list plus one to hold the array size */
+ new_array = (uint64 *) malloc(sizeof(uint64) * (list_length(elemlist) + 1));
+ if (!new_array)
+ {
+ pfree(rawstring);
+ list_free(elemlist);
+ return false;
+ }
+
+ /* validate list and insert the results in a sorted array */
+ foreach(l, elemlist)
+ {
+ char *tok = lfirst(l), *level_str = strchr(tok, ':');
+ int level = -1, sqlstate;
+ uint64 value;
+
+ if (level_str != NULL && (level_str - tok) == 5)
+ {
+ for (enum_entry = server_message_level_options;
+ enum_entry && enum_entry->name;
+ enum_entry++)
+ {
+ if (pg_strcasecmp(enum_entry->name, level_str + 1) == 0)
+ {
+ level = enum_entry->val;
+ break;
+ }
+ }
+ }
+ if (level < 0)
+ {
+ GUC_check_errdetail("Invalid sqlstate error definition: \"%s\".", tok);
+ new_array_len = -1;
+ break;
+ }
+ sqlstate = MAKE_SQLSTATE(pg_ascii_toupper(tok[0]), pg_ascii_toupper(tok[1]),
+ pg_ascii_toupper(tok[2]), pg_ascii_toupper(tok[3]),
+ pg_ascii_toupper(tok[4]));
+ value = (((uint64) sqlstate) << 32) | ((uint64) level);
+
+ for (i = 0; i <= new_array_len; i++)
+ {
+ if (i == new_array_len)
+ {
+ new_array[++new_array_len] = value;
+ break;
+ }
+ else if (sqlstate == (int) (new_array[i + 1] >> 32))
+ {
+ new_array[i + 1] = value;
+ break;
+ }
+ else if (sqlstate < (int) (new_array[i + 1] >> 32))
+ {
+ memmove(&new_array[i + 2], &new_array[i + 1],
+ (new_array_len - i) * sizeof(uint64));
+ ++new_array_len;
+ new_array[i + 1] = value;
+ break;
+ }
+ }
+ }
+
+ pfree(rawstring);
+ list_free(elemlist);
+
+ if (new_array_len < 0)
+ {
+ free(new_array);
+ return false;
+ }
+
+ /* store the length in the first field */
+ new_array[0] = new_array_len;
+
+ /* return the canonical version */
+ new_newval = (char *) malloc(strlen("XX000:warning,") * new_array_len);
+ if (!new_newval)
+ {
+ free(new_array);
+ return false;
+ }
+
+ rp = new_newval;
+ for (i = 1; i <= new_array_len; i++)
+ {
+ const char *level_str = "null";
+ for (enum_entry = server_message_level_options;
+ enum_entry && enum_entry->name;
+ enum_entry++)
+ {
+ if (enum_entry->val == (new_array[i] & 0xFFFFFFFF))
+ {
+ level_str = enum_entry->name;
+ break;
+ }
+ }
+ if (i > 1)
+ *rp++ = ',';
+ rp += sprintf(rp, "%s:%s",
+ unpack_sql_state(new_array[i] >> 32), level_str);
+ }
+
+ free(*newval);
+ *newval = new_newval;
+ *extra = new_array;
+
+ return true;
+}
+
+void
+assign_log_sqlstate_error(const char *newval, void *extra)
+{
+ uint64 *myextra = (uint64 *) extra;
+ log_sqlstate_error_statement_len = myextra[0];
+ log_sqlstate_error_statement = &myextra[1];
+}
diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c
index 1217098..775a20e 100644
--- a/src/backend/utils/misc/guc.c
+++ b/src/backend/utils/misc/guc.c
@@ -245,7 +245,7 @@ static const struct config_enum_entry client_message_level_options[] = {
{NULL, 0, false}
};
-static const struct config_enum_entry server_message_level_options[] = {
+const struct config_enum_entry server_message_level_options[] = {
{"debug", DEBUG2, true},
{"debug5", DEBUG5, false},
{"debug4", DEBUG4, false},
@@ -465,6 +465,7 @@ static char *server_version_string;
static int server_version_num;
static char *timezone_string;
static char *log_timezone_string;
+static char *log_sqlstate_error_statement_str;
static char *timezone_abbreviations_string;
static char *XactIsoLevel_string;
static char *session_authorization_string;
@@ -2947,6 +2948,17 @@ static struct config_string ConfigureNamesString[] =
},
{
+ {"log_sqlstate_error_statement", PGC_SUSET, LOGGING_WHEN,
+ gettext_noop("Overrides minimum error level per error type"),
+ gettext_noop("Value must be a comma-separated list in the format "
+ "\"sqlstate:level,...\"."),
+ },
+ &log_sqlstate_error_statement_str,
+ "",
+ check_log_sqlstate_error, assign_log_sqlstate_error, NULL
+ },
+
+ {
{"syslog_ident", PGC_SIGHUP, LOGGING_WHERE,
gettext_noop("Sets the program name used to identify PostgreSQL "
"messages in syslog."),
diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h
index 3adcc99..2ed5677 100644
--- a/src/include/utils/guc.h
+++ b/src/include/utils/guc.h
@@ -391,4 +391,8 @@ extern bool check_effective_cache_size(int *newval, void **extra, GucSource sour
extern void set_default_effective_cache_size(void);
extern void assign_xlog_sync_method(int new_sync_method, void *extra);
+/* in src/backend/utils/error/elog.c */
+extern void assign_log_sqlstate_error(const char *newval, void *extra);
+extern bool check_log_sqlstate_error(char **newval, void **extra, GucSource source);
+
#endif /* GUC_H */
diff --git a/src/include/utils/guc_tables.h b/src/include/utils/guc_tables.h
index 47ff880..1e577a4 100644
--- a/src/include/utils/guc_tables.h
+++ b/src/include/utils/guc_tables.h
@@ -251,6 +251,7 @@ extern const char *const config_group_names[];
extern const char *const config_type_names[];
extern const char *const GucContext_Names[];
extern const char *const GucSource_Names[];
+extern const struct config_enum_entry server_message_level_options[];
/* get the current set of variables */
extern struct config_generic **get_guc_variables(void);
--
1.8.4.2
Hi Oskari,
I had a quick look over the patch (Not compiled though). Here are few
comments on the changes:
1. Documentation is missing and thus becomes difficult to understand what
exactly you are trying to do. Or in other words, user will be uncertain
about
using it more efficiently.
2. Some more comments required. At each new function and specifically at
get_sqlstate_error_level().
3. Please add test-case if possible.
4. Some code part does not comply with PostgreSQL indentation style. (Can be
ignored as it will pass through pg_indent, but better fix it).
5. You have used ""XX000:warning," string to get maximum possible length of
the valid sqlstate:level identifier. It's perfect, but small explanation
about
that will be good there. Also in future if we have any other error level
which
exceeds this, we need changes here too. Right ?
I will look into this further. But please have your attention on above
points.
Thanks
On Fri, Jan 10, 2014 at 12:56 AM, Oskari Saarenmaa <os@ohmu.fi> wrote:
Allow the default log_min_error_statement to be overridden per sqlstate to
make it possible to filter out some error types while maintaining a low
log_min_error_statement or enable logging for some error types when the
default is to not log anything.I've tried to do something like this using rsyslog filters, but that's
pretty awkward and doesn't work at all when the statement is split to
multiple syslog messages.https://github.com/saaros/postgres/compare/log-by-sqlstate
src/backend/utils/error/elog.c | 183 ++++++++++++++++++++++++++++++
++++++++++-
src/backend/utils/misc/guc.c | 14 +++-
src/include/utils/guc.h | 4 +
src/include/utils/guc_tables.h | 1 +
4 files changed, 199 insertions(+), 3 deletions(-)/ Oskari
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
--
Jeevan B Chalke
Principal Software Engineer, Product Development
EnterpriseDB Corporation
The Enterprise PostgreSQL Company
Phone: +91 20 30589500
Website: www.enterprisedb.com
EnterpriseDB Blog: http://blogs.enterprisedb.com/
Follow us on Twitter: http://www.twitter.com/enterprisedb
This e-mail message (and any attachment) is intended for the use of the
individual or entity to whom it is addressed. This message contains
information from EnterpriseDB Corporation that may be privileged,
confidential, or exempt from disclosure under applicable law. If you are
not the intended recipient or authorized to receive this for the intended
recipient, any use, dissemination, distribution, retention, archiving, or
copying of this communication is strictly prohibited. If you have received
this e-mail in error, please notify the sender immediately by reply e-mail
and delete this message.
Hi,
On 13/01/14 10:26, Jeevan Chalke wrote:
1. Documentation is missing and thus becomes difficult to understand what
exactly you are trying to do. Or in other words, user will be uncertain
about using it more efficiently.
I figured I'd write documentation for this if it looks like a useful
feature which would be accepted for 9.4, but I guess it would've helped
to have a bit better description of this for the initial submission as well.
2. Some more comments required. At each new function and specifically at
get_sqlstate_error_level().
Just after I submitted the patch I noticed that I had a placeholder for
comment about that function but never wrote the actual comment, sorry
about that.
3. Please add test-case if possible.
Sure.
4. Some code part does not comply with PostgreSQL indentation style. (Can be
ignored as it will pass through pg_indent, but better fix it).
I'll try to fix this for v2.
5. You have used ""XX000:warning," string to get maximum possible length of
the valid sqlstate:level identifier. It's perfect, but small explanation
about that will be good there. Also in future if we have any other error level
which exceeds this, we need changes here too. Right ?
Good point, I'll address this in v2.
I will look into this further. But please have your attention on above
points.
Thanks for the review!
/ Oskari
On Fri, Jan 10, 2014 at 12:56 AM, Oskari Saarenmaa <os@ohmu.fi>
wrote:Allow the default log_min_error_statement to be overridden per
sqlstate to make it possible to filter out some error types while
maintaining a low log_min_error_statement or enable logging for some
error types when the default is to not log anything.I've tried to do something like this using rsyslog filters, but
that's pretty awkward and doesn't work at all when the statement is
split to multiple syslog messages.
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
On Mon, Jan 13, 2014 at 4:30 PM, Oskari Saarenmaa <os@ohmu.fi> wrote:
Hi,
On 13/01/14 10:26, Jeevan Chalke wrote:
1. Documentation is missing and thus becomes difficult to understand what
exactly you are trying to do. Or in other words, user will be uncertain
about using it more efficiently.I figured I'd write documentation for this if it looks like a useful
feature which would be accepted for 9.4, but I guess it would've helped to
have a bit better description of this for the initial submission as well.2. Some more comments required. At each new function and specifically at
get_sqlstate_error_level().
Just after I submitted the patch I noticed that I had a placeholder for
comment about that function but never wrote the actual comment, sorry about
that.3. Please add test-case if possible.
Sure.
4. Some code part does not comply with PostgreSQL indentation style. (Can
be
ignored as it will pass through pg_indent, but better fix it).I'll try to fix this for v2.
5. You have used ""XX000:warning," string to get maximum possible length
of
the valid sqlstate:level identifier. It's perfect, but small explanation
about that will be good there. Also in future if we have any other error
level
which exceeds this, we need changes here too. Right ?Good point, I'll address this in v2.
I will look into this further. But please have your attention on above
points.
Thanks for the review!
Since you are taking care of most of the points above. I will wait for v2
patch. Till then marking "Waiting on Author".
Thanks
/ Oskari
On Fri, Jan 10, 2014 at 12:56 AM, Oskari Saarenmaa <os@ohmu.fi>
wrote:
Allow the default log_min_error_statement to be overridden per
sqlstate to make it possible to filter out some error types while
maintaining a low log_min_error_statement or enable logging for some
error types when the default is to not log anything.I've tried to do something like this using rsyslog filters, but
that's pretty awkward and doesn't work at all when the statement is
split to multiple syslog messages.
--
Jeevan B Chalke
Principal Software Engineer, Product Development
EnterpriseDB Corporation
The Enterprise PostgreSQL Company
Phone: +91 20 30589500
Website: www.enterprisedb.com
EnterpriseDB Blog: http://blogs.enterprisedb.com/
Follow us on Twitter: http://www.twitter.com/enterprisedb
This e-mail message (and any attachment) is intended for the use of the
individual or entity to whom it is addressed. This message contains
information from EnterpriseDB Corporation that may be privileged,
confidential, or exempt from disclosure under applicable law. If you are
not the intended recipient or authorized to receive this for the intended
recipient, any use, dissemination, distribution, retention, archiving, or
copying of this communication is strictly prohibited. If you have received
this e-mail in error, please notify the sender immediately by reply e-mail
and delete this message.
On Tue, Jan 14, 2014 at 12:22:30PM +0530, Jeevan Chalke wrote:
On Mon, Jan 13, 2014 at 4:30 PM, Oskari Saarenmaa <os@ohmu.fi> wrote:
On 13/01/14 10:26, Jeevan Chalke wrote:
1. Documentation is missing and thus becomes difficult to understand
what exactly you are trying to do. Or in other words, user will be
uncertain about using it more efficiently.I figured I'd write documentation for this if it looks like a useful
feature which would be accepted for 9.4, but I guess it would've
helped to have a bit better description of this for the initial
submission as well.2. Some more comments required. At each new function and
specifically at get_sqlstate_error_level().Just after I submitted the patch I noticed that I had a placeholder
for comment about that function but never wrote the actual comment,
sorry about that.3. Please add test-case if possible.
Sure.
4. Some code part does not comply with PostgreSQL indentation style.
(Can be ignored as it will pass through pg_indent, but better fix
it).I'll try to fix this for v2.
5. You have used ""XX000:warning," string to get maximum possible
length of the valid sqlstate:level identifier. It's perfect, but
small explanation about that will be good there. Also in future if
we have any other error level which exceeds this, we need changes
here too. Right ?Good point, I'll address this in v2.
I will look into this further. But please have your attention on above
points.Thanks for the review!
Since you are taking care of most of the points above. I will wait for v2
patch. Till then marking "Waiting on Author".
Attached v2 of the patch which addresses the above points. I couldn't
figure out how to test log output, but at least the patch now tests that
it can set and show the log level.
Thanks,
Oskari
Attachments:
0001-Filter-error-log-statements-by-sqlstate.patchtext/plain; charset=us-asciiDownload
>From 213f647657f318141e3866087a17a863a0f322d9 Mon Sep 17 00:00:00 2001
From: Oskari Saarenmaa <os@ohmu.fi>
Date: Tue, 14 Jan 2014 15:47:39 +0200
Subject: [PATCH] Filter error log statements by sqlstate
Allow the default log_min_error_statement to be overridden per sqlstate to
make it possible to filter out some error types while maintaining a low
log_min_error_statement or enable logging for some error types when the
default is to not log anything.
---
doc/src/sgml/config.sgml | 30 ++++++
src/backend/utils/error/elog.c | 220 +++++++++++++++++++++++++++++++++++++-
src/backend/utils/misc/guc.c | 14 ++-
src/include/utils/guc.h | 4 +
src/include/utils/guc_tables.h | 1 +
src/test/regress/expected/guc.out | 24 +++++
src/test/regress/sql/guc.sql | 8 ++
7 files changed, 298 insertions(+), 3 deletions(-)
diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 0f2f2bf..73a58ad 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -3743,6 +3743,36 @@ local0.* /var/log/postgresql
</listitem>
</varlistentry>
+ <varlistentry id="guc-log-sqlstate-error-statement" xreflabel="log_sqlstate_error_statement">
+ <term><varname>log_sqlstate_error_statement</varname> (<type>string</type>)</term>
+ <indexterm>
+ <primary><varname>log_sqlstate_error_statement</> configuration parameter</primary>
+ </indexterm>
+ <listitem>
+ <para>
+ Controls which error types in SQL statements condition are recorded
+ in the server log. This overrides the global <xref
+ linkend="guc-log-min-messages"> per error type and can be used to
+ disable logging for certain error types and/or to enable logging for
+ other types.
+ </para>
+ <para>
+ The value must be a comma-separated list in the form
+ <literal>'ERRORCODE:LOGLEVEL,...'</literal>. For example, a setting
+ of <literal>'P0001:PANIC,22012:ERROR'</literal> would never log the
+ SQL statements for errors generated by the PL/pgSQL
+ <literal>RAISE</literal> statement but would always log the
+ statements causing division by zero errors.
+
+ See <xref linkend="errcodes-appendix"> for the list of valid error
+ codes and <xref linkend="guc-log-min-messages"> for valid log
+ levels.
+
+ Only superusers can change this setting.
+ </para>
+ </listitem>
+ </varlistentry>
+
<varlistentry id="guc-log-min-duration-statement" xreflabel="log_min_duration_statement">
<term><varname>log_min_duration_statement</varname> (<type>integer</type>)</term>
<indexterm>
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index 8705586..2e74fd5 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -74,7 +74,9 @@
#include "storage/ipc.h"
#include "storage/proc.h"
#include "tcop/tcopprot.h"
+#include "utils/builtins.h"
#include "utils/guc.h"
+#include "utils/guc_tables.h"
#include "utils/memutils.h"
#include "utils/ps_status.h"
@@ -111,6 +113,11 @@ char *Log_line_prefix = NULL; /* format for extra log line info */
int Log_destination = LOG_DESTINATION_STDERR;
char *Log_destination_string = NULL;
+static uint64 *log_sqlstate_error_statement = NULL;
+static size_t log_sqlstate_error_statement_len = 0;
+
+static int get_sqlstate_error_level(int sqlstate);
+
#ifdef HAVE_SYSLOG
/*
@@ -2496,6 +2503,7 @@ static void
write_csvlog(ErrorData *edata)
{
StringInfoData buf;
+ int requested_log_level;
bool print_stmt = false;
/* static counter for line numbers */
@@ -2639,7 +2647,10 @@ write_csvlog(ErrorData *edata)
appendStringInfoChar(&buf, ',');
/* user query --- only reported if not disabled by the caller */
- if (is_log_level_output(edata->elevel, log_min_error_statement) &&
+ requested_log_level = get_sqlstate_error_level(edata->sqlerrcode);
+ if (requested_log_level < 0)
+ requested_log_level = log_min_error_statement;
+ if (is_log_level_output(edata->elevel, requested_log_level) &&
debug_query_string != NULL &&
!edata->hide_stmt)
print_stmt = true;
@@ -2712,6 +2723,7 @@ static void
send_message_to_server_log(ErrorData *edata)
{
StringInfoData buf;
+ int requested_log_level;
initStringInfo(&buf);
@@ -2796,7 +2808,10 @@ send_message_to_server_log(ErrorData *edata)
/*
* If the user wants the query that generated this error logged, do it.
*/
- if (is_log_level_output(edata->elevel, log_min_error_statement) &&
+ requested_log_level = get_sqlstate_error_level(edata->sqlerrcode);
+ if (requested_log_level < 0)
+ requested_log_level = log_min_error_statement;
+ if (is_log_level_output(edata->elevel, requested_log_level) &&
debug_query_string != NULL &&
!edata->hide_stmt)
{
@@ -3598,3 +3613,204 @@ trace_recovery(int trace_level)
return trace_level;
}
+
+
+/*
+ * Statement log error level can be overriden per sqlstate, the variable
+ * log_sqlstate_error_statement is a sorted array of
+ * log_sqlstate_error_statement_len uint64s where the high 32 bits contain
+ * the sqlstate and low 32 bits contain the required error level.
+ */
+
+/*
+ * get_sqlstate_error_level - perform a binary search for the requested
+ * state and return if it was found; return -1 if it was not found.
+ */
+static int
+get_sqlstate_error_level(int sqlstate)
+{
+ uint64 left = 0,
+ right = log_sqlstate_error_statement_len;
+
+ while (left < right)
+ {
+ uint64 middle = left + (right - left) / 2;
+ int m_sqlstate = log_sqlstate_error_statement[middle] >> 32;
+
+ if (m_sqlstate == sqlstate)
+ return log_sqlstate_error_statement[middle] & 0xFFFFFFFF;
+ else if (m_sqlstate < sqlstate)
+ left = middle + 1;
+ else
+ right = middle;
+ }
+ return -1;
+}
+
+/*
+ * check_log_sqlstate_error - validate sqlstate:errorlevel lists and create
+ * sorted uint64 arrays from them; last occurance of each sqlstate is used.
+ */
+bool
+check_log_sqlstate_error(char **newval, void **extra, GucSource source)
+{
+ const struct config_enum_entry *enum_entry;
+ char *rawstring,
+ *new_newval,
+ *new_newval_end,
+ *vptr;
+ List *elemlist;
+ ListCell *l;
+ uint64 *new_array = NULL;
+ int i,
+ new_array_len = 0;
+
+ /* Need a modifiable copy of string */
+ rawstring = pstrdup(*newval);
+
+ /* Parse string into list of identifiers */
+ if (!SplitIdentifierString(rawstring, ',', &elemlist))
+ {
+ /* syntax error in list */
+ GUC_check_errdetail("List syntax is invalid.");
+ pfree(rawstring);
+ list_free(elemlist);
+ return false;
+ }
+
+ /*
+ * GUC wants malloced results, allocate room for as many elements on the
+ * list plus one to hold the array size
+ */
+ new_array = (uint64 *) malloc(sizeof(uint64) * (list_length(elemlist) + 1));
+ if (!new_array)
+ {
+ pfree(rawstring);
+ list_free(elemlist);
+ return false;
+ }
+
+ /* validate list and insert the results in a sorted array */
+ foreach(l, elemlist)
+ {
+ char *tok = lfirst(l),
+ *level_str = strchr(tok, ':');
+ int level = -1,
+ sqlstate;
+ uint64 value;
+
+ if (level_str != NULL && (level_str - tok) == 5)
+ {
+ for (enum_entry = server_message_level_options;
+ enum_entry && enum_entry->name;
+ enum_entry++)
+ {
+ if (pg_strcasecmp(enum_entry->name, level_str + 1) == 0)
+ {
+ level = enum_entry->val;
+ break;
+ }
+ }
+ }
+ if (level < 0)
+ {
+ GUC_check_errdetail("Invalid sqlstate error definition: \"%s\".", tok);
+ new_array_len = -1;
+ break;
+ }
+ sqlstate = MAKE_SQLSTATE(pg_ascii_toupper(tok[0]), pg_ascii_toupper(tok[1]),
+ pg_ascii_toupper(tok[2]), pg_ascii_toupper(tok[3]),
+ pg_ascii_toupper(tok[4]));
+ value = (((uint64) sqlstate) << 32) | ((uint64) level);
+
+ for (i = 0; i <= new_array_len; i++)
+ {
+ if (i == new_array_len)
+ {
+ new_array[++new_array_len] = value;
+ break;
+ }
+ else if (sqlstate == (int) (new_array[i + 1] >> 32))
+ {
+ new_array[i + 1] = value;
+ break;
+ }
+ else if (sqlstate < (int) (new_array[i + 1] >> 32))
+ {
+ memmove(&new_array[i + 2], &new_array[i + 1],
+ (new_array_len - i) * sizeof(uint64));
+ ++new_array_len;
+ new_array[i + 1] = value;
+ break;
+ }
+ }
+ }
+
+ pfree(rawstring);
+ list_free(elemlist);
+
+ if (new_array_len < 0)
+ {
+ free(new_array);
+ return false;
+ }
+
+ /* store the length in the first field */
+ new_array[0] = new_array_len;
+
+ /*
+ * calculate the maximum length for the canonical string and
+ * allocate a buffer for it. sqlstate is always 5 characters and
+ * the longest error level string currently is 'warning'.
+ */
+ new_newval = (char *) malloc(strlen("XX000:warning,") * new_array_len + 1);
+ if (!new_newval)
+ {
+ free(new_array);
+ return false;
+ }
+
+ vptr = new_newval;
+ for (i = 1; i <= new_array_len; i++)
+ {
+ const char *level_str = "null";
+
+ for (enum_entry = server_message_level_options;
+ enum_entry && enum_entry->name;
+ enum_entry++)
+ {
+ if (enum_entry->val == (new_array[i] & 0xFFFFFFFF))
+ {
+ level_str = enum_entry->name;
+ break;
+ }
+ }
+
+ vptr += snprintf(vptr, new_newval_end - vptr, "%s%s:%s",
+ (i > 1) ? "," : "",
+ unpack_sql_state(new_array[i] >> 32),
+ level_str);
+ }
+ *vptr = 0;
+
+ free(*newval);
+ *newval = new_newval;
+ *extra = new_array;
+
+ return true;
+}
+
+/*
+ * assign_log_sqlstate_error - take the array generated by
+ * check_log_sqlstate_error into use. 'extra' is an array of uint64s where
+ * the first element contains the list length and the remainder is
+ * sqlstate:errorlevel values.
+ */
+void
+assign_log_sqlstate_error(const char *newval, void *extra)
+{
+ uint64 *myextra = (uint64 *) extra;
+
+ log_sqlstate_error_statement_len = myextra[0];
+ log_sqlstate_error_statement = &myextra[1];
+}
diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c
index 1217098..f6cbee5 100644
--- a/src/backend/utils/misc/guc.c
+++ b/src/backend/utils/misc/guc.c
@@ -245,7 +245,7 @@ static const struct config_enum_entry client_message_level_options[] = {
{NULL, 0, false}
};
-static const struct config_enum_entry server_message_level_options[] = {
+const struct config_enum_entry server_message_level_options[] = {
{"debug", DEBUG2, true},
{"debug5", DEBUG5, false},
{"debug4", DEBUG4, false},
@@ -465,6 +465,7 @@ static char *server_version_string;
static int server_version_num;
static char *timezone_string;
static char *log_timezone_string;
+static char *log_sqlstate_error_statement_str;
static char *timezone_abbreviations_string;
static char *XactIsoLevel_string;
static char *session_authorization_string;
@@ -2947,6 +2948,17 @@ static struct config_string ConfigureNamesString[] =
},
{
+ {"log_sqlstate_error_statement", PGC_SUSET, LOGGING_WHEN,
+ gettext_noop("Overrides minimum error level per error type"),
+ gettext_noop("Value must be a comma-separated list in the format "
+ "\"sqlstate:level,...\"."),
+ },
+ &log_sqlstate_error_statement_str,
+ "",
+ check_log_sqlstate_error, assign_log_sqlstate_error, NULL
+ },
+
+ {
{"syslog_ident", PGC_SIGHUP, LOGGING_WHERE,
gettext_noop("Sets the program name used to identify PostgreSQL "
"messages in syslog."),
diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h
index 3adcc99..2ed5677 100644
--- a/src/include/utils/guc.h
+++ b/src/include/utils/guc.h
@@ -391,4 +391,8 @@ extern bool check_effective_cache_size(int *newval, void **extra, GucSource sour
extern void set_default_effective_cache_size(void);
extern void assign_xlog_sync_method(int new_sync_method, void *extra);
+/* in src/backend/utils/error/elog.c */
+extern void assign_log_sqlstate_error(const char *newval, void *extra);
+extern bool check_log_sqlstate_error(char **newval, void **extra, GucSource source);
+
#endif /* GUC_H */
diff --git a/src/include/utils/guc_tables.h b/src/include/utils/guc_tables.h
index 47ff880..1e577a4 100644
--- a/src/include/utils/guc_tables.h
+++ b/src/include/utils/guc_tables.h
@@ -251,6 +251,7 @@ extern const char *const config_group_names[];
extern const char *const config_type_names[];
extern const char *const GucContext_Names[];
extern const char *const GucSource_Names[];
+extern const struct config_enum_entry server_message_level_options[];
/* get the current set of variables */
extern struct config_generic **get_guc_variables(void);
diff --git a/src/test/regress/expected/guc.out b/src/test/regress/expected/guc.out
index 4f0065c..0d0c4e0 100644
--- a/src/test/regress/expected/guc.out
+++ b/src/test/regress/expected/guc.out
@@ -736,3 +736,27 @@ NOTICE: text search configuration "no_such_config" does not exist
select func_with_bad_set();
ERROR: invalid value for parameter "default_text_search_config": "no_such_config"
reset check_function_bodies;
+-- Test logging options
+SET log_sqlstate_error_statement = 'XX000:PANIC,22012:error,xx000:log';
+SHOW log_sqlstate_error_statement;
+ log_sqlstate_error_statement
+------------------------------
+ XX000:log,22012:error
+(1 row)
+
+SET log_sqlstate_error_statement = '';
+SHOW log_sqlstate_error_statement;
+ log_sqlstate_error_statement
+------------------------------
+
+(1 row)
+
+SET log_sqlstate_error_statement = 'x';
+ERROR: invalid value for parameter "log_sqlstate_error_statement": "x"
+DETAIL: Invalid sqlstate error definition: "x".
+SHOW log_sqlstate_error_statement;
+ log_sqlstate_error_statement
+------------------------------
+
+(1 row)
+
diff --git a/src/test/regress/sql/guc.sql b/src/test/regress/sql/guc.sql
index 3de8a6b..508a8a4 100644
--- a/src/test/regress/sql/guc.sql
+++ b/src/test/regress/sql/guc.sql
@@ -275,3 +275,11 @@ set default_text_search_config = no_such_config;
select func_with_bad_set();
reset check_function_bodies;
+
+-- Test logging options
+SET log_sqlstate_error_statement = 'XX000:PANIC,22012:error,xx000:log';
+SHOW log_sqlstate_error_statement;
+SET log_sqlstate_error_statement = '';
+SHOW log_sqlstate_error_statement;
+SET log_sqlstate_error_statement = 'x';
+SHOW log_sqlstate_error_statement;
--
1.8.4.2
Hi Oskari,
Patch looks good to me now. I have found no issues too. It is good to go in
now.
However, few small suggestions:
1. Whenever we know that a variable is containing only 32 bits, better
define
it as uint32 and not just int (m_sqlstate in get_sqlstate_error_level()
function). int size may differ in size on different platforms.
2. Also always cast the results with the actual return type of the function.
These are my views. Current code has absolutely no issues as such (at least
on
my machine).
Assigning back to you for your views on above points. If you are agree
resend
the patch with changes else feel free to mark it as "Ready for Committor".
Thanks
--
Jeevan B Chalke
Principal Software Engineer, Product Development
EnterpriseDB Corporation
The Enterprise PostgreSQL Company
Oskari Saarenmaa <os@ohmu.fi> writes:
[ 0001-Filter-error-log-statements-by-sqlstate.patch ]
I looked at this patch. It took me some time to understand that what
it actually does has got approximately nothing to do with what one might
first expect: rather than suppressing the entire log message about some
error, it only suppresses printing of the triggering SQL statement
(if that's available to begin with). The proposed documentation is
certainly not clear enough on that point, and the API which appears to
allow changing the error severity level associated with a SQLSTATE isn't
exactly helping to clarify things either.
Also, the patch claims it allows logging of statements that otherwise
wouldn't get logged, but AFAICS that's wrong, because we'll never get to
this code at all if errstart decides we're not going to log the message.
I find it hard to follow exactly what the use-case for this is; could
you make a defense of why we should carry a feature like this?
In any case, I'm finding it hard to believe that filtering by individual
SQLSTATEs is a practical API. When we've discussed providing better log
filtering in the past, that approach was invariably dismissed on the
grounds that it would be far too unwieldy to use --- any DBA attempting to
use it in anger would end up with a huge and ever-incomplete list of
SQLSTATEs he'd need to filter. A long time ago I suggested that filtering
by SQLSTATE class (the first two characters of SQLSTATE) might be useful,
but I'm not sure I still believe that, and anyway it's not what's
implemented here.
I'm concerned also about the potential performance impact of this patch,
if used with a SQLSTATE list as long as I think they're likely to get in
practice. Have you done any performance testing?
As far as the code goes, bit manipulations on uint64s are a pretty crummy
substitute for defining a struct with a couple of fields; and the way
you're choosing to sort the array seems mighty inefficient, as well as
probably wrong in detail (why is the loop ignoring the first array
element?); and rather than make fragile assumptions about the maximum
length of an elevel name, why not just leave the user's string as-is?
But I wouldn't advise worrying about code style issues until we decide if
we're accepting the feature. Right now my inclination is to reject it.
regards, tom lane
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Please fix the compiler warning:
elog.c: In function �check_log_sqlstate_error�:
elog.c:3789:41: warning: �new_newval_end� may be used uninitialized in
this function [-Wuninitialized]
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
17.01.2014 00:13, Tom Lane kirjoitti:
Oskari Saarenmaa <os@ohmu.fi> writes:
[ 0001-Filter-error-log-statements-by-sqlstate.patch ]
I looked at this patch. It took me some time to understand that what
it actually does has got approximately nothing to do with what one might
first expect: rather than suppressing the entire log message about some
error, it only suppresses printing of the triggering SQL statement
(if that's available to begin with). The proposed documentation is
certainly not clear enough on that point, and the API which appears to
allow changing the error severity level associated with a SQLSTATE isn't
exactly helping to clarify things either.Also, the patch claims it allows logging of statements that otherwise
wouldn't get logged, but AFAICS that's wrong, because we'll never get to
this code at all if errstart decides we're not going to log the message.
I agree the documentation (and perhaps the feature itself) are a bit
confusing, but the idea is to control SQL statement logging when errors
occur. This patch doesn't do anything about normal error logging, it
only controls when the statements are printed.
Running:
set log_min_messages = 'warning';
set log_min_error_statement = 'panic';
set log_sqlstate_error_statement = '';
do 'begin raise exception ''foobar 1''; end';
set log_sqlstate_error_statement = 'P0001:error';
do 'begin raise exception ''foobar 2''; end';
set log_min_error_statement = 'error';
set log_sqlstate_error_statement = 'P0001:panic';
do 'begin raise exception ''foobar 3''; end';
logs
2014-01-17 00:37:12 EET ERROR: foobar 1
2014-01-17 00:37:20 EET ERROR: foobar 2
2014-01-17 00:37:20 EET STATEMENT: do 'begin raise exception
''foobar 2''; end';
2014-01-17 00:38:34 EET ERROR: foobar 3
I find it hard to follow exactly what the use-case for this is; could
you make a defense of why we should carry a feature like this?
I usually run PG with log_min_messages = warning and
log_min_error_statement = error to log any unexpected errors. But as I
have a lot of check constraints in my database as well as a lot of
plpgsql and plpython code which raises exceptions on invalid user input
I also get tons of logs for statements causing "expected" errors which I
have to try to filter out with other tools.
In any case, I'm finding it hard to believe that filtering by individual
SQLSTATEs is a practical API. When we've discussed providing better log
filtering in the past, that approach was invariably dismissed on the
grounds that it would be far too unwieldy to use --- any DBA attempting to
use it in anger would end up with a huge and ever-incomplete list of
SQLSTATEs he'd need to filter. A long time ago I suggested that filtering
by SQLSTATE class (the first two characters of SQLSTATE) might be useful,
but I'm not sure I still believe that, and anyway it's not what's
implemented here.
I don't know about others, but filtering by individual SQLSTATE is
exactly what I need - I don't want to suppress all plpgsql errors or
constraint violations, but I may want to suppress plpgsql RAISE
EXCEPTION and CHECK violations.
I'm concerned also about the potential performance impact of this patch,
if used with a SQLSTATE list as long as I think they're likely to get in
practice. Have you done any performance testing?
Not yet. As this only applies to statement logging (for now at least) I
doubt it's a big deal, formatting and writing the statement somewhere is
probably at least as expensive as looking up the configuration.
As far as the code goes, bit manipulations on uint64s are a pretty crummy
substitute for defining a struct with a couple of fields; and the way
you're choosing to sort the array seems mighty inefficient, as well as
probably wrong in detail (why is the loop ignoring the first array
element?); and rather than make fragile assumptions about the maximum
length of an elevel name, why not just leave the user's string as-is?
But I wouldn't advise worrying about code style issues until we decide if
we're accepting the feature. Right now my inclination is to reject it.
I agree, I should've just defined a struct and used the original string
length when rewriting user string (it's rewritten to drop any
duplicates.) I don't think the sort is a big deal, it's only done when
the value is defined; the first array element is the length of the
array. I can address these points in a new version of this patch if the
feature looks useful.
Thanks for the review!
Oskari
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Oskari Saarenmaa <os@ohmu.fi> writes:
17.01.2014 00:13, Tom Lane kirjoitti:
I find it hard to follow exactly what the use-case for this is; could
you make a defense of why we should carry a feature like this?
I usually run PG with log_min_messages = warning and
log_min_error_statement = error to log any unexpected errors. But as I
have a lot of check constraints in my database as well as a lot of
plpgsql and plpython code which raises exceptions on invalid user input
I also get tons of logs for statements causing "expected" errors which I
have to try to filter out with other tools.
But if the goal is to reduce clutter in your log, wouldn't you wish
to suppress the *entire* log entry for "expected" errors, not just the
SQL-statement field? Certainly all the previous discussion about this
type of feature (and there has been plenty) has presumed that you'd want
to suppress whole entries.
In any case, I'm finding it hard to believe that filtering by individual
SQLSTATEs is a practical API.
I don't know about others, but filtering by individual SQLSTATE is
exactly what I need - I don't want to suppress all plpgsql errors or
constraint violations, but I may want to suppress plpgsql RAISE
EXCEPTION and CHECK violations.
Meh. Again, there's been lots of prior discussion, and I think there's
consensus that a filtering API based solely on a list of SQLSTATEs
wouldn't be widely adequate. The most recent discussion I can find
about this is in this thread:
/messages/by-id/20131205204512.GD6777@eldon.alvh.no-ip.org
That thread references an older one
/messages/by-id/19791.1335902957@sss.pgh.pa.us
and I'm pretty sure that there are several others you could find with
a bit of digging. The more ambitious proposals required decorating
ereport calls with a new kind of severity labeling, reflecting how
likely it'd be that DBAs would want to read about the particular
error in their logs. That's be a lot of work though, and would require
us to make a lot of value judgements that might be wrong. The main
alternative that was discussed was to filter on the basis of SQLSTATE
classes, and maybe relocate a few specific ERRCODEs to different classes
if it seemed that they were a lot unlike other things in their class.
It hasn't really been proven that SQLSTATE-class filtering would work
conveniently, but AFAICS the only way to prove or disprove that is for
somebody to code it up and use it in production.
What I'd suggest is that you revise this patch so that it can handle
filtering on the basis of either individual SQLSTATEs or whole classes,
the former being able to override the latter. With a bit of wholesale
notation invention, an example could be
log_sqlstates = 'P0,!P0001,!42,42P05'
which would mean "log all messages in class P0, except don't log P0001;
don't log anything in class 42, except always log 42P05; for everything
else, log according to log_min_messages".
If you don't like that notation, feel free to propose another. I did
not like the one you had to start with, though, because it looked like
it was actually changing the error severity level, not just the log or
don't log decision.
BTW, I'd suggest that this filtering only happen for messages < PANIC
level; it's pretty hard to believe that anybody would ever want to
suppress a PANIC report.
Another thought here is that if you're willing to have the filter
only able to *prevent* logging, and not to let it *cause* logging
of messages that would otherwise be suppressed by log_min_messages,
it could be implemented as a loadable module using the emit_log_hook.
An experimental feature, which is what this really is, is always a lot
easier sell in that format since anybody who finds it useless needn't
pay the overhead (which I'm still concerned about ...). But I'm not
sure how important it might be to be able to upgrade a message's log
priority, so maybe that approach would be significantly less usable.
regards, tom lane
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Hi Oskari,
Are you planning to work on what Tom has suggested ? It make sense to me as
well.
What are your views on that ?
Thanks
--
Jeevan B Chalke
Principal Software Engineer, Product Development
EnterpriseDB Corporation
The Enterprise PostgreSQL Company
30.01.2014 11:37, Jeevan Chalke kirjoitti:
Hi Oskari,
Are you planning to work on what Tom has suggested ? It make sense to me
as well.What are your views on that ?
Tom's suggestions make sense to me, but unfortunately I haven't had time
to work on this feature recently so I don't think it'll make it to 9.4
unless I can complete it during FOSDEM.
I updated https://github.com/saaros/postgres/tree/log-by-sqlstate some
time ago based on Tom's first set of comments but the tree is still
missing changes suggested in the last email.
/ Oskari
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
17.01.2014 19:07, Tom Lane kirjoitti:
Oskari Saarenmaa <os@ohmu.fi> writes:
I don't know about others, but filtering by individual SQLSTATE is
exactly what I need - I don't want to suppress all plpgsql errors or
constraint violations, but I may want to suppress plpgsql RAISE
EXCEPTION and CHECK violations.
[...]
It hasn't really been proven that SQLSTATE-class filtering would work
conveniently, but AFAICS the only way to prove or disprove that is for
somebody to code it up and use it in production.
[...]
Another thought here is that if you're willing to have the filter
only able to *prevent* logging, and not to let it *cause* logging
of messages that would otherwise be suppressed by log_min_messages,
it could be implemented as a loadable module using the emit_log_hook.
So this is what we ended up doing: a module with emit_log_hook to allow
upgrading "log_min_messages" and "log_min_error_statement" values per
sqlstate. I'm now using this in production and it has had a positive
impact in reducing the volume of (unwanted) logs being collected and
allowing a kludgy rsyslog.conf filter to be removed (which didn't really
work that well - it only dropped the first part of a multipart log
entry, writing partial pg log entries in syslog).
https://github.com/ohmu/pgloggingfilter
I'm not super happy about the syntax it uses, but at least it should be
obvious that it works just like the core GUCs but is settable per
sqlstate. I've been planning to sketch a proposal for a better way to
configure log verbosity and details based on sqlstate, statement
duration or other variables, but unfortunately haven't had time to do it
yet.
/ Oskari
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers