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,opt-host platform=x86-64 --clang large_tests scons: Reading SConscript files ... ====================================================================== SCONS ARGS:['scons.py', '--verbose', '-k', '-j1', '--mode=nacl,opt-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.5.0 kern.osrevision: 199506 kern.version: Darwin Kernel Version 17.5.0: Mon Mar 5 22:24:32 PST 2018; root:xnu-4570.51.1~1/RELEASE_X86_64 kern.posix1version: 200112 kern.osversion: 17E199 kern.osproductversion: 10.13.4 ====================================================================== CPU: ====================================================================== hw.machine: x86_64 hw.model: VMware7,1 hw.ncpu: 8 hw.ncpu: 8 hw.activecpu: 8 hw.physicalcpu: 8 hw.physicalcpu_max: 8 hw.logicalcpu: 8 hw.logicalcpu_max: 8 hw.cputype: 7 hw.cpusubtype: 4 hw.cpu64bit_capable: 1 hw.cpufamily: 526772277 hw.cpufrequency: 2574000000 hw.cpufrequency_min: 2574000000 hw.cpufrequency_max: 2574000000 ====================================================================== RAM: ====================================================================== hw.memsize: 17179869184 ====================================================================== LOAD: ====================================================================== TBD ====================================================================== UPTIME: ====================================================================== kern.boottime: { sec = 1552669774, usec = 152375 } Fri Mar 15 10:09:34 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: opt-mac TARGET_ROOT: /b/s/w/ir/k/native_client/scons-out/opt-mac-x86-64 OBJ_ROOT: /b/s/w/ir/k/native_client/scons-out/opt-mac-x86-64/obj BUILD_TYPE_DESCRIPTION: MacOS opt 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 -DNDEBUG -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/opt-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/opt-mac-x86-64/staging/sel_ldr -- scons-out/nacl-x86-64/obj/tests/benchmark/benchmark_test.nexe x86-64_nnacl_newlib_static [24066,3051619200:13:07:14.279407] Native Client module will be loaded at base address 0x0000550a00000000 Running suite of 1 benchmarks: Running Benchmark: Life (SIMD version)... RESULT BenchmarkLife: x86-64_nnacl_newlib_static= {0.066980, 0.003300} seconds --------------------------------------------------------------- Done running benchmark suite. [ OK ] nacl_newlib.run_benchmark_test (870 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/opt-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/opt-mac-x86-64/staging/sel_ldr -- scons-out/nacl-x86-64/obj/tests/clock/clock_test.nexe -c WARNING: should have taken less than 60.000000 secs [ OK ] nacl_newlib.run_clock_cputime_test (66610 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/opt-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/opt-mac-x86-64/staging/sel_ldr -e -- scons-out/nacl-x86-64/obj/tests/performance/performance_test.nexe x86-64_nnacl_newlib_static [24074,3051619200:13:07:28.614539] Native Client module will be loaded at base address 0x0000670a00000000 TestNull: Measuring real time: 0.006 usec (6.46e-09 sec) per iteration: 6.46e-07 sec for 100 iterations 0.002 usec (2.27e-09 sec) per iteration: 2.27e-06 sec for 1000 iterations 0.002 usec (2.025e-09 sec) per iteration: 2.025e-05 sec for 10000 iterations 0.002 usec (2.01061e-09 sec) per iteration: 0.0992894 sec for 49382716 iterations 0.002 usec (2.00664e-09 sec) per iteration: 0.0990935 sec for 49382716 iterations 0.002 usec (2.01581e-09 sec) per iteration: 0.0995463 sec for 49382716 iterations 0.002 usec (2.00479e-09 sec) per iteration: 0.0990018 sec for 49382716 iterations 0.002 usec (1.99636e-09 sec) per iteration: 0.0985857 sec for 49382716 iterations mean: 0.002007 usec stddev: 0.000006 usec relative stddev: 0.32% RESULT TestNull: x86-64_nnacl_newlib_static= {0.002007, 0.000006} us Measuring clock cycles: first runs (cycles): 195 21 21 21 18 30 27 30 27 21 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 30 30 195 min: 18 cycles q1: 18 cycles median: 21 cycles q3: 27 cycles max: 195 cycles RESULT TestNull_CycleCount: x86-64_nnacl_newlib_static= {21, 9} count Apparent clock speed: 10464 MHz TestNaClSyscall: Measuring real time: 0.157 usec (1.5709e-07 sec) per iteration: 1.5709e-05 sec for 100 iterations 0.156 usec (1.55756e-07 sec) per iteration: 0.0991508 sec for 636577 iterations 0.157 usec (1.5682e-07 sec) per iteration: 0.0998281 sec for 636577 iterations 0.157 usec (1.57081e-07 sec) per iteration: 0.0999942 sec for 636577 iterations 0.156 usec (1.56402e-07 sec) per iteration: 0.0995622 sec for 636577 iterations 0.156 usec (1.56148e-07 sec) per iteration: 0.0994004 sec for 636577 iterations mean: 0.156442 usec stddev: 0.000471 usec relative stddev: 0.30% RESULT TestNaClSyscall: x86-64_nnacl_newlib_static= {0.156442, 0.000471} us Measuring clock cycles: first runs (cycles): 687 312 300 300 297 291 288 291 288 291 ... slowest runs (cycles): ... 300 300 300 300 300 300 300 300 312 687 min: 288 cycles q1: 288 cycles median: 291 cycles q3: 297 cycles max: 687 cycles RESULT TestNaClSyscall_CycleCount: x86-64_nnacl_newlib_static= {291, 9} count Apparent clock speed: 1860 MHz TestSetjmpLongjmp: Measuring real time: 0.016 usec (1.62e-08 sec) per iteration: 1.62e-06 sec for 100 iterations 0.012 usec (1.2398e-08 sec) per iteration: 1.2398e-05 sec for 1000 iterations 0.012 usec (1.20843e-08 sec) per iteration: 0.0974695 sec for 8065817 iterations 0.012 usec (1.20957e-08 sec) per iteration: 0.0975617 sec for 8065817 iterations 0.012 usec (1.21315e-08 sec) per iteration: 0.0978502 sec for 8065817 iterations 0.012 usec (1.19868e-08 sec) per iteration: 0.0966835 sec for 8065817 iterations 0.012 usec (1.20201e-08 sec) per iteration: 0.0969519 sec for 8065817 iterations mean: 0.012064 usec stddev: 0.000053 usec relative stddev: 0.44% RESULT TestSetjmpLongjmp: x86-64_nnacl_newlib_static= {0.012064, 0.000053} us Measuring clock cycles: first runs (cycles): 354 24 24 24 42 24 39 24 39 24 ... slowest runs (cycles): ... 39 39 39 39 39 39 39 39 42 354 min: 21 cycles q1: 24 cycles median: 24 cycles q3: 39 cycles max: 354 cycles RESULT TestSetjmpLongjmp_CycleCount: x86-64_nnacl_newlib_static= {24, 15} count Apparent clock speed: 1989 MHz TestClockGetTime: Measuring real time: 0.178 usec (1.7818e-07 sec) per iteration: 1.7818e-05 sec for 100 iterations 0.176 usec (1.76466e-07 sec) per iteration: 0.0990383 sec for 561230 iterations 0.179 usec (1.79193e-07 sec) per iteration: 0.100569 sec for 561230 iterations 0.179 usec (1.78858e-07 sec) per iteration: 0.100381 sec for 561230 iterations 0.181 usec (1.81421e-07 sec) per iteration: 0.101819 sec for 561230 iterations 0.179 usec (1.78602e-07 sec) per iteration: 0.100237 sec for 561230 iterations mean: 0.178908 usec stddev: 0.001578 usec relative stddev: 0.88% RESULT TestClockGetTime: x86-64_nnacl_newlib_static= {0.178908, 0.001578} us Measuring clock cycles: first runs (cycles): 1722 465 438 441 435 447 438 435 438 435 ... slowest runs (cycles): ... 447 447 447 447 447 447 447 453 465 1722 min: 435 cycles q1: 435 cycles median: 438 cycles q3: 438 cycles max: 1722 cycles RESULT TestClockGetTime_CycleCount: x86-64_nnacl_newlib_static= {438, 3} count Apparent clock speed: 2448 MHz TestTlsVariable: Measuring real time: 0.010 usec (9.53e-09 sec) per iteration: 9.53e-07 sec for 100 iterations 0.006 usec (6.274e-09 sec) per iteration: 6.274e-06 sec for 1000 iterations 0.006 usec (6.4244e-09 sec) per iteration: 6.4244e-05 sec for 10000 iterations 0.006 usec (6.10084e-09 sec) per iteration: 0.0949635 sec for 15565655 iterations 0.009 usec (9.27591e-09 sec) per iteration: 0.144386 sec for 15565655 iterations 0.006 usec (6.08223e-09 sec) per iteration: 0.0946739 sec for 15565655 iterations 0.006 usec (6.1509e-09 sec) per iteration: 0.0957428 sec for 15565655 iterations 0.006 usec (6.06086e-09 sec) per iteration: 0.0943413 sec for 15565655 iterations mean: 0.006734 usec stddev: 0.001271 usec relative stddev: 18.88% RESULT TestTlsVariable: x86-64_nnacl_newlib_static= {0.006734, 0.001271} us Measuring clock cycles: first runs (cycles): 321 66 21 21 21 21 18 21 27 30 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 30 66 321 min: 18 cycles q1: 18 cycles median: 21 cycles q3: 27 cycles max: 321 cycles RESULT TestTlsVariable_CycleCount: x86-64_nnacl_newlib_static= {21, 9} count Apparent clock speed: 3118 MHz TestMmapAnonymous: Measuring real time: 8.775 usec (8.77507e-06 sec) per iteration: 0.000877507 sec for 100 iterations 10.011 usec (1.00106e-05 sec) per iteration: 0.114071 sec for 11395 iterations 8.716 usec (8.7165e-06 sec) per iteration: 0.0993245 sec for 11395 iterations 9.084 usec (9.08439e-06 sec) per iteration: 0.103517 sec for 11395 iterations 8.740 usec (8.74041e-06 sec) per iteration: 0.099597 sec for 11395 iterations 8.780 usec (8.78049e-06 sec) per iteration: 0.100054 sec for 11395 iterations mean: 9.066482 usec stddev: 0.490367 usec relative stddev: 5.41% RESULT TestMmapAnonymous: x86-64_nnacl_newlib_static= {9.066482, 0.490367} us Measuring clock cycles: first runs (cycles): 32910 25029 24075 23526 23487 23262 23679 23415 23814 23631 ... slowest runs (cycles): ... 23718 23724 23742 23742 23754 23814 23823 24075 25029 32910 min: 23124 cycles q1: 23274 cycles median: 23436 cycles q3: 23583 cycles max: 32910 cycles RESULT TestMmapAnonymous_CycleCount: x86-64_nnacl_newlib_static= {23436, 309} count Apparent clock speed: 2585 MHz TestAtomicIncrement: Measuring real time: 0.014 usec (1.42e-08 sec) per iteration: 1.42e-06 sec for 100 iterations 0.010 usec (9.905e-09 sec) per iteration: 9.905e-06 sec for 1000 iterations 0.010 usec (9.6903e-09 sec) per iteration: 9.6903e-05 sec for 10000 iterations 0.010 usec (9.65998e-09 sec) per iteration: 0.0996871 sec for 10319597 iterations 0.010 usec (9.67731e-09 sec) per iteration: 0.099866 sec for 10319597 iterations 0.010 usec (9.68609e-09 sec) per iteration: 0.0999565 sec for 10319597 iterations 0.010 usec (9.67839e-09 sec) per iteration: 0.0998771 sec for 10319597 iterations 0.010 usec (1.00823e-08 sec) per iteration: 0.104045 sec for 10319597 iterations mean: 0.009757 usec stddev: 0.000163 usec relative stddev: 1.67% RESULT TestAtomicIncrement: x86-64_nnacl_newlib_static= {0.009757, 0.000163} us Measuring clock cycles: first runs (cycles): 246 66 39 48 51 48 51 48 51 48 ... slowest runs (cycles): ... 51 51 51 51 51 51 51 51 66 246 min: 39 cycles q1: 48 cycles median: 48 cycles q3: 51 cycles max: 246 cycles RESULT TestAtomicIncrement_CycleCount: x86-64_nnacl_newlib_static= {48, 3} count Apparent clock speed: 4920 MHz TestUncontendedMutexLock: Measuring real time: 0.027 usec (2.736e-08 sec) per iteration: 2.736e-06 sec for 100 iterations 0.023 usec (2.3241e-08 sec) per iteration: 2.3241e-05 sec for 1000 iterations 0.024 usec (2.4211e-08 sec) per iteration: 0.104174 sec for 4302740 iterations 0.023 usec (2.28313e-08 sec) per iteration: 0.098237 sec for 4302740 iterations 0.023 usec (2.32209e-08 sec) per iteration: 0.0999136 sec for 4302740 iterations 0.023 usec (2.30558e-08 sec) per iteration: 0.0992031 sec for 4302740 iterations 0.023 usec (2.30477e-08 sec) per iteration: 0.0991684 sec for 4302740 iterations mean: 0.023273 usec stddev: 0.000485 usec relative stddev: 2.08% RESULT TestUncontendedMutexLock: x86-64_nnacl_newlib_static= {0.023273, 0.000485} us Measuring clock cycles: first runs (cycles): 432 114 81 81 81 81 81 81 81 81 ... slowest runs (cycles): ... 90 90 90 90 90 90 90 90 114 432 min: 78 cycles q1: 81 cycles median: 87 cycles q3: 90 cycles max: 432 cycles RESULT TestUncontendedMutexLock_CycleCount: x86-64_nnacl_newlib_static= {87, 9} count Apparent clock speed: 3738 MHz TestCondvarSignalNoOp: Measuring real time: 0.332 usec (3.3225e-07 sec) per iteration: 3.3225e-05 sec for 100 iterations 0.163 usec (1.62878e-07 sec) per iteration: 0.0490228 sec for 300978 iterations 0.163 usec (1.63342e-07 sec) per iteration: 0.0491625 sec for 300978 iterations 0.164 usec (1.63651e-07 sec) per iteration: 0.0492553 sec for 300978 iterations 0.163 usec (1.63372e-07 sec) per iteration: 0.0491714 sec for 300978 iterations 0.163 usec (1.63269e-07 sec) per iteration: 0.0491404 sec for 300978 iterations mean: 0.163303 usec stddev: 0.000249 usec relative stddev: 0.15% RESULT TestCondvarSignalNoOp: x86-64_nnacl_newlib_static= {0.163303, 0.000249} us Measuring clock cycles: first runs (cycles): 1365 435 435 432 429 435 432 435 435 432 ... slowest runs (cycles): ... 435 435 435 435 435 435 435 444 444 1365 min: 429 cycles q1: 432 cycles median: 432 cycles q3: 435 cycles max: 1365 cycles RESULT TestCondvarSignalNoOp_CycleCount: x86-64_nnacl_newlib_static= {432, 3} count Apparent clock speed: 2645 MHz TestThreadCreateAndJoin: Measuring real time: 66.172 usec (6.61721e-05 sec) per iteration: 0.00661721 sec for 100 iterations 63.457 usec (6.34572e-05 sec) per iteration: 0.0958838 sec for 1511 iterations 67.630 usec (6.76303e-05 sec) per iteration: 0.102189 sec for 1511 iterations 64.856 usec (6.48555e-05 sec) per iteration: 0.0979967 sec for 1511 iterations 65.294 usec (6.52942e-05 sec) per iteration: 0.0986595 sec for 1511 iterations 65.725 usec (6.57253e-05 sec) per iteration: 0.0993109 sec for 1511 iterations mean: 65.392498 usec stddev: 1.353668 usec relative stddev: 2.07% RESULT TestThreadCreateAndJoin: x86-64_nnacl_newlib_static= {65.392498, 1.353668} us Measuring clock cycles: first runs (cycles): 173868 173856 286071 173868 220179 166329 184146 190497 177366 170241 ... slowest runs (cycles): ... 184146 187302 190497 193968 202497 203682 205023 220179 229953 286071 min: 156975 cycles q1: 169641 cycles median: 171387 cycles q3: 173568 cycles max: 286071 cycles RESULT TestThreadCreateAndJoin_CycleCount: x86-64_nnacl_newlib_static= {171387, 3927} count Apparent clock speed: 2621 MHz TestThreadWakeup: Measuring real time: 32.620 usec (3.26197e-05 sec) per iteration: 0.00326197 sec for 100 iterations 31.856 usec (3.18563e-05 sec) per iteration: 0.0976396 sec for 3065 iterations 30.987 usec (3.09867e-05 sec) per iteration: 0.0949743 sec for 3065 iterations 30.265 usec (3.02648e-05 sec) per iteration: 0.0927615 sec for 3065 iterations 29.964 usec (2.99638e-05 sec) per iteration: 0.0918391 sec for 3065 iterations 29.952 usec (2.99523e-05 sec) per iteration: 0.091804 sec for 3065 iterations mean: 30.604797 usec stddev: 0.729980 usec relative stddev: 2.39% RESULT TestThreadWakeup: x86-64_nnacl_newlib_static= {30.604797, 0.729980} us Measuring clock cycles: first runs (cycles): 89451 117195 93834 116652 88374 97548 82404 89589 161250 107883 ... slowest runs (cycles): ... 100212 106995 107883 111225 116652 117195 126039 145995 161250 170847 min: 78057 cycles q1: 82221 cycles median: 83547 cycles q3: 88125 cycles max: 170847 cycles RESULT TestThreadWakeup_CycleCount: x86-64_nnacl_newlib_static= {83547, 5904} count Apparent clock speed: 2730 MHz TestCatchingFault: Measuring real time: 32.558 usec (3.25577e-05 sec) per iteration: 0.00325577 sec for 100 iterations 30.696 usec (3.0696e-05 sec) per iteration: 0.0942674 sec for 3071 iterations 31.059 usec (3.10594e-05 sec) per iteration: 0.0953834 sec for 3071 iterations 30.996 usec (3.0996e-05 sec) per iteration: 0.0951887 sec for 3071 iterations 30.998 usec (3.09979e-05 sec) per iteration: 0.0951947 sec for 3071 iterations 30.753 usec (3.07529e-05 sec) per iteration: 0.0944421 sec for 3071 iterations mean: 30.900442 usec stddev: 0.146616 usec relative stddev: 0.47% RESULT TestCatchingFault: x86-64_nnacl_newlib_static= {30.900442, 0.146616} us Measuring clock cycles: first runs (cycles): 143982 98691 111696 104907 135918 103863 128400 110103 103974 105333 ... slowest runs (cycles): ... 103863 103974 104616 104907 105333 110103 111696 128400 135918 143982 min: 79428 cycles q1: 80589 cycles median: 81024 cycles q3: 81774 cycles max: 143982 cycles RESULT TestCatchingFault_CycleCount: x86-64_nnacl_newlib_static= {81024, 1185} count Apparent clock speed: 2622 MHz TestThreadCreateAndJoinAfterSettingFaultHandler: Measuring real time: 67.661 usec (6.76607e-05 sec) per iteration: 0.00676607 sec for 100 iterations 70.103 usec (7.01033e-05 sec) per iteration: 0.103543 sec for 1477 iterations 67.142 usec (6.71421e-05 sec) per iteration: 0.0991689 sec for 1477 iterations 64.464 usec (6.44641e-05 sec) per iteration: 0.0952134 sec for 1477 iterations 64.233 usec (6.4233e-05 sec) per iteration: 0.0948721 sec for 1477 iterations 66.249 usec (6.62489e-05 sec) per iteration: 0.0978496 sec for 1477 iterations mean: 66.438254 usec stddev: 2.131869 usec relative stddev: 3.21% RESULT TestThreadCreateAndJoinAfterSettingFaultHandler: x86-64_nnacl_newlib_static= {66.438254, 2.131869} us Measuring clock cycles: first runs (cycles): 175827 179985 175653 169599 186357 228561 206958 196359 175806 180513 ... slowest runs (cycles): ... 201180 206958 210903 211293 220266 222117 228561 232695 278196 342825 min: 169599 cycles q1: 172509 cycles median: 174357 cycles q3: 179838 cycles max: 342825 cycles RESULT TestThreadCreateAndJoinAfterSettingFaultHandler_CycleCount: x86-64_nnacl_newlib_static= {174357, 7329} count Apparent clock speed: 2624 MHz [ OK ] nacl_newlib.run_performance_test (6569 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/opt-mac-x86-64/test_results/nacl_clock_cputime_test.out /b/s/w/ir/k/native_client/scons-out/opt-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/opt-mac-x86-64/obj/src/shared/platform/nacl_clock_test -c [ OK ] nacl_newlib.run_nacl_clock_cputime_test (1520 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/opt-mac-x86-64/test_results/nacl_interval_multi_reg_test.out /b/s/w/ir/k/native_client/scons-out/opt-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/opt-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 (600 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/opt-mac-x86-64/test_results/performance_test.out /b/s/w/ir/k/native_client/scons-out/opt-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/opt-mac-x86-64/obj/tests/performance/performance_test trusted_mac_x86-64 TestNull: Measuring real time: 0.000 usec (0 sec) per iteration: 0 sec for 100 iterations 0.003 usec (3e-09 sec) per iteration: 3e-06 sec for 1000 iterations 0.003 usec (2.7e-09 sec) per iteration: 2.7e-05 sec for 10000 iterations 0.003 usec (2.68604e-09 sec) per iteration: 0.099483 sec for 37037037 iterations 0.003 usec (2.67673e-09 sec) per iteration: 0.099138 sec for 37037037 iterations 0.003 usec (2.68993e-09 sec) per iteration: 0.099627 sec for 37037037 iterations 0.003 usec (2.66798e-09 sec) per iteration: 0.098814 sec for 37037037 iterations 0.003 usec (2.6811e-09 sec) per iteration: 0.0993 sec for 37037037 iterations mean: 0.002680 usec stddev: 0.000008 usec relative stddev: 0.28% RESULT TestNull: trusted_mac_x86-64= {0.002680, 0.000008} us Measuring clock cycles: first runs (cycles): 195 21 21 21 21 21 30 30 30 30 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 30 30 195 min: 21 cycles q1: 21 cycles median: 21 cycles q3: 30 cycles max: 195 cycles RESULT TestNull_CycleCount: trusted_mac_x86-64= {21, 9} count Apparent clock speed: 7835 MHz TestHostSyscall: Measuring real time: 1.200 usec (1.2e-06 sec) per iteration: 0.00012 sec for 100 iterations 1.001 usec (1.00144e-06 sec) per iteration: 0.083453 sec for 83333 iterations 1.012 usec (1.01169e-06 sec) per iteration: 0.084307 sec for 83333 iterations 1.003 usec (1.00296e-06 sec) per iteration: 0.08358 sec for 83333 iterations 1.005 usec (1.00548e-06 sec) per iteration: 0.08379 sec for 83333 iterations 1.005 usec (1.00484e-06 sec) per iteration: 0.083736 sec for 83333 iterations mean: 1.005282 usec stddev: 0.003505 usec relative stddev: 0.35% RESULT TestHostSyscall: trusted_mac_x86-64= {1.005282, 0.003505} us Measuring clock cycles: first runs (cycles): 3018 2709 2676 2676 2679 2679 2676 2676 2679 2679 ... slowest runs (cycles): ... 2706 2706 2706 2709 2709 2709 2712 2715 2715 3018 min: 2667 cycles q1: 2676 cycles median: 2700 cycles q3: 2703 cycles max: 3018 cycles RESULT TestHostSyscall_CycleCount: trusted_mac_x86-64= {2700, 27} count Apparent clock speed: 2686 MHz TestSetjmpLongjmp: Measuring real time: 5.240 usec (5.24e-06 sec) per iteration: 0.000524 sec for 100 iterations 4.691 usec (4.6913e-06 sec) per iteration: 0.089524 sec for 19083 iterations 4.926 usec (4.92632e-06 sec) per iteration: 0.094009 sec for 19083 iterations 4.754 usec (4.75449e-06 sec) per iteration: 0.09073 sec for 19083 iterations 4.724 usec (4.72358e-06 sec) per iteration: 0.09014 sec for 19083 iterations 4.571 usec (4.57061e-06 sec) per iteration: 0.087221 sec for 19083 iterations mean: 4.733260 usec stddev: 0.114920 usec relative stddev: 2.43% RESULT TestSetjmpLongjmp: trusted_mac_x86-64= {4.733260, 0.114920} us Measuring clock cycles: first runs (cycles): 18426 18456 17265 17310 17853 17544 16467 17445 17739 16698 ... slowest runs (cycles): ... 18435 18456 18570 18657 18711 19719 31104 31677 35388 57414 min: 12276 cycles q1: 12315 cycles median: 12387 cycles q3: 17442 cycles max: 57414 cycles RESULT TestSetjmpLongjmp_CycleCount: trusted_mac_x86-64= {12387, 5127} count Apparent clock speed: 2617 MHz TestClockGetTime: Measuring real time: 0.090 usec (9e-08 sec) per iteration: 9e-06 sec for 100 iterations 0.091 usec (9.1e-08 sec) per iteration: 9.1e-05 sec for 1000 iterations 0.077 usec (7.70797e-08 sec) per iteration: 0.084703 sec for 1098901 iterations 0.077 usec (7.67003e-08 sec) per iteration: 0.084286 sec for 1098901 iterations 0.077 usec (7.67394e-08 sec) per iteration: 0.084329 sec for 1098901 iterations 0.077 usec (7.66448e-08 sec) per iteration: 0.084225 sec for 1098901 iterations 0.074 usec (7.41268e-08 sec) per iteration: 0.081458 sec for 1098901 iterations mean: 0.076258 usec stddev: 0.001076 usec relative stddev: 1.41% RESULT TestClockGetTime: trusted_mac_x86-64= {0.076258, 0.001076} us Measuring clock cycles: first runs (cycles): 1335 210 198 201 195 195 195 195 195 201 ... slowest runs (cycles): ... 201 201 201 201 201 201 201 210 216 1335 min: 195 cycles q1: 195 cycles median: 195 cycles q3: 198 cycles max: 1335 cycles RESULT TestClockGetTime_CycleCount: trusted_mac_x86-64= {195, 3} count Apparent clock speed: 2557 MHz TestMmapAnonymous: Measuring real time: 3.820 usec (3.82e-06 sec) per iteration: 0.000382 sec for 100 iterations 3.038 usec (3.03835e-06 sec) per iteration: 0.079538 sec for 26178 iterations 3.089 usec (3.08916e-06 sec) per iteration: 0.080868 sec for 26178 iterations 3.055 usec (3.0547e-06 sec) per iteration: 0.079966 sec for 26178 iterations 3.187 usec (3.18733e-06 sec) per iteration: 0.083438 sec for 26178 iterations 3.051 usec (3.05134e-06 sec) per iteration: 0.079878 sec for 26178 iterations mean: 3.084178 usec stddev: 0.054245 usec relative stddev: 1.76% RESULT TestMmapAnonymous: trusted_mac_x86-64= {3.084178, 0.054245} us Measuring clock cycles: first runs (cycles): 11994 8469 8286 8343 8223 8238 8238 8232 8238 8226 ... slowest runs (cycles): ... 8292 8295 8298 8343 8346 8352 8367 8379 8469 11994 min: 8223 cycles q1: 8253 cycles median: 8259 cycles q3: 8274 cycles max: 11994 cycles RESULT TestMmapAnonymous_CycleCount: trusted_mac_x86-64= {8259, 21} count Apparent clock speed: 2678 MHz TestAtomicIncrement: Measuring real time: 0.010 usec (1e-08 sec) per iteration: 1e-06 sec for 100 iterations 0.007 usec (7e-09 sec) per iteration: 7e-06 sec for 1000 iterations 0.007 usec (7.4e-09 sec) per iteration: 7.4e-05 sec for 10000 iterations 0.007 usec (7.34502e-09 sec) per iteration: 0.099257 sec for 13513513 iterations 0.007 usec (7.34272e-09 sec) per iteration: 0.099226 sec for 13513513 iterations 0.007 usec (7.35952e-09 sec) per iteration: 0.099453 sec for 13513513 iterations 0.007 usec (7.3391e-09 sec) per iteration: 0.099177 sec for 13513513 iterations 0.007 usec (7.42501e-09 sec) per iteration: 0.100338 sec for 13513513 iterations mean: 0.007362 usec stddev: 0.000032 usec relative stddev: 0.44% RESULT TestAtomicIncrement: trusted_mac_x86-64= {0.007362, 0.000032} us Measuring clock cycles: first runs (cycles): 288 54 54 54 54 54 54 54 48 48 ... slowest runs (cycles): ... 54 54 54 54 54 54 54 54 54 288 min: 39 cycles q1: 48 cycles median: 48 cycles q3: 51 cycles max: 288 cycles RESULT TestAtomicIncrement_CycleCount: trusted_mac_x86-64= {48, 3} count Apparent clock speed: 6520 MHz TestUncontendedMutexLock: Measuring real time: 0.210 usec (2.1e-07 sec) per iteration: 2.1e-05 sec for 100 iterations 0.027 usec (2.6628e-08 sec) per iteration: 0.01268 sec for 476190 iterations 0.026 usec (2.63949e-08 sec) per iteration: 0.012569 sec for 476190 iterations 0.026 usec (2.62332e-08 sec) per iteration: 0.012492 sec for 476190 iterations 0.027 usec (2.66784e-08 sec) per iteration: 0.012704 sec for 476190 iterations 0.027 usec (2.67477e-08 sec) per iteration: 0.012737 sec for 476190 iterations mean: 0.026536 usec stddev: 0.000192 usec relative stddev: 0.73% RESULT TestUncontendedMutexLock: trusted_mac_x86-64= {0.026536, 0.000192} us Measuring clock cycles: first runs (cycles): 525 126 84 87 96 93 93 102 87 96 ... slowest runs (cycles): ... 96 96 96 96 96 96 96 102 126 525 min: 84 cycles q1: 87 cycles median: 93 cycles q3: 96 cycles max: 525 cycles RESULT TestUncontendedMutexLock_CycleCount: trusted_mac_x86-64= {93, 9} count Apparent clock speed: 3505 MHz TestCondvarSignalNoOp: Measuring real time: 0.170 usec (1.7e-07 sec) per iteration: 1.7e-05 sec for 100 iterations 0.014 usec (1.38771e-08 sec) per iteration: 0.008163 sec for 588235 iterations 0.014 usec (1.38295e-08 sec) per iteration: 0.008135 sec for 588235 iterations 0.014 usec (1.38601e-08 sec) per iteration: 0.008153 sec for 588235 iterations 0.014 usec (1.38601e-08 sec) per iteration: 0.008153 sec for 588235 iterations 0.014 usec (1.39944e-08 sec) per iteration: 0.008232 sec for 588235 iterations mean: 0.013884 usec stddev: 0.000057 usec relative stddev: 0.41% RESULT TestCondvarSignalNoOp: trusted_mac_x86-64= {0.013884, 0.000057} us Measuring clock cycles: first runs (cycles): 468 75 69 60 60 60 60 69 60 60 ... slowest runs (cycles): ... 69 69 69 69 69 69 69 75 84 468 min: 60 cycles q1: 60 cycles median: 60 cycles q3: 60 cycles max: 468 cycles RESULT TestCondvarSignalNoOp_CycleCount: trusted_mac_x86-64= {60, 0} count Apparent clock speed: 4321 MHz TestThreadCreateAndJoin: Measuring real time: 87.260 usec (8.726e-05 sec) per iteration: 0.008726 sec for 100 iterations 83.245 usec (8.32452e-05 sec) per iteration: 0.095399 sec for 1146 iterations 88.446 usec (8.84459e-05 sec) per iteration: 0.101359 sec for 1146 iterations 86.528 usec (8.65279e-05 sec) per iteration: 0.099161 sec for 1146 iterations 83.123 usec (8.3123e-05 sec) per iteration: 0.095259 sec for 1146 iterations 81.908 usec (8.19084e-05 sec) per iteration: 0.093867 sec for 1146 iterations mean: 84.650087 usec stddev: 2.439550 usec relative stddev: 2.88% RESULT TestThreadCreateAndJoin: trusted_mac_x86-64= {84.650087, 2.439550} us Measuring clock cycles: first runs (cycles): 247884 286128 171441 151005 157857 147501 147735 262599 222543 269793 ... slowest runs (cycles): ... 253539 253617 253626 254211 258396 262599 269793 283269 286128 347235 min: 141576 cycles q1: 222543 cycles median: 234606 cycles q3: 247458 cycles max: 347235 cycles RESULT TestThreadCreateAndJoin_CycleCount: trusted_mac_x86-64= {234606, 24915} count Apparent clock speed: 2771 MHz TestThreadWakeup: Measuring real time: 22.560 usec (2.256e-05 sec) per iteration: 0.002256 sec for 100 iterations 19.808 usec (1.9808e-05 sec) per iteration: 0.087789 sec for 4432 iterations 20.084 usec (2.00844e-05 sec) per iteration: 0.089014 sec for 4432 iterations 19.692 usec (1.9692e-05 sec) per iteration: 0.087275 sec for 4432 iterations 20.024 usec (2.00241e-05 sec) per iteration: 0.088747 sec for 4432 iterations 19.606 usec (1.96056e-05 sec) per iteration: 0.086892 sec for 4432 iterations mean: 19.842825 usec stddev: 0.185183 usec relative stddev: 0.93% RESULT TestThreadWakeup: trusted_mac_x86-64= {19.842825, 0.185183} us Measuring clock cycles: first runs (cycles): 65949 52518 51417 52365 62280 67959 99525 63858 111663 89673 ... slowest runs (cycles): ... 67959 68322 68436 70500 72165 78072 79305 89673 99525 111663 min: 50697 cycles q1: 51714 cycles median: 52533 cycles q3: 59193 cycles max: 111663 cycles RESULT TestThreadWakeup_CycleCount: trusted_mac_x86-64= {52533, 7479} count Apparent clock speed: 2647 MHz WARNING: should have taken less than 2.000000 secs [ OK ] nacl_newlib.run_trusted_performance_test (3809 ms) scons: done building targets. ********************************************************************** COMMAND EXECUTION REPORT ********************************************************************** 6 command_tester.py 1 doSizeCheck ********************************************************************** ENVIRONMENT USAGE REPORT ********************************************************************** 4 nacl-x86-64 3 opt-mac-x86-64 Command return code: 0