2 # Copyright (c) 2012 The Native Client Authors. All rights reserved.
3 # Use of this source code is governed by a BSD-style license that can be
4 # found in the LICENSE file.
7 """Simple testing harness for running commands and checking expected output.
9 This harness is used instead of shell scripts to ensure windows compatibility
24 GlobalPlatform=None # for pychecker, initialized in ProcessOptions
38 def DifferentFromGolden(actual, golden, output_type):
39 """Compares actual output against golden output.
41 If there are any differences, output an error message (to stdout) with
45 actual: actual output from the program under test, as a single
48 golden: expected output from the program under test, as a single
51 output_type: the name / title for the output type being compared.
52 Used in banner output.
55 True when there is a difference, False otherwise.
58 diff = list(test_lib.DiffStringsIgnoringWhiteSpace(golden, actual))
59 diff = '\n'.join(diff)
61 Banner('Error %s diff found' % output_type)
63 Banner('Potential New Golden Output')
69 def ResetGlobalSettings():
73 'using_nacl_signal_handler': False,
75 # When declares_exit_status is set, we read the expected exit
76 # status from stderr. We look for a line of the form
77 # "** intended_exit_status=X". This allows crash tests to
78 # declare their expected exit status close to where the crash is
79 # generated, rather than in a Scons file. It reduces the risk
80 # that the test passes accidentally by crashing during setup.
81 'declares_exit_status': False,
83 # List of environment variables to set.
89 # An environment description that should include all factors that may
90 # affect tracked performance. Used to compare different environments.
91 'perf_env_description': None,
93 # Track total time taken for the command: '0' or '1'.
102 'stdout_golden': None,
103 'stderr_golden': None,
106 # This option must be '1' for the output to be captured, for checking
107 # against golden files, special exit_status signals, etc.
108 # When this option is '0', stdout and stderr will be streamed out.
109 'capture_output': '1',
110 # This option must be '1' for the stderr to be captured with stdout
111 # (it's ignored if capture_output == 0). If this option is '0' only
112 # stdout will be captured and stderr will be streamed out.
113 'capture_stderr': '1',
115 'filter_regex': None,
116 'filter_inverse': False,
117 'filter_group_only': False,
119 # Number of times a test is run.
120 # This is useful for getting multiple samples for time perf tests.
123 # Scripts for processing output along with its arguments.
124 # This script is given the output of a single run.
125 'process_output_single': None,
126 # This script is given the concatenated output of all |num_runs|, after
127 # having been filtered by |process_output_single| for individual runs.
128 'process_output_combined': None,
136 def StringifyList(lst):
139 def DestringifyList(lst):
140 # BUG(robertm): , is a legitimate character for an environment variable
142 return lst.split(',')
144 # The following messages match gtest's formatting. This improves log
145 # greppability for people who primarily work on Chrome. It also allows
146 # gtest-specific hooks on the buildbots to fire.
147 # The buildbots expect test names in the format "suite_name.test_name", so we
148 # prefix the test name with a bogus suite name (nacl).
150 return '[ RUN ] %s' % (GlobalSettings['name'],)
152 def FailureMessage(total_time):
153 return '[ FAILED ] %s (%d ms)' % (GlobalSettings['name'],
156 def SuccessMessage(total_time):
157 return '[ OK ] %s (%d ms)' % (GlobalSettings['name'],
160 def LogPerfResult(graph_name, trace_name, value, units):
161 # NOTE: This RESULT message is parsed by Chrome's perf graph generator.
162 Print('RESULT %s: %s= %s %s' %
163 (graph_name, trace_name, value, units))
165 def PrintTotalTime(total_time):
166 if int(GlobalSettings['track_cmdtime']):
167 LogPerfResult(GlobalSettings['name'],
168 'TOTAL_' + GlobalSettings['perf_env_description'],
173 # On POSIX systems, exit() codes are 8-bit. You cannot use exit() to
174 # make it look like the process was killed by a signal. Instead,
175 # NaCl's signal handler encodes the signal number into the exit() code
176 # by returning with exit(-signum) or equivalently, exit((-signum) & 0xff).
177 def IndirectSignal(signum):
178 return (-signum) & 0xff
180 # Windows exit codes that indicate unhandled exceptions.
181 STATUS_ACCESS_VIOLATION = 0xc0000005
182 STATUS_ILLEGAL_INSTRUCTION = 0xc000001d
183 STATUS_PRIVILEGED_INSTRUCTION = 0xc0000096
184 STATUS_FLOAT_DIVIDE_BY_ZERO = 0xc000008e
185 STATUS_INTEGER_DIVIDE_BY_ZERO = 0xc0000094
187 # Python's wrapper for GetExitCodeProcess() treats the STATUS_* values
188 # as negative, although the unsigned values are used in headers and
189 # are more widely recognised.
190 def MungeWindowsErrorExit(num):
191 return num - 0x100000000
193 # If a crash occurs in x86-32 untrusted code on Windows, the kernel
194 # apparently gets confused about the cause. It fails to take %cs into
195 # account when examining the faulting instruction, so it looks at the
196 # wrong instruction, so we could get either of the errors below.
197 # See http://code.google.com/p/nativeclient/issues/detail?id=1689
198 win32_untrusted_crash_exit = [
199 MungeWindowsErrorExit(STATUS_ACCESS_VIOLATION),
200 MungeWindowsErrorExit(STATUS_PRIVILEGED_INSTRUCTION)]
203 MungeWindowsErrorExit(STATUS_FLOAT_DIVIDE_BY_ZERO),
204 MungeWindowsErrorExit(STATUS_INTEGER_DIVIDE_BY_ZERO),
207 # We patch Windows' KiUserExceptionDispatcher on x86-64 to terminate
208 # the process safely when untrusted code crashes. We get the exit
209 # code associated with the HLT instruction.
210 win64_exit_via_ntdll_patch = [
211 MungeWindowsErrorExit(STATUS_PRIVILEGED_INSTRUCTION)]
214 # Mach exception code for Mac OS X.
218 # 32-bit processes on Mac OS X return SIGBUS in most of the cases where Linux
219 # returns SIGSEGV, except for actual x86 segmentation violations. 64-bit
220 # processes on Mac OS X behave differently.
223 'linux2': [-5], # SIGTRAP
224 'darwin': [-5], # SIGTRAP
226 'trusted_sigabrt' : {
227 'linux2': [-6], # SIGABRT
228 'mac32': [-6], # SIGABRT
229 'mac64': [-6], # SIGABRT
230 # On Windows, NaClAbort() exits using the HLT instruction.
231 'win32': [MungeWindowsErrorExit(STATUS_PRIVILEGED_INSTRUCTION)],
232 'win64': [MungeWindowsErrorExit(STATUS_PRIVILEGED_INSTRUCTION)],
234 'naclabort_coverage' : {
235 # This case is here because NaClAbort() behaves differently when
236 # code coverage is enabled.
237 # This is not used on Windows.
238 'linux2': [IndirectSignal(6)], # SIGABRT
239 'mac32': [IndirectSignal(6)], # SIGABRT
240 'mac64': [IndirectSignal(6)], # SIGABRT
243 # This is not used on Windows because Windows does not have an
244 # equivalent of SIGPIPE.
245 'linux2': [-13], # SIGPIPE
246 'mac32': [-13], # SIGPIPE
247 'mac64': [-13], # SIGPIPE
249 'untrusted_sigsegv': {
250 'linux2': [-11], # SIGSEGV
251 'mac32': [-11], # SIGSEGV
252 'mac64': [-11], # SIGSEGV
253 'win32': win32_untrusted_crash_exit,
254 'win64': win64_exit_via_ntdll_patch,
256 'untrusted_sigill' : {
257 'linux2': [-4], # SIGILL
258 'mac32': [-4], # SIGILL
259 'mac64': [-4], # SIGILL
260 'win32': win32_untrusted_crash_exit,
261 'win64': win64_exit_via_ntdll_patch,
263 'untrusted_sigfpe' : {
264 'linux2': [-8], # SIGFPE
265 'mac32': [-8], # SIGFPE
266 'mac64': [-8], # SIGFPE
267 'win32': win32_sigfpe,
268 'win64': win64_exit_via_ntdll_patch,
270 'untrusted_segfault': {
271 'linux2': [-11], # SIGSEGV
272 'mac32': [-10], # SIGBUS
273 'mac64': [-10], # SIGBUS
274 'mach_exception': EXC_BAD_ACCESS,
275 'win32': win32_untrusted_crash_exit,
276 'win64': win64_exit_via_ntdll_patch,
278 'untrusted_sigsegv_or_equivalent': {
279 'linux2': [-11], # SIGSEGV
280 'mac32': [-11], # SIGSEGV
281 'mac64': [-10], # SIGBUS
282 'win32': win32_untrusted_crash_exit,
283 'win64': win64_exit_via_ntdll_patch,
285 'trusted_segfault': {
286 'linux2': [-11], # SIGSEGV
287 'mac32': [-10], # SIGBUS
288 'mac64': [-11], # SIGSEGV
289 'mach_exception': EXC_BAD_ACCESS,
290 'win32': [MungeWindowsErrorExit(STATUS_ACCESS_VIOLATION)],
291 'win64': [MungeWindowsErrorExit(STATUS_ACCESS_VIOLATION)],
293 'trusted_sigsegv_or_equivalent': {
294 'linux2': [-11], # SIGSEGV
295 'mac32': [-11], # SIGSEGV
296 'mac64': [-11], # SIGSEGV
300 # This is like 'untrusted_segfault', but without the 'untrusted_'
301 # prefix which marks the status type as expecting a
302 # gracefully-printed exit message from nacl_signal_common.c. This
303 # is a special case because we use different methods for writing
304 # the exception stack frame on different platforms. On Mac and
305 # Windows, NaCl uses a system call which will detect unwritable
306 # pages, so the exit status appears as an unhandled fault from
307 # untrusted code. On Linux, NaCl's signal handler writes the
308 # frame directly, so the exit status comes from getting a SIGSEGV
309 # inside the SIGSEGV handler.
310 'unwritable_exception_stack': {
311 'linux2': [-11], # SIGSEGV
312 'mac32': [-10], # SIGBUS
313 'mac64': [-10], # SIGBUS
314 'win32': win32_untrusted_crash_exit,
315 'win64': win64_exit_via_ntdll_patch,
317 # Expectations for __builtin_trap(), which is compiled to different
318 # instructions by the GCC and LLVM toolchains. The exact exit status
319 # does not matter too much, as long as it's a crash and not a graceful
320 # exit via exit() or _exit(). We want __builtin_trap() to trigger the
321 # debugger or a crash reporter.
322 'untrusted_builtin_trap': {
323 'linux2': [-4, -5, -11],
324 'mac32': [-4, -10, -11],
325 'mac64': [-4, -10, -11],
326 'win32': win32_untrusted_crash_exit +
327 [MungeWindowsErrorExit(STATUS_ILLEGAL_INSTRUCTION)],
328 'win64': win64_exit_via_ntdll_patch,
333 def ProcessOptions(argv):
334 global GlobalPlatform
336 """Process command line options and return the unprocessed left overs."""
337 ResetGlobalSettings()
339 opts, args = getopt.getopt(argv, '', [x + '=' for x in GlobalSettings])
340 except getopt.GetoptError, err:
341 Print(str(err)) # will print something like 'option -a not recognized'
345 # strip the leading '--'
347 assert option in GlobalSettings
348 if option == 'exit_status':
349 GlobalSettings[option] = a
350 elif type(GlobalSettings[option]) == int:
351 GlobalSettings[option] = int(a)
353 GlobalSettings[option] = a
355 if (sys.platform == 'win32') and (GlobalSettings['subarch'] == '64'):
356 GlobalPlatform = 'win64'
357 elif (sys.platform == 'darwin'):
359 GlobalPlatform = 'mac' + GlobalSettings['subarch']
361 GlobalPlatform = sys.platform
363 # return the unprocessed options, i.e. the command
367 # Parse output for signal type and number
369 # The '** Signal' output is from the nacl signal handler code.
371 # Since it is possible for there to be an output race with another
372 # thread, or additional output due to atexit functions, we scan the
373 # output in reverse order for the signal signature.
374 def GetNaClSignalInfoFromStderr(stderr):
375 lines = stderr.splitlines()
377 # Scan for signal msg in reverse order
378 for curline in reversed(lines):
379 match = re.match('\*\* (Signal|Mach exception) (\d+) from '
380 '(trusted|untrusted) code', curline)
381 if match is not None:
382 return match.group(0)
385 def GetQemuSignalFromStderr(stderr, default):
386 for line in reversed(stderr.splitlines()):
387 # Look for 'qemu: uncaught target signal XXX'.
389 if (len(words) > 4 and
390 words[0] == 'qemu:' and words[1] == 'uncaught' and
391 words[2] == 'target' and words[3] == 'signal'):
392 return -int(words[4])
395 def FormatExitStatus(number):
396 # Include the hex version because it makes the Windows error exit
397 # statuses (STATUS_*) more recognisable.
398 return '%i (0x%x)' % (number, number & 0xffffffff)
400 def FormatResult((exit_status, printed_status)):
401 return 'exit status %s and signal info %r' % (
402 FormatExitStatus(exit_status), printed_status)
404 def PrintStdStreams(stdout, stderr):
405 if stderr is not None:
406 Banner('Stdout for %s:' % os.path.basename(GlobalSettings['name']))
408 Banner('Stderr for %s:' % os.path.basename(GlobalSettings['name']))
411 def GetIntendedExitStatuses(stderr):
413 for line in stderr.splitlines():
414 match = re.match(r'\*\* intended_exit_status=(.*)$', line)
415 if match is not None:
416 statuses.append(match.group(1))
419 def CheckExitStatus(failed, req_status, using_nacl_signal_handler,
420 exit_status, stdout, stderr):
421 if GlobalSettings['declares_exit_status']:
422 assert req_status == 0
423 intended_statuses = GetIntendedExitStatuses(stderr)
424 if len(intended_statuses) == 0:
425 Print('\nERROR: Command returned exit status %s but did not output an '
426 'intended_exit_status line to stderr - did it exit too early?'
427 % FormatExitStatus(exit_status))
429 elif len(intended_statuses) != 1:
430 Print('\nERROR: Command returned exit status %s but produced '
431 'multiple intended_exit_status lines (%s)'
432 % (FormatExitStatus(exit_status), ', '.join(intended_statuses)))
435 req_status = intended_statuses[0]
437 expected_sigtype = 'normal'
438 if req_status in status_map:
439 expected_statuses = status_map[req_status][GlobalPlatform]
440 if using_nacl_signal_handler:
441 if req_status.startswith('trusted_'):
442 expected_sigtype = 'trusted'
443 elif req_status.startswith('untrusted_'):
444 expected_sigtype = 'untrusted'
446 expected_statuses = [int(req_status)]
448 expected_printed_status = None
449 if expected_sigtype == 'normal':
450 expected_results = [(status, None) for status in expected_statuses]
452 if sys.platform == 'darwin':
454 default = '<mach_exception field missing for %r>' % req_status
455 expected_printed_status = '** Mach exception %s from %s code' % (
456 status_map.get(req_status, {}).get('mach_exception', default),
458 expected_results = [(status, expected_printed_status)
459 for status in expected_statuses]
462 assert sys.platform != 'win32'
464 def MapStatus(status):
465 # Expected value should be a signal number, negated.
466 assert status < 0, status
467 expected_printed_signum = -status
468 expected_printed_status = '** Signal %d from %s code' % (
469 expected_printed_signum,
471 return (IndirectSignal(expected_printed_signum),
472 expected_printed_status)
474 expected_results = [MapStatus(status) for status in expected_statuses]
476 # If an uncaught signal occurs under QEMU (on ARM), the exit status
477 # contains the signal number, mangled as per IndirectSignal(). We
478 # extract the unadulterated signal number from QEMU's log message in
479 # stderr instead. If we are not using QEMU, or no signal is raised
480 # under QEMU, this is a no-op.
481 if stderr is not None:
482 exit_status = GetQemuSignalFromStderr(stderr, exit_status)
484 if using_nacl_signal_handler and stderr is not None:
485 actual_printed_status = GetNaClSignalInfoFromStderr(stderr)
487 actual_printed_status = None
489 actual_result = (exit_status, actual_printed_status)
490 msg = '\nERROR: Command returned: %s\n' % FormatResult(actual_result)
491 msg += 'but we expected: %s' % '\n or: '.join(FormatResult(r)
492 for r in expected_results)
493 if actual_result not in expected_results:
498 def CheckTimeBounds(total_time):
499 if GlobalSettings['time_error']:
500 if total_time > GlobalSettings['time_error']:
501 Print('ERROR: should have taken less than %f secs' %
502 (GlobalSettings['time_error']))
505 if GlobalSettings['time_warning']:
506 if total_time > GlobalSettings['time_warning']:
507 Print('WARNING: should have taken less than %f secs' %
508 (GlobalSettings['time_warning']))
511 def CheckGoldenOutput(stdout, stderr):
512 for (stream, getter) in [
513 ('stdout', lambda: stdout),
514 ('stderr', lambda: stderr),
515 ('log', lambda: open(GlobalSettings['log_file']).read()),
517 golden = stream + '_golden'
518 if GlobalSettings[golden]:
519 golden_data = open(GlobalSettings[golden]).read()
521 if GlobalSettings['filter_regex']:
522 actual = test_lib.RegexpFilterLines(GlobalSettings['filter_regex'],
523 GlobalSettings['filter_inverse'],
524 GlobalSettings['filter_group_only'],
526 if DifferentFromGolden(actual, golden_data, stream):
530 def ProcessLogOutputSingle(stdout, stderr):
531 output_processor = GlobalSettings['process_output_single']
532 if output_processor is None:
533 return (True, stdout, stderr)
535 output_processor_cmd = DestringifyList(output_processor)
536 # Also, get the output from log_file to get NaClLog output in Windows.
537 log_output = open(GlobalSettings['log_file']).read()
538 # Assume the log processor does not care about the order of the lines.
539 all_output = log_output + stdout + stderr
540 _, retcode, failed, new_stdout, new_stderr = \
541 test_lib.RunTestWithInputOutput(
542 output_processor_cmd, all_output,
543 timeout=GlobalSettings['time_error'])
544 # Print the result, since we have done some processing and we need
545 # to have the processed data. However, if we intend to process it some
546 # more later via process_output_combined, do not duplicate the data here.
547 # Only print out the final result!
548 if not GlobalSettings['process_output_combined']:
549 PrintStdStreams(new_stdout, new_stderr)
550 if retcode != 0 or failed:
551 return (False, new_stdout, new_stderr)
553 return (True, new_stdout, new_stderr)
555 def ProcessLogOutputCombined(stdout, stderr):
556 output_processor = GlobalSettings['process_output_combined']
557 if output_processor is None:
560 output_processor_cmd = DestringifyList(output_processor)
561 all_output = stdout + stderr
562 _, retcode, failed, new_stdout, new_stderr = \
563 test_lib.RunTestWithInputOutput(
564 output_processor_cmd, all_output,
565 timeout=GlobalSettings['time_error'])
566 # Print the result, since we have done some processing.
567 PrintStdStreams(new_stdout, new_stderr)
568 if retcode != 0 or failed:
573 def DoRun(command, stdin_data):
575 Run the command, given stdin_data. Returns a return code (0 is good)
576 and optionally a captured version of stdout, stderr from the run
577 (if the global setting capture_output is true).
579 # Initialize stdout, stderr to indicate we have not captured
580 # any of stdout or stderr.
583 if not int(GlobalSettings['capture_output']):
584 # We are only blurting out the stdout and stderr, not capturing it
585 # for comparison, etc.
586 assert (not GlobalSettings['stdout_golden']
587 and not GlobalSettings['stderr_golden']
588 and not GlobalSettings['log_golden']
589 and not GlobalSettings['filter_regex']
590 and not GlobalSettings['filter_inverse']
591 and not GlobalSettings['filter_group_only']
592 and not GlobalSettings['process_output_single']
593 and not GlobalSettings['process_output_combined']
595 # If python ever changes popen.stdout.read() to not risk deadlock,
596 # we could stream and capture, and use RunTestWithInputOutput instead.
597 (total_time, exit_status, failed) = test_lib.RunTestWithInput(
599 timeout=GlobalSettings['time_error'])
600 PrintTotalTime(total_time)
601 if not CheckExitStatus(failed,
602 GlobalSettings['exit_status'],
603 GlobalSettings['using_nacl_signal_handler'],
604 exit_status, None, None):
605 Print(FailureMessage(total_time))
606 return (1, stdout, stderr)
608 (total_time, exit_status,
609 failed, stdout, stderr) = test_lib.RunTestWithInputOutput(
610 command, stdin_data, int(GlobalSettings['capture_stderr']),
611 timeout=GlobalSettings['time_error'])
612 PrintTotalTime(total_time)
613 # CheckExitStatus may spew stdout/stderr when there is an error.
614 # Otherwise, we do not spew stdout/stderr in this case (capture_output).
615 if not CheckExitStatus(failed,
616 GlobalSettings['exit_status'],
617 GlobalSettings['using_nacl_signal_handler'],
618 exit_status, stdout, stderr):
619 PrintStdStreams(stdout, stderr)
620 Print(FailureMessage(total_time))
621 return (1, stdout, stderr)
622 if not CheckGoldenOutput(stdout, stderr):
623 Print(FailureMessage(total_time))
624 return (1, stdout, stderr)
625 success, stdout, stderr = ProcessLogOutputSingle(stdout, stderr)
627 Print(FailureMessage(total_time) + ' ProcessLogOutputSingle failed!')
628 return (1, stdout, stderr)
630 if not CheckTimeBounds(total_time):
631 Print(FailureMessage(total_time))
632 return (1, stdout, stderr)
634 Print(SuccessMessage(total_time))
635 return (0, stdout, stderr)
638 def DisableCrashDialog():
640 Disable Windows' crash dialog box, which pops up when a process exits with
641 an unhandled fault. This causes the process to hang on the Buildbots. We
642 duplicate this function from SConstruct because ErrorMode flags are
643 overwritten in scons due to race conditions. See bug
644 https://code.google.com/p/nativeclient/issues/detail?id=2968
646 if sys.platform == 'win32':
649 # The double call is to preserve existing flags, as discussed at
650 # http://blogs.msdn.com/oldnewthing/archive/2004/07/27/198410.aspx
651 new_flags = win32con.SEM_NOGPFAULTERRORBOX
652 existing_flags = win32api.SetErrorMode(new_flags)
653 win32api.SetErrorMode(existing_flags | new_flags)
658 command = ProcessOptions(argv)
660 if not GlobalSettings['name']:
661 GlobalSettings['name'] = command[0]
662 GlobalSettings['name'] = os.path.basename(GlobalSettings['name'])
665 num_runs = GlobalSettings['num_runs']
667 Print(' (running %d times)' % num_runs)
669 if GlobalSettings['osenv']:
670 Banner('setting environment')
671 env_vars = DestringifyList(GlobalSettings['osenv'])
674 for env_var in env_vars:
675 key, val = env_var.split('=', 1)
676 Print('[%s] = [%s]' % (key, val))
677 os.environ[key] = val
680 if GlobalSettings['stdin']:
681 stdin_data = open(GlobalSettings['stdin'])
683 run_under = GlobalSettings['run_under']
685 command = run_under.split(',') + command
687 # print the command in copy-and-pastable fashion
688 print ' '.join(pipes.quote(arg) for arg in env_vars + command)
690 # Concatenate output when running multiple times (e.g., for timing).
694 num_runs = GlobalSettings['num_runs']
695 while cur_runs < num_runs:
697 # Clear out previous log_file.
698 if GlobalSettings['log_file']:
700 os.unlink(GlobalSettings['log_file']) # might not pre-exist
703 ret_code, stdout, stderr = DoRun(command, stdin_data)
706 combined_stdout += stdout
707 combined_stderr += stderr
708 # Process the log output after all the runs.
709 success = ProcessLogOutputCombined(combined_stdout, combined_stderr)
711 # Bogus time, since only ProcessLogOutputCombined failed.
712 Print(FailureMessage(0.0) + ' ProcessLogOutputCombined failed!')
714 if GlobalSettings['output_stamp'] is not None:
715 # Create an empty stamp file to indicate success.
716 fh = open(GlobalSettings['output_stamp'], 'w')
720 if __name__ == '__main__':
721 retval = Main(sys.argv[1:])
722 # Add some whitepsace to make the logs easier to read.
723 sys.stdout.write('\n\n')