Re: [PATCH] Include application_name in "connection authorized" logmessage

On Wed, Jun 20, 2018 at 2:45 PM, Stephen Frost <sfrost@snowman.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

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