Re: [PATCH] Include application_name in "connection authorized" log message

From: Gilles Darold <gilles(dot)darold(at)dalibo(dot)com>
To: Don Seiler <don(at)seiler(dot)us>, Stephen Frost <sfrost(at)snowman(dot)net>
Cc: pgsql-hackers(at)lists(dot)postgresql(dot)org
Subject: Re: [PATCH] Include application_name in "connection authorized" log message
Date: 2018-06-25 15:50:40
Message-ID: f998457c-d33b-86a1-bfdb-1b6ac59d34c8@dalibo.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Le 21/06/2018 à 16:21, Don Seiler a écrit :
> On Wed, Jun 20, 2018 at 2:45 PM, Stephen Frost <sfrost(at)snowman(dot)net
> <mailto:sfrost(at)snowman(dot)net>> wrote:
>
>
> diff --git a/src/include/libpq/libpq-be.h
> b/src/include/libpq/libpq-be.h
> index 7698cd1f88..088ef346a8 100644
> --- a/src/include/libpq/libpq-be.h
> +++ b/src/include/libpq/libpq-be.h
> @@ -135,6 +135,7 @@ typedef struct Port
>          */
>         char       *database_name;
>         char       *user_name;
> +       char       *application_name;
>         char       *cmdline_options;
>         List       *guc_options;
>
> We should have some comments here about how this is the "startup
> packet
> application_name" and that it's specifically used for the "connection
> authorized" message and that it shouldn't really be used
> post-connection-startup (the GUC should be used instead, as
> applications
> can change it post-startup).
>
>
> Makes sense. I've now moved that variable declaration underneath the
> others with a small comment block above it.
>
>
> diff --git a/src/backend/postmaster/postmaster.c
> b/src/backend/postmaster/postmaster.c
> index a4b53b33cd..8e75c80728 100644
> --- a/src/backend/postmaster/postmaster.c
> +++ b/src/backend/postmaster/postmaster.c
> @@ -2094,6 +2094,10 @@ retry1:
>                               pstrdup(nameptr));
>                                 port->guc_options =
> lappend(port->guc_options,
>                               pstrdup(valptr));
> +
> +                               /* Copy application_name to port
> as well */
> +                               if (strcmp(nameptr,
> "application_name") == 0)
> +  port->application_name = pstrdup(valptr);
>                         }
>                         offset = valoffset + strlen(valptr) + 1;
>                 }
>
> That comment feels a bit lacking- this is a pretty special case which
> should be explained.
>
>
> I've added longer comment explaining again why we are doing this here.
>
>
> diff --git a/src/backend/utils/init/postinit.c
> b/src/backend/utils/init/postinit.c
> index 09e0df290d..86db7630d5 100644
> --- a/src/backend/utils/init/postinit.c
> +++ b/src/backend/utils/init/postinit.c
> @@ -266,8 +266,8 @@ PerformAuthentication(Port *port)
>  #ifdef USE_SSL
>                         if (port->ssl_in_use)
>                                 ereport(LOG,
> -  (errmsg("connection authorized: user=%s database=%s SSL enabled
> (protocol=%s, cipher=%s, bits=%d, compression=%s)",
> -      port->user_name, port->database_name,
> +  (errmsg("connection authorized: user=%s database=%s
> application=%s SSL enabled (protocol=%s, cipher=%s, bits=%d,
> compression=%s)",
> +      port->user_name, port->database_name, port->application_name
>       be_tls_get_version(port),
>       be_tls_get_cipher(port),
>       be_tls_get_cipher_bits(port),
> @@ -275,8 +275,8 @@ PerformAuthentication(Port *port)
>                         else
>  #endif
>                                 ereport(LOG,
> -  (errmsg("connection authorized: user=%s database=%s",
> -      port->user_name, port->database_name)));
> +  (errmsg("connection authorized: user=%s database=%s
> application=%s",
> +      port->user_name, port->database_name,
> port->application_name)));
>                 }
>         }
>
> You definitely need to be handling the case where application_name is
> *not* passed in more cleanly.  I don't think we should output anything
> different from what we do today in those cases.
>
>
> I've added some conditional logic similar to the ternary operator
> usage in src/backend/catalog/pg_collation.c:92. If application_name is
> set, we'll include "application=%s" in the log message, otherwise we
> make no mention of it now (output will be identical to what we
> currently do).
>
> Also, these don't need to be / shouldn't be 3 seperate
> patches/commits,
> and there should be a sensible commit message which explains what the
> change is entirely.
>
>
> After much head scratching/banging on both our parts yesterday, I've
> finally figured this out. Thanks again for your patience and time.
>
> If you could update the patch accordingly and re-send, that'd be
> awesome. :)
>
>
> See attached.
>
>
>
> --
> Don Seiler
> www.seiler.us <http://www.seiler.us>

Hi,

I've reviewed this patch, log entry is the following when
"log_connection = on" ajnd application_name is set:

    2018-06-25 17:01:30.079 CEST [22002] LOG:  connection authorized:
user=postgres database=postgres application=psql

when application_name is not set:

    2018-06-25 17:04:22.653 CEST [22076] LOG:  connection authorized:
user=dbuser database=test

I would prefer the following output to conform to elog.c output:

    2018-06-25 17:32:46.854 CEST [23265] LOG:  connection authorized:
user=postgres database=postgres application=[unknown]

I think this will make changes to src/backend/utils/init/postinit.c code
more readable with less duplicated code when written as follow:

diff --git a/src/backend/utils/init/postinit.c
b/src/backend/utils/init/postinit.c
index 09e0df290d..0b3323eaf2 100644
--- a/src/backend/utils/init/postinit.c
+++ b/src/backend/utils/init/postinit.c
@@ -263,11 +263,16 @@ PerformAuthentication(Port *port)
                }
                else
                {
+                       const char *appname = port->application_name;
+
+                       if (appname == NULL || *appname == '\0')
+                               appname = _("[unknown]");
+
 #ifdef USE_SSL
                        if (port->ssl_in_use)
                                ereport(LOG,
- (errmsg("connection authorized: user=%s database=%s SSL enabled
(protocol=%s, cipher=%s, bits=%d, compression=%s)",
- port->user_name, port->database_name,
+ (errmsg("connection authorized: user=%s database=%s application=%s SSL
enabled (protocol=%s, cipher=%s, bits=%d, compression=%s)",
+ port->user_name, port->database_name, appname,
be_tls_get_version(port),
be_tls_get_cipher(port),
be_tls_get_cipher_bits(port),
@@ -275,8 +280,8 @@ PerformAuthentication(Port *port)
                        else
 #endif
                                ereport(LOG,
- (errmsg("connection authorized: user=%s database=%s",
- port->user_name, port->database_name)));
+ (errmsg("connection authorized: user=%s database=%s application=%s",
+ port->user_name, port->database_name, appname)));
                }
        }

--
Gilles Darold
Consultant PostgreSQL
http://dalibo.com - http://dalibo.org

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Laurenz Albe 2018-06-25 16:10:21 Re: Loaded footgun open_datasync on Windows
Previous Message Lætitia Avrot 2018-06-25 15:45:37 Re: Constraint documentation