rosunit.baretest

1 # Software License Agreement (BSD License) 2 # 3 # Copyright (c) 2010, Willow Garage, Inc. 4 # All rights reserved. 5 # 6 # Redistribution and use in source and binary forms, with or without 7 # modification, are permitted provided that the following conditions 8 # are met: 9 # 10 # * Redistributions of source code must retain the above copyright 11 # notice, this list of conditions and the following disclaimer. 12 # * Redistributions in binary form must reproduce the above 13 # copyright notice, this list of conditions and the following 14 # disclaimer in the documentation and/or other materials provided 15 # with the distribution. 16 # * Neither the name of Willow Garage, Inc. nor the names of its 17 # contributors may be used to endorse or promote products derived 18 # from this software without specific prior written permission. 19 # 20 # THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS 21 # "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT 22 # LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS 23 # FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE 24 # COPYRIGHT OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, 25 # INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, 26 # BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; 27 # LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER 28 # CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT 29 # LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN 30 # ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE 31 # POSSIBILITY OF SUCH DAMAGE. 32 # 33 # Revision $Id$ 34 35 """ 36 rostest implementation of running bare (gtest-compatible) unit test 37 executables. These do not run in a ROS environment. 38 """ 39 40 import os 41 import cStringIO 42 import unittest 43 import time 44 import signal 45 import subprocess 46 import traceback 47 48 import rospkg 49 50 from .core import xml_results_file, rostest_name_from_path, create_xml_runner, printlog, printerrlog, printlog_bold 51 52 from . import pmon 53 from . import junitxml 54 55 BARE_TIME_LIMIT = 60. 56 TIMEOUT_SIGINT = 15.0 #seconds 57 TIMEOUT_SIGTERM = 2.0 #seconds 58

59 -class TestTimeoutException(Exception): pass

60

61 -class BareTestCase(unittest.TestCase):

62

63 - def __init__(self, exe, args, retry=0, time_limit=None, test_name=None, text_mode=False, package_name=None):

64 """ 65 @param exe: path to executable to run 66 @type exe: str 67 @param args: arguments to exe 68 @type args: [str] 69 @type retry: int 70 @param time_limit: (optional) time limit for test. Defaults to BARE_TIME_LIMIT. 71 @type time_limit: float 72 @param test_name: (optional) override automatically generated test name 73 @type test_name: str 74 @param package_name: (optional) override automatically inferred package name 75 @type package_name: str 76 """ 77 super(BareTestCase, self).__init__() 78 self.text_mode = text_mode 79 if package_name: 80 self.package = package_name 81 else: 82 self.package = rospkg.get_package_name(exe) 83 self.exe = os.path.abspath(exe) 84 if test_name is None: 85 self.test_name = os.path.basename(exe) 86 else: 87 self.test_name = test_name 88 89 # invoke pyunit tests with python executable 90 if self.exe.endswith('.py'): 91 self.args = ['python', self.exe] + args 92 else: 93 self.args = [self.exe] + args 94 if text_mode: 95 self.args = self.args + ['--text'] 96 97 self.retry = retry 98 self.time_limit = time_limit or BARE_TIME_LIMIT 99 self.pmon = None 100 self.results = junitxml.Result(self.test_name)

101

102 - def setUp(self):

103 self.pmon = pmon.start_process_monitor()

104

105 - def tearDown(self):

106 if self.pmon is not None: 107 pmon.shutdown_process_monitor(self.pmon) 108 self.pmon = None

109

110 - def runTest(self):

