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

64 -class TestTimeoutException(Exception): pass

65

66 -class BareTestCase(unittest.TestCase):

67

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

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

106

107 - def setUp(self):

108 self.pmon = pmon.start_process_monitor()

109

110 - def tearDown(self):

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

114

115 - def runTest(self):

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

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

192 -class LocalProcess(pmon.Process):

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

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

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

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

232 - def get_info(self):

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

244

245 - def _configure_logging(self):

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

290

291 - def start(self):

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

354

355 - def is_alive(self):

356 """ 357 @return: True if process is still running 358 @rtype: bool 359 """ 360 if not self.started: #not started yet 361 return True 362 if self.stopped or self.popen is None: 363 return False 364 self.exit_code = self.popen.poll() 365 if self.exit_code is not None: 366 return False 367 return True

368

369 - def get_exit_description(self):

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

388

389 - def _stop_unix(self, errors):

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

436

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

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

458

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

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

512

513 -def _format_errors(errors):

514 formatted = [] 515 for e in errors: 516 if '_testMethodName' in e[0].__dict__: 517 formatted.append(e[0]._testMethodName) 518 elif 'description' in e[0].__dict__: 519 formatted.append('%s: %s\n' % (str(e[0].description), str(e[1]))) 520 else: 521 formatted.append(str(e[0].__dict__)) 522 return formatted

523

524 -def print_unittest_summary(result):

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

539

Source Code for Module rosunit.baretest