[PATCH] Logging: fix for logs from bg processes

[Ondrej Lichtner]

From: Ondrej Lichtner <olichtne(a)redhat.com&gt;

This commit fixes a bug in logging where there would be logs from
background commands. The bug is another one of bugs that were introduced
when we started retrieving logs through rpc. After this commit the logs
from background processes are retrieved through the result object that
we send through the created pipe.

This fix is not perfect because the logs from background commands will
be retrieved through their corresponding wait/intr/kill command. This
will result in logs from these commands not arriving at the moment of
their creation and if more than one background command was running then
the logs will not be in the "correct" order. However this fix is the
easiest and most "clean" of ways to fix this. We might consider better a
better way to do this when we redo the logging infrastructure.

Signed-off-by: Ondrej Lichtner <olichtne(a)redhat.com&gt;
---
 lnst/Common/LoggingHandler.py |  4 ++++
 lnst/Common/NetTestCommand.py | 16 ++++++++++++++++
 2 files changed, 20 insertions(+)

diff --git a/lnst/Common/LoggingHandler.py b/lnst/Common/LoggingHandler.py
index 7b7174e..cea0529 100644
--- a/lnst/Common/LoggingHandler.py
+++ b/lnst/Common/LoggingHandler.py
@@ -40,6 +40,10 @@ class LogBuffer(logging.Handler):
         s = pickle.dumps(d, 1)
         return xmlrpclib.Binary(s)
 
+    def add_buffer(self, buf):
+        for i in buf:
+            self.buffer.append(i)
+
     def emit(self, record):
         s = self.makePickle(record)
         self.buffer.append(s)
diff --git a/lnst/Common/NetTestCommand.py b/lnst/Common/NetTestCommand.py
index a41cc2f..671fe36 100644
--- a/lnst/Common/NetTestCommand.py
+++ b/lnst/Common/NetTestCommand.py
@@ -16,6 +16,7 @@ import sys
 import signal
 import imp
 import pickle, traceback
+from lnst.Common.Logs import Logs
 from lnst.Common.ExecCmd import exec_cmd, ExecCmdFail
 
 def str_command(command):
@@ -64,6 +65,7 @@ class BgCommand:
                           " id \"%s\", pid \"%d\"" %
(self._bg_id, self._pid))
             self._read_pipe = read_pipe
             return {"passed": True}
+        Logs.get_buffer().flush()
         os.close(read_pipe)
         os.setpgrp()
         self._cmd_cls.set_handle_intr()
@@ -75,6 +77,8 @@ class BgCommand:
         except:
             type, value, tb = sys.exc_info()
             result = {"Exception":
''.join(traceback.format_exception(type, value, tb))}
+        buf = Logs.get_buffer()
+        result["logs"] = buf.flush()
         tmp = pickle.dumps(result)
         os.write(write_pipe, tmp)
         os.close(write_pipe)
@@ -255,6 +259,10 @@ class NetTestCommandWait(NetTestCommandControl):
         bg_cmd.wait_for()
         result = bg_cmd.get_result()
         self._command_context.del_bg_cmd(bg_cmd)
+        buf = Logs.get_buffer()
+        logs = result["logs"]
+        buf.add_buffer(logs)
+        del result["logs"]
         self.set_result(result)
 
 class NetTestCommandIntr(NetTestCommandControl):
@@ -264,6 +272,10 @@ class NetTestCommandIntr(NetTestCommandControl):
         bg_cmd.interrupt()
         result = bg_cmd.get_result()
         self._command_context.del_bg_cmd(bg_cmd)
+        buf = Logs.get_buffer()
+        logs = result["logs"]
+        buf.add_buffer(logs)
+        del result["logs"]
         self.set_result(result)
 
 class NetTestCommandKill(NetTestCommandControl):
@@ -271,7 +283,11 @@ class NetTestCommandKill(NetTestCommandControl):
         bg_id = self._command["value"]
         bg_cmd = self._command_context.get_bg_cmd(bg_id)
         bg_cmd.kill()
+        result = bg_cmd.get_result()
         self._command_context.del_bg_cmd(bg_cmd)
+        buf = Logs.get_buffer()
+        logs = result["logs"]
+        buf.add_buffer(logs)
         self.set_result({"passed": True})
 
 def get_command_class(command_context, command, resource_table):
-- 
1.7.11.7