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 force_sel_ldr=../out_64/sel_ldr force_irt=../out_64/irt_x64/irt_core.nexe perf_prefix=gn_ scons: Reading SConscript files ... ====================================================================== SCONS ARGS:['scons.py', '--verbose', '-k', '-j1', '--mode=nacl,dbg-host', 'platform=x86-64', '--clang', 'large_tests', 'force_sel_ldr=../out_64/sel_ldr', 'force_irt=../out_64/irt_x64/irt_core.nexe', 'perf_prefix=gn_'] ====================================================================== ====================================================================== 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 = 1552674630, usec = 596376 } Fri Mar 15 11:30:30 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 gn_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 /b/s/w/ir/k/out_64/sel_ldr -- scons-out/nacl-x86-64/obj/tests/benchmark/benchmark_test.nexe gn_x86-64_nnacl_newlib_static [ RUN ] nacl_newlib.run_benchmark_test /b/s/w/ir/k/out_64/sel_ldr -- scons-out/nacl-x86-64/obj/tests/benchmark/benchmark_test.nexe gn_x86-64_nnacl_newlib_static [24464,2962969472:12:34:36.329149] Native Client module will be loaded at base address 0x00002a9900000000 Running suite of 1 benchmarks: Running Benchmark: Life (SIMD version)... RESULT BenchmarkLife: gn_x86-64_nnacl_newlib_static= {0.133020, 0.001990} seconds --------------------------------------------------------------- Done running benchmark suite. [ OK ] nacl_newlib.run_benchmark_test (1320 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 gn_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 /b/s/w/ir/k/out_64/sel_ldr -- scons-out/nacl-x86-64/obj/tests/clock/clock_test.nexe -c [ RUN ] nacl_newlib.run_clock_cputime_test /b/s/w/ir/k/out_64/sel_ldr -- scons-out/nacl-x86-64/obj/tests/clock/clock_test.nexe -c [ OK ] nacl_newlib.run_clock_cputime_test (59160 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: gn_x86-64_nnacl_newlib_static= 524.896 KB RESULT hello_world_size.out: ZIPPED_gn_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 gn_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 /b/s/w/ir/k/out_64/sel_ldr -e -- scons-out/nacl-x86-64/obj/tests/performance/performance_test.nexe gn_x86-64_nnacl_newlib_static [ RUN ] nacl_newlib.run_performance_test /b/s/w/ir/k/out_64/sel_ldr -e -- scons-out/nacl-x86-64/obj/tests/performance/performance_test.nexe gn_x86-64_nnacl_newlib_static [24474,2962969472:12:34:53.941124] Native Client module will be loaded at base address 0x00004b3000000000 TestNull: Measuring real time: 0.008 usec (7.79e-09 sec) per iteration: 7.79e-07 sec for 100 iterations 0.002 usec (1.817e-09 sec) per iteration: 1.817e-06 sec for 1000 iterations 0.002 usec (1.512e-09 sec) per iteration: 1.512e-05 sec for 10000 iterations 0.001 usec (1.46459e-09 sec) per iteration: 0.0968645 sec for 66137566 iterations 0.001 usec (1.44883e-09 sec) per iteration: 0.0958223 sec for 66137566 iterations 0.001 usec (1.44722e-09 sec) per iteration: 0.0957153 sec for 66137566 iterations 0.001 usec (1.4499e-09 sec) per iteration: 0.0958928 sec for 66137566 iterations 0.001 usec (1.45994e-09 sec) per iteration: 0.0965566 sec for 66137566 iterations mean: 0.001454 usec stddev: 0.000007 usec relative stddev: 0.47% RESULT TestNull: gn_x86-64_nnacl_newlib_static= {0.001454, 0.000007} us Measuring clock cycles: first runs (cycles): 126 39 18 18 27 18 18 27 27 18 ... slowest runs (cycles): ... 27 27 27 27 27 27 27 27 39 126 min: 18 cycles q1: 18 cycles median: 18 cycles q3: 27 cycles max: 126 cycles RESULT TestNull_CycleCount: gn_x86-64_nnacl_newlib_static= {18, 9} count Apparent clock speed: 12379 MHz TestNaClSyscall: Measuring real time: 0.163 usec (1.6286e-07 sec) per iteration: 1.6286e-05 sec for 100 iterations 0.153 usec (1.53425e-07 sec) per iteration: 0.0942068 sec for 614024 iterations 0.151 usec (1.51349e-07 sec) per iteration: 0.0929321 sec for 614024 iterations 0.151 usec (1.51281e-07 sec) per iteration: 0.0928899 sec for 614024 iterations 0.152 usec (1.5195e-07 sec) per iteration: 0.0933008 sec for 614024 iterations 0.150 usec (1.50394e-07 sec) per iteration: 0.0923456 sec for 614024 iterations mean: 0.151680 usec stddev: 0.001004 usec relative stddev: 0.66% RESULT TestNaClSyscall: gn_x86-64_nnacl_newlib_static= {0.151680, 0.001004} us Measuring clock cycles: first runs (cycles): 690 534 525 525 465 483 471 486 474 537 ... slowest runs (cycles): ... 492 495 525 525 534 537 546 546 570 690 min: 462 cycles q1: 474 cycles median: 480 cycles q3: 483 cycles max: 690 cycles RESULT TestNaClSyscall_CycleCount: gn_x86-64_nnacl_newlib_static= {480, 9} count Apparent clock speed: 3165 MHz TestSetjmpLongjmp: Measuring real time: 0.021 usec (2.112e-08 sec) per iteration: 2.112e-06 sec for 100 iterations 0.013 usec (1.2712e-08 sec) per iteration: 1.2712e-05 sec for 1000 iterations 0.010 usec (9.83331e-09 sec) per iteration: 0.0773545 sec for 7866582 iterations 0.010 usec (9.84384e-09 sec) per iteration: 0.0774374 sec for 7866582 iterations 0.010 usec (9.79025e-09 sec) per iteration: 0.0770158 sec for 7866582 iterations 0.010 usec (9.79842e-09 sec) per iteration: 0.0770801 sec for 7866582 iterations 0.010 usec (9.75043e-09 sec) per iteration: 0.0767026 sec for 7866582 iterations mean: 0.009803 usec stddev: 0.000033 usec relative stddev: 0.34% RESULT TestSetjmpLongjmp: gn_x86-64_nnacl_newlib_static= {0.009803, 0.000033} us Measuring clock cycles: first runs (cycles): 255 48 30 30 30 30 30 30 27 30 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 30 48 255 min: 18 cycles q1: 21 cycles median: 21 cycles q3: 27 cycles max: 255 cycles RESULT TestSetjmpLongjmp_CycleCount: gn_x86-64_nnacl_newlib_static= {21, 6} count Apparent clock speed: 2142 MHz TestClockGetTime: Measuring real time: 0.344 usec (3.4404e-07 sec) per iteration: 3.4404e-05 sec for 100 iterations 0.258 usec (2.58073e-07 sec) per iteration: 0.0750121 sec for 290663 iterations 0.258 usec (2.58011e-07 sec) per iteration: 0.0749944 sec for 290663 iterations 0.259 usec (2.59108e-07 sec) per iteration: 0.0753131 sec for 290663 iterations 0.258 usec (2.58428e-07 sec) per iteration: 0.0751154 sec for 290663 iterations 0.258 usec (2.58046e-07 sec) per iteration: 0.0750044 sec for 290663 iterations mean: 0.258333 usec stddev: 0.000416 usec relative stddev: 0.16% RESULT TestClockGetTime: gn_x86-64_nnacl_newlib_static= {0.258333, 0.000416} us Measuring clock cycles: first runs (cycles): 1404 921 840 840 783 780 864 786 792 789 ... slowest runs (cycles): ... 840 849 852 858 861 864 873 876 921 1404 min: 774 cycles q1: 783 cycles median: 786 cycles q3: 795 cycles max: 1404 cycles RESULT TestClockGetTime_CycleCount: gn_x86-64_nnacl_newlib_static= {786, 12} count Apparent clock speed: 3043 MHz TestTlsVariable: Measuring real time: 0.015 usec (1.46e-08 sec) per iteration: 1.46e-06 sec for 100 iterations 0.008 usec (7.943e-09 sec) per iteration: 7.943e-06 sec for 1000 iterations 0.008 usec (7.8607e-09 sec) per iteration: 7.8607e-05 sec for 10000 iterations 0.004 usec (4.38162e-09 sec) per iteration: 0.0557408 sec for 12721513 iterations 0.004 usec (4.3914e-09 sec) per iteration: 0.0558652 sec for 12721513 iterations 0.004 usec (4.36526e-09 sec) per iteration: 0.0555328 sec for 12721513 iterations 0.004 usec (4.34347e-09 sec) per iteration: 0.0552555 sec for 12721513 iterations 0.004 usec (4.36591e-09 sec) per iteration: 0.055541 sec for 12721513 iterations mean: 0.004370 usec stddev: 0.000016 usec relative stddev: 0.37% RESULT TestTlsVariable: gn_x86-64_nnacl_newlib_static= {0.004370, 0.000016} us Measuring clock cycles: first runs (cycles): 189 60 60 27 18 18 27 18 18 18 ... slowest runs (cycles): ... 27 27 27 27 27 27 27 60 60 189 min: 18 cycles q1: 18 cycles median: 18 cycles q3: 27 cycles max: 189 cycles RESULT TestTlsVariable_CycleCount: gn_x86-64_nnacl_newlib_static= {18, 9} count Apparent clock speed: 4119 MHz TestMmapAnonymous: Measuring real time: 6.523 usec (6.52328e-06 sec) per iteration: 0.000652328 sec for 100 iterations 5.125 usec (5.12477e-06 sec) per iteration: 0.0785576 sec for 15329 iterations 5.089 usec (5.08862e-06 sec) per iteration: 0.0780035 sec for 15329 iterations 5.137 usec (5.13712e-06 sec) per iteration: 0.0787469 sec for 15329 iterations 5.106 usec (5.10649e-06 sec) per iteration: 0.0782773 sec for 15329 iterations 5.085 usec (5.08532e-06 sec) per iteration: 0.0779529 sec for 15329 iterations mean: 5.108465 usec stddev: 0.020100 usec relative stddev: 0.39% RESULT TestMmapAnonymous: gn_x86-64_nnacl_newlib_static= {5.108465, 0.020100} us Measuring clock cycles: first runs (cycles): 18840 15954 15582 15324 15354 15405 15495 19128 25509 24528 ... slowest runs (cycles): ... 24810 25149 25347 25434 25506 25509 25656 32154 41697 98979 min: 14856 cycles q1: 14934 cycles median: 15042 cycles q3: 15876 cycles max: 98979 cycles RESULT TestMmapAnonymous_CycleCount: gn_x86-64_nnacl_newlib_static= {15042, 942} count Apparent clock speed: 2945 MHz TestAtomicIncrement: Measuring real time: 0.016 usec (1.594e-08 sec) per iteration: 1.594e-06 sec for 100 iterations 0.010 usec (9.531e-09 sec) per iteration: 9.531e-06 sec for 1000 iterations 0.009 usec (9.0952e-09 sec) per iteration: 9.0952e-05 sec for 10000 iterations 0.008 usec (7.60767e-09 sec) per iteration: 0.0836449 sec for 10994810 iterations 0.008 usec (7.55862e-09 sec) per iteration: 0.0831056 sec for 10994810 iterations 0.008 usec (7.52905e-09 sec) per iteration: 0.0827805 sec for 10994810 iterations 0.008 usec (7.53478e-09 sec) per iteration: 0.0828435 sec for 10994810 iterations 0.008 usec (7.59413e-09 sec) per iteration: 0.083496 sec for 10994810 iterations mean: 0.007565 usec stddev: 0.000031 usec relative stddev: 0.41% RESULT TestAtomicIncrement: gn_x86-64_nnacl_newlib_static= {0.007565, 0.000031} us Measuring clock cycles: first runs (cycles): 141 48 48 48 48 48 48 39 39 48 ... slowest runs (cycles): ... 48 48 48 48 48 48 48 48 48 141 min: 39 cycles q1: 48 cycles median: 48 cycles q3: 48 cycles max: 141 cycles RESULT TestAtomicIncrement_CycleCount: gn_x86-64_nnacl_newlib_static= {48, 0} count Apparent clock speed: 6345 MHz TestUncontendedMutexLock: Measuring real time: 0.024 usec (2.364e-08 sec) per iteration: 2.364e-06 sec for 100 iterations 0.022 usec (2.2315e-08 sec) per iteration: 2.2315e-05 sec for 1000 iterations 0.019 usec (1.89886e-08 sec) per iteration: 0.0850933 sec for 4481290 iterations 0.019 usec (1.88567e-08 sec) per iteration: 0.0845023 sec for 4481290 iterations 0.019 usec (1.88328e-08 sec) per iteration: 0.0843952 sec for 4481290 iterations 0.019 usec (1.89574e-08 sec) per iteration: 0.0849536 sec for 4481290 iterations 0.019 usec (1.89424e-08 sec) per iteration: 0.0848866 sec for 4481290 iterations mean: 0.018916 usec stddev: 0.000060 usec relative stddev: 0.32% RESULT TestUncontendedMutexLock: gn_x86-64_nnacl_newlib_static= {0.018916, 0.000060} us Measuring clock cycles: first runs (cycles): 276 108 84 78 75 87 75 78 84 78 ... slowest runs (cycles): ... 87 87 87 87 87 90 93 93 108 276 min: 75 cycles q1: 75 cycles median: 78 cycles q3: 84 cycles max: 276 cycles RESULT TestUncontendedMutexLock_CycleCount: gn_x86-64_nnacl_newlib_static= {78, 9} count Apparent clock speed: 4124 MHz TestCondvarSignalNoOp: Measuring real time: 0.410 usec (4.0966e-07 sec) per iteration: 4.0966e-05 sec for 100 iterations 0.204 usec (2.03914e-07 sec) per iteration: 0.0497762 sec for 244104 iterations 0.203 usec (2.03201e-07 sec) per iteration: 0.0496023 sec for 244104 iterations 0.204 usec (2.04323e-07 sec) per iteration: 0.049876 sec for 244104 iterations 0.203 usec (2.02576e-07 sec) per iteration: 0.0494496 sec for 244104 iterations 0.205 usec (2.05122e-07 sec) per iteration: 0.0500711 sec for 244104 iterations mean: 0.203827 usec stddev: 0.000882 usec relative stddev: 0.43% RESULT TestCondvarSignalNoOp: gn_x86-64_nnacl_newlib_static= {0.203827, 0.000882} us Measuring clock cycles: first runs (cycles): 1044 672 720 672 630 621 618 732 612 684 ... slowest runs (cycles): ... 636 672 672 684 690 699 720 732 798 1044 min: 612 cycles q1: 621 cycles median: 627 cycles q3: 633 cycles max: 1044 cycles RESULT TestCondvarSignalNoOp_CycleCount: gn_x86-64_nnacl_newlib_static= {627, 12} count Apparent clock speed: 3076 MHz TestThreadCreateAndJoin: Measuring real time: 64.997 usec (6.49965e-05 sec) per iteration: 0.00649966 sec for 100 iterations 44.628 usec (4.46285e-05 sec) per iteration: 0.0686386 sec for 1538 iterations 44.600 usec (4.45995e-05 sec) per iteration: 0.0685941 sec for 1538 iterations 44.542 usec (4.45425e-05 sec) per iteration: 0.0685064 sec for 1538 iterations 44.966 usec (4.49663e-05 sec) per iteration: 0.0691582 sec for 1538 iterations 44.802 usec (4.48016e-05 sec) per iteration: 0.0689048 sec for 1538 iterations mean: 44.707676 usec stddev: 0.155537 usec relative stddev: 0.35% RESULT TestThreadCreateAndJoin: gn_x86-64_nnacl_newlib_static= {44.707676, 0.155537} us Measuring clock cycles: first runs (cycles): 137187 205062 208017 180141 159180 251184 176937 143937 142269 135498 ... slowest runs (cycles): ... 150567 151068 159180 160314 174750 176937 180141 205062 208017 251184 min: 125940 cycles q1: 128166 cycles median: 132468 cycles q3: 136593 cycles max: 251184 cycles RESULT TestThreadCreateAndJoin_CycleCount: gn_x86-64_nnacl_newlib_static= {132468, 8427} count Apparent clock speed: 2963 MHz TestThreadWakeup: Measuring real time: 11.473 usec (1.14729e-05 sec) per iteration: 0.00114729 sec for 100 iterations 9.671 usec (9.67133e-06 sec) per iteration: 0.0842953 sec for 8716 iterations 9.963 usec (9.96333e-06 sec) per iteration: 0.0868404 sec for 8716 iterations 9.466 usec (9.4661e-06 sec) per iteration: 0.0825066 sec for 8716 iterations 9.517 usec (9.5171e-06 sec) per iteration: 0.082951 sec for 8716 iterations 9.380 usec (9.37983e-06 sec) per iteration: 0.0817546 sec for 8716 iterations mean: 9.599537 usec stddev: 0.205120 usec relative stddev: 2.14% RESULT TestThreadWakeup: gn_x86-64_nnacl_newlib_static= {9.599537, 0.205120} us Measuring clock cycles: first runs (cycles): 57099 54273 35214 148383 102852 57957 122160 61383 112932 42606 ... slowest runs (cycles): ... 60834 61281 61383 62391 66594 93537 102852 112932 122160 148383 min: 31788 cycles q1: 54471 cycles median: 55839 cycles q3: 57594 cycles max: 148383 cycles RESULT TestThreadWakeup_CycleCount: gn_x86-64_nnacl_newlib_static= {55839, 3123} count Apparent clock speed: 5817 MHz TestCatchingFault: Measuring real time: 16.428 usec (1.64284e-05 sec) per iteration: 0.00164284 sec for 100 iterations 14.118 usec (1.41178e-05 sec) per iteration: 0.0859348 sec for 6087 iterations 14.114 usec (1.41143e-05 sec) per iteration: 0.0859136 sec for 6087 iterations 14.126 usec (1.41265e-05 sec) per iteration: 0.085988 sec for 6087 iterations 14.124 usec (1.41244e-05 sec) per iteration: 0.0859752 sec for 6087 iterations 14.064 usec (1.40644e-05 sec) per iteration: 0.0856098 sec for 6087 iterations mean: 14.109456 usec stddev: 0.022975 usec relative stddev: 0.16% RESULT TestCatchingFault: gn_x86-64_nnacl_newlib_static= {14.109456, 0.022975} us Measuring clock cycles: first runs (cycles): 47250 59307 76233 92544 73668 59271 54033 52620 54678 50949 ... slowest runs (cycles): ... 54033 54678 56439 58944 59271 59307 66072 73668 76233 92544 min: 41349 cycles q1: 42000 cycles median: 42324 cycles q3: 46500 cycles max: 92544 cycles RESULT TestCatchingFault_CycleCount: gn_x86-64_nnacl_newlib_static= {42324, 4500} count Apparent clock speed: 3000 MHz TestThreadCreateAndJoinAfterSettingFaultHandler: Measuring real time: 46.781 usec (4.67806e-05 sec) per iteration: 0.00467806 sec for 100 iterations 44.660 usec (4.46598e-05 sec) per iteration: 0.0954379 sec for 2137 iterations 44.884 usec (4.48842e-05 sec) per iteration: 0.0959176 sec for 2137 iterations 48.119 usec (4.81186e-05 sec) per iteration: 0.102829 sec for 2137 iterations 45.222 usec (4.52216e-05 sec) per iteration: 0.0966386 sec for 2137 iterations 45.329 usec (4.53291e-05 sec) per iteration: 0.0968684 sec for 2137 iterations mean: 45.642667 usec stddev: 1.260709 usec relative stddev: 2.76% RESULT TestThreadCreateAndJoinAfterSettingFaultHandler: gn_x86-64_nnacl_newlib_static= {45.642667, 1.260709} us Measuring clock cycles: first runs (cycles): 134409 262875 267078 309783 156192 147240 132213 135459 149808 137469 ... slowest runs (cycles): ... 138684 147240 149808 156192 172911 188175 191331 262875 267078 309783 min: 126024 cycles q1: 128223 cycles median: 132222 cycles q3: 135573 cycles max: 309783 cycles RESULT TestThreadCreateAndJoinAfterSettingFaultHandler_CycleCount: gn_x86-64_nnacl_newlib_static= {132222, 7350} count Apparent clock speed: 2897 MHz [ OK ] nacl_newlib.run_performance_test (5880 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 gn_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 (11150 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 gn_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 (970 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 gn_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 gn_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 gn_trusted_mac_x86-64 TestNull: Measuring real time: 0.020 usec (2e-08 sec) per iteration: 2e-06 sec for 100 iterations 0.002 usec (2e-09 sec) per iteration: 2e-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.22497e-09 sec) per iteration: 0.101135 sec for 45454545 iterations 0.002 usec (2.207e-09 sec) per iteration: 0.100318 sec for 45454545 iterations 0.002 usec (2.20772e-09 sec) per iteration: 0.100351 sec for 45454545 iterations 0.002 usec (2.19648e-09 sec) per iteration: 0.09984 sec for 45454545 iterations 0.002 usec (2.21962e-09 sec) per iteration: 0.100892 sec for 45454545 iterations mean: 0.002211 usec stddev: 0.000010 usec relative stddev: 0.46% RESULT TestNull: gn_trusted_mac_x86-64= {0.002211, 0.000010} us Measuring clock cycles: first runs (cycles): 144 18 18 27 18 18 27 27 18 18 ... slowest runs (cycles): ... 27 27 27 27 27 27 27 27 27 144 min: 18 cycles q1: 18 cycles median: 18 cycles q3: 27 cycles max: 144 cycles RESULT TestNull_CycleCount: gn_trusted_mac_x86-64= {18, 9} count Apparent clock speed: 8141 MHz TestHostSyscall: Measuring real time: 0.730 usec (7.3e-07 sec) per iteration: 7.3e-05 sec for 100 iterations 0.496 usec (4.96036e-07 sec) per iteration: 0.06795 sec for 136986 iterations 0.493 usec (4.93306e-07 sec) per iteration: 0.067576 sec for 136986 iterations 0.494 usec (4.9389e-07 sec) per iteration: 0.067656 sec for 136986 iterations 0.500 usec (4.9989e-07 sec) per iteration: 0.068478 sec for 136986 iterations 0.495 usec (4.94649e-07 sec) per iteration: 0.06776 sec for 136986 iterations mean: 0.495554 usec stddev: 0.002353 usec relative stddev: 0.47% RESULT TestHostSyscall: gn_trusted_mac_x86-64= {0.495554, 0.002353} us Measuring clock cycles: first runs (cycles): 1671 1533 1512 1467 1458 1455 1470 1455 1458 1470 ... slowest runs (cycles): ... 1473 1473 1473 1473 1473 1476 1512 1533 1671 1686 min: 1455 cycles q1: 1461 cycles median: 1464 cycles q3: 1470 cycles max: 1686 cycles RESULT TestHostSyscall_CycleCount: gn_trusted_mac_x86-64= {1464, 9} count Apparent clock speed: 2954 MHz TestSetjmpLongjmp: Measuring real time: 3.410 usec (3.41e-06 sec) per iteration: 0.000341 sec for 100 iterations 2.323 usec (2.32293e-06 sec) per iteration: 0.06812 sec for 29325 iterations 2.311 usec (2.31124e-06 sec) per iteration: 0.067777 sec for 29325 iterations 2.332 usec (2.33156e-06 sec) per iteration: 0.068373 sec for 29325 iterations 2.345 usec (2.34469e-06 sec) per iteration: 0.068758 sec for 29325 iterations 2.331 usec (2.33078e-06 sec) per iteration: 0.06835 sec for 29325 iterations mean: 2.328239 usec stddev: 0.011003 usec relative stddev: 0.47% RESULT TestSetjmpLongjmp: gn_trusted_mac_x86-64= {2.328239, 0.011003} us Measuring clock cycles: first runs (cycles): 7272 7005 7008 7014 7008 7011 7008 7002 7011 7008 ... slowest runs (cycles): ... 9477 9489 9528 9531 9633 9693 9738 9810 10089 10140 min: 6999 cycles q1: 7014 cycles median: 7050 cycles q3: 8847 cycles max: 10140 cycles RESULT TestSetjmpLongjmp_CycleCount: gn_trusted_mac_x86-64= {7050, 1833} count Apparent clock speed: 3028 MHz TestClockGetTime: Measuring real time: 0.080 usec (8e-08 sec) per iteration: 8e-06 sec for 100 iterations 0.076 usec (7.6e-08 sec) per iteration: 7.6e-05 sec for 1000 iterations 0.066 usec (6.62424e-08 sec) per iteration: 0.087161 sec for 1315789 iterations 0.066 usec (6.6158e-08 sec) per iteration: 0.08705 sec for 1315789 iterations 0.066 usec (6.62485e-08 sec) per iteration: 0.087169 sec for 1315789 iterations 0.065 usec (6.54535e-08 sec) per iteration: 0.086123 sec for 1315789 iterations 0.064 usec (6.3935e-08 sec) per iteration: 0.084125 sec for 1315789 iterations mean: 0.065607 usec stddev: 0.000887 usec relative stddev: 1.35% RESULT TestClockGetTime: gn_trusted_mac_x86-64= {0.065607, 0.000887} us Measuring clock cycles: first runs (cycles): 564 213 201 201 198 210 210 204 204 198 ... slowest runs (cycles): ... 210 210 210 210 210 210 210 210 213 564 min: 198 cycles q1: 201 cycles median: 201 cycles q3: 210 cycles max: 564 cycles RESULT TestClockGetTime_CycleCount: gn_trusted_mac_x86-64= {201, 9} count Apparent clock speed: 3064 MHz TestMmapAnonymous: Measuring real time: 2.930 usec (2.93e-06 sec) per iteration: 0.000293 sec for 100 iterations 1.632 usec (1.63163e-06 sec) per iteration: 0.055686 sec for 34129 iterations 1.613 usec (1.61323e-06 sec) per iteration: 0.055058 sec for 34129 iterations 1.627 usec (1.62656e-06 sec) per iteration: 0.055513 sec for 34129 iterations 1.628 usec (1.62771e-06 sec) per iteration: 0.055552 sec for 34129 iterations 1.628 usec (1.62806e-06 sec) per iteration: 0.055564 sec for 34129 iterations mean: 1.625439 usec stddev: 0.006335 usec relative stddev: 0.39% RESULT TestMmapAnonymous: gn_trusted_mac_x86-64= {1.625439, 0.006335} us Measuring clock cycles: first runs (cycles): 5616 4977 4860 4854 4863 4848 4860 4839 4854 4860 ... slowest runs (cycles): ... 7269 7272 7296 7320 7485 7545 7647 7785 13620 201165 min: 4815 cycles q1: 4860 cycles median: 6528 cycles q3: 6966 cycles max: 201165 cycles RESULT TestMmapAnonymous_CycleCount: gn_trusted_mac_x86-64= {6528, 2106} count Apparent clock speed: 4016 MHz TestAtomicIncrement: Measuring real time: 0.010 usec (1e-08 sec) per iteration: 1e-06 sec for 100 iterations 0.013 usec (1.3e-08 sec) per iteration: 1.3e-05 sec for 1000 iterations 0.008 usec (7.51972e-09 sec) per iteration: 0.057844 sec for 7692307 iterations 0.008 usec (7.60149e-09 sec) per iteration: 0.058473 sec for 7692307 iterations 0.008 usec (7.55677e-09 sec) per iteration: 0.058129 sec for 7692307 iterations 0.008 usec (7.60708e-09 sec) per iteration: 0.058516 sec for 7692307 iterations 0.008 usec (7.54442e-09 sec) per iteration: 0.058034 sec for 7692307 iterations mean: 0.007566 usec stddev: 0.000034 usec relative stddev: 0.44% RESULT TestAtomicIncrement: gn_trusted_mac_x86-64= {0.007566, 0.000034} us Measuring clock cycles: first runs (cycles): 195 54 51 51 54 54 51 42 51 54 ... slowest runs (cycles): ... 54 54 54 54 54 54 54 57 66 195 min: 42 cycles q1: 51 cycles median: 51 cycles q3: 54 cycles max: 195 cycles RESULT TestAtomicIncrement_CycleCount: gn_trusted_mac_x86-64= {51, 3} count Apparent clock speed: 6741 MHz TestUncontendedMutexLock: Measuring real time: 0.230 usec (2.3e-07 sec) per iteration: 2.3e-05 sec for 100 iterations 0.022 usec (2.24388e-08 sec) per iteration: 0.009756 sec for 434782 iterations 0.022 usec (2.22755e-08 sec) per iteration: 0.009685 sec for 434782 iterations 0.023 usec (2.25906e-08 sec) per iteration: 0.009822 sec for 434782 iterations 0.022 usec (2.208e-08 sec) per iteration: 0.0096 sec for 434782 iterations 0.022 usec (2.23537e-08 sec) per iteration: 0.009719 sec for 434782 iterations mean: 0.022348 usec stddev: 0.000170 usec relative stddev: 0.76% RESULT TestUncontendedMutexLock: gn_trusted_mac_x86-64= {0.022348, 0.000170} us Measuring clock cycles: first runs (cycles): 270 105 96 96 84 87 93 90 93 90 ... slowest runs (cycles): ... 102 102 102 102 102 102 102 102 105 270 min: 84 cycles q1: 93 cycles median: 99 cycles q3: 102 cycles max: 270 cycles RESULT TestUncontendedMutexLock_CycleCount: gn_trusted_mac_x86-64= {99, 9} count Apparent clock speed: 4430 MHz TestCondvarSignalNoOp: Measuring real time: 0.110 usec (1.1e-07 sec) per iteration: 1.1e-05 sec for 100 iterations 0.013 usec (1.29041e-08 sec) per iteration: 0.011731 sec for 909090 iterations 0.013 usec (1.26621e-08 sec) per iteration: 0.011511 sec for 909090 iterations 0.013 usec (1.2507e-08 sec) per iteration: 0.01137 sec for 909090 iterations 0.013 usec (1.26027e-08 sec) per iteration: 0.011457 sec for 909090 iterations 0.012 usec (1.23365e-08 sec) per iteration: 0.011215 sec for 909090 iterations mean: 0.012602 usec stddev: 0.000187 usec relative stddev: 1.48% RESULT TestCondvarSignalNoOp: gn_trusted_mac_x86-64= {0.012602, 0.000187} us Measuring clock cycles: first runs (cycles): 303 75 63 63 63 60 63 69 60 63 ... slowest runs (cycles): ... 66 66 66 69 69 72 72 75 75 303 min: 60 cycles q1: 63 cycles median: 63 cycles q3: 63 cycles max: 303 cycles RESULT TestCondvarSignalNoOp_CycleCount: gn_trusted_mac_x86-64= {63, 0} count Apparent clock speed: 4999 MHz TestThreadCreateAndJoin: Measuring real time: 35.830 usec (3.583e-05 sec) per iteration: 0.003583 sec for 100 iterations 18.371 usec (1.83713e-05 sec) per iteration: 0.051256 sec for 2790 iterations 17.886 usec (1.78864e-05 sec) per iteration: 0.049903 sec for 2790 iterations 18.317 usec (1.83172e-05 sec) per iteration: 0.051105 sec for 2790 iterations 18.539 usec (1.85387e-05 sec) per iteration: 0.051723 sec for 2790 iterations 17.852 usec (1.78516e-05 sec) per iteration: 0.049806 sec for 2790 iterations mean: 18.193047 usec stddev: 0.274701 usec relative stddev: 1.51% RESULT TestThreadCreateAndJoin: gn_trusted_mac_x86-64= {18.193047, 0.274701} us Measuring clock cycles: first runs (cycles): 99432 242136 97005 153885 231063 65997 55263 54042 52995 53241 ... slowest runs (cycles): ... 58401 62721 64044 65997 97005 99432 101616 153885 231063 242136 min: 52767 cycles q1: 53184 cycles median: 53406 cycles q3: 53769 cycles max: 242136 cycles RESULT TestThreadCreateAndJoin_CycleCount: gn_trusted_mac_x86-64= {53406, 585} count Apparent clock speed: 2936 MHz TestThreadWakeup: Measuring real time: 9.050 usec (9.05e-06 sec) per iteration: 0.000905 sec for 100 iterations 6.799 usec (6.79926e-06 sec) per iteration: 0.075125 sec for 11049 iterations 6.850 usec (6.8503e-06 sec) per iteration: 0.075689 sec for 11049 iterations 6.679 usec (6.67861e-06 sec) per iteration: 0.073792 sec for 11049 iterations 6.906 usec (6.90551e-06 sec) per iteration: 0.076299 sec for 11049 iterations 6.767 usec (6.76659e-06 sec) per iteration: 0.074764 sec for 11049 iterations mean: 6.800054 usec stddev: 0.076831 usec relative stddev: 1.13% RESULT TestThreadWakeup: gn_trusted_mac_x86-64= {6.800054, 0.076831} us Measuring clock cycles: first runs (cycles): 23379 20535 20379 19932 19464 31902 29775 49995 32133 56550 ... slowest runs (cycles): ... 34302 34758 38106 46740 49572 49995 56550 66048 67170 74799 min: 19230 cycles q1: 19407 cycles median: 19509 cycles q3: 21168 cycles max: 74799 cycles RESULT TestThreadWakeup_CycleCount: gn_trusted_mac_x86-64= {19509, 1761} count Apparent clock speed: 2869 MHz WARNING: should have taken less than 2.000000 secs [ OK ] nacl_newlib.run_trusted_performance_test (3050 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