From d0ec6e3762269ff0f31b9cbecb76029ebd309a68 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.1.7-Release-Notes.md           | 15 ++++++
 server/core/log_manager.cc                    | 54 ++++++++++++++-----
 2 files changed, 56 insertions(+), 13 deletions(-)

diff --git a/Documentation/Release-Notes/MaxScale-2.1.7-Release-Notes.md b/Documentation/Release-Notes/MaxScale-2.1.7-Release-Notes.md
index e2b704192..7752de439 100644
--- a/Documentation/Release-Notes/MaxScale-2.1.7-Release-Notes.md
+++ b/Documentation/Release-Notes/MaxScale-2.1.7-Release-Notes.md
@@ -26,6 +26,21 @@ The output of `show servers` now shows the number of times a connection was
 taken from a server's pool as well as the ratio of connections taken from the
 pool versus newly created connections.
 
+### 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.
+
 ## Bug fixes
 
 [Here is a list of bugs fixed in MaxScale 2.1.7.](https://jira.mariadb.org/issues/?jql=project%20%3D%20MXS%20AND%20issuetype%20%3D%20Bug%20AND%20status%20%3D%20Closed%20AND%20fixVersion%20%3D%202.1.7)
diff --git a/server/core/log_manager.cc b/server/core/log_manager.cc
index 358d2bc3b..044869c31 100644
--- a/server/core/log_manager.cc
+++ b/server/core/log_manager.cc
@@ -11,25 +11,29 @@
  * Public License.
  */
 #include <maxscale/log_manager.h>
-#include <sys/types.h>
-#include <sys/stat.h>
-#include <fcntl.h>
 
-#include <unistd.h>
-#include <stdio.h>
+#include <errno.h>
+#include <fcntl.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 <maxscale/atomic.h>
-#include <maxscale/platform.h>
+#include <unistd.h>
 
-#include <maxscale/hashtable.h>
-#include <maxscale/spinlock.h>
-#include <maxscale/debug.h>
 #include <maxscale/alloc.h>
+#include <maxscale/atomic.h>
+#include <maxscale/config.h>
+#include <maxscale/debug.h>
+#include <maxscale/hashtable.h>
+#include <maxscale/platform.h>
+#include <maxscale/session.h>
+#include <maxscale/spinlock.h>
 #include <maxscale/utils.h>
 #include "maxscale/mlist.h"
 
@@ -2895,6 +2899,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[] =
@@ -2940,6 +2959,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;
@@ -2958,13 +2978,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, "[");