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

61 -class TestTimeoutException(Exception): pass

62

63 -class BareTestCase(unittest.TestCase):

64

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

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

103

104 - def setUp(self):

105 self.pmon = pmon.start_process_monitor()

106

107 - def tearDown(self):

108 if self.pmon is not None: 109 pmon.shutdown_process_monitor(self.pmon) 110 self.pmon = None

111

112 - def runTest(self):

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

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

189 -class LocalProcess(pmon.Process):

190 """ 191 Process launched on local machine 192 """ 193

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

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

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

229 - def get_info(self):

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

241

242 - def _configure_logging(self):

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

287

288 - def start(self):

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

351

352 - def is_alive(self):

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

365

366 - def get_exit_description(self):

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

385

386 - def _stop_unix(self, errors):

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

433

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

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

455

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

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

509

510 -def _format_errors(errors):

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

520

521 -def print_unittest_summary(result):

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

536

Source Code for Module rosunit.baretest