Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1mktDg-000416-44 for pgsql-hackers@arkaria.postgresql.org; Wed, 10 Nov 2021 19:25:16 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1mktDe-0001Pg-HL for pgsql-hackers@arkaria.postgresql.org; Wed, 10 Nov 2021 19:25:14 +0000 Received: from makus.postgresql.org ([2001:4800:3e1:1::229]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1mktDd-0001Oz-VK for pgsql-hackers@lists.postgresql.org; Wed, 10 Nov 2021 19:25:14 +0000 Received: from sss.pgh.pa.us ([66.207.139.130]) by makus.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1mktDb-0007xY-7g for pgsql-hackers@lists.postgresql.org; Wed, 10 Nov 2021 19:25:12 +0000 Received: from sss1.sss.pgh.pa.us (localhost [127.0.0.1]) by sss.pgh.pa.us (8.15.2/8.15.2) with ESMTP id 1AAJP8rT1455732; Wed, 10 Nov 2021 14:25:08 -0500 From: Tom Lane To: Robert Haas cc: PostgreSQL Hackers , Peter Eisentraut Subject: Re: Frontend error logging style In-reply-to: <1442862.1636560925@sss.pgh.pa.us> References: <1363732.1636496441@sss.pgh.pa.us> <1442862.1636560925@sss.pgh.pa.us> Comments: In-reply-to Tom Lane message dated "Wed, 10 Nov 2021 11:15:25 -0500" MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----- =_aaaaaaaaaa0" Content-ID: <1455676.1636572258.0@sss.pgh.pa.us> Date: Wed, 10 Nov 2021 14:25:08 -0500 Message-ID: <1455731.1636572308@sss.pgh.pa.us> List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk ------- =_aaaaaaaaaa0 Content-Type: text/plain; charset="us-ascii" Content-ID: <1455676.1636572258.1@sss.pgh.pa.us> I wrote: > Hmm, interesting. Taking up my point #2, I'd been thinking about > proposing that we convert > pg_log_error("query failed: %s", PQerrorMessage(conn)); > pg_log_error("query was: %s", todo); > to > pg_log_error("query failed: %s", PQerrorMessage(conn)); > pg_log_error_detail("Query was: %s", todo); After looking around a bit, I see that a lot of these add-on messages are more nearly hints than details, so we'd probably better support both those cases right off the bat. To move things along a bit, here's a draft patch to logging.h/.c only to implement what I'm envisioning. I don't think there's much point in doing the per-call-site gruntwork until we have agreement on what the API is, so this seems like enough for discussion. (As a fervent hater of colorization, I don't have an opinion about whether or how to colorize the "detail:" and "hint:" fragments. But I'll happily take somebody else's adjustment to add that.) regards, tom lane ------- =_aaaaaaaaaa0 Content-Type: text/x-diff; name="frontend-logging-API-revision-wip.patch"; charset="us-ascii" Content-ID: <1455676.1636572258.2@sss.pgh.pa.us> Content-Description: frontend-logging-API-revision-wip.patch Content-Transfer-Encoding: quoted-printable diff --git a/src/common/logging.c b/src/common/logging.c index fb1a9b1f87..84a4cdfd1f 100644 --- a/src/common/logging.c +++ b/src/common/logging.c @@ -151,6 +151,9 @@ pg_logging_init(const char *argv0) } } = +/* + * Change the logging flags. + */ void pg_logging_config(int new_flags) { @@ -194,17 +197,19 @@ pg_logging_set_locus_callback(void (*cb) (const char= **filename, uint64 *lineno) } = void -pg_log_generic(enum pg_log_level level, const char *pg_restrict fmt,...) +pg_log_generic(enum pg_log_level level, enum pg_log_part part, + const char *pg_restrict fmt,...) { va_list ap; = va_start(ap, fmt); - pg_log_generic_v(level, fmt, ap); + pg_log_generic_v(level, part, fmt, ap); va_end(ap); } = void -pg_log_generic_v(enum pg_log_level level, const char *pg_restrict fmt, va= _list ap) +pg_log_generic_v(enum pg_log_level level, enum pg_log_part part, + const char *pg_restrict fmt, va_list ap) { int save_errno =3D errno; const char *filename =3D NULL; @@ -232,7 +237,8 @@ pg_log_generic_v(enum pg_log_level level, const char *= pg_restrict fmt, va_list a = fmt =3D _(fmt); = - if (!(log_flags & PG_LOG_FLAG_TERSE) || filename) + if (part =3D=3D PG_LOG_PRIMARY && + (!(log_flags & PG_LOG_FLAG_TERSE) || filename)) { if (sgr_locus) fprintf(stderr, ANSI_ESCAPE_FMT, sgr_locus); @@ -251,30 +257,34 @@ pg_log_generic_v(enum pg_log_level level, const char= *pg_restrict fmt, va_list a = if (!(log_flags & PG_LOG_FLAG_TERSE)) { - switch (level) + switch (part) { - case PG_LOG_FATAL: - if (sgr_error) - fprintf(stderr, ANSI_ESCAPE_FMT, sgr_error); - fprintf(stderr, _("fatal: ")); - if (sgr_error) - fprintf(stderr, ANSI_ESCAPE_RESET); - break; - case PG_LOG_ERROR: - if (sgr_error) - fprintf(stderr, ANSI_ESCAPE_FMT, sgr_error); - fprintf(stderr, _("error: ")); - if (sgr_error) - fprintf(stderr, ANSI_ESCAPE_RESET); + case PG_LOG_PRIMARY: + switch (level) + { + case PG_LOG_ERROR: + if (sgr_error) + fprintf(stderr, ANSI_ESCAPE_FMT, sgr_error); + fprintf(stderr, _("error: ")); + if (sgr_error) + fprintf(stderr, ANSI_ESCAPE_RESET); + break; + case PG_LOG_WARNING: + if (sgr_warning) + fprintf(stderr, ANSI_ESCAPE_FMT, sgr_warning); + fprintf(stderr, _("warning: ")); + if (sgr_warning) + fprintf(stderr, ANSI_ESCAPE_RESET); + break; + default: + break; + } break; - case PG_LOG_WARNING: - if (sgr_warning) - fprintf(stderr, ANSI_ESCAPE_FMT, sgr_warning); - fprintf(stderr, _("warning: ")); - if (sgr_warning) - fprintf(stderr, ANSI_ESCAPE_RESET); + case PG_LOG_DETAIL: + fprintf(stderr, _("detail: ")); break; - default: + case PG_LOG_HINT: + fprintf(stderr, _("hint: ")); break; } } diff --git a/src/include/common/logging.h b/src/include/common/logging.h index a71cf84249..ec589ccd03 100644 --- a/src/include/common/logging.h +++ b/src/include/common/logging.h @@ -16,7 +16,7 @@ enum pg_log_level { /* - * Not initialized yet + * Not initialized yet (not to be used as an actual message log level). */ PG_LOG_NOTSET =3D 0, = @@ -43,20 +43,42 @@ enum pg_log_level PG_LOG_ERROR, = /* - * Severe errors that cause program termination. (One-shot programs may - * chose to label even fatal errors as merely "errors". The distinction - * is up to the program.) - */ - PG_LOG_FATAL, - - /* - * Turn all logging off. + * Turn all logging off (not to be used as an actual message log level). */ PG_LOG_OFF, }; = +/* + * __pg_log_level is the minimum log level that will actually be shown. + */ extern enum pg_log_level __pg_log_level; = +/* + * A log message can have several parts. The primary message is required= , + * others are optional. When emitting multiple parts, do so in the order= of + * this enum, for consistency. + */ +enum pg_log_part +{ + /* + * The primary message. Try to keep it to one line; follow the backend'= s + * style guideline for primary messages. + */ + PG_LOG_PRIMARY, + + /* + * Additional detail. Follow the backend's style guideline for detail + * messages. + */ + PG_LOG_DETAIL, + + /* + * Hint (not guaranteed correct) about how to fix the problem. Follow t= he + * backend's style guideline for hint messages. + */ + PG_LOG_HINT, +}; + /* * Kind of a hack to be able to produce the psql output exactly as requir= ed by * the regression tests. @@ -70,27 +92,85 @@ void pg_logging_increase_verbosity(void); void pg_logging_set_pre_callback(void (*cb) (void)); void pg_logging_set_locus_callback(void (*cb) (const char **filename, ui= nt64 *lineno)); = -void pg_log_generic(enum pg_log_level level, const char *pg_restrict fmt= ,...) pg_attribute_printf(2, 3); -void pg_log_generic_v(enum pg_log_level level, const char *pg_restrict f= mt, va_list ap) pg_attribute_printf(2, 0); +void pg_log_generic(enum pg_log_level level, enum pg_log_part part, + const char *pg_restrict fmt,...) + pg_attribute_printf(3, 4); +void pg_log_generic_v(enum pg_log_level level, enum pg_log_part part, + const char *pg_restrict fmt, va_list ap) + pg_attribute_printf(3, 0); = -#define pg_log_fatal(...) do { \ - if (likely(__pg_log_level <=3D PG_LOG_FATAL)) pg_log_generic(PG_LOG_FAT= AL, __VA_ARGS__); \ +/* + * Preferred style is to use these macros to perform logging; don't call + * pg_log_generic[_v] directly, except perhaps in error interface code. + */ +#define pg_log_error(...) do { \ + if (likely(__pg_log_level <=3D PG_LOG_ERROR)) \ + pg_log_generic(PG_LOG_ERROR, PG_LOG_PRIMARY, __VA_ARGS__); \ } while(0) = -#define pg_log_error(...) do { \ - if (likely(__pg_log_level <=3D PG_LOG_ERROR)) pg_log_generic(PG_LOG_ERR= OR, __VA_ARGS__); \ +#define pg_log_error_detail(...) do { \ + if (likely(__pg_log_level <=3D PG_LOG_ERROR)) \ + pg_log_generic(PG_LOG_ERROR, PG_LOG_DETAIL, __VA_ARGS__); \ + } while(0) + +#define pg_log_error_hint(...) do { \ + if (likely(__pg_log_level <=3D PG_LOG_ERROR)) \ + pg_log_generic(PG_LOG_ERROR, PG_LOG_HINT, __VA_ARGS__); \ } while(0) = #define pg_log_warning(...) do { \ - if (likely(__pg_log_level <=3D PG_LOG_WARNING)) pg_log_generic(PG_LOG_W= ARNING, __VA_ARGS__); \ + if (likely(__pg_log_level <=3D PG_LOG_WARNING)) \ + pg_log_generic(PG_LOG_WARNING, PG_LOG_PRIMARY, __VA_ARGS__); \ + } while(0) + +#define pg_log_warning_detail(...) do { \ + if (likely(__pg_log_level <=3D PG_LOG_WARNING)) \ + pg_log_generic(PG_LOG_WARNING, PG_LOG_DETAIL, __VA_ARGS__); \ + } while(0) + +#define pg_log_warning_hint(...) do { \ + if (likely(__pg_log_level <=3D PG_LOG_WARNING)) \ + pg_log_generic(PG_LOG_WARNING, PG_LOG_HINT, __VA_ARGS__); \ } while(0) = #define pg_log_info(...) do { \ - if (likely(__pg_log_level <=3D PG_LOG_INFO)) pg_log_generic(PG_LOG_INFO= , __VA_ARGS__); \ + if (likely(__pg_log_level <=3D PG_LOG_INFO)) \ + pg_log_generic(PG_LOG_INFO, PG_LOG_PRIMARY, __VA_ARGS__); \ + } while(0) + +#define pg_log_info_detail(...) do { \ + if (likely(__pg_log_level <=3D PG_LOG_INFO)) \ + pg_log_generic(PG_LOG_INFO, PG_LOG_DETAIL, __VA_ARGS__); \ + } while(0) + +#define pg_log_info_hint(...) do { \ + if (likely(__pg_log_level <=3D PG_LOG_INFO)) \ + pg_log_generic(PG_LOG_INFO, PG_LOG_HINT, __VA_ARGS__); \ } while(0) = #define pg_log_debug(...) do { \ - if (unlikely(__pg_log_level <=3D PG_LOG_DEBUG)) pg_log_generic(PG_LOG_D= EBUG, __VA_ARGS__); \ + if (unlikely(__pg_log_level <=3D PG_LOG_DEBUG)) \ + pg_log_generic(PG_LOG_DEBUG, PG_LOG_PRIMARY, __VA_ARGS__); \ + } while(0) + +#define pg_log_debug_detail(...) do { \ + if (unlikely(__pg_log_level <=3D PG_LOG_DEBUG)) \ + pg_log_generic(PG_LOG_DEBUG, PG_LOG_DETAIL, __VA_ARGS__); \ + } while(0) + +#define pg_log_debug_hint(...) do { \ + if (unlikely(__pg_log_level <=3D PG_LOG_DEBUG)) \ + pg_log_generic(PG_LOG_DEBUG, PG_LOG_HINT, __VA_ARGS__); \ + } while(0) + +/* + * A common special case: pg_log_error() and immediately exit(1). There = is + * no situation where it makes sense to suppress the message, so we ignor= e + * __pg_log_level. + */ +#define pg_log_fatal(...) do { \ + pg_log_generic(PG_LOG_ERROR, PG_LOG_PRIMARY, __VA_ARGS__); \ + exit(1); \ } while(0) = #endif /* COMMON_LOGGING_H */ ------- =_aaaaaaaaaa0--