111 self.failIf(self.package is None, "unable to determine package of executable") 112 113 done = False 114 while not done: 115 test_name = self.test_name 116 117 printlog("Running test [%s]", test_name) 118 119 #setup the test 120 # - we pass in the output test_file name so we can scrape it 121 test_file = xml_results_file(self.package, test_name, False) 122 if os.path.exists(test_file): 123 printlog("removing previous test results file [%s]", test_file) 124 os.remove(test_file) 125 126 self.args.append('--gtest_output=xml:%s'%test_file) 127 128 # run the test, blocks until completion 129 printlog("running test %s"%test_name) 130 timeout_failure = False 131 132 run_id = None 133 #TODO: really need different, non-node version of LocalProcess instead of these extra args 134 process = LocalProcess(run_id, self.package, self.test_name, self.args, os.environ, False, cwd='cwd', is_node=False) 135 136 pm = self.pmon 137 pm.register(process) 138 success = process.start() 139 self.assert_(success, "test failed to start") 140 141 #poll until test terminates or alloted time exceed 142 timeout_t = time.time() + self.time_limit 143 try: 144 while process.is_alive(): 145 #test fails on timeout 146 if time.time() > timeout_t: 147 raise TestTimeoutException("test max time allotted") 148 time.sleep(0.1) 149 150 except TestTimeoutException, e: 151 if self.retry: 152 timeout_failure = True 153 else: 154 raise 155 156 if not timeout_failure: 157 printlog("test [%s] finished"%test_name) 158 else: 159 printerrlog("test [%s] timed out"%test_name) 160 161 162 if self.text_mode: 163 results = self.results 164 elif not self.text_mode: 165 # load in test_file 166 if not timeout_failure: 167 self.assert_(os.path.isfile(test_file), "test [%s] did not generate test results"%test_name) 168 printlog("test [%s] results are in [%s]", test_name, test_file) 169 results = junitxml.read(test_file, test_name) 170 test_fail = results.num_errors or results.num_failures 171 else: 172 test_fail = True 173 174 if self.retry > 0 and test_fail: 175 self.retry -= 1 176 printlog("test [%s] failed, retrying. Retries left: %s"%(test_name, self.retry)) 177 else: 178 done = True 179 self.results = results 180 printlog("test [%s] results summary: %s errors, %s failures, %s tests", 181 test_name, results.num_errors, results.num_failures, results.num_tests) 182 183 printlog("[ROSTEST] test [%s] done", test_name)

184 185 186 #TODO: this is a straight copy from roslaunch. Need to reduce, refactor

187 -class LocalProcess(pmon.Process):

188 """ 189 Process launched on local machine 190 """ 191

192 - def __init__(self, run_id, package, name, args, env, log_output, respawn=False, required=False, cwd=None, is_node=True):

193 """ 194 @param run_id: unique run ID for this roslaunch. Used to 195 generate log directory location. run_id may be None if this 196 feature is not being used. 197 @type run_id: str 198 @param package: name of package process is part of 199 @type package: str 200 @param name: name of process 201 @type name: str 202 @param args: list of arguments to process 203 @type args: [str] 204 @param env: environment dictionary for process 205 @type env: {str : str} 206 @param log_output: if True, log output streams of process 207 @type log_output: bool 208 @param respawn: respawn process if it dies (default is False) 209 @type respawn: bool 210 @param cwd: working directory of process, or None 211 @type cwd: str 212 @param is_node: (optional) if True, process is ROS node and accepts ROS node command-line arguments. Default: True 213 @type is_node: False 214 """ 215 super(LocalProcess, self).__init__(package, name, args, env, respawn, required) 216 self.run_id = run_id 217 self.popen = None 218 self.log_output = log_output 219 self.started = False 220 self.stopped = False 221 self.cwd = cwd 222 self.log_dir = None 223 self.pid = -1 224 self.is_node = is_node

225 226 # NOTE: in the future, info() is going to have to be sufficient for relaunching a process

227 - def get_info(self):

228 """ 229 Get all data about this process in dictionary form 230 """ 231 info = super(LocalProcess, self).get_info() 232 info['pid'] = self.pid 233 if self.run_id: 234 info['run_id'] = self.run_id 235 info['log_output'] = self.log_output 236 if self.cwd is not None: 237 info['cwd'] = self.cwd 238 return info

239

240 - def _configure_logging(self):

