From 130b686d9bff01eec314f8637a2e18ded707c50d Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Markus=20M=C3=A4kel=C3=A4?= <markus.makela@mariadb.com>
Date: Fri, 15 Sep 2017 10:03:46 +0300
Subject: [PATCH] MXS-1405: Log subprocess output immediately

When the subprocess outputs a line, the message should be logged
immediately. This allows automated timestamps for the output of the
executed subprocess.
---
 server/core/externcmd.cc         | 33 ++++++++++++++++++++++----------
 server/core/maxscale/externcmd.h |  3 +--
 server/core/monitor.cc           | 22 +++++++--------------
 3 files changed, 31 insertions(+), 27 deletions(-)

diff --git a/server/core/externcmd.cc b/server/core/externcmd.cc
index 6e9f3b248..27e92407f 100644
--- a/server/core/externcmd.cc
+++ b/server/core/externcmd.cc
@@ -159,11 +159,8 @@ void externcmd_free(EXTERNCMD* cmd)
     }
 }
 
-int externcmd_execute(EXTERNCMD* cmd, char** dest)
+int externcmd_execute(EXTERNCMD* cmd)
 {
-    // Always set dest to NULL before starting
-    *dest = NULL;
-
     // Create a pipe where the command can print output
     int fd[2];
 
@@ -173,10 +170,6 @@ int externcmd_execute(EXTERNCMD* cmd, char** dest)
         return -1;
     }
 
-    // Make them non-blocking
-    fcntl(fd[0], F_SETFL, O_NONBLOCK);
-    fcntl(fd[1], F_SETFL, O_NONBLOCK);
-
     int rval = 0;
     pid_t pid;
 
@@ -219,8 +212,9 @@ int externcmd_execute(EXTERNCMD* cmd, char** dest)
         uint64_t t = 0;
         uint64_t t_max = cmd->timeout * 1000;
 
-        // Close the write end of the pipe
+        // Close the write end of the pipe and make the read end non-blocking
         close(fd[1]);
+        fcntl(fd[0], F_SETFL, O_NONBLOCK);
 
         while (again)
         {
@@ -284,12 +278,31 @@ int externcmd_execute(EXTERNCMD* cmd, char** dest)
             {
                 // Read all available output
                 output.append(buf, n);
+
+                for (size_t pos = output.find("\n");
+                     pos != std::string::npos; pos = output.find("\n"))
+                {
+                    if (pos == 0)
+                    {
+                        output.erase(0, 1);
+                    }
+                    else
+                    {
+                        std::string line = output.substr(0, pos);
+                        output.erase(0, pos + 1);
+                        MXS_NOTICE("%s", line.c_str());
+                    }
+                }
             }
         }
 
+        if (!output.empty())
+        {
+            MXS_NOTICE("%s", output.c_str());
+        }
+
         // Close the read end of the pipe and copy the data to the output parameter
         close(fd[0]);
-        *dest = MXS_STRDUP_A(output.c_str());
     }
 
     return rval;
diff --git a/server/core/maxscale/externcmd.h b/server/core/maxscale/externcmd.h
index 9b7a1d3d9..746c87c9b 100644
--- a/server/core/maxscale/externcmd.h
+++ b/server/core/maxscale/externcmd.h
@@ -58,11 +58,10 @@ void externcmd_free(EXTERNCMD* cmd);
  * The output of the command must be freed by the caller by calling MXS_FREE.
  *
  * @param cmd  Command to execute
- * @param dest Pointer where to store the output of the command
  *
  * @return The return value of the executed command or -1 on error
  */
-int externcmd_execute(EXTERNCMD* cmd, char** dest);
+int externcmd_execute(EXTERNCMD* cmd);
 
 /**
  * Substitute all occurrences of @c match with @c replace in the arguments for @c cmd
diff --git a/server/core/monitor.cc b/server/core/monitor.cc
index bf8e76380..93bdb313a 100644
--- a/server/core/monitor.cc
+++ b/server/core/monitor.cc
@@ -1209,29 +1209,21 @@ monitor_launch_script(MXS_MONITOR* mon, MXS_MONITOR_SERVERS* ptr, const char* sc
         externcmd_substitute_arg(cmd, "[$]SYNCEDLIST", nodelist);
     }
 
-    char* out = NULL;
-    std::string str;
-    int rv = externcmd_execute(cmd, &out);
-
-    if (out)
-    {
-        str = trim(out);
-        MXS_FREE(out);
-    }
+    int rv = externcmd_execute(cmd);
 
     if (rv)
     {
         if (rv == -1)
         {
             // Internal error
-            MXS_ERROR("Failed to execute script '%s' on server state change event '%s': %s",
-                      script, mon_get_event_name(ptr), str.c_str());
+            MXS_ERROR("Failed to execute script '%s' on server state change event '%s'",
+                      script, mon_get_event_name(ptr));
         }
         else
         {
             // Script returned a non-zero value
-            MXS_ERROR("Script '%s' returned %d on event '%s': %s",
-                      script, rv, mon_get_event_name(ptr), str.c_str());
+            MXS_ERROR("Script '%s' returned %d on event '%s'",
+                      script, rv, mon_get_event_name(ptr));
         }
     }
     else
@@ -1273,8 +1265,8 @@ monitor_launch_script(MXS_MONITOR* mon, MXS_MONITOR_SERVERS* ptr, const char* sc
             scriptStr = cmd->argv[0]; // print at least something
         }
 
-        MXS_NOTICE("Executed monitor script '%s' on event '%s': %s",
-                   scriptStr, mon_get_event_name(ptr), str.c_str());
+        MXS_NOTICE("Executed monitor script '%s' on event '%s'",
+                   scriptStr, mon_get_event_name(ptr));
 
         if (!memError)
         {