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 from __future__ import print_function 41 42 import errno 43 import os 44 try: 45 from cStringIO import StringIO 46 except ImportError: 47 from io import StringIO 48 import unittest 49 import time 50 import signal 51 import subprocess 52 import traceback 53 54 import rospkg 55 56 from .core import xml_results_file, rostest_name_from_path, create_xml_runner, printlog, printerrlog, printlog_bold 57 58 from . import pmon 59 from . import junitxml 60 61 BARE_TIME_LIMIT = 60. 62 TIMEOUT_SIGINT = 15.0 #seconds 63 TIMEOUT_SIGTERM = 2.0 #seconds 64

65 -class TestTimeoutException(Exception): pass

66

67 -class BareTestCase(unittest.TestCase):

68

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

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

107

108 - def setUp(self):

109 self.pmon = pmon.start_process_monitor()

110

111 - def tearDown(self):

112 if self.pmon is not None: 113 pmon.shutdown_process_monitor(self.pmon) 114 self.pmon = None

115

116 - def runTest(self):

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

190 191 192 #TODO: this is a straight copy from roslaunch. Need to reduce, refactor

193 -class LocalProcess(pmon.Process):

194 """ 195 Process launched on local machine 196 """ 197

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

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

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

233 - def get_info(self):

234 """ 235 Get all data about this process in dictionary form 236 """ 237 info = super(LocalProcess, self).get_info() 238 info['pid'] = self.pid 239 if self.run_id: 240 info['run_id'] = self.run_id 241 info['log_output'] = self.log_output 242 if self.cwd is not None: 243 info['cwd'] = self.cwd 244 return info

245

246 - def _configure_logging(self):

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

291

292 - def start(self):

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

361

362 - def is_alive(self):

363 """ 364 @return: True if process is still running 365 @rtype: bool 366 """ 367 if not self.started: #not started yet 368 return True 369 if self.stopped or self.popen is None: 370 return False 371 self.exit_code = self.popen.poll() 372 if self.exit_code is not None: 373 return False 374 return True

375

376 - def get_exit_description(self):

377 """ 378 @return: human-readable description of exit state 379 @rtype: str 380 """ 381 # #973: include location of output location in message 382 if self.exit_code is not None: 383 if self.exit_code: 384 if self.log_dir: 385 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)) 386 else: 387 return 'process has died [pid %s, exit code %s]'%(self.pid, self.exit_code) 388 else: 389 if self.log_dir: 390 return 'process has finished cleanly.\nlog file: %s*.log'%(os.path.join(self.log_dir, self.name)) 391 else: 392 return 'process has finished cleanly' 393 else: 394 return 'process has died'

395

396 - def _stop_unix(self, errors):

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

443

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

445 """ 446 Stop the process. Record any significant error messages in the errors parameter 447 448 @param errors: error messages. stop() will record messages into this list. 449 @type errors: [str] 450 """ 451 super(LocalProcess, self).stop(errors) 452 self.lock.acquire() 453 try: 454 try: 455 if self.popen is None: 456 return 457 #NOTE: currently POSIX-only. Need to add in Windows code once I have a test environment: 458 # http://aspn.activestate.com/ASPN/Cookbook/Python/Recipe/347462 459 self._stop_unix(errors) 460 except: 461 printerrlog("[%s] EXCEPTION %s"%(self.name, traceback.format_exc())) 462 finally: 463 self.stopped = True 464 self.lock.release()

465

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

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

519

520 -def _format_errors(errors):

521 formatted = [] 522 for e in errors: 523 if '_testMethodName' in e[0].__dict__: 524 formatted.append(e[0]._testMethodName) 525 elif 'description' in e[0].__dict__: 526 formatted.append('%s: %s\n' % (str(e[0].description), str(e[1]))) 527 else: 528 formatted.append(str(e[0].__dict__)) 529 return formatted

530

531 -def print_unittest_summary(result):

532 """ 533 Print summary of python unittest result to stdout 534 @param result: test results 535 """ 536 buff = StringIO() 537 buff.write("-------------------------------------------------------------\nSUMMARY:\n") 538 if result.wasSuccessful(): 539 buff.write("\033[32m * RESULT: SUCCESS\033[0m\n") 540 else: 541 buff.write(" * RESULT: FAIL\n") 542 buff.write(" * TESTS: %s\n"%result.testsRun) 543 buff.write(" * ERRORS: %s [%s]\n"%(len(result.errors), ', '.join(_format_errors(result.errors)))) 544 buff.write(" * FAILURES: %s [%s]\n"%(len(result.failures), ', '.join(_format_errors(result.failures)))) 545 print(buff.getvalue())

546

Source Code for Module rosunit.baretest