241 """ 242 Configure logging of node's log file and stdout/stderr 243 @return: stdout log file name, stderr log file 244 name. Values are None if stdout/stderr are not logged. 245 @rtype: str, str 246 """ 247 log_dir = rospkg.get_log_dir(env=os.environ) 248 if self.run_id: 249 log_dir = os.path.join(log_dir, self.run_id) 250 if not os.path.exists(log_dir): 251 try: 252 os.makedirs(log_dir) 253 except OSError, (errno, msg): 254 if errno == 13: 255 raise RLException("unable to create directory for log file [%s].\nPlease check permissions."%log_dir) 256 else: 257 raise RLException("unable to create directory for log file [%s]: %s"%(log_dir, msg)) 258 # #973: save log dir for error messages 259 self.log_dir = log_dir 260 261 # send stdout/stderr to file. in the case of respawning, we have to 262 # open in append mode 263 # note: logfileerr: disabling in favor of stderr appearing in the console. 264 # will likely reinstate once roserr/rosout is more properly used. 265 logfileout = logfileerr = None 266 267 if self.log_output: 268 outf, errf = [os.path.join(log_dir, '%s-%s.log'%(self.name, n)) for n in ['stdout', 'stderr']] 269 if self.respawn: 270 mode = 'a' 271 else: 272 mode = 'w' 273 logfileout = open(outf, mode) 274 if is_child_mode(): 275 logfileerr = open(errf, mode) 276 277 # #986: pass in logfile name to node 278 node_log_file = log_dir 279 if self.is_node: 280 # #1595: on respawn, these keep appending 281 self.args = _cleanup_remappings(self.args, '__log:=') 282 self.args.append("__log:=%s"%os.path.join(log_dir, "%s.log"%self.name)) 283 284 return logfileout, logfileerr

285

286 - def start(self):

287 """ 288 Start the process. 289 290 @raise pmon.FatalProcessLaunch: if process cannot be started and it 291 is not likely to ever succeed 292 """ 293 super(LocalProcess, self).start() 294 try: 295 self.lock.acquire() 296 self.started = self.stopped = False 297 298 full_env = self.env 299 300 # _configure_logging() can mutate self.args 301 try: 302 logfileout, logfileerr = self._configure_logging() 303 except Exception as e: 304 printerrlog("[%s] ERROR: unable to configure logging [%s]"%(self.name, str(e))) 305 # it's not safe to inherit from this process as 306 # rostest changes stdout to a StringIO, which is not a 307 # proper file. 308 logfileout, logfileerr = subprocess.PIPE, subprocess.PIPE 309 310 if self.cwd == 'node': 311 cwd = os.path.dirname(self.args[0]) 312 elif self.cwd == 'cwd': 313 cwd = os.getcwd() 314 elif self.cwd == 'ros-root': 315 cwd = get_ros_root() 316 else: 317 cwd = rospkg.get_ros_home() 318 319 try: 320 self.popen = subprocess.Popen(self.args, cwd=cwd, stdout=logfileout, stderr=logfileerr, env=full_env, close_fds=True, preexec_fn=os.setsid) 321 except OSError, (errno, msg): 322 self.started = True # must set so is_alive state is correct 323 if errno == 8: #Exec format error 324 raise pmon.FatalProcessLaunch("Unable to launch [%s]. \nIf it is a script, you may be missing a '#!' declaration at the top."%self.name) 325 elif errno == 2: #no such file or directory 326 raise pmon.FatalProcessLaunch("""Roslaunch got a '%s' error while attempting to run: 327 328 %s 329 330 Please make sure that all the executables in this command exist and have 331 executable permission. This is often caused by a bad launch-prefix."""%(msg, ' '.join(self.args))) 332 else: 333 raise pmon.FatalProcessLaunch("unable to launch [%s]: %s"%(' '.join(self.args), msg)) 334 335 self.started = True 336 # Check that the process is either still running (poll returns 337 # None) or that it completed successfully since when we 338 # launched it above (poll returns the return code, 0). 339 poll_result = self.popen.poll() 340 if poll_result is None or poll_result == 0: 341 self.pid = self.popen.pid 342 printlog_bold("process[%s]: started with pid [%s]"%(self.name, self.pid)) 343 return True 344 else: 345 printerrlog("failed to start local process: %s"%(' '.join(self.args))) 346 return False 347 finally: 348 self.lock.release()

