lvmdbusd: Add lvm flight recorder

To help out with debug, when an exception is thrown in the dbus service we
will dump all the information we have on the last 16 commands that were
executed along with the stack strace.

Signed-off-by: Tony Asleson <tasleson@redhat.com>

diff --git a/daemons/lvmdbusd/cfg.py b/daemons/lvmdbusd/cfg.py
index bde6a641ac657fd746166a9da1b7e1b86481dabe..8aec8aeed0068aaf168cd85da461c4cbe903e031 100644 (file)
--- a/daemons/lvmdbusd/cfg.py
+++ b/daemons/lvmdbusd/cfg.py
@@ -78,3 +78,6 @@ load = None
 
 # Global cached state
 db = None
+
+# lvm flight recorder
+blackbox = None

diff --git a/daemons/lvmdbusd/cmdhandler.py b/daemons/lvmdbusd/cmdhandler.py
index 370fb618c45027365ddbc87876a708be94b63ed9..1522ebf2de013b14ac5e4786c278a24256da5ce6 100644 (file)
--- a/daemons/lvmdbusd/cmdhandler.py
+++ b/daemons/lvmdbusd/cmdhandler.py
@@ -11,6 +11,7 @@ from subprocess import Popen, PIPE
 import time
 import threading
 from itertools import chain
+import collections
 
 try:
        from . import cfg
@@ -28,13 +29,51 @@ total_count = 0
 
 # We need to prevent different threads from using the same lvm shell
 # at the same time.
-cmd_lock = threading.Lock()
+cmd_lock = threading.RLock()
 
 # The actual method which gets called to invoke the lvm command, can vary
 # from forking a new process to using lvm shell
 _t_call = None
 
 
+class LvmExecutionMeta(object):
+
+       def __init__(self, start, ended, cmd, ec, stdout_txt, stderr_txt):
+               self.start = start
+               self.ended = ended
+               self.cmd = cmd
+               self.ec = ec
+               self.stdout_txt = stdout_txt
+               self.stderr_txt = stderr_txt
+
+       def __str__(self):
+               return "EC= %d for %s\n" \
+                       "STARTED: %f, ENDED: %f\n" \
+                       "STDOUT=%s\n" \
+                       "STDERR=%s\n" % \
+                       (self.ec, str(self.cmd), self.start, self.ended, self.stdout_txt,
+                       self.stderr_txt)
+
+
+class LvmFlightRecorder(object):
+
+       def __init__(self):
+               self.queue = collections.deque(maxlen=16)
+
+       def add(self, lvm_exec_meta):
+               self.queue.append(lvm_exec_meta)
+
+       def dump(self):
+               with cmd_lock:
+                       log_error("LVM dbus flight recorder START")
+                       for c in self.queue:
+                               log_error(str(c))
+                       log_error("LVM dbus flight recorder END")
+
+
+cfg.blackbox = LvmFlightRecorder()
+
+
 def _debug_c(cmd, exit_code, out):
        log_error('CMD= %s' % ' '.join(cmd))
        log_error(("EC= %d" % exit_code))
@@ -105,9 +144,10 @@ def time_wrapper(command, debug=False):
        with cmd_lock:
                start = time.time()
                results = _t_call(command, debug)
-               total_time += (time.time() - start)
+               ended = time.time()
+               total_time += (ended - start)
                total_count += 1
-
+               cfg.blackbox.add(LvmExecutionMeta(start, ended, command, *results))
        return results
 
 

diff --git a/daemons/lvmdbusd/request.py b/daemons/lvmdbusd/request.py
index cf258f182028496df7766df30d393c7144f42caf..02f8c889e11e1d5bed3d3ea3bba21956e49cec5e 100644 (file)
--- a/daemons/lvmdbusd/request.py
+++ b/daemons/lvmdbusd/request.py
@@ -69,6 +69,7 @@ class RequestEntry(object):
                        # have gotten a job by the time we hit an error
                        # Lets get the stacktrace and set that to the error message
                        st = traceback.format_exc()
+                       cfg.blackbox.dump()
                        log_error("Exception returned to client: \n%s" % st)
                        self.register_error(-1, str(e), e)