Back to build
Raw log | Switch to full mode | Login

Running command: /b/s/w/ir/cache/vpython/7c7ecd/bin/python scons.py --verbose -k -j1 --mode=nacl,dbg-host platform=x86-64 --clang large_tests scons: Reading SConscript files ... ====================================================================== SCONS ARGS:['scons.py', '--verbose', '-k', '-j1', '--mode=nacl,dbg-host', 'platform=x86-64', '--clang', 'large_tests'] ====================================================================== ====================================================================== Python Info: ====================================================================== darwin 2.7.14+chromium14 (6cc0aad35b-dirty:6cc0aad35b, Oct 3 2017, 17:23:56) [GCC 4.2.1 Compatible Apple LLVM 8.0.0 (clang-800.0.38)] ====================================================================== ENV: ====================================================================== PATH /b/s/w/ir/cache/vpython/7c7ecd/bin:/b/s/w/ir/cipd_bin_packages:/b/s/w/ir/cipd_bin_packages/bin:/b/s/cipd_cache/bin:/opt/local/bin:/opt/local/sbin:/usr/local/sbin:/usr/local/git/bin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/b/s/w/ir/kitchen-checkout/depot_tools ====================================================================== OS: ====================================================================== kern.ostype: Darwin kern.osrelease: 17.7.0 kern.osrevision: 199506 kern.version: Darwin Kernel Version 17.7.0: Thu Jun 21 22:53:14 PDT 2018; root:xnu-4570.71.2~1/RELEASE_X86_64 kern.posix1version: 200112 kern.osversion: 17G65 kern.osproductversion: 10.13.6 ====================================================================== CPU: ====================================================================== hw.machine: x86_64 hw.model: Macmini7,1 hw.ncpu: 4 hw.ncpu: 4 hw.activecpu: 4 hw.physicalcpu: 2 hw.physicalcpu_max: 2 hw.logicalcpu: 4 hw.logicalcpu_max: 4 hw.cputype: 7 hw.cpusubtype: 8 hw.cpu64bit_capable: 1 hw.cpufamily: 280134364 hw.cpufrequency: 3000000000 hw.cpufrequency_min: 3000000000 hw.cpufrequency_max: 3000000000 hw.cputhreadtype: 1 ====================================================================== RAM: ====================================================================== hw.memsize: 17179869184 ====================================================================== LOAD: ====================================================================== TBD ====================================================================== UPTIME: ====================================================================== kern.boottime: { sec = 1552669750, usec = 875430 } Fri Mar 15 10:09:10 2019 ====================================================================== The following environments have been configured ====================================================================== NACL_BUILD_FAMILY: UNTRUSTED BUILD_TYPE: nacl TARGET_ROOT: /b/s/w/ir/k/native_client/scons-out/nacl-x86-64 OBJ_ROOT: /b/s/w/ir/k/native_client/scons-out/nacl-x86-64/obj BUILD_TYPE_DESCRIPTION: NaCl module build BUILD_OS: BUILD_ARCHITECTURE: x86 BUILD_SUBARCH: 64 TARGET_OS: TARGET_ARCHITECTURE: x86 TARGET_SUBARCH: 64 CC: /b/s/w/ir/k/native_client/toolchain/mac_x86/pnacl_newlib_raw/bin/x86_64-nacl-clang ASPPCOM: /b/s/w/ir/k/native_client/toolchain/mac_x86/pnacl_newlib_raw/bin/x86_64-nacl-clang -m64 -D__STDC_LIMIT_MACROS=1 -D__STDC_FORMAT_MACROS=1 -D_GNU_SOURCE=1 -D_POSIX_C_SOURCE=199506 -D_XOPEN_SOURCE=600 -DDYNAMIC_ANNOTATIONS_ENABLED=1 -DDYNAMIC_ANNOTATIONS_PREFIX=NACL_ -DNACL_BUILD_ARCH=x86 -DNACL_BUILD_SUBARCH=64 -I/b/s/w/ir/k/native_client/scons-out/nacl-x86-64/include -I/b/s/w/ir/k -c -o UNKNOWN COMPILER NACL_BUILD_FAMILY: TRUSTED BUILD_TYPE: dbg-mac TARGET_ROOT: /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64 OBJ_ROOT: /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj BUILD_TYPE_DESCRIPTION: MacOS dbg build BUILD_OS: BUILD_ARCHITECTURE: x86 BUILD_SUBARCH: 64 TARGET_OS: TARGET_ARCHITECTURE: x86 TARGET_SUBARCH: 64 CC: /b/s/w/ir/k/third_party/llvm-build/Release+Asserts/bin/clang ASPPCOM: /b/s/w/ir/k/third_party/llvm-build/Release+Asserts/bin/clang -isysroot /b/s/w/ir/cache/osx_sdk/XCode.app/Contents/Developer/Platforms/MacOSX.platform/Developer/SDKs/MacOSX10.13.sdk -mmacosx-version-min=10.6 -m64 -D__STDC_LIMIT_MACROS=1 -D__STDC_FORMAT_MACROS=1 -D_DEBUG -I/b/s/w/ir/k -c -o UNKNOWN COMPILER NACL_BUILD_FAMILY: UNTRUSTED_IRT BUILD_TYPE: nacl_irt TARGET_ROOT: /b/s/w/ir/k/native_client/scons-out/nacl_irt-x86-64 OBJ_ROOT: /b/s/w/ir/k/native_client/scons-out/nacl_irt-x86-64/obj BUILD_TYPE_DESCRIPTION: NaCl IRT build BUILD_OS: BUILD_ARCHITECTURE: x86 BUILD_SUBARCH: 64 TARGET_OS: TARGET_ARCHITECTURE: x86 TARGET_SUBARCH: 64 CC: /b/s/w/ir/k/native_client/toolchain/mac_x86/pnacl_newlib_raw/bin/x86_64-nacl-clang ASPPCOM: /b/s/w/ir/k/native_client/toolchain/mac_x86/pnacl_newlib_raw/bin/x86_64-nacl-clang -m64 -D__STDC_LIMIT_MACROS=1 -D__STDC_FORMAT_MACROS=1 -D_GNU_SOURCE=1 -D_POSIX_C_SOURCE=199506 -D_XOPEN_SOURCE=600 -DDYNAMIC_ANNOTATIONS_ENABLED=1 -DDYNAMIC_ANNOTATIONS_PREFIX=NACL_ -DNACL_BUILD_ARCH=x86 -DNACL_BUILD_SUBARCH=64 -I/b/s/w/ir/k/native_client/scons-out/nacl_irt-x86-64/include -I/b/s/w/ir/k -I/b/s/w/ir/k/native_client/src/untrusted/pthread -c -o UNKNOWN COMPILER *** BROKEN run_ncval_annotate_test *** BROKEN run_gdb_invalid_memory_test *** BROKEN run_nanosleep_test *** BROKEN run_timefuncs_test *** BROKEN run_raw_timefuncs_test *** BROKEN run_main_thread_pthread_exit_test2 *** BROKEN run_overflowinline_test *** BROKEN run_stack_frame_noopt_frame_test *** BROKEN run_stack_frame_noopt_noframe_test *** BROKEN run_stack_frame_opt_frame_test *** BROKEN run_stack_frame_opt_noframe_test *** BROKEN run_vla_test *** BROKEN run_nacl_sync_cond_test SKIPPING test text_overlaps_rodata SKIPPING test text_overlaps_data There are 13 broken tests. ====================================================================== B U I L D - O U T P U T: ====================================================================== scons: done reading SConscript files. scons: Building targets ... /b/s/w/ir/cache/vpython/7c7ecd/bin/python tools/command_tester.py --name nacl_newlib.run_benchmark_test --time_warning 10 --time_error 100 --perf_env_description x86-64_nnacl_newlib_static --subarch 64 --arch x86 --capture_output 0 --output_stamp /b/s/w/ir/k/native_client/scons-out/nacl-x86-64/test_results/benchmark_test.out scons-out/dbg-mac-x86-64/staging/sel_ldr -- scons-out/nacl-x86-64/obj/tests/benchmark/benchmark_test.nexe x86-64_nnacl_newlib_static [ RUN ] nacl_newlib.run_benchmark_test scons-out/dbg-mac-x86-64/staging/sel_ldr -- scons-out/nacl-x86-64/obj/tests/benchmark/benchmark_test.nexe x86-64_nnacl_newlib_static [28539,2849473408:13:05:11.180004] Native Client module will be loaded at base address 0x0000122500000000 Running suite of 1 benchmarks: Running Benchmark: Life (SIMD version)... RESULT BenchmarkLife: x86-64_nnacl_newlib_static= {0.126490, 0.000220} seconds --------------------------------------------------------------- Done running benchmark suite. [ OK ] nacl_newlib.run_benchmark_test (1270 ms) /b/s/w/ir/cache/vpython/7c7ecd/bin/python tools/command_tester.py --name nacl_newlib.run_clock_cputime_test --time_warning 60 --time_error 600 --perf_env_description x86-64_nnacl_newlib_static --subarch 64 --arch x86 --output_stamp /b/s/w/ir/k/native_client/scons-out/nacl-x86-64/test_results/clock_cputime_test.out scons-out/dbg-mac-x86-64/staging/sel_ldr -- scons-out/nacl-x86-64/obj/tests/clock/clock_test.nexe -c [ RUN ] nacl_newlib.run_clock_cputime_test scons-out/dbg-mac-x86-64/staging/sel_ldr -- scons-out/nacl-x86-64/obj/tests/clock/clock_test.nexe -c [ OK ] nacl_newlib.run_clock_cputime_test (59150 ms) doSizeCheck(["scons-out/nacl-x86-64/obj/tests/hello_world/hello_world_size.out"], ["scons-out/nacl-x86-64/obj/tests/hello_world/hello_world.nexe"]) RESULT hello_world_size.out: x86-64_nnacl_newlib_static= 524.896 KB RESULT hello_world_size.out: ZIPPED_x86-64_nnacl_newlib_static= 187.825 KB /b/s/w/ir/cache/vpython/7c7ecd/bin/python tools/command_tester.py --name nacl_newlib.run_performance_test --time_warning 10 --time_error 100 --perf_env_description x86-64_nnacl_newlib_static --subarch 64 --arch x86 --capture_output 0 --output_stamp /b/s/w/ir/k/native_client/scons-out/nacl-x86-64/test_results/performance_test.out scons-out/dbg-mac-x86-64/staging/sel_ldr -e -- scons-out/nacl-x86-64/obj/tests/performance/performance_test.nexe x86-64_nnacl_newlib_static [ RUN ] nacl_newlib.run_performance_test scons-out/dbg-mac-x86-64/staging/sel_ldr -e -- scons-out/nacl-x86-64/obj/tests/performance/performance_test.nexe x86-64_nnacl_newlib_static [28545,2849473408:13:05:28.676922] Native Client module will be loaded at base address 0x0000286200000000 TestNull: Measuring real time: 0.007 usec (6.67e-09 sec) per iteration: 6.67e-07 sec for 100 iterations 0.002 usec (1.833e-09 sec) per iteration: 1.833e-06 sec for 1000 iterations 0.002 usec (1.5133e-09 sec) per iteration: 1.5133e-05 sec for 10000 iterations 0.001 usec (1.45997e-09 sec) per iteration: 0.096476 sec for 66080750 iterations 0.001 usec (1.45659e-09 sec) per iteration: 0.0962524 sec for 66080750 iterations 0.001 usec (1.45735e-09 sec) per iteration: 0.0963029 sec for 66080750 iterations 0.001 usec (1.45215e-09 sec) per iteration: 0.0959594 sec for 66080750 iterations 0.001 usec (1.46135e-09 sec) per iteration: 0.096567 sec for 66080750 iterations mean: 0.001457 usec stddev: 0.000003 usec relative stddev: 0.22% RESULT TestNull: x86-64_nnacl_newlib_static= {0.001457, 0.000003} us Measuring clock cycles: first runs (cycles): 144 18 27 39 18 18 18 27 18 18 ... slowest runs (cycles): ... 27 27 27 27 27 27 27 27 39 144 min: 18 cycles q1: 18 cycles median: 18 cycles q3: 27 cycles max: 144 cycles RESULT TestNull_CycleCount: x86-64_nnacl_newlib_static= {18, 9} count Apparent clock speed: 12350 MHz TestNaClSyscall: Measuring real time: 0.237 usec (2.3739e-07 sec) per iteration: 2.3739e-05 sec for 100 iterations 0.150 usec (1.49895e-07 sec) per iteration: 0.0631429 sec for 421247 iterations 0.149 usec (1.49094e-07 sec) per iteration: 0.0628052 sec for 421247 iterations 0.150 usec (1.49885e-07 sec) per iteration: 0.0631386 sec for 421247 iterations 0.148 usec (1.48462e-07 sec) per iteration: 0.0625391 sec for 421247 iterations 0.149 usec (1.49295e-07 sec) per iteration: 0.06289 sec for 421247 iterations mean: 0.149326 usec stddev: 0.000536 usec relative stddev: 0.36% RESULT TestNaClSyscall: x86-64_nnacl_newlib_static= {0.149326, 0.000536} us Measuring clock cycles: first runs (cycles): 738 600 498 495 465 525 456 465 468 465 ... slowest runs (cycles): ... 477 477 477 495 498 513 525 555 600 738 min: 450 cycles q1: 465 cycles median: 465 cycles q3: 468 cycles max: 738 cycles RESULT TestNaClSyscall_CycleCount: x86-64_nnacl_newlib_static= {465, 3} count Apparent clock speed: 3114 MHz TestSetjmpLongjmp: Measuring real time: 0.019 usec (1.937e-08 sec) per iteration: 1.937e-06 sec for 100 iterations 0.013 usec (1.2969e-08 sec) per iteration: 1.2969e-05 sec for 1000 iterations 0.010 usec (9.77018e-09 sec) per iteration: 0.0753349 sec for 7710694 iterations 0.010 usec (9.76958e-09 sec) per iteration: 0.0753302 sec for 7710694 iterations 0.010 usec (9.85998e-09 sec) per iteration: 0.0760273 sec for 7710694 iterations 0.010 usec (9.85426e-09 sec) per iteration: 0.0759832 sec for 7710694 iterations 0.010 usec (9.75071e-09 sec) per iteration: 0.0751847 sec for 7710694 iterations mean: 0.009801 usec stddev: 0.000046 usec relative stddev: 0.47% RESULT TestSetjmpLongjmp: x86-64_nnacl_newlib_static= {0.009801, 0.000046} us Measuring clock cycles: first runs (cycles): 438 48 18 21 18 21 21 21 18 21 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 30 48 438 min: 18 cycles q1: 21 cycles median: 21 cycles q3: 30 cycles max: 438 cycles RESULT TestSetjmpLongjmp_CycleCount: x86-64_nnacl_newlib_static= {21, 9} count Apparent clock speed: 2143 MHz TestClockGetTime: Measuring real time: 0.351 usec (3.5101e-07 sec) per iteration: 3.5101e-05 sec for 100 iterations 0.253 usec (2.53093e-07 sec) per iteration: 0.0721042 sec for 284892 iterations 0.253 usec (2.53006e-07 sec) per iteration: 0.0720795 sec for 284892 iterations 0.251 usec (2.5128e-07 sec) per iteration: 0.0715876 sec for 284892 iterations 0.252 usec (2.52169e-07 sec) per iteration: 0.071841 sec for 284892 iterations 0.251 usec (2.50568e-07 sec) per iteration: 0.0713848 sec for 284892 iterations mean: 0.252023 usec stddev: 0.000980 usec relative stddev: 0.39% RESULT TestClockGetTime: x86-64_nnacl_newlib_static= {0.252023, 0.000980} us Measuring clock cycles: first runs (cycles): 1518 807 771 837 768 774 777 762 777 774 ... slowest runs (cycles): ... 795 807 834 837 837 837 867 870 870 1518 min: 762 cycles q1: 771 cycles median: 774 cycles q3: 777 cycles max: 1518 cycles RESULT TestClockGetTime_CycleCount: x86-64_nnacl_newlib_static= {774, 6} count Apparent clock speed: 3071 MHz TestTlsVariable: Measuring real time: 0.014 usec (1.409e-08 sec) per iteration: 1.409e-06 sec for 100 iterations 0.008 usec (8.037e-09 sec) per iteration: 8.037e-06 sec for 1000 iterations 0.008 usec (7.6027e-09 sec) per iteration: 7.6027e-05 sec for 10000 iterations 0.004 usec (4.39595e-09 sec) per iteration: 0.0578209 sec for 13153221 iterations 0.004 usec (4.36639e-09 sec) per iteration: 0.0574321 sec for 13153221 iterations 0.004 usec (4.39672e-09 sec) per iteration: 0.0578311 sec for 13153221 iterations 0.004 usec (4.37388e-09 sec) per iteration: 0.0575306 sec for 13153221 iterations 0.004 usec (4.3598e-09 sec) per iteration: 0.0573455 sec for 13153221 iterations mean: 0.004379 usec stddev: 0.000015 usec relative stddev: 0.35% RESULT TestTlsVariable: x86-64_nnacl_newlib_static= {0.004379, 0.000015} us Measuring clock cycles: first runs (cycles): 207 60 21 21 27 18 18 27 27 18 ... slowest runs (cycles): ... 27 27 27 27 27 27 27 27 60 207 min: 18 cycles q1: 18 cycles median: 18 cycles q3: 27 cycles max: 207 cycles RESULT TestTlsVariable_CycleCount: x86-64_nnacl_newlib_static= {18, 9} count Apparent clock speed: 4111 MHz TestMmapAnonymous: Measuring real time: 6.329 usec (6.3289e-06 sec) per iteration: 0.00063289 sec for 100 iterations 5.100 usec (5.10041e-06 sec) per iteration: 0.0805865 sec for 15800 iterations 5.155 usec (5.1549e-06 sec) per iteration: 0.0814473 sec for 15800 iterations 5.134 usec (5.13445e-06 sec) per iteration: 0.0811243 sec for 15800 iterations 5.128 usec (5.12763e-06 sec) per iteration: 0.0810166 sec for 15800 iterations 5.118 usec (5.11752e-06 sec) per iteration: 0.0808567 sec for 15800 iterations mean: 5.126982 usec stddev: 0.018061 usec relative stddev: 0.35% RESULT TestMmapAnonymous: x86-64_nnacl_newlib_static= {5.126982, 0.018061} us Measuring clock cycles: first runs (cycles): 21483 16224 15669 15462 15717 15480 15522 15504 15663 24378 ... slowest runs (cycles): ... 22710 24006 24378 24720 24990 24999 25014 25227 25305 41223 min: 14937 cycles q1: 15033 cycles median: 15132 cycles q3: 15591 cycles max: 41223 cycles RESULT TestMmapAnonymous_CycleCount: x86-64_nnacl_newlib_static= {15132, 558} count Apparent clock speed: 2951 MHz TestAtomicIncrement: Measuring real time: 0.017 usec (1.709e-08 sec) per iteration: 1.709e-06 sec for 100 iterations 0.009 usec (9.24e-09 sec) per iteration: 9.24e-06 sec for 1000 iterations 0.009 usec (9.0991e-09 sec) per iteration: 9.0991e-05 sec for 10000 iterations 0.008 usec (7.57059e-09 sec) per iteration: 0.0832015 sec for 10990097 iterations 0.008 usec (7.54164e-09 sec) per iteration: 0.0828833 sec for 10990097 iterations 0.008 usec (7.54951e-09 sec) per iteration: 0.0829699 sec for 10990097 iterations 0.008 usec (7.58886e-09 sec) per iteration: 0.0834023 sec for 10990097 iterations 0.008 usec (7.58629e-09 sec) per iteration: 0.083374 sec for 10990097 iterations mean: 0.007567 usec stddev: 0.000019 usec relative stddev: 0.25% RESULT TestAtomicIncrement: x86-64_nnacl_newlib_static= {0.007567, 0.000019} us Measuring clock cycles: first runs (cycles): 159 48 48 48 48 39 39 48 48 48 ... slowest runs (cycles): ... 48 48 48 48 48 48 48 48 48 159 min: 39 cycles q1: 48 cycles median: 48 cycles q3: 48 cycles max: 159 cycles RESULT TestAtomicIncrement_CycleCount: x86-64_nnacl_newlib_static= {48, 0} count Apparent clock speed: 6343 MHz TestUncontendedMutexLock: Measuring real time: 0.024 usec (2.379e-08 sec) per iteration: 2.379e-06 sec for 100 iterations 0.021 usec (2.1255e-08 sec) per iteration: 2.1255e-05 sec for 1000 iterations 0.019 usec (1.89307e-08 sec) per iteration: 0.0890647 sec for 4704775 iterations 0.019 usec (1.89158e-08 sec) per iteration: 0.0889947 sec for 4704775 iterations 0.019 usec (1.88612e-08 sec) per iteration: 0.0887375 sec for 4704775 iterations 0.019 usec (1.88561e-08 sec) per iteration: 0.0887137 sec for 4704775 iterations 0.019 usec (1.88826e-08 sec) per iteration: 0.0888385 sec for 4704775 iterations mean: 0.018889 usec stddev: 0.000030 usec relative stddev: 0.16% RESULT TestUncontendedMutexLock: x86-64_nnacl_newlib_static= {0.018889, 0.000030} us Measuring clock cycles: first runs (cycles): 330 108 75 78 75 87 75 78 84 78 ... slowest runs (cycles): ... 87 87 87 87 87 87 87 87 108 330 min: 75 cycles q1: 75 cycles median: 78 cycles q3: 84 cycles max: 330 cycles RESULT TestUncontendedMutexLock_CycleCount: x86-64_nnacl_newlib_static= {78, 9} count Apparent clock speed: 4129 MHz TestCondvarSignalNoOp: Measuring real time: 0.396 usec (3.9595e-07 sec) per iteration: 3.9595e-05 sec for 100 iterations 0.202 usec (2.02405e-07 sec) per iteration: 0.0511187 sec for 252557 iterations 0.202 usec (2.02312e-07 sec) per iteration: 0.0510952 sec for 252557 iterations 0.201 usec (2.00614e-07 sec) per iteration: 0.0506664 sec for 252557 iterations 0.203 usec (2.02822e-07 sec) per iteration: 0.0512241 sec for 252557 iterations 0.204 usec (2.03715e-07 sec) per iteration: 0.0514497 sec for 252557 iterations mean: 0.202373 usec stddev: 0.001010 usec relative stddev: 0.50% RESULT TestCondvarSignalNoOp: x86-64_nnacl_newlib_static= {0.202373, 0.001010} us Measuring clock cycles: first runs (cycles): 1041 705 672 687 633 621 615 627 612 615 ... slowest runs (cycles): ... 633 633 669 672 681 684 687 693 705 1041 min: 606 cycles q1: 612 cycles median: 618 cycles q3: 624 cycles max: 1041 cycles RESULT TestCondvarSignalNoOp_CycleCount: x86-64_nnacl_newlib_static= {618, 12} count Apparent clock speed: 3054 MHz TestThreadCreateAndJoin: Measuring real time: 71.766 usec (7.1766e-05 sec) per iteration: 0.0071766 sec for 100 iterations 45.224 usec (4.52243e-05 sec) per iteration: 0.0629975 sec for 1393 iterations 44.842 usec (4.48419e-05 sec) per iteration: 0.0624647 sec for 1393 iterations 45.342 usec (4.53421e-05 sec) per iteration: 0.0631615 sec for 1393 iterations 45.314 usec (4.53137e-05 sec) per iteration: 0.063122 sec for 1393 iterations 44.827 usec (4.48272e-05 sec) per iteration: 0.0624442 sec for 1393 iterations mean: 45.109832 usec stddev: 0.228179 usec relative stddev: 0.51% RESULT TestThreadCreateAndJoin: x86-64_nnacl_newlib_static= {45.109832, 0.228179} us Measuring clock cycles: first runs (cycles): 174255 246288 203784 215316 153825 141192 135159 138936 139548 130902 ... slowest runs (cycles): ... 153825 166626 174255 177219 186534 188955 195414 203784 215316 246288 min: 127524 cycles q1: 129465 cycles median: 134265 cycles q3: 136092 cycles max: 246288 cycles RESULT TestThreadCreateAndJoin_CycleCount: x86-64_nnacl_newlib_static= {134265, 6627} count Apparent clock speed: 2976 MHz TestThreadWakeup: Measuring real time: 12.026 usec (1.20256e-05 sec) per iteration: 0.00120256 sec for 100 iterations 9.632 usec (9.63238e-06 sec) per iteration: 0.0800932 sec for 8315 iterations 9.579 usec (9.57851e-06 sec) per iteration: 0.0796453 sec for 8315 iterations 9.363 usec (9.36324e-06 sec) per iteration: 0.0778554 sec for 8315 iterations 9.414 usec (9.4141e-06 sec) per iteration: 0.0782782 sec for 8315 iterations 9.374 usec (9.37385e-06 sec) per iteration: 0.0779436 sec for 8315 iterations mean: 9.472415 usec stddev: 0.111246 usec relative stddev: 1.17% RESULT TestThreadWakeup: x86-64_nnacl_newlib_static= {9.472415, 0.111246} us Measuring clock cycles: first runs (cycles): 113103 241449 33396 30468 29235 56145 39897 162378 70278 37449 ... slowest runs (cycles): ... 30468 33396 37449 39897 53922 56145 70278 113103 162378 241449 min: 27564 cycles q1: 27819 cycles median: 27951 cycles q3: 28143 cycles max: 241449 cycles RESULT TestThreadWakeup_CycleCount: x86-64_nnacl_newlib_static= {27951, 324} count Apparent clock speed: 2951 MHz TestCatchingFault: Measuring real time: 16.145 usec (1.61446e-05 sec) per iteration: 0.00161446 sec for 100 iterations 13.921 usec (1.39206e-05 sec) per iteration: 0.086224 sec for 6194 iterations 13.925 usec (1.39251e-05 sec) per iteration: 0.086252 sec for 6194 iterations 13.918 usec (1.39179e-05 sec) per iteration: 0.0862075 sec for 6194 iterations 13.934 usec (1.39336e-05 sec) per iteration: 0.0863046 sec for 6194 iterations 13.878 usec (1.38776e-05 sec) per iteration: 0.085958 sec for 6194 iterations mean: 13.914955 usec stddev: 0.019407 usec relative stddev: 0.14% RESULT TestCatchingFault: x86-64_nnacl_newlib_static= {13.914955, 0.019407} us Measuring clock cycles: first runs (cycles): 50493 45255 100338 139263 125868 98037 50235 44763 55800 52614 ... slowest runs (cycles): ... 48297 50235 50493 52614 52614 55800 98037 100338 125868 139263 min: 40980 cycles q1: 41352 cycles median: 41502 cycles q3: 41682 cycles max: 139263 cycles RESULT TestCatchingFault_CycleCount: x86-64_nnacl_newlib_static= {41502, 330} count Apparent clock speed: 2983 MHz TestThreadCreateAndJoinAfterSettingFaultHandler: Measuring real time: 47.329 usec (4.73291e-05 sec) per iteration: 0.00473291 sec for 100 iterations 44.986 usec (4.4986e-05 sec) per iteration: 0.0950104 sec for 2112 iterations 44.855 usec (4.4855e-05 sec) per iteration: 0.0947338 sec for 2112 iterations 44.894 usec (4.48941e-05 sec) per iteration: 0.0948163 sec for 2112 iterations 45.732 usec (4.57324e-05 sec) per iteration: 0.0965869 sec for 2112 iterations 44.923 usec (4.4923e-05 sec) per iteration: 0.0948775 sec for 2112 iterations mean: 45.078121 usec stddev: 0.329932 usec relative stddev: 0.73% RESULT TestThreadCreateAndJoinAfterSettingFaultHandler: x86-64_nnacl_newlib_static= {45.078121, 0.329932} us Measuring clock cycles: first runs (cycles): 184023 323328 183507 186825 210099 137274 141177 132315 162966 130779 ... slowest runs (cycles): ... 148263 150066 162966 183507 184023 186189 186825 210099 292491 323328 min: 127125 cycles q1: 128787 cycles median: 133509 cycles q3: 135489 cycles max: 323328 cycles RESULT TestThreadCreateAndJoinAfterSettingFaultHandler_CycleCount: x86-64_nnacl_newlib_static= {133509, 6702} count Apparent clock speed: 2962 MHz [ OK ] nacl_newlib.run_performance_test (5660 ms) /b/s/w/ir/cache/vpython/7c7ecd/bin/python /b/s/w/ir/k/native_client/tools/command_tester.py --name nacl_newlib.run_nacl_clock_cputime_test --time_warning 60 --time_error 600 --perf_env_description trusted_mac_x86-64 --subarch 64 --arch x86 --output_stamp /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/test_results/nacl_clock_cputime_test.out /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/src/shared/platform/nacl_clock_test -c [ RUN ] nacl_newlib.run_nacl_clock_cputime_test /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/src/shared/platform/nacl_clock_test -c [ OK ] nacl_newlib.run_nacl_clock_cputime_test (11250 ms) /b/s/w/ir/cache/vpython/7c7ecd/bin/python /b/s/w/ir/k/native_client/tools/command_tester.py --name nacl_newlib.run_nacl_interval_multi_reg_test --time_warning 60 --time_error 600 --perf_env_description trusted_mac_x86-64 --subarch 64 --arch x86 --output_stamp /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/test_results/nacl_interval_multi_reg_test.out /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/src/trusted/interval_multiset/nacl_interval_test -k NaClIntervalListMultiset -k NaClIntervalRangeTree -c 1000000 [ RUN ] nacl_newlib.run_nacl_interval_multi_reg_test /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/src/trusted/interval_multiset/nacl_interval_test -k NaClIntervalListMultiset -k NaClIntervalRangeTree -c 1000000 [ OK ] nacl_newlib.run_nacl_interval_multi_reg_test (1030 ms) /b/s/w/ir/cache/vpython/7c7ecd/bin/python /b/s/w/ir/k/native_client/tools/command_tester.py --name nacl_newlib.run_trusted_performance_test --time_warning 2 --time_error 20 --perf_env_description trusted_mac_x86-64 --subarch 64 --arch x86 --capture_output 0 --output_stamp /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/test_results/performance_test.out /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/tests/performance/performance_test trusted_mac_x86-64 [ RUN ] nacl_newlib.run_trusted_performance_test /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/tests/performance/performance_test trusted_mac_x86-64 TestNull: Measuring real time: 0.020 usec (2e-08 sec) per iteration: 2e-06 sec for 100 iterations 0.003 usec (3e-09 sec) per iteration: 3e-06 sec for 1000 iterations 0.002 usec (2.2e-09 sec) per iteration: 2.2e-05 sec for 10000 iterations 0.002 usec (2.1991e-09 sec) per iteration: 0.099959 sec for 45454545 iterations 0.002 usec (2.18431e-09 sec) per iteration: 0.099287 sec for 45454545 iterations 0.002 usec (2.22638e-09 sec) per iteration: 0.101199 sec for 45454545 iterations 0.002 usec (2.2106e-09 sec) per iteration: 0.100482 sec for 45454545 iterations 0.002 usec (2.19802e-09 sec) per iteration: 0.09991 sec for 45454545 iterations mean: 0.002204 usec stddev: 0.000014 usec relative stddev: 0.64% RESULT TestNull: trusted_mac_x86-64= {0.002204, 0.000014} us Measuring clock cycles: first runs (cycles): 183 18 27 18 18 18 27 18 18 27 ... slowest runs (cycles): ... 27 27 27 27 27 27 27 27 27 183 min: 18 cycles q1: 18 cycles median: 18 cycles q3: 27 cycles max: 183 cycles RESULT TestNull_CycleCount: trusted_mac_x86-64= {18, 9} count Apparent clock speed: 8168 MHz TestHostSyscall: Measuring real time: 0.760 usec (7.6e-07 sec) per iteration: 7.6e-05 sec for 100 iterations 0.505 usec (5.05419e-07 sec) per iteration: 0.066502 sec for 131578 iterations 0.499 usec (4.9908e-07 sec) per iteration: 0.065668 sec for 131578 iterations 0.509 usec (5.08877e-07 sec) per iteration: 0.066957 sec for 131578 iterations 0.503 usec (5.02766e-07 sec) per iteration: 0.066153 sec for 131578 iterations 0.494 usec (4.93555e-07 sec) per iteration: 0.064941 sec for 131578 iterations mean: 0.501940 usec stddev: 0.005280 usec relative stddev: 1.05% RESULT TestHostSyscall: trusted_mac_x86-64= {0.501940, 0.005280} us Measuring clock cycles: first runs (cycles): 1788 1614 1524 1527 1521 1518 1518 1527 1524 1521 ... slowest runs (cycles): ... 1539 1539 1539 1539 1539 1539 1539 1539 1614 1788 min: 1512 cycles q1: 1518 cycles median: 1527 cycles q3: 1536 cycles max: 1788 cycles RESULT TestHostSyscall_CycleCount: trusted_mac_x86-64= {1527, 18} count Apparent clock speed: 3042 MHz TestSetjmpLongjmp: Measuring real time: 3.210 usec (3.21e-06 sec) per iteration: 0.000321 sec for 100 iterations 2.356 usec (2.35564e-06 sec) per iteration: 0.073383 sec for 31152 iterations 2.352 usec (2.35173e-06 sec) per iteration: 0.073261 sec for 31152 iterations 2.372 usec (2.3715e-06 sec) per iteration: 0.073877 sec for 31152 iterations 2.332 usec (2.33218e-06 sec) per iteration: 0.072652 sec for 31152 iterations 2.357 usec (2.35677e-06 sec) per iteration: 0.073418 sec for 31152 iterations mean: 2.353563 usec stddev: 0.012626 usec relative stddev: 0.54% RESULT TestSetjmpLongjmp: trusted_mac_x86-64= {2.353563, 0.012626} us Measuring clock cycles: first runs (cycles): 7428 7194 7119 7146 7134 7113 7110 7137 7137 7107 ... slowest runs (cycles): ... 9450 9486 9570 9630 9666 9672 9744 9837 9891 33636 min: 6942 cycles q1: 7134 cycles median: 7149 cycles q3: 8748 cycles max: 33636 cycles RESULT TestSetjmpLongjmp_CycleCount: trusted_mac_x86-64= {7149, 1614} count Apparent clock speed: 3038 MHz TestClockGetTime: Measuring real time: 0.070 usec (7e-08 sec) per iteration: 7e-06 sec for 100 iterations 0.077 usec (7.7e-08 sec) per iteration: 7.7e-05 sec for 1000 iterations 0.066 usec (6.64472e-08 sec) per iteration: 0.086295 sec for 1298701 iterations 0.067 usec (6.66997e-08 sec) per iteration: 0.086623 sec for 1298701 iterations 0.066 usec (6.5614e-08 sec) per iteration: 0.085213 sec for 1298701 iterations 0.063 usec (6.34095e-08 sec) per iteration: 0.08235 sec for 1298701 iterations 0.065 usec (6.49472e-08 sec) per iteration: 0.084347 sec for 1298701 iterations mean: 0.065424 usec stddev: 0.001183 usec relative stddev: 1.81% RESULT TestClockGetTime: trusted_mac_x86-64= {0.065424, 0.001183} us Measuring clock cycles: first runs (cycles): 1353 222 201 198 201 210 210 225 210 201 ... slowest runs (cycles): ... 210 210 210 210 210 210 210 222 225 1353 min: 198 cycles q1: 201 cycles median: 201 cycles q3: 210 cycles max: 1353 cycles RESULT TestClockGetTime_CycleCount: trusted_mac_x86-64= {201, 9} count Apparent clock speed: 3072 MHz TestMmapAnonymous: Measuring real time: 2.420 usec (2.42e-06 sec) per iteration: 0.000242 sec for 100 iterations 1.636 usec (1.63584e-06 sec) per iteration: 0.067596 sec for 41322 iterations 1.641 usec (1.64077e-06 sec) per iteration: 0.0678 sec for 41322 iterations 1.621 usec (1.621e-06 sec) per iteration: 0.066983 sec for 41322 iterations 1.632 usec (1.63175e-06 sec) per iteration: 0.067427 sec for 41322 iterations 1.661 usec (1.66069e-06 sec) per iteration: 0.068623 sec for 41322 iterations mean: 1.638009 usec stddev: 0.013079 usec relative stddev: 0.80% RESULT TestMmapAnonymous: trusted_mac_x86-64= {1.638009, 0.013079} us Measuring clock cycles: first runs (cycles): 5472 4869 4824 4815 4824 4836 4827 4887 4947 4842 ... slowest runs (cycles): ... 6972 7047 7083 7140 7332 7365 7374 7401 7416 7635 min: 4812 cycles q1: 4839 cycles median: 4854 cycles q3: 6111 cycles max: 7635 cycles RESULT TestMmapAnonymous_CycleCount: trusted_mac_x86-64= {4854, 1272} count Apparent clock speed: 2963 MHz TestAtomicIncrement: Measuring real time: 0.010 usec (1e-08 sec) per iteration: 1e-06 sec for 100 iterations 0.008 usec (8e-09 sec) per iteration: 8e-06 sec for 1000 iterations 0.008 usec (8.1e-09 sec) per iteration: 8.1e-05 sec for 10000 iterations 0.008 usec (7.55843e-09 sec) per iteration: 0.093314 sec for 12345679 iterations 0.008 usec (7.53802e-09 sec) per iteration: 0.093062 sec for 12345679 iterations 0.008 usec (7.52109e-09 sec) per iteration: 0.092853 sec for 12345679 iterations 0.008 usec (7.562e-09 sec) per iteration: 0.093358 sec for 12345679 iterations 0.008 usec (7.61432e-09 sec) per iteration: 0.094004 sec for 12345679 iterations mean: 0.007559 usec stddev: 0.000031 usec relative stddev: 0.42% RESULT TestAtomicIncrement: trusted_mac_x86-64= {0.007559, 0.000031} us Measuring clock cycles: first runs (cycles): 168 42 54 54 51 51 45 54 54 51 ... slowest runs (cycles): ... 54 54 54 54 54 54 54 57 60 168 min: 42 cycles q1: 51 cycles median: 51 cycles q3: 54 cycles max: 168 cycles RESULT TestAtomicIncrement_CycleCount: trusted_mac_x86-64= {51, 3} count Apparent clock speed: 6747 MHz TestUncontendedMutexLock: Measuring real time: 0.220 usec (2.2e-07 sec) per iteration: 2.2e-05 sec for 100 iterations 0.022 usec (2.23894e-08 sec) per iteration: 0.010177 sec for 454545 iterations 0.022 usec (2.24708e-08 sec) per iteration: 0.010214 sec for 454545 iterations 0.022 usec (2.1989e-08 sec) per iteration: 0.009995 sec for 454545 iterations 0.023 usec (2.25346e-08 sec) per iteration: 0.010243 sec for 454545 iterations 0.022 usec (2.20792e-08 sec) per iteration: 0.010036 sec for 454545 iterations mean: 0.022293 usec stddev: 0.000218 usec relative stddev: 0.98% RESULT TestUncontendedMutexLock: trusted_mac_x86-64= {0.022293, 0.000218} us Measuring clock cycles: first runs (cycles): 285 105 99 102 99 102 99 102 102 90 ... slowest runs (cycles): ... 99 99 99 99 102 102 102 102 105 285 min: 84 cycles q1: 87 cycles median: 93 cycles q3: 96 cycles max: 285 cycles RESULT TestUncontendedMutexLock_CycleCount: trusted_mac_x86-64= {93, 9} count Apparent clock speed: 4172 MHz TestCondvarSignalNoOp: Measuring real time: 0.120 usec (1.2e-07 sec) per iteration: 1.2e-05 sec for 100 iterations 0.013 usec (1.25796e-08 sec) per iteration: 0.010483 sec for 833333 iterations 0.013 usec (1.26048e-08 sec) per iteration: 0.010504 sec for 833333 iterations 0.013 usec (1.25652e-08 sec) per iteration: 0.010471 sec for 833333 iterations 0.013 usec (1.25052e-08 sec) per iteration: 0.010421 sec for 833333 iterations 0.013 usec (1.25328e-08 sec) per iteration: 0.010444 sec for 833333 iterations mean: 0.012558 usec stddev: 0.000035 usec relative stddev: 0.28% RESULT TestCondvarSignalNoOp: trusted_mac_x86-64= {0.012558, 0.000035} us Measuring clock cycles: first runs (cycles): 270 75 63 63 63 63 60 66 60 63 ... slowest runs (cycles): ... 66 66 69 72 72 72 72 75 81 270 min: 60 cycles q1: 63 cycles median: 63 cycles q3: 63 cycles max: 270 cycles RESULT TestCondvarSignalNoOp_CycleCount: trusted_mac_x86-64= {63, 0} count Apparent clock speed: 5017 MHz TestThreadCreateAndJoin: Measuring real time: 36.110 usec (3.611e-05 sec) per iteration: 0.003611 sec for 100 iterations 17.987 usec (1.79874e-05 sec) per iteration: 0.049807 sec for 2769 iterations 17.741 usec (1.77411e-05 sec) per iteration: 0.049125 sec for 2769 iterations 18.067 usec (1.80668e-05 sec) per iteration: 0.050027 sec for 2769 iterations 17.979 usec (1.79794e-05 sec) per iteration: 0.049785 sec for 2769 iterations 18.304 usec (1.83044e-05 sec) per iteration: 0.050685 sec for 2769 iterations mean: 18.015818 usec stddev: 0.180848 usec relative stddev: 1.00% RESULT TestThreadCreateAndJoin: trusted_mac_x86-64= {18.015818, 0.180848} us Measuring clock cycles: first runs (cycles): 72900 94464 78405 134610 107241 151029 93099 172314 89031 152640 ... slowest runs (cycles): ... 72900 78405 89031 93099 94464 107241 134610 151029 152640 172314 min: 52656 cycles q1: 53124 cycles median: 53298 cycles q3: 53535 cycles max: 172314 cycles RESULT TestThreadCreateAndJoin_CycleCount: trusted_mac_x86-64= {53298, 411} count Apparent clock speed: 2958 MHz TestThreadWakeup: Measuring real time: 9.330 usec (9.33e-06 sec) per iteration: 0.000933 sec for 100 iterations 6.928 usec (6.92825e-06 sec) per iteration: 0.074257 sec for 10718 iterations 7.474 usec (7.47397e-06 sec) per iteration: 0.080106 sec for 10718 iterations 9.123 usec (9.12269e-06 sec) per iteration: 0.097777 sec for 10718 iterations 9.079 usec (9.07921e-06 sec) per iteration: 0.097311 sec for 10718 iterations 9.119 usec (9.11877e-06 sec) per iteration: 0.097735 sec for 10718 iterations mean: 8.344579 usec stddev: 0.949575 usec relative stddev: 11.38% RESULT TestThreadWakeup: trusted_mac_x86-64= {8.344579, 0.949575} us Measuring clock cycles: first runs (cycles): 26478 25791 25920 24981 25920 34293 28620 51777 70797 35943 ... slowest runs (cycles): ... 41106 51777 57066 58923 58974 70152 70797 76932 89364 107457 min: 19743 cycles q1: 23973 cycles median: 25170 cycles q3: 28389 cycles max: 107457 cycles RESULT TestThreadWakeup_CycleCount: trusted_mac_x86-64= {25170, 4416} count Apparent clock speed: 3016 MHz WARNING: should have taken less than 2.000000 secs [ OK ] nacl_newlib.run_trusted_performance_test (3330 ms) scons: done building targets. ********************************************************************** COMMAND EXECUTION REPORT ********************************************************************** 6 command_tester.py 1 doSizeCheck ********************************************************************** ENVIRONMENT USAGE REPORT ********************************************************************** 3 dbg-mac-x86-64 4 nacl-x86-64 Command return code: 0