349

350 - def is_alive(self):

351 """ 352 @return: True if process is still running 353 @rtype: bool 354 """ 355 if not self.started: #not started yet 356 return True 357 if self.stopped or self.popen is None: 358 return False 359 self.exit_code = self.popen.poll() 360 if self.exit_code is not None: 361 return False 362 return True

363

364 - def get_exit_description(self):

365 """ 366 @return: human-readable description of exit state 367 @rtype: str 368 """ 369 # #973: include location of output location in message 370 if self.exit_code is not None: 371 if self.exit_code: 372 if self.log_dir: 373 return 'process has died [pid %s, exit code %s].\nlog files: %s*.log'%(self.pid, self.exit_code, os.path.join(self.log_dir, self.name)) 374 else: 375 return 'process has died [pid %s, exit code %s]'%(self.pid, self.exit_code) 376 else: 377 if self.log_dir: 378 return 'process has finished cleanly.\nlog file: %s*.log'%(os.path.join(self.log_dir, self.name)) 379 else: 380 return 'process has finished cleanly' 381 else: 382 return 'process has died'

383

384 - def _stop_unix(self, errors):

385 """ 386 UNIX implementation of process killing 387 388 @param errors: error messages. stop() will record messages into this list. 389 @type errors: [str] 390 """ 391 self.exit_code = self.popen.poll() 392 if self.exit_code is not None: 393 #print "process[%s].stop(): process has already returned %s"%(self.name, self.exit_code) 394 self.popen = None 395 self.stopped = True 396 return 397 398 pid = self.popen.pid 399 pgid = os.getpgid(pid) 400 401 try: 402 # Start with SIGINT and escalate from there. 403 os.killpg(pgid, signal.SIGINT) 404 timeout_t = time.time() + TIMEOUT_SIGINT 405 retcode = self.popen.poll() 406 while time.time() < timeout_t and retcode is None: 407 time.sleep(0.1) 408 retcode = self.popen.poll() 409 # Escalate non-responsive process 410 if retcode is None: 411 printerrlog("[%s] escalating to SIGTERM"%self.name) 412 timeout_t = time.time() + TIMEOUT_SIGTERM 413 os.killpg(pgid, signal.SIGTERM) 414 retcode = self.popen.poll() 415 while time.time() < timeout_t and retcode is None: 416 time.sleep(0.2) 417 retcode = self.popen.poll() 418 if retcode is None: 419 printerrlog("[%s] escalating to SIGKILL"%self.name) 420 errors.append("process[%s, pid %s]: required SIGKILL. May still be running."%(self.name, pid)) 421 try: 422 os.killpg(pgid, signal.SIGKILL) 423 # #2096: don't block on SIGKILL, because this results in more orphaned processes overall 424 except OSError as e: 425 if e.args[0] == 3: 426 printerrlog("no [%s] process with pid [%s]"%(self.name, pid)) 427 else: 428 printerrlog("errors shutting down [%s]: %s"%(self.name, e)) 429 finally: 430 self.popen = None

431

432 - def stop(self, errors=[]):

433 """ 434 Stop the process. Record any significant error messages in the errors parameter 435 436 @param errors: error messages. stop() will record messages into this list. 437 @type errors: [str] 438 """ 439 super(LocalProcess, self).stop(errors) 440 self.lock.acquire() 441 try: 442 try: 443 if self.popen is None: 444 return 445 #NOTE: currently POSIX-only. Need to add in Windows code once I have a test environment: 446 # http://aspn.activestate.com/ASPN/Cookbook/Python/Recipe/347462 447 self._stop_unix(errors) 448 except: 449 printerrlog("[%s] EXCEPTION %s"%(self.name, traceback.format_exc())) 450 finally: 451 self.stopped = True 452 self.lock.release()

