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 signal 49 import subprocess 50 import time 51 import traceback 52 import unittest 53 54 import rospkg 55 56 from . import junitxml 57 from . import pmon 58 from .core import create_xml_runner # noqa: F401 59 from .core import printerrlog 60 from .core import printlog 61 from .core import printlog_bold 62 from .core import rostest_name_from_path # noqa: F401 63 from .core import xml_results_file 64 65 BARE_TIME_LIMIT = 60. 66 TIMEOUT_SIGINT = 15.0 # seconds 67 TIMEOUT_SIGTERM = 2.0 # seconds 68 69

70 -class TestTimeoutException(Exception):

71 pass

72 73

74 -class BareTestCase(unittest.TestCase):

75

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

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

114

115 - def setUp(self):

116 self.pmon = pmon.start_process_monitor()

117

118 - def tearDown(self):

119 if self.pmon is not None: 120 pmon.shutdown_process_monitor(self.pmon) 121 self.pmon = None

122

123 - def runTest(self):

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

196 197 198 # TODO: this is a straight copy from roslaunch. Need to reduce, refactor

199 -class LocalProcess(pmon.Process):

200 """ 201 Process launched on local machine 202 """ 203

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

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

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

239 - def get_info(self):

240 """ 241 Get all data about this process in dictionary form 242 """ 243 info = super(LocalProcess, self).get_info() 244 info['pid'] = self.pid 245 if self.run_id: 246 info['run_id'] = self.run_id 247 info['log_output'] = self.log_output 248 if self.cwd is not None: 249 info['cwd'] = self.cwd 250 return info

251

252 - def _configure_logging(self):

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

296

297 - def start(self):

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

367

368 - def is_alive(self):

369 """ 370 @return: True if process is still running 371 @rtype: bool 372 """ 373 if not self.started: # not started yet 374 return True 375 if self.stopped or self.popen is None: 376 return False 377 self.exit_code = self.popen.poll() 378 if self.exit_code is not None: 379 return False 380 return True

381

382 - def get_exit_description(self):

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

401

402 - def _stop_unix(self, errors):

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

449

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

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

471 472

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

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

526 527

528 -def _format_errors(errors):

529 formatted = [] 530 for e in errors: 531 if '_testMethodName' in e[0].__dict__: 532 formatted.append(e[0]._testMethodName) 533 elif 'description' in e[0].__dict__: 534 formatted.append('%s: %s\n' % (str(e[0].description), str(e[1]))) 535 else: 536 formatted.append(str(e[0].__dict__)) 537 return formatted

538 539

540 -def print_unittest_summary(result):

541 """ 542 Print summary of python unittest result to stdout 543 @param result: test results 544 """ 545 buff = StringIO() 546 buff.write('-------------------------------------------------------------\nSUMMARY:\n') 547 if result.wasSuccessful(): 548 buff.write('\033[32m * RESULT: SUCCESS\033[0m\n') 549 else: 550 buff.write(' * RESULT: FAIL\n') 551 buff.write(' * TESTS: %s\n' % result.testsRun) 552 buff.write(' * ERRORS: %s [%s]\n' % (len(result.errors), ', '.join(_format_errors(result.errors)))) 553 buff.write(' * FAILURES: %s [%s]\n' % (len(result.failures), ', '.join(_format_errors(result.failures)))) 554 print(buff.getvalue())

555

Source Code for Module rosunit.baretest