From 63257f1b2a9084ba10c40e90ed4ee6cabb432088 Mon Sep 17 00:00:00 2001
From: Johan Wikman <johan.wikman@mariadb.com>
Date: Wed, 30 Aug 2017 13:20:33 +0300
Subject: [PATCH] MXS-1378 Log session id

If the session id is known, it will be logged together with all
messages. If present, the session id appears, enclosed in paranthesis,
right after the message category. E.g.

    2017-08-30 12:20:49   warning: (4711) [masking] The rule ...
---
 .../MaxScale-2.2.0-Release-Notes.md           | 15 ++++++
 server/core/log_manager.cc                    | 49 ++++++++++++++-----
 2 files changed, 52 insertions(+), 12 deletions(-)

diff --git a/Documentation/Release-Notes/MaxScale-2.2.0-Release-Notes.md b/Documentation/Release-Notes/MaxScale-2.2.0-Release-Notes.md
index 3a6935ed5..14a0c4aad 100644
--- a/Documentation/Release-Notes/MaxScale-2.2.0-Release-Notes.md
+++ b/Documentation/Release-Notes/MaxScale-2.2.0-Release-Notes.md
@@ -89,6 +89,21 @@ The `function` type rule will now match a query that does not use a function
 when the filter is in whitelist mode (`action=allow`). This means that queries
 that don't use functions are allowed though in whitelist mode.
 
+### Logging
+
+When known, the session id will be included in all logged messages. This allows
+a range of logged messages related to a particular session (that is, client) to
+be bound together, and makes it easier to investigate problems. In practice this
+is visible so that if a logged message earlier looked like
+```
+2017-08-30 12:20:49   warning: [masking] The rule ...
+```
+it will now look like
+```
+2017-08-30 12:20:49   warning: (4711) [masking] The rule ...
+```
+where `4711` is the session id.
+
 ## Dropped Features
 
 ### MaxAdmin
diff --git a/server/core/log_manager.cc b/server/core/log_manager.cc
index a55e3196e..cb6c8b557 100644
--- a/server/core/log_manager.cc
+++ b/server/core/log_manager.cc
@@ -12,29 +12,30 @@
  */
 #include <maxscale/log_manager.h>
 
-#include <sys/types.h>
-#include <sys/stat.h>
+#include <errno.h>
 #include <fcntl.h>
-#include <unistd.h>
-#include <stdio.h>
+#include <inttypes.h>
+#include <sched.h>
+#include <stdarg.h>
 #include <stdint.h>
+#include <stdio.h>
 #include <stdlib.h>
 #include <string.h>
-#include <stdarg.h>
-#include <errno.h>
+#include <sys/stat.h>
+#include <sys/types.h>
 #include <syslog.h>
-#include <sched.h>
+#include <unistd.h>
 
+#include <maxscale/alloc.h>
 #include <maxscale/atomic.h>
 #include <maxscale/config.h>
-#include <maxscale/platform.h>
+#include <maxscale/debug.h>
 #include <maxscale/hashtable.h>
 #include <maxscale/json_api.h>
+#include <maxscale/platform.h>
+#include <maxscale/session.h>
 #include <maxscale/spinlock.h>
-#include <maxscale/debug.h>
-#include <maxscale/alloc.h>
 #include <maxscale/utils.h>
-
 #include "maxscale/mlist.h"
 
 #define MAX_PREFIXLEN 250
@@ -2893,6 +2894,21 @@ int mxs_log_message(int priority,
         {
             va_list valist;
 
+            uint64_t session_id = session_get_current_id();
+            int session_len = 0;
+
+            char session[20]; // Enough to fit "9223372036854775807"
+
+            if (session_id != 0)
+            {
+                sprintf(session, "%" PRIu64, session_id);
+                session_len = strlen(session) + 3; // +3 due to "() "
+            }
+            else
+            {
+                session_len = 0;
+            }
+
             int modname_len = modname ? strlen(modname) + 3 : 0; // +3 due to "[...] "
 
             static const char SUPPRESSION[] =
@@ -2938,6 +2954,7 @@ int mxs_log_message(int priority,
 
                 int buffer_len = 0;
                 buffer_len += prefix.len;
+                buffer_len += session_len;
                 buffer_len += modname_len;
                 buffer_len += augmentation_len;
                 buffer_len += message_len;
@@ -2956,13 +2973,21 @@ int mxs_log_message(int priority,
                 char buffer[buffer_len];
 
                 char *prefix_text = buffer;
-                char *modname_text = prefix_text + prefix.len;
+                char *session_text = prefix_text + prefix.len;
+                char *modname_text = session_text + session_len;
                 char *augmentation_text = modname_text + modname_len;
                 char *message_text = augmentation_text + augmentation_len;
                 char *suppression_text = message_text + message_len;
 
                 strcpy(prefix_text, prefix.text);
 
+                if (session_len)
+                {
+                    strcpy(session_text, "(");
+                    strcat(session_text, session);
+                    strcat(session_text, ") ");
+                }
+
                 if (modname_len)
                 {
                     strcpy(modname_text, "[");