ENH: unify appearance of log msgs in executeCmd -- separate additional information with "--"

pull/220/head
Yaroslav Halchenko 2013-05-09 11:50:17 -04:00
parent 810a28f136
commit 7a86d30c6d
2 changed files with 10 additions and 10 deletions

View File

@ -394,7 +394,7 @@ class Action:
time.sleep(0.1) time.sleep(0.1)
retcode = popen.poll() retcode = popen.poll()
if retcode is None: if retcode is None:
logSys.error("%s timed out after %i seconds." % logSys.error("%s -- timed out after %i seconds." %
(realCmd, timeout)) (realCmd, timeout))
os.kill(popen.pid, signal.SIGTERM) # Terminate the process os.kill(popen.pid, signal.SIGTERM) # Terminate the process
time.sleep(0.1) time.sleep(0.1)
@ -404,7 +404,7 @@ class Action:
time.sleep(0.1) time.sleep(0.1)
retcode = popen.poll() retcode = popen.poll()
except OSError, e: except OSError, e:
logSys.error("%s failed with %s" % (realCmd, e)) logSys.error("%s -- failed with %s" % (realCmd, e))
return False return False
finally: finally:
_cmd_lock.release() _cmd_lock.release()
@ -412,23 +412,23 @@ class Action:
std_level = retcode == 0 and logging.DEBUG or logging.ERROR std_level = retcode == 0 and logging.DEBUG or logging.ERROR
if std_level >= logSys.getEffectiveLevel(): if std_level >= logSys.getEffectiveLevel():
stdout.seek(0) stdout.seek(0)
logSys.log(std_level, "%s stdout: %r" % (realCmd, stdout.read())) logSys.log(std_level, "%s -- stdout: %r" % (realCmd, stdout.read()))
stderr.seek(0) stderr.seek(0)
logSys.log(std_level, "%s stderr: %r" % (realCmd, stderr.read())) logSys.log(std_level, "%s -- stderr: %r" % (realCmd, stderr.read()))
stdout.close() stdout.close()
stderr.close() stderr.close()
if retcode == 0: if retcode == 0:
logSys.debug("%s returned successfully" % realCmd) logSys.debug("%s -- returned successfully" % realCmd)
return True return True
elif retcode is None: elif retcode is None:
logSys.error("Unable to kill PID %i: %s" % (popen.pid, realCmd)) logSys.error("%s -- unable to kill PID %i" % (realCmd, popen.pid))
elif retcode < 0: elif retcode < 0:
logSys.error("%s killed with %s" % logSys.error("%s -- killed with %s" %
(realCmd, signame.get(-retcode, "signal %i" % -retcode))) (realCmd, signame.get(-retcode, "signal %i" % -retcode)))
else: else:
msg = _RETCODE_HINTS.get(retcode, None) msg = _RETCODE_HINTS.get(retcode, None)
logSys.error("%s returned %i" % (realCmd, retcode)) logSys.error("%s -- returned %i" % (realCmd, retcode))
if msg: if msg:
logSys.info("HINT on %i: %s" logSys.info("HINT on %i: %s"
% (retcode, msg % locals())) % (retcode, msg % locals()))

View File

@ -122,8 +122,8 @@ class ExecuteAction(unittest.TestCase):
stime = time.time() stime = time.time()
Action.executeCmd('sleep 60', timeout=2) # Should take a minute Action.executeCmd('sleep 60', timeout=2) # Should take a minute
self.assertAlmostEqual(time.time() - stime, 2.1, places=1) self.assertAlmostEqual(time.time() - stime, 2.1, places=1)
self.assertTrue(self._is_logged('sleep 60 timed out after 2 seconds')) self.assertTrue(self._is_logged('sleep 60 -- timed out after 2 seconds'))
self.assertTrue(self._is_logged('sleep 60 killed with SIGTERM')) self.assertTrue(self._is_logged('sleep 60 -- killed with SIGTERM'))
def testCaptureStdOutErr(self): def testCaptureStdOutErr(self):
Action.executeCmd('echo "How now brown cow"') Action.executeCmd('echo "How now brown cow"')