Le jeudi 19 août 2021, 15:04:30 CEST Alvaro Herrera a écrit :
> On 2021-Aug-13, Ronan Dunklau wrote:
> > ereport(NOTICE,
> >
> > (errmsg("My log message")),
> > (errtag("EMITTER", "MYEXTENSION")),
> > (errtag("MSG-ID", "%d", error_message_id))
> >
> > );
>
> Interesting idea. I agree this would be useful.
>
> > Please find attached a very small POC patch to better demonstrate what I
> > propose.
>
> Seems like a good start. I think a further step towards a committable
> patch would include a test module that uses the new tagging
> functionality.
Please find attached the original patch + a new one adding a test module.
The test module exposes a function for generating logs with tags, and a log
hook which format the tags in the DETAIL field for easy regression testing.
Next step would be to emit those tags in the CSV logs. I'm not sure what
representation they should have though: a nested csv in it's own column ? A
key => value pairs list similar to hstore ? A json object ?
Also we should probably make this available to the client too, but once again
the format of the tag field needs to be defined. Any opinion ?
--
Ronan Dunklau
>From e5af5d1a07e65926eee90e0d18443a673d1fcba8 Mon Sep 17 00:00:00 2001
From: Ronan Dunklau <ronan.dunk...@aiven.io>
Date: Fri, 13 Aug 2021 15:03:18 +0200
Subject: [PATCH v2 1/3] Add ErrorTag support
---
src/backend/utils/error/elog.c | 48 ++++++++++++++++++++++++++++++++++
src/include/utils/elog.h | 10 +++++++
2 files changed, 58 insertions(+)
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index a3e1c59a82..5b9b1b8a72 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -465,6 +465,7 @@ errstart(int elevel, const char *domain)
edata->sqlerrcode = ERRCODE_SUCCESSFUL_COMPLETION;
/* errno is saved here so that error parameter eval can't change it */
edata->saved_errno = errno;
+ edata->tags = NIL;
/*
* Any allocations for this error state level should go into ErrorContext
@@ -516,6 +517,7 @@ errfinish(const char *filename, int lineno, const char *funcname)
int elevel;
MemoryContext oldcontext;
ErrorContextCallback *econtext;
+ ListCell *lc;
recursion_depth++;
CHECK_STACK_DEPTH();
@@ -621,7 +623,18 @@ errfinish(const char *filename, int lineno, const char *funcname)
pfree(edata->constraint_name);
if (edata->internalquery)
pfree(edata->internalquery);
+ /* Every tag should have been palloc'ed */
+ if (edata->tags != NIL)
+ {
+ foreach(lc, edata->tags)
+ {
+ ErrorTag *tag = (ErrorTag *) lfirst(lc);
+ pfree(tag->tagvalue);
+ pfree(tag);
+ }
+ pfree(edata->tags);
+ }
errordata_stack_depth--;
/* Exit error-handling context */
@@ -1192,6 +1205,41 @@ errhint_plural(const char *fmt_singular, const char *fmt_plural,
return 0; /* return value does not matter */
}
+int
+errtag(const char *tag, const char *fmt_value,...)
+{
+ ErrorData *edata = &errordata[errordata_stack_depth];
+ ErrorTag *etag;
+ MemoryContext oldcontext;
+ StringInfoData buf;
+
+ recursion_depth++;
+ CHECK_STACK_DEPTH();
+ oldcontext = MemoryContextSwitchTo(edata->assoc_context);
+ etag = palloc(sizeof(ErrorTag));
+ etag->tagname = tag;
+ initStringInfo(&buf);
+ for (;;)
+ {
+ va_list args;
+ int needed;
+
+ errno = edata->saved_errno;
+ va_start(args, fmt_value);
+ needed = appendStringInfoVA(&buf, fmt_value, args);
+ va_end(args);
+ if (needed == 0)
+ break;
+ enlargeStringInfo(&buf, needed);
+ }
+ etag->tagvalue = pstrdup(buf.data);
+ edata->tags = lappend(edata->tags, etag);
+ pfree(buf.data);
+ MemoryContextSwitchTo(oldcontext);
+ recursion_depth--;
+ return 0;
+}
+
/*
* errcontext_msg --- add a context error message text to the current error
diff --git a/src/include/utils/elog.h b/src/include/utils/elog.h
index f53607e12e..1c490d1b11 100644
--- a/src/include/utils/elog.h
+++ b/src/include/utils/elog.h
@@ -15,6 +15,7 @@
#define ELOG_H
#include <setjmp.h>
+#include "nodes/pg_list.h"
/* Error level codes */
#define DEBUG5 10 /* Debugging messages, in categories of
@@ -193,6 +194,8 @@ extern int errhint(const char *fmt,...) pg_attribute_printf(1, 2);
extern int errhint_plural(const char *fmt_singular, const char *fmt_plural,
unsigned long n,...) pg_attribute_printf(1, 4) pg_attribute_printf(2, 4);
+extern int errtag(const char *tag, const char *fmt_value,...) pg_attribute_printf(2, 3);
+
/*
* errcontext() is typically called in error context callback functions, not
* within an ereport() invocation. The callback function can be in a different
@@ -395,11 +398,18 @@ typedef struct ErrorData
int internalpos; /* cursor index into internalquery */
char *internalquery; /* text of internally-generated query */
int saved_errno; /* errno at entry */
+ List *tags; /* List of error tags */
/* context containing associated non-constant strings */
struct MemoryContextData *assoc_context;
} ErrorData;
+typedef struct ErrorTag
+{
+ const char *tagname;
+ char *tagvalue;
+} ErrorTag;
+
extern void EmitErrorReport(void);
extern ErrorData *CopyErrorData(void);
extern void FreeErrorData(ErrorData *edata);
--
2.32.0
>From 2cee45f3a6273141c177dff7d869c66e6fad01e4 Mon Sep 17 00:00:00 2001
From: Ronan Dunklau <ronan.dunk...@aiven.io>
Date: Fri, 20 Aug 2021 10:46:20 +0200
Subject: [PATCH v2 2/3] Add test module for the new tag functionality.
This test module consists of an extension exposing a function which just
logs things, and a hook which adds the tags to the detail field in order
to be tested in "regular" output.
---
src/test/modules/test_logging/Makefile | 20 +++
.../test_logging/expected/test_logging.out | 18 +++
.../modules/test_logging/sql/test_logging.sql | 5 +
.../test_logging/test_logging--1.0.sql | 4 +
src/test/modules/test_logging/test_logging.c | 121 ++++++++++++++++++
.../modules/test_logging/test_logging.control | 5 +
6 files changed, 173 insertions(+)
create mode 100644 src/test/modules/test_logging/Makefile
create mode 100644 src/test/modules/test_logging/expected/test_logging.out
create mode 100644 src/test/modules/test_logging/sql/test_logging.sql
create mode 100644 src/test/modules/test_logging/test_logging--1.0.sql
create mode 100644 src/test/modules/test_logging/test_logging.c
create mode 100644 src/test/modules/test_logging/test_logging.control
diff --git a/src/test/modules/test_logging/Makefile b/src/test/modules/test_logging/Makefile
new file mode 100644
index 0000000000..1191886e43
--- /dev/null
+++ b/src/test/modules/test_logging/Makefile
@@ -0,0 +1,20 @@
+# src/test/modules/test_logging/Makefile
+
+MODULES = test_logging
+
+EXTENSION = test_logging
+DATA = test_logging--1.0.sql
+PGFILEDESC = "test_logging - simple log hook test"
+
+REGRESS = test_logging
+
+ifdef USE_PGXS
+PG_CONFIG = pg_config
+PGXS := $(shell $(PG_CONFIG) --pgxs)
+include $(PGXS)
+else
+subdir = src/test/modules/test_logging
+top_builddir = ../../../..
+include $(top_builddir)/src/Makefile.global
+include $(top_srcdir)/contrib/contrib-global.mk
+endif
diff --git a/src/test/modules/test_logging/expected/test_logging.out b/src/test/modules/test_logging/expected/test_logging.out
new file mode 100644
index 0000000000..41423da535
--- /dev/null
+++ b/src/test/modules/test_logging/expected/test_logging.out
@@ -0,0 +1,18 @@
+CREATE EXTENSION test_logging;
+SET log_min_messages = NOTICE;
+SELECT test_logging(18, 'This is a test message', NULL);
+NOTICE: This is a test message
+DETAIL: NB TAGS: 0 TAGS:
+ test_logging
+--------------
+
+(1 row)
+
+SELECT test_logging(18, 'This is a test message', '{"tag1": "value1", "tag2": "value2"}');
+NOTICE: This is a test message
+DETAIL: NB TAGS: 2 TAGS: tag1: value1 tag2: value2
+ test_logging
+--------------
+
+(1 row)
+
diff --git a/src/test/modules/test_logging/sql/test_logging.sql b/src/test/modules/test_logging/sql/test_logging.sql
new file mode 100644
index 0000000000..bb964b4b63
--- /dev/null
+++ b/src/test/modules/test_logging/sql/test_logging.sql
@@ -0,0 +1,5 @@
+CREATE EXTENSION test_logging;
+SET log_min_messages = NOTICE;
+SELECT test_logging(18, 'This is a test message', NULL);
+SELECT test_logging(18, 'This is a test message', '{"tag1": "value1", "tag2": "value2"}');
+
diff --git a/src/test/modules/test_logging/test_logging--1.0.sql b/src/test/modules/test_logging/test_logging--1.0.sql
new file mode 100644
index 0000000000..663af2db8f
--- /dev/null
+++ b/src/test/modules/test_logging/test_logging--1.0.sql
@@ -0,0 +1,4 @@
+CREATE FUNCTION test_logging(level int, message text, tags jsonb)
+RETURNS VOID
+AS 'MODULE_PATHNAME'
+LANGUAGE C;
diff --git a/src/test/modules/test_logging/test_logging.c b/src/test/modules/test_logging/test_logging.c
new file mode 100644
index 0000000000..f92eff5150
--- /dev/null
+++ b/src/test/modules/test_logging/test_logging.c
@@ -0,0 +1,121 @@
+/*--------------------------------------------------------------------------
+ *
+ * test_logging.c
+ * Test logging functions
+ *
+ * Copyright (c) 2021, PostgreSQL Global Development Group
+ *
+ * IDENTIFICATION
+ * src/test/modules/test_logging/test_logging.c
+ *
+ * -------------------------------------------------------------------------
+ */
+
+#include <unistd.h>
+#include "postgres.h"
+
+#include "fmgr.h"
+#include "utils/builtins.h"
+#include "utils/elog.h"
+#include "utils/jsonb.h"
+
+PG_MODULE_MAGIC;
+
+static emit_log_hook_type prev_log_hook = NULL;
+
+void _PG_init(void);
+void _PG_fini(void);
+
+static void move_tags_to_detail(ErrorData *edata);
+
+static char *
+jsonb_value_to_tagvalue(JsonbValue *v)
+{
+ switch (v->type)
+ {
+ case jbvNull:
+ return "";
+ case jbvString:
+ return pnstrdup(v->val.string.val, v->val.string.len);
+ default:
+ elog(ERROR, "jsonb type not allowed here: %d", (int) v->type);
+ }
+}
+
+static void
+jsonb_tags_to_key_value_text_pairs(Jsonb *tags, List **keys, List **values)
+{
+ JsonbValue v;
+ JsonbIterator *it;
+ JsonbIteratorToken r;
+ bool skipNested = false;
+
+ it = JsonbIteratorInit(&tags->root);
+ *keys = *values = NIL;
+ while ((r = JsonbIteratorNext(&it, &v, skipNested)) != WJB_DONE)
+ {
+ skipNested = true;
+ if (r == WJB_KEY)
+ {
+ *keys = lappend(*keys, pnstrdup(v.val.string.val, v.val.string.len));
+ r = JsonbIteratorNext(&it, &v, skipNested);
+ Assert(r != WJB_DONE);
+ *values = lappend(*values, jsonb_value_to_tagvalue(&v));
+ }
+ }
+}
+
+PG_FUNCTION_INFO_V1(test_logging);
+Datum
+test_logging(PG_FUNCTION_ARGS)
+{
+ int level = PG_GETARG_INT32(0);
+ char *message = "";
+ List *keys = NIL,
+ *values = NIL;
+ ListCell *lk,
+ *lv;
+
+ if (!PG_ARGISNULL(1))
+ {
+ message = text_to_cstring(PG_GETARG_TEXT_PP(1));
+ }
+ if (!PG_ARGISNULL(2))
+ {
+ jsonb_tags_to_key_value_text_pairs(PG_GETARG_JSONB_P(2), &keys, &values);
+ }
+ ereport(level,
+ (errmsg("%s", message),
+ ({
+ forboth(lk, keys, lv, values)
+ {
+ (errtag(lfirst(lk), "%s", (char *) lfirst(lv)));
+ }})
+ ));
+
+ PG_RETURN_VOID();
+}
+
+void
+move_tags_to_detail(ErrorData *edata)
+{
+ StringInfoData buf;
+ ListCell *lc;
+
+ initStringInfo(&buf);
+ foreach(lc, edata->tags)
+ {
+ ErrorTag *tag = (ErrorTag *) lfirst(lc);
+
+ appendStringInfo(&buf, "%s: %s ", tag->tagname, tag->tagvalue);
+ }
+ errdetail("NB TAGS: %d TAGS: %s", list_length(edata->tags), buf.data);
+ pfree(buf.data);
+}
+
+void
+_PG_init(void)
+{
+ prev_log_hook = emit_log_hook;
+ emit_log_hook = move_tags_to_detail;
+}
diff --git a/src/test/modules/test_logging/test_logging.control b/src/test/modules/test_logging/test_logging.control
new file mode 100644
index 0000000000..b1596b4b1d
--- /dev/null
+++ b/src/test/modules/test_logging/test_logging.control
@@ -0,0 +1,5 @@
+# test_logging extension
+comment = 'test_logging - simple extension for emitting logs'
+default_version = '1.0'
+module_pathname = '$libdir/test_logging'
+relocatable = true
--
2.32.0