453

454 -def print_runner_summary(runner_results, junit_results, runner_name='ROSUNIT'):

455 """ 456 Print summary of runner results and actual test results to 457 stdout. For rosunit and rostest, the test is wrapped in an 458 external runner. The results from this runner are important if the 459 runner itself has a failure. 460 461 @param runner_result: unittest runner result object 462 @type runner_result: _XMLTestResult 463 @param junit_results: Parsed JUnit test results 464 @type junit_results: rosunit.junitxml.Result 465 """ 466 # we have two separate result objects, which can be a bit 467 # confusing. 'result' counts successful _running_ of tests 468 # (i.e. doesn't check for actual test success). The 'r' result 469 # object contains results of the actual tests. 470 471 buff = cStringIO.StringIO() 472 473 buff.write("[%s]"%(runner_name)+'-'*71+'\n\n') 474 for tc_result in junit_results.test_case_results: 475 buff.write(tc_result.description) 476 for tc_result in runner_results.failures: 477 buff.write("[%s][failed]\n"%tc_result[0]._testMethodName) 478 479 buff.write('\nSUMMARY\n') 480 if runner_results.wasSuccessful() and (junit_results.num_errors + junit_results.num_failures) == 0: 481 buff.write("\033[32m * RESULT: SUCCESS\033[0m\n") 482 else: 483 buff.write("\033[1;31m * RESULT: FAIL\033[0m\n") 484 485 # TODO: still some issues with the numbers adding up if tests fail to launch 486 487 # number of errors from the inner tests, plus add in count for tests 488 # that didn't run properly ('result' object). 489 buff.write(" * TESTS: %s\n"%junit_results.num_tests) 490 num_errors = junit_results.num_errors+len(runner_results.errors) 491 if num_errors: 492 buff.write("\033[1;31m * ERRORS: %s\033[0m\n"%num_errors) 493 else: 494 buff.write(" * ERRORS: 0\n") 495 num_failures = junit_results.num_failures+len(runner_results.failures) 496 if num_failures: 497 buff.write("\033[1;31m * FAILURES: %s\033[0m\n"%num_failures) 498 else: 499 buff.write(" * FAILURES: 0\n") 500 501 if runner_results.failures: 502 buff.write("\nERROR: The following tests failed to run:\n") 503 for tc_result in runner_results.failures: 504 buff.write(" * " +tc_result[0]._testMethodName + "\n") 505 506 print buff.getvalue()

507

508 -def _format_errors(errors):

509 formatted = [] 510 for e in errors: 511 if '_testMethodName' in e[0].__dict__: 512 formatted.append(e[0]._testMethodName) 513 elif 'description' in e[0].__dict__: 514 formatted.append('%s: %s\n' % (str(e[0].description), str(e[1]))) 515 else: 516 formatted.append(str(e[0].__dict__)) 517 return formatted

518

519 -def print_unittest_summary(result):

520 """ 521 Print summary of python unittest result to stdout 522 @param result: test results 523 """ 524 buff = cStringIO.StringIO() 525 buff.write("-------------------------------------------------------------\nSUMMARY:\n") 526 if result.wasSuccessful(): 527 buff.write("\033[32m * RESULT: SUCCESS\033[0m\n") 528 else: 529 buff.write(" * RESULT: FAIL\n") 530 buff.write(" * TESTS: %s\n"%result.testsRun) 531 buff.write(" * ERRORS: %s [%s]\n"%(len(result.errors), ', '.join(_format_errors(result.errors)))) 532 buff.write(" * FAILURES: %s [%s]\n"%(len(result.failures), ', '.join(_format_errors(result.failures)))) 533 print buff.getvalue()

534

Source Code for Module rosunit.baretest