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 = 1552943920, usec = 500963 } Mon Mar 18 14:18:40 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 [12388,2531390336:14:57:44.171561] Native Client module will be loaded at base address 0x000001fa00000000 Running suite of 1 benchmarks: Running Benchmark: Life (SIMD version)... RESULT BenchmarkLife: x86-64_nnacl_newlib_static= {0.065870, 0.007900} 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 (67270 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 [12393,2531390336:14:57:58.652296] Native Client module will be loaded at base address 0x00001d3f00000000 TestNull: Measuring real time: 0.007 usec (6.77e-09 sec) per iteration: 6.77e-07 sec for 100 iterations 0.002 usec (2.276e-09 sec) per iteration: 2.276e-06 sec for 1000 iterations 0.002 usec (2.027e-09 sec) per iteration: 2.027e-05 sec for 10000 iterations 0.002 usec (2.01835e-09 sec) per iteration: 0.0995732 sec for 49333991 iterations 0.002 usec (2.01762e-09 sec) per iteration: 0.099537 sec for 49333991 iterations 0.002 usec (2.013e-09 sec) per iteration: 0.0993094 sec for 49333991 iterations 0.002 usec (2.00877e-09 sec) per iteration: 0.0991008 sec for 49333991 iterations 0.002 usec (2.35152e-09 sec) per iteration: 0.11601 sec for 49333991 iterations mean: 0.002082 usec stddev: 0.000135 usec relative stddev: 6.48% RESULT TestNull: x86-64_nnacl_newlib_static= {0.002082, 0.000135} us Measuring clock cycles: first runs (cycles): 240 30 30 21 18 21 18 21 18 30 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 30 30 240 min: 18 cycles q1: 18 cycles median: 21 cycles q3: 27 cycles max: 240 cycles RESULT TestNull_CycleCount: x86-64_nnacl_newlib_static= {21, 9} count Apparent clock speed: 10087 MHz TestNaClSyscall: Measuring real time: 0.158 usec (1.582e-07 sec) per iteration: 1.582e-05 sec for 100 iterations 0.157 usec (1.56909e-07 sec) per iteration: 0.0991838 sec for 632111 iterations 0.157 usec (1.56725e-07 sec) per iteration: 0.0990674 sec for 632111 iterations 0.154 usec (1.53614e-07 sec) per iteration: 0.0971013 sec for 632111 iterations 0.156 usec (1.56242e-07 sec) per iteration: 0.0987626 sec for 632111 iterations 0.157 usec (1.57173e-07 sec) per iteration: 0.0993511 sec for 632111 iterations mean: 0.156133 usec stddev: 0.001295 usec relative stddev: 0.83% RESULT TestNaClSyscall: x86-64_nnacl_newlib_static= {0.156133, 0.001295} us Measuring clock cycles: first runs (cycles): 639 297 291 291 288 297 300 300 288 288 ... slowest runs (cycles): ... 300 300 300 300 300 300 306 306 306 639 min: 288 cycles q1: 288 cycles median: 291 cycles q3: 300 cycles max: 639 cycles RESULT TestNaClSyscall_CycleCount: x86-64_nnacl_newlib_static= {291, 12} count Apparent clock speed: 1864 MHz TestSetjmpLongjmp: Measuring real time: 0.019 usec (1.897e-08 sec) per iteration: 1.897e-06 sec for 100 iterations 0.015 usec (1.4637e-08 sec) per iteration: 1.4637e-05 sec for 1000 iterations 0.012 usec (1.22175e-08 sec) per iteration: 0.0834701 sec for 6832001 iterations 0.012 usec (1.21255e-08 sec) per iteration: 0.0828415 sec for 6832001 iterations 0.012 usec (1.21869e-08 sec) per iteration: 0.0832609 sec for 6832001 iterations 0.013 usec (1.25633e-08 sec) per iteration: 0.0858322 sec for 6832001 iterations 0.012 usec (1.21431e-08 sec) per iteration: 0.0829617 sec for 6832001 iterations mean: 0.012247 usec stddev: 0.000161 usec relative stddev: 1.32% RESULT TestSetjmpLongjmp: x86-64_nnacl_newlib_static= {0.012247, 0.000161} us Measuring clock cycles: first runs (cycles): 411 72 24 33 36 33 33 24 24 24 ... slowest runs (cycles): ... 33 33 33 33 33 33 33 36 72 411 min: 24 cycles q1: 24 cycles median: 33 cycles q3: 33 cycles max: 411 cycles RESULT TestSetjmpLongjmp_CycleCount: x86-64_nnacl_newlib_static= {33, 9} count Apparent clock speed: 2694 MHz TestClockGetTime: Measuring real time: 0.163 usec (1.6276e-07 sec) per iteration: 1.6276e-05 sec for 100 iterations 0.159 usec (1.59254e-07 sec) per iteration: 0.0978456 sec for 614401 iterations 0.160 usec (1.59865e-07 sec) per iteration: 0.0982212 sec for 614401 iterations 0.164 usec (1.63529e-07 sec) per iteration: 0.100472 sec for 614401 iterations 0.161 usec (1.61315e-07 sec) per iteration: 0.099112 sec for 614401 iterations 0.178 usec (1.77963e-07 sec) per iteration: 0.109341 sec for 614401 iterations mean: 0.164385 usec stddev: 0.006947 usec relative stddev: 4.23% RESULT TestClockGetTime: x86-64_nnacl_newlib_static= {0.164385, 0.006947} us Measuring clock cycles: first runs (cycles): 2232 759 747 714 669 723 753 726 693 639 ... slowest runs (cycles): ... 735 747 747 753 756 759 780 786 843 2232 min: 492 cycles q1: 567 cycles median: 648 cycles q3: 699 cycles max: 2232 cycles RESULT TestClockGetTime_CycleCount: x86-64_nnacl_newlib_static= {648, 132} count Apparent clock speed: 3942 MHz TestTlsVariable: Measuring real time: 0.017 usec (1.683e-08 sec) per iteration: 1.683e-06 sec for 100 iterations 0.010 usec (1.0102e-08 sec) per iteration: 1.0102e-05 sec for 1000 iterations 0.008 usec (7.72291e-09 sec) per iteration: 0.0764493 sec for 9899029 iterations 0.006 usec (6.04223e-09 sec) per iteration: 0.0598122 sec for 9899029 iterations 0.008 usec (7.60797e-09 sec) per iteration: 0.0753115 sec for 9899029 iterations 0.009 usec (8.77241e-09 sec) per iteration: 0.0868383 sec for 9899029 iterations 0.006 usec (6.04535e-09 sec) per iteration: 0.0598431 sec for 9899029 iterations mean: 0.007238 usec stddev: 0.001056 usec relative stddev: 14.59% RESULT TestTlsVariable: x86-64_nnacl_newlib_static= {0.007238, 0.001056} us Measuring clock cycles: first runs (cycles): 357 69 21 21 24 21 21 21 21 30 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 30 69 357 min: 21 cycles q1: 21 cycles median: 21 cycles q3: 30 cycles max: 357 cycles RESULT TestTlsVariable_CycleCount: x86-64_nnacl_newlib_static= {21, 9} count Apparent clock speed: 2901 MHz TestMmapAnonymous: Measuring real time: 8.593 usec (8.59342e-06 sec) per iteration: 0.000859342 sec for 100 iterations 8.317 usec (8.3171e-06 sec) per iteration: 0.0967778 sec for 11636 iterations 8.606 usec (8.60616e-06 sec) per iteration: 0.100141 sec for 11636 iterations 10.811 usec (1.08112e-05 sec) per iteration: 0.125799 sec for 11636 iterations 8.259 usec (8.2593e-06 sec) per iteration: 0.0961052 sec for 11636 iterations 8.264 usec (8.26445e-06 sec) per iteration: 0.0961652 sec for 11636 iterations mean: 8.851638 usec stddev: 0.988074 usec relative stddev: 11.16% RESULT TestMmapAnonymous: x86-64_nnacl_newlib_static= {8.851638, 0.988074} us Measuring clock cycles: first runs (cycles): 31938 23655 22689 22431 22473 22140 22407 22470 22398 22431 ... slowest runs (cycles): ... 22554 22554 22581 22608 22689 22695 22791 23055 23655 31938 min: 22059 cycles q1: 22245 cycles median: 22338 cycles q3: 22452 cycles max: 31938 cycles RESULT TestMmapAnonymous_CycleCount: x86-64_nnacl_newlib_static= {22338, 207} count Apparent clock speed: 2524 MHz TestAtomicIncrement: Measuring real time: 0.014 usec (1.415e-08 sec) per iteration: 1.415e-06 sec for 100 iterations 0.010 usec (9.909e-09 sec) per iteration: 9.909e-06 sec for 1000 iterations 0.010 usec (9.6882e-09 sec) per iteration: 9.6882e-05 sec for 10000 iterations 0.010 usec (9.72764e-09 sec) per iteration: 0.100407 sec for 10321834 iterations 0.010 usec (1.01907e-08 sec) per iteration: 0.105187 sec for 10321834 iterations 0.011 usec (1.05071e-08 sec) per iteration: 0.108452 sec for 10321834 iterations 0.010 usec (1.01324e-08 sec) per iteration: 0.104585 sec for 10321834 iterations 0.010 usec (9.72474e-09 sec) per iteration: 0.100377 sec for 10321834 iterations mean: 0.010057 usec stddev: 0.000298 usec relative stddev: 2.97% RESULT TestAtomicIncrement: x86-64_nnacl_newlib_static= {0.010057, 0.000298} us Measuring clock cycles: first runs (cycles): 249 66 48 51 51 51 51 51 51 51 ... slowest runs (cycles): ... 51 51 51 51 51 51 51 66 75 249 min: 42 cycles q1: 51 cycles median: 51 cycles q3: 51 cycles max: 249 cycles RESULT TestAtomicIncrement_CycleCount: x86-64_nnacl_newlib_static= {51, 0} count Apparent clock speed: 5071 MHz TestUncontendedMutexLock: Measuring real time: 0.028 usec (2.773e-08 sec) per iteration: 2.773e-06 sec for 100 iterations 0.023 usec (2.3267e-08 sec) per iteration: 2.3267e-05 sec for 1000 iterations 0.025 usec (2.51763e-08 sec) per iteration: 0.108206 sec for 4297932 iterations 0.023 usec (2.31611e-08 sec) per iteration: 0.0995449 sec for 4297932 iterations 0.023 usec (2.30948e-08 sec) per iteration: 0.0992599 sec for 4297932 iterations 0.023 usec (2.32313e-08 sec) per iteration: 0.0998465 sec for 4297932 iterations 0.023 usec (2.31927e-08 sec) per iteration: 0.0996808 sec for 4297932 iterations mean: 0.023571 usec stddev: 0.000804 usec relative stddev: 3.41% RESULT TestUncontendedMutexLock: x86-64_nnacl_newlib_static= {0.023571, 0.000804} us Measuring clock cycles: first runs (cycles): 603 111 81 81 81 81 81 81 81 90 ... slowest runs (cycles): ... 90 90 90 90 90 90 90 90 111 603 min: 81 cycles q1: 81 cycles median: 90 cycles q3: 90 cycles max: 603 cycles RESULT TestUncontendedMutexLock_CycleCount: x86-64_nnacl_newlib_static= {90, 9} count Apparent clock speed: 3818 MHz TestCondvarSignalNoOp: Measuring real time: 0.262 usec (2.6185e-07 sec) per iteration: 2.6185e-05 sec for 100 iterations 0.165 usec (1.64622e-07 sec) per iteration: 0.0628687 sec for 381898 iterations 0.164 usec (1.6418e-07 sec) per iteration: 0.0626998 sec for 381898 iterations 0.164 usec (1.63817e-07 sec) per iteration: 0.0625616 sec for 381898 iterations 0.163 usec (1.63392e-07 sec) per iteration: 0.062399 sec for 381898 iterations 0.169 usec (1.68762e-07 sec) per iteration: 0.0644497 sec for 381898 iterations mean: 0.164954 usec stddev: 0.001946 usec relative stddev: 1.18% RESULT TestCondvarSignalNoOp: x86-64_nnacl_newlib_static= {0.164954, 0.001946} us Measuring clock cycles: first runs (cycles): 1335 453 432 432 432 444 435 444 432 432 ... slowest runs (cycles): ... 435 438 438 438 441 444 444 453 474 1335 min: 432 cycles q1: 432 cycles median: 435 cycles q3: 435 cycles max: 1335 cycles RESULT TestCondvarSignalNoOp_CycleCount: x86-64_nnacl_newlib_static= {435, 3} count Apparent clock speed: 2637 MHz TestThreadCreateAndJoin: Measuring real time: 73.458 usec (7.34583e-05 sec) per iteration: 0.00734583 sec for 100 iterations 77.673 usec (7.76732e-05 sec) per iteration: 0.105713 sec for 1361 iterations 71.452 usec (7.14523e-05 sec) per iteration: 0.0972466 sec for 1361 iterations 71.575 usec (7.15752e-05 sec) per iteration: 0.0974139 sec for 1361 iterations 74.441 usec (7.44411e-05 sec) per iteration: 0.101314 sec for 1361 iterations 65.765 usec (6.57652e-05 sec) per iteration: 0.0895065 sec for 1361 iterations mean: 72.181413 usec stddev: 3.932744 usec relative stddev: 5.45% RESULT TestThreadCreateAndJoin: x86-64_nnacl_newlib_static= {72.181413, 3.932744} us Measuring clock cycles: first runs (cycles): 237339 242094 210864 203691 217263 210390 219516 199584 198693 217053 ... slowest runs (cycles): ... 216357 216711 216906 217053 217263 218136 219516 234036 237339 242094 min: 198693 cycles q1: 211416 cycles median: 213138 cycles q3: 214785 cycles max: 242094 cycles RESULT TestThreadCreateAndJoin_CycleCount: x86-64_nnacl_newlib_static= {213138, 3369} count Apparent clock speed: 2953 MHz TestThreadWakeup: Measuring real time: 35.084 usec (3.50836e-05 sec) per iteration: 0.00350835 sec for 100 iterations 32.466 usec (3.24662e-05 sec) per iteration: 0.0925287 sec for 2850 iterations 33.889 usec (3.38895e-05 sec) per iteration: 0.096585 sec for 2850 iterations 33.030 usec (3.30302e-05 sec) per iteration: 0.094136 sec for 2850 iterations 29.750 usec (2.975e-05 sec) per iteration: 0.0847875 sec for 2850 iterations 32.928 usec (3.29283e-05 sec) per iteration: 0.0938456 sec for 2850 iterations mean: 32.412827 usec stddev: 1.408591 usec relative stddev: 4.35% RESULT TestThreadWakeup: x86-64_nnacl_newlib_static= {32.412827, 1.408591} us Measuring clock cycles: first runs (cycles): 100962 89508 89742 89925 74214 106455 105855 104433 87507 119808 ... slowest runs (cycles): ... 119238 119808 131109 132114 136662 140484 146784 157974 162051 165489 min: 60318 cycles q1: 76722 cycles median: 79809 cycles q3: 99366 cycles max: 165489 cycles RESULT TestThreadWakeup_CycleCount: x86-64_nnacl_newlib_static= {79809, 22644} count Apparent clock speed: 2462 MHz TestCatchingFault: Measuring real time: 37.557 usec (3.75569e-05 sec) per iteration: 0.00375569 sec for 100 iterations 34.525 usec (3.45248e-05 sec) per iteration: 0.0919049 sec for 2662 iterations 33.189 usec (3.31886e-05 sec) per iteration: 0.088348 sec for 2662 iterations 33.748 usec (3.37477e-05 sec) per iteration: 0.0898365 sec for 2662 iterations 34.213 usec (3.42134e-05 sec) per iteration: 0.091076 sec for 2662 iterations 34.290 usec (3.42903e-05 sec) per iteration: 0.0912807 sec for 2662 iterations mean: 33.992940 usec stddev: 0.474749 usec relative stddev: 1.40% RESULT TestCatchingFault: x86-64_nnacl_newlib_static= {33.992940, 0.474749} us Measuring clock cycles: first runs (cycles): 106884 93408 89784 89256 104888 206936 139088 114456 152360 135002 ... slowest runs (cycles): ... 113352 114456 125676 135002 136408 139088 150744 151709 152360 206936 min: 88672 cycles q1: 89856 cycles median: 90884 cycles q3: 91932 cycles max: 206936 cycles RESULT TestCatchingFault_CycleCount: x86-64_nnacl_newlib_static= {90884, 2076} count Apparent clock speed: 2674 MHz TestThreadCreateAndJoinAfterSettingFaultHandler: Measuring real time: 87.479 usec (8.74792e-05 sec) per iteration: 0.00874792 sec for 100 iterations 74.082 usec (7.40818e-05 sec) per iteration: 0.0846755 sec for 1143 iterations 75.332 usec (7.5332e-05 sec) per iteration: 0.0861045 sec for 1143 iterations 70.281 usec (7.02806e-05 sec) per iteration: 0.0803307 sec for 1143 iterations 75.723 usec (7.57228e-05 sec) per iteration: 0.0865512 sec for 1143 iterations 74.041 usec (7.40413e-05 sec) per iteration: 0.0846292 sec for 1143 iterations mean: 73.891702 usec stddev: 1.924898 usec relative stddev: 2.61% RESULT TestThreadCreateAndJoinAfterSettingFaultHandler: x86-64_nnacl_newlib_static= {73.891702, 1.924898} us Measuring clock cycles: first runs (cycles): 198285 171999 191979 342678 411141 203979 221388 312264 194271 180507 ... slowest runs (cycles): ... 221388 221853 229062 231648 243882 262467 312264 342678 379392 411141 min: 167004 cycles q1: 171906 cycles median: 173700 cycles q3: 187254 cycles max: 411141 cycles RESULT TestThreadCreateAndJoinAfterSettingFaultHandler_CycleCount: x86-64_nnacl_newlib_static= {173700, 15348} count Apparent clock speed: 2351 MHz [ OK ] nacl_newlib.run_performance_test (6310 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 (1980 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 (460 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.68291e-09 sec) per iteration: 0.099367 sec for 37037037 iterations 0.003 usec (2.67122e-09 sec) per iteration: 0.098934 sec for 37037037 iterations 0.003 usec (2.72319e-09 sec) per iteration: 0.100859 sec for 37037037 iterations 0.003 usec (2.67894e-09 sec) per iteration: 0.09922 sec for 37037037 iterations 0.003 usec (2.67295e-09 sec) per iteration: 0.098998 sec for 37037037 iterations mean: 0.002686 usec stddev: 0.000019 usec relative stddev: 0.71% RESULT TestNull: trusted_mac_x86-64= {0.002686, 0.000019} us Measuring clock cycles: first runs (cycles): 183 21 30 30 30 30 30 21 21 21 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 30 30 183 min: 21 cycles q1: 21 cycles median: 30 cycles q3: 30 cycles max: 183 cycles RESULT TestNull_CycleCount: trusted_mac_x86-64= {30, 9} count Apparent clock speed: 11170 MHz TestHostSyscall: Measuring real time: 1.150 usec (1.15e-06 sec) per iteration: 0.000115 sec for 100 iterations 1.019 usec (1.01891e-06 sec) per iteration: 0.0886 sec for 86956 iterations 1.009 usec (1.00899e-06 sec) per iteration: 0.087738 sec for 86956 iterations 0.999 usec (9.99321e-07 sec) per iteration: 0.086897 sec for 86956 iterations 0.989 usec (9.88937e-07 sec) per iteration: 0.085994 sec for 86956 iterations 1.001 usec (1.00116e-06 sec) per iteration: 0.087057 sec for 86956 iterations mean: 1.003464 usec stddev: 0.010025 usec relative stddev: 1.00% RESULT TestHostSyscall: trusted_mac_x86-64= {1.003464, 0.010025} us Measuring clock cycles: first runs (cycles): 3024 2715 2676 2673 2676 2664 2667 2664 2667 2664 ... slowest runs (cycles): ... 2730 2730 2730 2736 2739 2739 2739 2805 3024 15327 min: 2664 cycles q1: 2667 cycles median: 2697 cycles q3: 2700 cycles max: 15327 cycles RESULT TestHostSyscall_CycleCount: trusted_mac_x86-64= {2697, 33} count Apparent clock speed: 2688 MHz TestSetjmpLongjmp: Measuring real time: 5.150 usec (5.15e-06 sec) per iteration: 0.000515 sec for 100 iterations 4.672 usec (4.67245e-06 sec) per iteration: 0.090725 sec for 19417 iterations 4.562 usec (4.56167e-06 sec) per iteration: 0.088574 sec for 19417 iterations 4.569 usec (4.56924e-06 sec) per iteration: 0.088721 sec for 19417 iterations 4.570 usec (4.57022e-06 sec) per iteration: 0.08874 sec for 19417 iterations 4.558 usec (4.55827e-06 sec) per iteration: 0.088508 sec for 19417 iterations mean: 4.586373 usec stddev: 0.043275 usec relative stddev: 0.94% RESULT TestSetjmpLongjmp: trusted_mac_x86-64= {4.586373, 0.043275} us Measuring clock cycles: first runs (cycles): 13146 12210 12141 12279 12150 12186 12147 12174 12156 12177 ... slowest runs (cycles): ... 12207 12210 12210 12216 12216 12219 12222 12258 12279 13146 min: 12138 cycles q1: 12162 cycles median: 12177 cycles q3: 12195 cycles max: 13146 cycles RESULT TestSetjmpLongjmp_CycleCount: trusted_mac_x86-64= {12177, 33} count Apparent clock speed: 2655 MHz TestClockGetTime: Measuring real time: 0.090 usec (9e-08 sec) per iteration: 9e-06 sec for 100 iterations 0.081 usec (8.1e-08 sec) per iteration: 8.1e-05 sec for 1000 iterations 0.079 usec (7.88309e-08 sec) per iteration: 0.097322 sec for 1234567 iterations 0.079 usec (7.88608e-08 sec) per iteration: 0.097359 sec for 1234567 iterations 0.079 usec (7.92683e-08 sec) per iteration: 0.097862 sec for 1234567 iterations 0.079 usec (7.9423e-08 sec) per iteration: 0.098053 sec for 1234567 iterations 0.079 usec (7.94651e-08 sec) per iteration: 0.098105 sec for 1234567 iterations mean: 0.079170 usec stddev: 0.000273 usec relative stddev: 0.34% RESULT TestClockGetTime: trusted_mac_x86-64= {0.079170, 0.000273} us Measuring clock cycles: first runs (cycles): 1290 231 210 210 210 210 213 216 210 234 ... slowest runs (cycles): ... 216 216 216 216 216 219 222 231 234 1290 min: 201 cycles q1: 210 cycles median: 213 cycles q3: 216 cycles max: 1290 cycles RESULT TestClockGetTime_CycleCount: trusted_mac_x86-64= {213, 6} count Apparent clock speed: 2690 MHz TestMmapAnonymous: Measuring real time: 3.850 usec (3.85e-06 sec) per iteration: 0.000385 sec for 100 iterations 3.028 usec (3.02845e-06 sec) per iteration: 0.078661 sec for 25974 iterations 3.122 usec (3.12185e-06 sec) per iteration: 0.081087 sec for 25974 iterations 3.062 usec (3.06237e-06 sec) per iteration: 0.079542 sec for 25974 iterations 2.991 usec (2.9908e-06 sec) per iteration: 0.077683 sec for 25974 iterations 3.077 usec (3.07719e-06 sec) per iteration: 0.079927 sec for 25974 iterations mean: 3.056133 usec stddev: 0.044354 usec relative stddev: 1.45% RESULT TestMmapAnonymous: trusted_mac_x86-64= {3.056133, 0.044354} us Measuring clock cycles: first runs (cycles): 11955 8718 8196 8205 8160 8178 8202 8199 8181 8187 ... slowest runs (cycles): ... 8325 8328 8340 8346 8364 8397 8409 8442 8718 11955 min: 8160 cycles q1: 8190 cycles median: 8208 cycles q3: 8253 cycles max: 11955 cycles RESULT TestMmapAnonymous_CycleCount: trusted_mac_x86-64= {8208, 63} count Apparent clock speed: 2686 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.34287e-09 sec) per iteration: 0.099228 sec for 13513513 iterations 0.007 usec (7.40718e-09 sec) per iteration: 0.100097 sec for 13513513 iterations 0.007 usec (7.49775e-09 sec) per iteration: 0.101321 sec for 13513513 iterations 0.007 usec (7.43234e-09 sec) per iteration: 0.100437 sec for 13513513 iterations 0.007 usec (7.34657e-09 sec) per iteration: 0.099278 sec for 13513513 iterations mean: 0.007405 usec stddev: 0.000058 usec relative stddev: 0.78% RESULT TestAtomicIncrement: trusted_mac_x86-64= {0.007405, 0.000058} us Measuring clock cycles: first runs (cycles): 225 54 51 48 48 48 48 48 48 48 ... slowest runs (cycles): ... 48 48 48 48 48 48 51 54 54 225 min: 48 cycles q1: 48 cycles median: 48 cycles q3: 48 cycles max: 225 cycles RESULT TestAtomicIncrement_CycleCount: trusted_mac_x86-64= {48, 0} count Apparent clock speed: 6482 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.6544e-08 sec) per iteration: 0.01264 sec for 476190 iterations 0.027 usec (2.65608e-08 sec) per iteration: 0.012648 sec for 476190 iterations 0.027 usec (2.65272e-08 sec) per iteration: 0.012632 sec for 476190 iterations 0.027 usec (2.65797e-08 sec) per iteration: 0.012657 sec for 476190 iterations 0.027 usec (2.67981e-08 sec) per iteration: 0.012761 sec for 476190 iterations mean: 0.026602 usec stddev: 0.000100 usec relative stddev: 0.37% RESULT TestUncontendedMutexLock: trusted_mac_x86-64= {0.026602, 0.000100} us Measuring clock cycles: first runs (cycles): 549 144 111 111 111 105 90 96 90 99 ... slowest runs (cycles): ... 111 111 111 111 123 129 132 144 153 549 min: 84 cycles q1: 96 cycles median: 99 cycles q3: 105 cycles max: 549 cycles RESULT TestUncontendedMutexLock_CycleCount: trusted_mac_x86-64= {99, 9} count Apparent clock speed: 3722 MHz TestCondvarSignalNoOp: Measuring real time: 0.100 usec (1e-07 sec) per iteration: 1e-05 sec for 100 iterations 0.021 usec (2.1193e-08 sec) per iteration: 0.021193 sec for 1000000 iterations 0.021 usec (2.1111e-08 sec) per iteration: 0.021111 sec for 1000000 iterations 0.021 usec (2.1184e-08 sec) per iteration: 0.021184 sec for 1000000 iterations 0.021 usec (2.1021e-08 sec) per iteration: 0.021021 sec for 1000000 iterations 0.021 usec (2.1193e-08 sec) per iteration: 0.021193 sec for 1000000 iterations mean: 0.021140 usec stddev: 0.000067 usec relative stddev: 0.32% RESULT TestCondvarSignalNoOp: trusted_mac_x86-64= {0.021140, 0.000067} us Measuring clock cycles: first runs (cycles): 711 81 60 66 66 60 75 63 63 66 ... slowest runs (cycles): ... 87 87 90 90 90 90 90 90 93 711 min: 60 cycles q1: 75 cycles median: 81 cycles q3: 84 cycles max: 711 cycles RESULT TestCondvarSignalNoOp_CycleCount: trusted_mac_x86-64= {81, 9} count Apparent clock speed: 3832 MHz TestThreadCreateAndJoin: Measuring real time: 71.830 usec (7.183e-05 sec) per iteration: 0.007183 sec for 100 iterations 80.867 usec (8.08671e-05 sec) per iteration: 0.112567 sec for 1392 iterations 79.106 usec (7.91063e-05 sec) per iteration: 0.110116 sec for 1392 iterations 79.969 usec (7.99691e-05 sec) per iteration: 0.111317 sec for 1392 iterations 78.184 usec (7.81839e-05 sec) per iteration: 0.108832 sec for 1392 iterations 74.146 usec (7.41458e-05 sec) per iteration: 0.103211 sec for 1392 iterations mean: 78.454454 usec stddev: 2.331410 usec relative stddev: 2.97% RESULT TestThreadCreateAndJoin: trusted_mac_x86-64= {78.454454, 2.331410} us Measuring clock cycles: first runs (cycles): 245037 326220 219138 262965 264603 212742 147738 265158 245721 242220 ... slowest runs (cycles): ... 287919 290517 293079 295026 295206 297123 298134 302970 306531 326220 min: 133581 cycles q1: 141102 cycles median: 162969 cycles q3: 245721 cycles max: 326220 cycles RESULT TestThreadCreateAndJoin_CycleCount: trusted_mac_x86-64= {162969, 104619} count Apparent clock speed: 2077 MHz TestThreadWakeup: Measuring real time: 21.970 usec (2.197e-05 sec) per iteration: 0.002197 sec for 100 iterations 19.933 usec (1.99334e-05 sec) per iteration: 0.090717 sec for 4551 iterations 19.969 usec (1.99692e-05 sec) per iteration: 0.09088 sec for 4551 iterations 20.182 usec (2.01819e-05 sec) per iteration: 0.091848 sec for 4551 iterations 19.990 usec (1.99897e-05 sec) per iteration: 0.090973 sec for 4551 iterations 20.666 usec (2.06656e-05 sec) per iteration: 0.094049 sec for 4551 iterations mean: 20.147967 usec stddev: 0.272799 usec relative stddev: 1.35% RESULT TestThreadWakeup: trusted_mac_x86-64= {20.147967, 0.272799} us Measuring clock cycles: first runs (cycles): 65094 60645 52485 51663 60117 74829 86820 57039 54273 75420 ... slowest runs (cycles): ... 65094 66141 66825 70842 73872 74829 75420 76953 86820 105096 min: 50667 cycles q1: 51762 cycles median: 52404 cycles q3: 53514 cycles max: 105096 cycles RESULT TestThreadWakeup_CycleCount: trusted_mac_x86-64= {52404, 1752} count Apparent clock speed: 2601 MHz WARNING: should have taken less than 2.000000 secs [ OK ] nacl_newlib.run_trusted_performance_test (4040 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