Module: check_mk
Branch: master
Commit: 83aa0342ebc1675148d0d9da0ffb9599a027cc24
URL:
http://git.mathias-kettner.de/git/?p=check_mk.git;a=commit;h=83aa0342ebc167…
Author: Lars Michelsen <lm(a)mathias-kettner.de>
Date: Mon Aug 27 20:32:55 2018 +0200
Reworked output handling of background job processes
* The output of background jobs was previously handled like this:
stdout: Was set to a IO buffer object which was written from the
executing function (in the executing thread) and continuously read
from the main thread for writing it to the process status file.
The underlying stdout file descriptor was not set which means that
the output of subprocesses or libraries (e.g. libldap debug output)
was not captured.
stderr: Was also captured using an IO buffer and transported to
var/log/web.log of the site instead of logging it to the job output.
The underlying stdout file descriptor was not set which means that
the output of subprocesses or libraries (e.g. libldap debug output)
was not captured.
* Now both, stdout and stderr, are set to a tempfile.TemporaryFile()
sys.stdout and sys.stderr are set and also the FDs 1 and 2 are set.
This means that all output of the background job is written to the
temporary file.
It is continuously read from the main thread of the background job
and written to the status file.
* The logging produced by the background job, which normally goes to
var/log/web.log is now also written to stdout which is finally
shown in the progress info.
Change-Id: I6a674e2469479fa838f3933bf9f90c40a793eb88
---
cmk/gui/background_job.py | 53 +++++++++++++++++++++++++++--------------------
1 file changed, 30 insertions(+), 23 deletions(-)
diff --git a/cmk/gui/background_job.py b/cmk/gui/background_job.py
index 1b7a433..5de69b2 100644
--- a/cmk/gui/background_job.py
+++ b/cmk/gui/background_job.py
@@ -28,14 +28,16 @@
import os
import sys
import time
+import tempfile
import pprint
import threading
import multiprocessing
-from cStringIO import StringIO
+import io
import psutil
import shutil
import signal
import traceback
+import logging
from cmk.gui.i18n import _
from cmk.gui.globals import html
@@ -213,8 +215,8 @@ class BackgroundProcess(multiprocessing.Process):
if not self._logger:
self._logger = cmk.log.logger
- sys.stderr = StreamLogger(self._logger, cmk.log.ERROR)
- sys.stdout = StringIO()
+ self._open_stdout_and_stderr()
+ self._enable_logging_to_stdout()
self._job_parameters["logger"] = self._logger
@@ -223,15 +225,16 @@ class BackgroundProcess(multiprocessing.Process):
def _execute_function(self):
- # The specific function is called in a separate thread
- # The main thread collects the stdout from the function-thread and updates the
status file accordingly
+ # The specific function is called in a separate thread The main thread
+ # collects the output produced by the function-thread and updates the
+ # status file accordingly
t = threading.Thread(target=self._call_function_with_exception_handling,
args=[self._job_parameters])
t.start()
last_progress_info = ""
while t.isAlive():
time.sleep(0.2)
- progress_info = sys.stdout.getvalue() # pylint: disable=no-member
+ progress_info = self._read_output()
if progress_info != last_progress_info:
self._jobstatus.update_status({"progress_info":
BackgroundProcessInterface.parse_progress_info(progress_info)})
last_progress_info = progress_info
@@ -239,8 +242,7 @@ class BackgroundProcess(multiprocessing.Process):
# Final progress info update
job_status_update = {}
- progress_info = sys.stdout.getvalue() # pylint: disable=no-member
-
+ progress_info = self._read_output()
if progress_info != last_progress_info:
job_status_update.update({"progress_info":
BackgroundProcessInterface.parse_progress_info(progress_info)})
@@ -272,25 +274,27 @@ class BackgroundProcess(multiprocessing.Process):
job_interface.send_exception(_("Exception: %s") % (e))
-
-# TODO(ab): Wouldn't it be better to also write the stderr to the job results instead
of just writing
-# it to the web.log?
-class StreamLogger(object):
- """File like stream object to redirects writes to the given
logger"""
- def __init__(self, logger, level):
- super(StreamLogger, self).__init__()
- self._logger = logger
- self._level = level
- self._linebuf = ''
+ def _open_stdout_and_stderr(self):
+ """Create a temporary file and use it as stdout / stderr
buffer"""
+ # We can not use io.BytesIO() or similar because we need real file descriptors
+ # to be able to catch the (debug) output of libraries like libldap or
subproccesses
+ sys.stdout = sys.stderr = tempfile.TemporaryFile(mode='w+b')
+ os.dup2(sys.stdout.fileno(), 1)
+ os.dup2(sys.stderr.fileno(), 2)
- def write(self, buf):
- for line in buf.rstrip().splitlines():
- self._logger.log(self._level, line.rstrip())
+ def _read_output(self):
+ sys.stderr.flush()
+ sys.stderr.seek(0, io.SEEK_SET)
+ return sys.stderr.read()
- def flush(self):
- pass
+ def _enable_logging_to_stdout(self):
+ """In addition to the web.log we also want to see the job specific
logs
+ in stdout (which results in job progress info)"""
+ handler = logging.StreamHandler(stream=sys.stdout)
+ handler.setFormatter(cmk.log.get_formatter())
+ cmk.log.logger.addHandler(handler)
@@ -521,6 +525,9 @@ class BackgroundJob(object):
p.start()
p.join()
+ job_status = self.get_status()
+ self._logger.debug("Started job \"%s\" (PID: %d)" %
(self._job_id, job_status["pid"]))
+
def _start_background_subprocess(self, job_parameters):
try: