rosunit: removing logging, which is vestigial from roslaunch
This commit is contained in:
Ken Conley
parent
7207de556c
commit
d7c117c93f
|
|
@ -40,7 +40,6 @@ executables. These do not run in a ROS environment.
|
|||
import os
|
||||
import cStringIO
|
||||
import unittest
|
||||
import logging
|
||||
import time
|
||||
import signal
|
||||
import subprocess
|
||||
|
|
@ -55,8 +54,6 @@ from .core import xml_results_file, rostest_name_from_path, create_xml_runner, p
|
|||
from . import pmon
|
||||
from . import junitxml
|
||||
|
||||
_logger = logging.getLogger('rosunit')
|
||||
|
||||
BARE_TIME_LIMIT = 60.
|
||||
TIMEOUT_SIGINT = 15.0 #seconds
|
||||
TIMEOUT_SIGTERM = 2.0 #seconds
|
||||
|
|
@ -293,10 +290,6 @@ class LocalProcess(pmon.Process):
|
|||
super(LocalProcess, self).start()
|
||||
try:
|
||||
self.lock.acquire()
|
||||
if self.started:
|
||||
_logger.info("process[%s]: restarting os process", self.name)
|
||||
else:
|
||||
_logger.info("process[%s]: starting os process", self.name)
|
||||
self.started = self.stopped = False
|
||||
|
||||
full_env = self.env
|
||||
|
|
@ -304,8 +297,7 @@ class LocalProcess(pmon.Process):
|
|||
# _configure_logging() can mutate self.args
|
||||
try:
|
||||
logfileout, logfileerr = self._configure_logging()
|
||||
except Exception, e:
|
||||
_logger.error(traceback.format_exc())
|
||||
except Exception as e:
|
||||
printerrlog("[%s] ERROR: unable to configure logging [%s]"%(self.name, str(e)))
|
||||
# it's not safe to inherit from this process as
|
||||
# rostest changes stdout to a StringIO, which is not a
|
||||
|
|
@ -321,14 +313,10 @@ class LocalProcess(pmon.Process):
|
|||
else:
|
||||
cwd = rospkg.get_ros_home()
|
||||
|
||||
_logger.info("process[%s]: start w/ args [%s]", self.name, self.args)
|
||||
_logger.info("process[%s]: cwd will be [%s]", self.name, cwd)
|
||||
|
||||
try:
|
||||
self.popen = subprocess.Popen(self.args, cwd=cwd, stdout=logfileout, stderr=logfileerr, env=full_env, close_fds=True, preexec_fn=os.setsid)
|
||||
except OSError, (errno, msg):
|
||||
self.started = True # must set so is_alive state is correct
|
||||
_logger.error("OSError(%d, %s)", errno, msg)
|
||||
if errno == 8: #Exec format error
|
||||
raise pmon.FatalProcessLaunch("Unable to launch [%s]. \nIf it is a script, you may be missing a '#!' declaration at the top."%self.name)
|
||||
elif errno == 2: #no such file or directory
|
||||
|
|
@ -399,7 +387,6 @@ executable permission. This is often caused by a bad launch-prefix."""%(msg, ' '
|
|||
"""
|
||||
self.exit_code = self.popen.poll()
|
||||
if self.exit_code is not None:
|
||||
_logger.debug("process[%s].stop(): process has already returned %s", self.name, self.exit_code)
|
||||
#print "process[%s].stop(): process has already returned %s"%(self.name, self.exit_code)
|
||||
self.popen = None
|
||||
self.stopped = True
|
||||
|
|
@ -407,13 +394,10 @@ executable permission. This is often caused by a bad launch-prefix."""%(msg, ' '
|
|||
|
||||
pid = self.popen.pid
|
||||
pgid = os.getpgid(pid)
|
||||
_logger.info("process[%s]: killing os process with pid[%s] pgid[%s]", self.name, pid, pgid)
|
||||
|
||||
try:
|
||||
# Start with SIGINT and escalate from there.
|
||||
_logger.info("[%s] sending SIGINT to pgid [%s]", self.name, pgid)
|
||||
os.killpg(pgid, signal.SIGINT)
|
||||
_logger.info("[%s] sent SIGINT to pgid [%s]", self.name, pgid)
|
||||
timeout_t = time.time() + TIMEOUT_SIGINT
|
||||
retcode = self.popen.poll()
|
||||
while time.time() < timeout_t and retcode is None:
|
||||
|
|
@ -424,33 +408,21 @@ executable permission. This is often caused by a bad launch-prefix."""%(msg, ' '
|
|||
printerrlog("[%s] escalating to SIGTERM"%self.name)
|
||||
timeout_t = time.time() + TIMEOUT_SIGTERM
|
||||
os.killpg(pgid, signal.SIGTERM)
|
||||
_logger.info("[%s] sent SIGTERM to pgid [%s]"%(self.name, pgid))
|
||||
retcode = self.popen.poll()
|
||||
while time.time() < timeout_t and retcode is None:
|
||||
time.sleep(0.2)
|
||||
_logger.debug('poll for retcode')
|
||||
retcode = self.popen.poll()
|
||||
if retcode is None:
|
||||
printerrlog("[%s] escalating to SIGKILL"%self.name)
|
||||
errors.append("process[%s, pid %s]: required SIGKILL. May still be running."%(self.name, pid))
|
||||
try:
|
||||
os.killpg(pgid, signal.SIGKILL)
|
||||
_logger.info("[%s] sent SIGKILL to pgid [%s]"%(self.name, pgid))
|
||||
# #2096: don't block on SIGKILL, because this results in more orphaned processes overall
|
||||
#self.popen.wait()
|
||||
#os.wait()
|
||||
_logger.info("process[%s]: sent SIGKILL", self.name)
|
||||
except OSError, e:
|
||||
except OSError as e:
|
||||
if e.args[0] == 3:
|
||||
printerrlog("no [%s] process with pid [%s]"%(self.name, pid))
|
||||
else:
|
||||
printerrlog("errors shutting down [%s], see log for details"%self.name)
|
||||
_logger.error(traceback.format_exc())
|
||||
else:
|
||||
_logger.info("process[%s]: SIGTERM killed with return value %s", self.name, retcode)
|
||||
else:
|
||||
_logger.info("process[%s]: SIGINT killed with return value %s", self.name, retcode)
|
||||
|
||||
printerrlog("errors shutting down [%s]: %s"%(self.name, e))
|
||||
finally:
|
||||
self.popen = None
|
||||
|
||||
|
|
@ -465,15 +437,13 @@ executable permission. This is often caused by a bad launch-prefix."""%(msg, ' '
|
|||
self.lock.acquire()
|
||||
try:
|
||||
try:
|
||||
_logger.debug("process[%s].stop() starting", self.name)
|
||||
if self.popen is None:
|
||||
_logger.debug("process[%s].stop(): popen is None, nothing to kill")
|
||||
return
|
||||
#NOTE: currently POSIX-only. Need to add in Windows code once I have a test environment:
|
||||
# http://aspn.activestate.com/ASPN/Cookbook/Python/Recipe/347462
|
||||
self._stop_unix(errors)
|
||||
except:
|
||||
_logger.error("[%s] EXCEPTION %s", self.name, traceback.format_exc())
|
||||
printerrlog("[%s] EXCEPTION %s"%(self.name, traceback.format_exc()))
|
||||
finally:
|
||||
self.stopped = True
|
||||
self.lock.release()
|
||||
|
|
|
|||
|
|
@ -42,23 +42,19 @@ from .xmlrunner import XMLTestRunner
|
|||
|
||||
XML_OUTPUT_FLAG = '--gtest_output=xml:' #use gtest-compatible flag
|
||||
|
||||
_logger = logging.getLogger('runner')
|
||||
def printlog(msg, *args):
|
||||
if args:
|
||||
msg = msg%args
|
||||
_logger.info(msg)
|
||||
print "[ROSUNIT]"+msg
|
||||
|
||||
def printlog_bold(msg, *args):
|
||||
if args:
|
||||
msg = msg%args
|
||||
_logger.info(msg)
|
||||
print '\033[1m[ROSUNIT]%s\033[0m'%msg
|
||||
|
||||
def printerrlog(msg, *args):
|
||||
if args:
|
||||
msg = msg%args
|
||||
_logger.error(msg)
|
||||
print >> sys.stderr, "[ROSUNIT]"+msg
|
||||
|
||||
# this is a copy of the roslogging utility. it's been moved here as it is a common
|
||||
|
|
|
|||
|
|
@ -42,15 +42,12 @@ import os
|
|||
import sys
|
||||
import time
|
||||
import traceback
|
||||
import logging
|
||||
import Queue
|
||||
import atexit
|
||||
from threading import Thread, RLock, Lock
|
||||
|
||||
from .core import printlog, printlog_bold, printerrlog
|
||||
|
||||
_logger = logging.getLogger("rosunit")
|
||||
|
||||
class PmonException(Exception): pass
|
||||
|
||||
class FatalProcessLaunch(PmonException):
|
||||
|
|
@ -68,11 +65,9 @@ _shutting_down = False
|
|||
def start_process_monitor():
|
||||
global _pmon_counter
|
||||
if _shutting_down:
|
||||
#_logger.error("start_process_monitor: cannot start new ProcessMonitor (shutdown initiated)")
|
||||
return None
|
||||
_pmon_counter += 1
|
||||
name = "ProcessMonitor-%s"%_pmon_counter
|
||||
_logger.info("start_process_monitor: creating ProcessMonitor")
|
||||
process_monitor = ProcessMonitor(name)
|
||||
with _shutdown_lock:
|
||||
# prevent race condition with pmon_shutdown() being triggered
|
||||
|
|
@ -80,7 +75,6 @@ def start_process_monitor():
|
|||
# during startup)
|
||||
_pmons.append(process_monitor)
|
||||
process_monitor.start()
|
||||
_logger.info("start_process_monitor: ProcessMonitor started")
|
||||
return process_monitor
|
||||
|
||||
def shutdown_process_monitor(process_monitor):
|
||||
|
|
@ -98,19 +92,11 @@ def shutdown_process_monitor(process_monitor):
|
|||
if process_monitor is None or process_monitor.is_shutdown:
|
||||
return False
|
||||
|
||||
# I've decided to comment out use of _logger until after
|
||||
# critical section is done, just in case _logger is already
|
||||
# being torn down
|
||||
|
||||
#_logger.debug("shutdown_process_monitor: shutting down ProcessMonitor")
|
||||
process_monitor.shutdown()
|
||||
#_logger.debug("shutdown_process_monitor: joining ProcessMonitor")
|
||||
process_monitor.join(20.0)
|
||||
if process_monitor.isAlive():
|
||||
_logger.error("shutdown_process_monitor: ProcessMonitor shutdown failed!")
|
||||
return False
|
||||
else:
|
||||
_logger.debug("shutdown_process_monitor: ProcessMonitor shutdown succeeded")
|
||||
return True
|
||||
except Exception, e:
|
||||
return False
|
||||
|
|
@ -251,8 +237,6 @@ class ProcessMonitor(Thread):
|
|||
# #642: flag to prevent process monitor exiting prematurely
|
||||
self._registrations_complete = False
|
||||
|
||||
_logger.info("created process monitor %s"%self)
|
||||
|
||||
def add_process_listener(self, l):
|
||||
"""
|
||||
Listener for process events. MUST be called before
|
||||
|
|
@ -269,7 +253,6 @@ class ProcessMonitor(Thread):
|
|||
@type p: L{Process}
|
||||
@raise PmonException: if process with same name is already registered
|
||||
"""
|
||||
_logger.info("ProcessMonitor.register[%s]"%p.name)
|
||||
e = None
|
||||
with self.plock:
|
||||
if self.has_process(p.name):
|
||||
|
|
@ -279,10 +262,7 @@ class ProcessMonitor(Thread):
|
|||
else:
|
||||
self.procs.append(p)
|
||||
if e:
|
||||
_logger.error("ProcessMonitor.register[%s] failed %s"%(p.name, e))
|
||||
raise e
|
||||
else:
|
||||
_logger.info("ProcessMonitor.register[%s] complete"%p.name)
|
||||
|
||||
def register_core_proc(self, p):
|
||||
"""
|
||||
|
|
@ -303,13 +283,10 @@ class ProcessMonitor(Thread):
|
|||
will exit if there are no processes left to monitor.
|
||||
"""
|
||||
self._registrations_complete = True
|
||||
_logger.info("registrations completed %s"%self)
|
||||
|
||||
def unregister(self, p):
|
||||
_logger.info("ProcessMonitor.unregister[%s] starting"%p.name)
|
||||
with self.plock:
|
||||
self.procs.remove(p)
|
||||
_logger.info("ProcessMonitor.unregister[%s] complete"%p.name)
|
||||
|
||||
def has_process(self, name):
|
||||
"""
|
||||
|
|
@ -343,7 +320,6 @@ class ProcessMonitor(Thread):
|
|||
"""
|
||||
if not isinstance(name, basestring):
|
||||
raise PmonException("kill_process takes in a process name but was given: %s"%name)
|
||||
_logger.debug("ProcessMonitor.kill_process[%s]"%name)
|
||||
printlog("[%s] kill requested"%name)
|
||||
with self.plock:
|
||||
p = self.get_process(name)
|
||||
|
|
@ -351,8 +327,8 @@ class ProcessMonitor(Thread):
|
|||
try:
|
||||
# no need to accumulate errors, so pass in []
|
||||
p.stop([])
|
||||
except:
|
||||
_logger.error(traceback.format_exc())
|
||||
except Exception as e:
|
||||
printerrlog("Exception: %s"%(str(e)))
|
||||
return True
|
||||
else:
|
||||
return False
|
||||
|
|
@ -361,7 +337,6 @@ class ProcessMonitor(Thread):
|
|||
"""
|
||||
Shutdown the process monitor thread
|
||||
"""
|
||||
_logger.info("ProcessMonitor.shutdown %s"%self)
|
||||
self.is_shutdown = True
|
||||
|
||||
def get_active_names(self):
|
||||
|
|
@ -395,7 +370,6 @@ class ProcessMonitor(Thread):
|
|||
try:
|
||||
self._run()
|
||||
except:
|
||||
_logger.error(traceback.format_exc())
|
||||
traceback.print_exc()
|
||||
finally:
|
||||
self._post_run()
|
||||
|
|
@ -416,7 +390,6 @@ class ProcessMonitor(Thread):
|
|||
for p in procs:
|
||||
try:
|
||||
if not p.is_alive():
|
||||
_logger.debug("Process[%s] has died, respawn=%s, required=%s, exit_code=%s",p.name, p.respawn, p.required, p.exit_code)
|
||||
exit_code_str = p.get_exit_description()
|
||||
if p.respawn:
|
||||
printlog_bold("[%s] %s\nrespawning..."%(p.name, exit_code_str))
|
||||
|
|
@ -451,8 +424,8 @@ class ProcessMonitor(Thread):
|
|||
# save process data to dead list
|
||||
with plock:
|
||||
self.dead_list.append(DeadProcess(d))
|
||||
except:
|
||||
_logger.error(traceback.format_exc())
|
||||
except Exception as e:
|
||||
printerrlog("Exception: %s"%(str(e)))
|
||||
|
||||
# dead check is to make sure that ProcessMonitor at least
|
||||
# waits until its had at least one process before exiting
|
||||
|
|
@ -470,14 +443,12 @@ class ProcessMonitor(Thread):
|
|||
r.start()
|
||||
except:
|
||||
traceback.print_exc()
|
||||
_logger.error("Restart failed %s",traceback.format_exc())
|
||||
del respawn[:]
|
||||
time.sleep(0.1) #yield thread
|
||||
#moved this to finally block of _post_run
|
||||
#self._post_run() #kill all processes
|
||||
|
||||
def _post_run(self):
|
||||
_logger.info("ProcessMonitor._post_run %s"%self)
|
||||
# this is already true entering, but go ahead and make sure
|
||||
self.is_shutdown = True
|
||||
# killall processes on run exit
|
||||
|
|
@ -488,7 +459,6 @@ class ProcessMonitor(Thread):
|
|||
with self.plock:
|
||||
# make copy of core_procs for threadsafe usage
|
||||
core_procs = self.core_procs[:]
|
||||
_logger.info("ProcessMonitor._post_run %s: remaining procs are %s"%(self, self.procs))
|
||||
|
||||
# enqueue all non-core procs in reverse order for parallel kill
|
||||
# #526/885: ignore core procs
|
||||
|
|
@ -516,13 +486,11 @@ class ProcessMonitor(Thread):
|
|||
_kill_process(p, shutdown_errors)
|
||||
|
||||
# delete everything except dead_list
|
||||
_logger.info("ProcessMonitor exit: cleaning up data structures")
|
||||
with self.plock:
|
||||
del core_procs[:]
|
||||
del self.procs[:]
|
||||
del self.core_procs[:]
|
||||
|
||||
_logger.info("ProcessMonitor exit: pmon has shutdown")
|
||||
self.done = True
|
||||
|
||||
if shutdown_errors:
|
||||
|
|
@ -538,12 +506,11 @@ def _kill_process(p, errors):
|
|||
@type errors: [str]
|
||||
"""
|
||||
try:
|
||||
_logger.info("ProcessMonitor exit: killing %s", p.name)
|
||||
printlog("[%s] killing on exit"%p.name)
|
||||
# we accumulate errors from each process so that we can print these at the end
|
||||
p.stop(errors)
|
||||
except:
|
||||
_logger.error(traceback.format_exc())
|
||||
except Exception as e:
|
||||
printerrlog("Exception: %s"%(str(e)))
|
||||
|
||||
class _ProcessKiller(Thread):
|
||||
|
||||
|
|
|
|||
|
|
@ -41,7 +41,6 @@ import unittest
|
|||
import logging
|
||||
|
||||
import roslib.packages
|
||||
import roslib.roslogging
|
||||
|
||||
from . import pmon
|
||||
from . core import xml_results_file, create_xml_runner
|
||||
|
|
@ -52,13 +51,6 @@ from .baretest import BareTestCase, print_runner_summary
|
|||
|
||||
_NAME = 'rosunit'
|
||||
|
||||
def configure_logging(test_name):
|
||||
logfile_basename = 'rosunit-%s.log'%(test_name)
|
||||
logfile_name = roslib.roslogging.configure_logging('rosunit-%s'%(test_name), filename=logfile_basename)
|
||||
if logfile_name:
|
||||
print "... logging to %s"%logfile_name
|
||||
return logfile_name
|
||||
|
||||
def rosunitmain():
|
||||
from optparse import OptionParser
|
||||
parser = OptionParser(usage="usage: %prog [options] <file> [test args...]", prog=_NAME)
|
||||
|
|
@ -86,10 +78,6 @@ def rosunitmain():
|
|||
test_name = test_name[:test_name.rfind('.')]
|
||||
time_limit = float(options.time_limit) if options.time_limit else None
|
||||
|
||||
logfile_name = configure_logging(test_name)
|
||||
logger = logging.getLogger('rosunit')
|
||||
logger.info('rosunit starting with options %s, args %s'%(options, args))
|
||||
|
||||
# compute some common names we'll be using to generate test names and files
|
||||
pkg_dir, pkg = roslib.packages.get_dir_pkg(test_file)
|
||||
|
||||
|
|
@ -113,9 +101,7 @@ def rosunitmain():
|
|||
is_rostest=True)
|
||||
runner_result = xml_runner.run(suite)
|
||||
finally:
|
||||
logger.info("calling pmon_shutdown")
|
||||
pmon.pmon_shutdown()
|
||||
logger.info("... done calling pmon_shutdown")
|
||||
|
||||
# summary is worthless if textMode is on as we cannot scrape .xml results
|
||||
results = test_case.results
|
||||
|
|
@ -124,9 +110,6 @@ def rosunitmain():
|
|||
else:
|
||||
print "WARNING: overall test result is not accurate when --text is enabled"
|
||||
|
||||
if logfile_name:
|
||||
print "rosunit log file is in %s"%logfile_name
|
||||
|
||||
if runner_result is not None and not runner_result.wasSuccessful():
|
||||
sys.exit(1)
|
||||
elif results.num_errors or results.num_failures:
|
||||
|
|
|
|||
|
|
@ -0,0 +1,4 @@
|
|||
[nosetests]
|
||||
with-coverage=1
|
||||
cover-package=rosunit
|
||||
with-xunit=1
|
||||
Loading…
Reference in New Issue