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 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,opt-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.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 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 [19751,2531390336:15:04:44.781101] Native Client module will be loaded at base address 0x0000482900000000 Running suite of 1 benchmarks: Running Benchmark: Life (SIMD version)... RESULT BenchmarkLife: gn_x86-64_nnacl_newlib_static= {0.066130, 0.000760} seconds --------------------------------------------------------------- Done running benchmark suite. [ OK ] nacl_newlib.run_benchmark_test (860 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 WARNING: should have taken less than 60.000000 secs [ OK ] nacl_newlib.run_clock_cputime_test (67400 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 [19757,2531390336:15:04:59.241890] Native Client module will be loaded at base address 0x000030ea00000000 TestNull: Measuring real time: 0.007 usec (6.59e-09 sec) per iteration: 6.59e-07 sec for 100 iterations 0.002 usec (2.284e-09 sec) per iteration: 2.284e-06 sec for 1000 iterations 0.002 usec (2.0266e-09 sec) per iteration: 2.0266e-05 sec for 10000 iterations 0.002 usec (2.02284e-09 sec) per iteration: 0.0998145 sec for 49343728 iterations 0.002 usec (2.00961e-09 sec) per iteration: 0.0991614 sec for 49343728 iterations 0.002 usec (2.01351e-09 sec) per iteration: 0.099354 sec for 49343728 iterations 0.002 usec (2.01397e-09 sec) per iteration: 0.0993769 sec for 49343728 iterations 0.002 usec (2.02746e-09 sec) per iteration: 0.100042 sec for 49343728 iterations mean: 0.002017 usec stddev: 0.000007 usec relative stddev: 0.33% RESULT TestNull: gn_x86-64_nnacl_newlib_static= {0.002017, 0.000007} us Measuring clock cycles: first runs (cycles): 237 21 18 30 30 30 30 30 21 21 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 30 30 237 min: 18 cycles q1: 21 cycles median: 30 cycles q3: 30 cycles max: 237 cycles RESULT TestNull_CycleCount: gn_x86-64_nnacl_newlib_static= {30, 9} count Apparent clock speed: 14870 MHz TestNaClSyscall: Measuring real time: 0.158 usec (1.5802e-07 sec) per iteration: 1.5802e-05 sec for 100 iterations 0.158 usec (1.58062e-07 sec) per iteration: 0.100027 sec for 632831 iterations 0.145 usec (1.45103e-07 sec) per iteration: 0.0918256 sec for 632831 iterations 0.158 usec (1.58353e-07 sec) per iteration: 0.10021 sec for 632831 iterations 0.158 usec (1.58125e-07 sec) per iteration: 0.100067 sec for 632831 iterations 0.155 usec (1.55061e-07 sec) per iteration: 0.0981273 sec for 632831 iterations mean: 0.154941 usec stddev: 0.005066 usec relative stddev: 3.27% RESULT TestNaClSyscall: gn_x86-64_nnacl_newlib_static= {0.154941, 0.005066} us Measuring clock cycles: first runs (cycles): 918 486 426 459 462 432 435 420 423 426 ... slowest runs (cycles): ... 435 435 435 435 435 435 459 462 486 918 min: 384 cycles q1: 414 cycles median: 420 cycles q3: 426 cycles max: 918 cycles RESULT TestNaClSyscall_CycleCount: gn_x86-64_nnacl_newlib_static= {420, 12} count Apparent clock speed: 2711 MHz TestSetjmpLongjmp: Measuring real time: 0.021 usec (2.094e-08 sec) per iteration: 2.094e-06 sec for 100 iterations 0.016 usec (1.5951e-08 sec) per iteration: 1.5951e-05 sec for 1000 iterations 0.013 usec (1.31538e-08 sec) per iteration: 0.0824638 sec for 6269199 iterations 0.012 usec (1.22205e-08 sec) per iteration: 0.0766127 sec for 6269199 iterations 0.012 usec (1.20999e-08 sec) per iteration: 0.0758564 sec for 6269199 iterations 0.012 usec (1.21307e-08 sec) per iteration: 0.0760497 sec for 6269199 iterations 0.012 usec (1.22027e-08 sec) per iteration: 0.0765009 sec for 6269199 iterations mean: 0.012361 usec stddev: 0.000399 usec relative stddev: 3.22% RESULT TestSetjmpLongjmp: gn_x86-64_nnacl_newlib_static= {0.012361, 0.000399} us Measuring clock cycles: first runs (cycles): 375 60 24 33 36 33 33 24 24 24 ... slowest runs (cycles): ... 33 33 33 33 33 33 33 36 60 375 min: 24 cycles q1: 24 cycles median: 33 cycles q3: 33 cycles max: 375 cycles RESULT TestSetjmpLongjmp_CycleCount: gn_x86-64_nnacl_newlib_static= {33, 9} count Apparent clock speed: 2670 MHz TestClockGetTime: Measuring real time: 0.159 usec (1.5883e-07 sec) per iteration: 1.5883e-05 sec for 100 iterations 0.159 usec (1.58945e-07 sec) per iteration: 0.100073 sec for 629603 iterations 0.158 usec (1.58044e-07 sec) per iteration: 0.0995053 sec for 629603 iterations 0.161 usec (1.60721e-07 sec) per iteration: 0.10119 sec for 629603 iterations 0.229 usec (2.29296e-07 sec) per iteration: 0.144366 sec for 629603 iterations 0.174 usec (1.73895e-07 sec) per iteration: 0.109485 sec for 629603 iterations mean: 0.176180 usec stddev: 0.027171 usec relative stddev: 15.42% RESULT TestClockGetTime: gn_x86-64_nnacl_newlib_static= {0.176180, 0.027171} us Measuring clock cycles: first runs (cycles): 2478 693 516 606 567 1260 588 549 567 552 ... slowest runs (cycles): ... 675 678 687 693 693 699 747 804 1260 2478 min: 495 cycles q1: 588 cycles median: 621 cycles q3: 642 cycles max: 2478 cycles RESULT TestClockGetTime_CycleCount: gn_x86-64_nnacl_newlib_static= {621, 54} count Apparent clock speed: 3525 MHz TestTlsVariable: Measuring real time: 0.013 usec (1.309e-08 sec) per iteration: 1.309e-06 sec for 100 iterations 0.010 usec (9.81e-09 sec) per iteration: 9.81e-06 sec for 1000 iterations 0.010 usec (9.5952e-09 sec) per iteration: 9.5952e-05 sec for 10000 iterations 0.007 usec (6.74748e-09 sec) per iteration: 0.0703214 sec for 10421877 iterations 0.006 usec (6.09724e-09 sec) per iteration: 0.0635447 sec for 10421877 iterations 0.006 usec (6.02801e-09 sec) per iteration: 0.0628231 sec for 10421877 iterations 0.006 usec (6.04602e-09 sec) per iteration: 0.0630109 sec for 10421877 iterations 0.006 usec (6.08516e-09 sec) per iteration: 0.0634188 sec for 10421877 iterations mean: 0.006201 usec stddev: 0.000275 usec relative stddev: 4.43% RESULT TestTlsVariable: gn_x86-64_nnacl_newlib_static= {0.006201, 0.000275} us Measuring clock cycles: first runs (cycles): 267 66 30 30 33 33 21 21 21 21 ... slowest runs (cycles): ... 30 30 30 30 30 30 33 33 66 267 min: 21 cycles q1: 21 cycles median: 21 cycles q3: 30 cycles max: 267 cycles RESULT TestTlsVariable_CycleCount: gn_x86-64_nnacl_newlib_static= {21, 9} count Apparent clock speed: 3387 MHz TestMmapAnonymous: Measuring real time: 8.864 usec (8.86437e-06 sec) per iteration: 0.000886437 sec for 100 iterations 8.574 usec (8.57394e-06 sec) per iteration: 0.0967227 sec for 11281 iterations 9.271 usec (9.27106e-06 sec) per iteration: 0.104587 sec for 11281 iterations 8.468 usec (8.46783e-06 sec) per iteration: 0.0955256 sec for 11281 iterations 8.438 usec (8.43801e-06 sec) per iteration: 0.0951891 sec for 11281 iterations 8.367 usec (8.36738e-06 sec) per iteration: 0.0943924 sec for 11281 iterations mean: 8.623644 usec stddev: 0.330465 usec relative stddev: 3.83% RESULT TestMmapAnonymous: gn_x86-64_nnacl_newlib_static= {8.623644, 0.330465} us Measuring clock cycles: first runs (cycles): 31947 23127 22425 22161 22251 22296 22254 22167 22269 22038 ... slowest runs (cycles): ... 38541 38973 39237 39243 39270 40113 40140 40197 40728 40842 min: 21939 cycles q1: 22218 cycles median: 22569 cycles q3: 35076 cycles max: 40842 cycles RESULT TestMmapAnonymous_CycleCount: gn_x86-64_nnacl_newlib_static= {22569, 12858} count Apparent clock speed: 2617 MHz TestAtomicIncrement: Measuring real time: 0.014 usec (1.399e-08 sec) per iteration: 1.399e-06 sec for 100 iterations 0.010 usec (9.901e-09 sec) per iteration: 9.901e-06 sec for 1000 iterations 0.010 usec (9.6903e-09 sec) per iteration: 9.6903e-05 sec for 10000 iterations 0.010 usec (1.03254e-08 sec) per iteration: 0.106554 sec for 10319597 iterations 0.011 usec (1.05156e-08 sec) per iteration: 0.108517 sec for 10319597 iterations 0.010 usec (9.72534e-09 sec) per iteration: 0.100362 sec for 10319597 iterations 0.010 usec (9.76743e-09 sec) per iteration: 0.100796 sec for 10319597 iterations 0.010 usec (9.73778e-09 sec) per iteration: 0.10049 sec for 10319597 iterations mean: 0.010014 usec stddev: 0.000337 usec relative stddev: 3.37% RESULT TestAtomicIncrement: gn_x86-64_nnacl_newlib_static= {0.010014, 0.000337} us Measuring clock cycles: first runs (cycles): 258 51 51 48 51 51 51 42 51 51 ... slowest runs (cycles): ... 51 51 51 51 51 51 51 51 51 258 min: 42 cycles q1: 51 cycles median: 51 cycles q3: 51 cycles max: 258 cycles RESULT TestAtomicIncrement_CycleCount: gn_x86-64_nnacl_newlib_static= {51, 0} count Apparent clock speed: 5093 MHz TestUncontendedMutexLock: Measuring real time: 0.028 usec (2.805e-08 sec) per iteration: 2.805e-06 sec for 100 iterations 0.023 usec (2.3265e-08 sec) per iteration: 2.3265e-05 sec for 1000 iterations 0.024 usec (2.4063e-08 sec) per iteration: 0.10343 sec for 4298302 iterations 0.026 usec (2.6157e-08 sec) per iteration: 0.112431 sec for 4298302 iterations 0.024 usec (2.3531e-08 sec) per iteration: 0.101143 sec for 4298302 iterations 0.023 usec (2.31743e-08 sec) per iteration: 0.0996101 sec for 4298302 iterations 0.023 usec (2.31226e-08 sec) per iteration: 0.0993878 sec for 4298302 iterations mean: 0.024010 usec stddev: 0.001125 usec relative stddev: 4.69% RESULT TestUncontendedMutexLock: gn_x86-64_nnacl_newlib_static= {0.024010, 0.001125} us Measuring clock cycles: first runs (cycles): 465 132 93 90 90 93 90 96 84 99 ... slowest runs (cycles): ... 108 108 111 111 114 117 123 129 132 465 min: 78 cycles q1: 84 cycles median: 90 cycles q3: 93 cycles max: 465 cycles RESULT TestUncontendedMutexLock_CycleCount: gn_x86-64_nnacl_newlib_static= {90, 9} count Apparent clock speed: 3749 MHz TestCondvarSignalNoOp: Measuring real time: 0.379 usec (3.7874e-07 sec) per iteration: 3.7874e-05 sec for 100 iterations 0.161 usec (1.61393e-07 sec) per iteration: 0.0426132 sec for 264033 iterations 0.179 usec (1.78522e-07 sec) per iteration: 0.0471357 sec for 264033 iterations 0.216 usec (2.16449e-07 sec) per iteration: 0.0571498 sec for 264033 iterations 0.223 usec (2.23394e-07 sec) per iteration: 0.0589833 sec for 264033 iterations 0.223 usec (2.22946e-07 sec) per iteration: 0.0588651 sec for 264033 iterations mean: 0.200541 usec stddev: 0.025670 usec relative stddev: 12.80% RESULT TestCondvarSignalNoOp: gn_x86-64_nnacl_newlib_static= {0.200541, 0.025670} us Measuring clock cycles: first runs (cycles): 1683 666 576 609 606 675 633 627 693 582 ... slowest runs (cycles): ... 696 699 702 714 714 720 723 729 732 1683 min: 552 cycles q1: 606 cycles median: 633 cycles q3: 663 cycles max: 1683 cycles RESULT TestCondvarSignalNoOp_CycleCount: gn_x86-64_nnacl_newlib_static= {633, 57} count Apparent clock speed: 3156 MHz TestThreadCreateAndJoin: Measuring real time: 68.143 usec (6.81428e-05 sec) per iteration: 0.00681428 sec for 100 iterations 71.755 usec (7.17554e-05 sec) per iteration: 0.105265 sec for 1467 iterations 70.474 usec (7.04741e-05 sec) per iteration: 0.103385 sec for 1467 iterations 67.398 usec (6.73976e-05 sec) per iteration: 0.0988723 sec for 1467 iterations 64.472 usec (6.44722e-05 sec) per iteration: 0.0945806 sec for 1467 iterations 67.023 usec (6.70232e-05 sec) per iteration: 0.0983231 sec for 1467 iterations mean: 68.224488 usec stddev: 2.597479 usec relative stddev: 3.81% RESULT TestThreadCreateAndJoin: gn_x86-64_nnacl_newlib_static= {68.224488, 2.597479} us Measuring clock cycles: first runs (cycles): 230319 234756 201714 184803 192141 271152 256878 211767 186720 179898 ... slowest runs (cycles): ... 186720 192141 194520 200892 201714 211767 230319 234756 256878 271152 min: 170220 cycles q1: 171957 cycles median: 172977 cycles q3: 174642 cycles max: 271152 cycles RESULT TestThreadCreateAndJoin_CycleCount: gn_x86-64_nnacl_newlib_static= {172977, 2685} count Apparent clock speed: 2535 MHz TestThreadWakeup: Measuring real time: 33.854 usec (3.38535e-05 sec) per iteration: 0.00338535 sec for 100 iterations 31.909 usec (3.19093e-05 sec) per iteration: 0.0942283 sec for 2953 iterations 31.968 usec (3.19679e-05 sec) per iteration: 0.0944011 sec for 2953 iterations 32.132 usec (3.21324e-05 sec) per iteration: 0.0948871 sec for 2953 iterations 30.909 usec (3.0909e-05 sec) per iteration: 0.0912744 sec for 2953 iterations 30.909 usec (3.09094e-05 sec) per iteration: 0.0912756 sec for 2953 iterations mean: 31.565622 usec stddev: 0.540903 usec relative stddev: 1.71% RESULT TestThreadWakeup: gn_x86-64_nnacl_newlib_static= {31.565622, 0.540903} us Measuring clock cycles: first runs (cycles): 82053 72480 71484 71823 78243 100359 107511 92502 109683 73821 ... slowest runs (cycles): ... 89412 92502 94071 95334 95454 100359 105237 107511 109683 166923 min: 70605 cycles q1: 82668 cycles median: 83970 cycles q3: 85362 cycles max: 166923 cycles RESULT TestThreadWakeup_CycleCount: gn_x86-64_nnacl_newlib_static= {83970, 2694} count Apparent clock speed: 2660 MHz TestCatchingFault: Measuring real time: 37.090 usec (3.70902e-05 sec) per iteration: 0.00370902 sec for 100 iterations 32.978 usec (3.29783e-05 sec) per iteration: 0.0889095 sec for 2696 iterations 31.365 usec (3.13648e-05 sec) per iteration: 0.0845596 sec for 2696 iterations 31.448 usec (3.14478e-05 sec) per iteration: 0.0847834 sec for 2696 iterations 30.879 usec (3.08788e-05 sec) per iteration: 0.0832492 sec for 2696 iterations 31.236 usec (3.12359e-05 sec) per iteration: 0.0842119 sec for 2696 iterations mean: 31.581120 usec stddev: 0.725144 usec relative stddev: 2.30% RESULT TestCatchingFault: gn_x86-64_nnacl_newlib_static= {31.581120, 0.725144} us Measuring clock cycles: first runs (cycles): 105714 84060 82998 84225 83931 122955 145881 102429 83010 139722 ... slowest runs (cycles): ... 111204 111219 116538 117387 119748 122955 132723 139722 140994 145881 min: 80499 cycles q1: 81714 cycles median: 82596 cycles q3: 84189 cycles max: 145881 cycles RESULT TestCatchingFault_CycleCount: gn_x86-64_nnacl_newlib_static= {82596, 2475} count Apparent clock speed: 2615 MHz TestThreadCreateAndJoinAfterSettingFaultHandler: Measuring real time: 71.202 usec (7.1202e-05 sec) per iteration: 0.0071202 sec for 100 iterations 66.706 usec (6.67056e-05 sec) per iteration: 0.0936546 sec for 1404 iterations 67.188 usec (6.71883e-05 sec) per iteration: 0.0943324 sec for 1404 iterations 68.120 usec (6.81204e-05 sec) per iteration: 0.095641 sec for 1404 iterations 67.127 usec (6.71266e-05 sec) per iteration: 0.0942457 sec for 1404 iterations 68.596 usec (6.85961e-05 sec) per iteration: 0.0963089 sec for 1404 iterations mean: 67.547382 usec stddev: 0.698961 usec relative stddev: 1.03% RESULT TestThreadCreateAndJoinAfterSettingFaultHandler: gn_x86-64_nnacl_newlib_static= {67.547382, 0.698961} us Measuring clock cycles: first runs (cycles): 171258 178812 234294 219198 292968 262962 241170 257679 236433 249396 ... slowest runs (cycles): ... 250506 251643 252303 257679 258825 261087 262962 270069 283626 292968 min: 171258 cycles q1: 223323 cycles median: 235581 cycles q3: 242295 cycles max: 292968 cycles RESULT TestThreadCreateAndJoinAfterSettingFaultHandler_CycleCount: gn_x86-64_nnacl_newlib_static= {235581, 18972} count Apparent clock speed: 3488 MHz [ OK ] nacl_newlib.run_performance_test (6279 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/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 (1560 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/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 (690 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/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 gn_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 gn_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.6851e-09 sec) per iteration: 0.099448 sec for 37037037 iterations 0.003 usec (2.78537e-09 sec) per iteration: 0.103162 sec for 37037037 iterations 0.003 usec (2.67465e-09 sec) per iteration: 0.099061 sec for 37037037 iterations 0.003 usec (2.67249e-09 sec) per iteration: 0.098981 sec for 37037037 iterations 0.003 usec (2.67257e-09 sec) per iteration: 0.098984 sec for 37037037 iterations mean: 0.002698 usec stddev: 0.000044 usec relative stddev: 1.63% RESULT TestNull: gn_trusted_mac_x86-64= {0.002698, 0.000044} us Measuring clock cycles: first runs (cycles): 183 30 27 21 18 21 18 21 18 30 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 30 30 183 min: 18 cycles q1: 18 cycles median: 21 cycles q3: 27 cycles max: 183 cycles RESULT TestNull_CycleCount: gn_trusted_mac_x86-64= {21, 9} count Apparent clock speed: 7783 MHz TestHostSyscall: Measuring real time: 1.300 usec (1.3e-06 sec) per iteration: 0.00013 sec for 100 iterations 0.977 usec (9.76756e-07 sec) per iteration: 0.075135 sec for 76923 iterations 0.979 usec (9.79447e-07 sec) per iteration: 0.075342 sec for 76923 iterations 0.976 usec (9.75768e-07 sec) per iteration: 0.075059 sec for 76923 iterations 0.953 usec (9.52784e-07 sec) per iteration: 0.073291 sec for 76923 iterations 0.947 usec (9.47285e-07 sec) per iteration: 0.072868 sec for 76923 iterations mean: 0.966408 usec stddev: 0.013535 usec relative stddev: 1.40% RESULT TestHostSyscall: gn_trusted_mac_x86-64= {0.966408, 0.013535} us Measuring clock cycles: first runs (cycles): 2784 2556 2517 2526 2526 2526 2526 2526 2517 2526 ... slowest runs (cycles): ... 2556 2556 2556 2559 2559 2559 2559 2559 2559 2784 min: 2517 cycles q1: 2526 cycles median: 2547 cycles q3: 2550 cycles max: 2784 cycles RESULT TestHostSyscall_CycleCount: gn_trusted_mac_x86-64= {2547, 24} count Apparent clock speed: 2636 MHz TestSetjmpLongjmp: Measuring real time: 4.920 usec (4.92e-06 sec) per iteration: 0.000492 sec for 100 iterations 4.625 usec (4.62534e-06 sec) per iteration: 0.09401 sec for 20325 iterations 4.723 usec (4.72325e-06 sec) per iteration: 0.096 sec for 20325 iterations 4.666 usec (4.66578e-06 sec) per iteration: 0.094832 sec for 20325 iterations 4.670 usec (4.66982e-06 sec) per iteration: 0.094914 sec for 20325 iterations 5.289 usec (5.2895e-06 sec) per iteration: 0.107509 sec for 20325 iterations mean: 4.794736 usec stddev: 0.249330 usec relative stddev: 5.20% RESULT TestSetjmpLongjmp: gn_trusted_mac_x86-64= {4.794736, 0.249330} us Measuring clock cycles: first runs (cycles): 13488 12105 12048 12057 12051 12069 12048 12057 12063 12072 ... slowest runs (cycles): ... 12087 12090 12093 12096 12102 12102 12105 12105 12129 13488 min: 12039 cycles q1: 12057 cycles median: 12066 cycles q3: 12078 cycles max: 13488 cycles RESULT TestSetjmpLongjmp_CycleCount: gn_trusted_mac_x86-64= {12066, 21} count Apparent clock speed: 2517 MHz TestClockGetTime: Measuring real time: 0.080 usec (8e-08 sec) per iteration: 8e-06 sec for 100 iterations 0.097 usec (9.7e-08 sec) per iteration: 9.7e-05 sec for 1000 iterations 0.082 usec (8.1936e-08 sec) per iteration: 0.08447 sec for 1030927 iterations 0.082 usec (8.15615e-08 sec) per iteration: 0.084084 sec for 1030927 iterations 0.076 usec (7.62877e-08 sec) per iteration: 0.078647 sec for 1030927 iterations 0.076 usec (7.61208e-08 sec) per iteration: 0.078475 sec for 1030927 iterations 0.076 usec (7.63691e-08 sec) per iteration: 0.078731 sec for 1030927 iterations mean: 0.078455 usec stddev: 0.002693 usec relative stddev: 3.43% RESULT TestClockGetTime: gn_trusted_mac_x86-64= {0.078455, 0.002693} us Measuring clock cycles: first runs (cycles): 1209 222 207 207 207 204 207 210 210 207 ... slowest runs (cycles): ... 210 210 210 210 210 210 210 213 222 1209 min: 189 cycles q1: 204 cycles median: 207 cycles q3: 210 cycles max: 1209 cycles RESULT TestClockGetTime_CycleCount: gn_trusted_mac_x86-64= {207, 6} count Apparent clock speed: 2638 MHz TestMmapAnonymous: Measuring real time: 3.670 usec (3.67e-06 sec) per iteration: 0.000367 sec for 100 iterations 3.072 usec (3.07241e-06 sec) per iteration: 0.083714 sec for 27247 iterations 3.107 usec (3.1072e-06 sec) per iteration: 0.084662 sec for 27247 iterations 3.175 usec (3.17496e-06 sec) per iteration: 0.086508 sec for 27247 iterations 3.167 usec (3.16703e-06 sec) per iteration: 0.086292 sec for 27247 iterations 3.062 usec (3.06217e-06 sec) per iteration: 0.083435 sec for 27247 iterations mean: 3.116754 usec stddev: 0.046800 usec relative stddev: 1.50% RESULT TestMmapAnonymous: gn_trusted_mac_x86-64= {3.116754, 0.046800} us Measuring clock cycles: first runs (cycles): 12408 8568 8319 8262 8286 8271 8373 8253 8256 8259 ... slowest runs (cycles): ... 8400 8400 8403 8406 8421 8424 8451 8457 8568 12408 min: 8244 cycles q1: 8262 cycles median: 8289 cycles q3: 8304 cycles max: 12408 cycles RESULT TestMmapAnonymous_CycleCount: gn_trusted_mac_x86-64= {8289, 42} count Apparent clock speed: 2659 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.3e-09 sec) per iteration: 7.3e-05 sec for 10000 iterations 0.007 usec (7.36139e-09 sec) per iteration: 0.100841 sec for 13698630 iterations 0.007 usec (7.39147e-09 sec) per iteration: 0.101253 sec for 13698630 iterations 0.007 usec (7.37935e-09 sec) per iteration: 0.101087 sec for 13698630 iterations 0.007 usec (7.37242e-09 sec) per iteration: 0.100992 sec for 13698630 iterations 0.007 usec (7.34935e-09 sec) per iteration: 0.100676 sec for 13698630 iterations mean: 0.007371 usec stddev: 0.000015 usec relative stddev: 0.20% RESULT TestAtomicIncrement: gn_trusted_mac_x86-64= {0.007371, 0.000015} us Measuring clock cycles: first runs (cycles): 228 54 51 54 39 48 48 39 48 48 ... slowest runs (cycles): ... 51 51 51 51 51 54 54 54 54 228 min: 39 cycles q1: 48 cycles median: 48 cycles q3: 48 cycles max: 228 cycles RESULT TestAtomicIncrement_CycleCount: gn_trusted_mac_x86-64= {48, 0} count Apparent clock speed: 6512 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.65251e-08 sec) per iteration: 0.012631 sec for 476190 iterations 0.027 usec (2.65503e-08 sec) per iteration: 0.012643 sec for 476190 iterations 0.026 usec (2.63529e-08 sec) per iteration: 0.012549 sec for 476190 iterations 0.027 usec (2.65293e-08 sec) per iteration: 0.012633 sec for 476190 iterations 0.027 usec (2.65209e-08 sec) per iteration: 0.012629 sec for 476190 iterations mean: 0.026496 usec stddev: 0.000072 usec relative stddev: 0.27% RESULT TestUncontendedMutexLock: gn_trusted_mac_x86-64= {0.026496, 0.000072} us Measuring clock cycles: first runs (cycles): 387 120 84 84 96 96 93 93 96 87 ... slowest runs (cycles): ... 96 96 96 96 96 96 96 96 120 387 min: 84 cycles q1: 87 cycles median: 93 cycles q3: 96 cycles max: 387 cycles RESULT TestUncontendedMutexLock_CycleCount: gn_trusted_mac_x86-64= {93, 9} count Apparent clock speed: 3510 MHz TestCondvarSignalNoOp: Measuring real time: 0.110 usec (1.1e-07 sec) per iteration: 1.1e-05 sec for 100 iterations 0.014 usec (1.36873e-08 sec) per iteration: 0.012443 sec for 909090 iterations 0.014 usec (1.36862e-08 sec) per iteration: 0.012442 sec for 909090 iterations 0.014 usec (1.36796e-08 sec) per iteration: 0.012436 sec for 909090 iterations 0.014 usec (1.36785e-08 sec) per iteration: 0.012435 sec for 909090 iterations 0.014 usec (1.36829e-08 sec) per iteration: 0.012439 sec for 909090 iterations mean: 0.013683 usec stddev: 0.000003 usec relative stddev: 0.03% RESULT TestCondvarSignalNoOp: gn_trusted_mac_x86-64= {0.013683, 0.000003} us Measuring clock cycles: first runs (cycles): 594 84 60 60 60 60 60 60 60 60 ... slowest runs (cycles): ... 72 72 72 72 72 72 72 81 84 594 min: 60 cycles q1: 60 cycles median: 63 cycles q3: 63 cycles max: 594 cycles RESULT TestCondvarSignalNoOp_CycleCount: gn_trusted_mac_x86-64= {63, 3} count Apparent clock speed: 4604 MHz TestThreadCreateAndJoin: Measuring real time: 81.280 usec (8.128e-05 sec) per iteration: 0.008128 sec for 100 iterations 80.416 usec (8.04163e-05 sec) per iteration: 0.098912 sec for 1230 iterations 80.780 usec (8.07805e-05 sec) per iteration: 0.09936 sec for 1230 iterations 80.480 usec (8.04805e-05 sec) per iteration: 0.098991 sec for 1230 iterations 82.164 usec (8.21642e-05 sec) per iteration: 0.101062 sec for 1230 iterations 82.763 usec (8.27634e-05 sec) per iteration: 0.101799 sec for 1230 iterations mean: 81.320976 usec stddev: 0.960079 usec relative stddev: 1.18% RESULT TestThreadCreateAndJoin: gn_trusted_mac_x86-64= {81.320976, 0.960079} us Measuring clock cycles: first runs (cycles): 248928 280881 280821 251049 266064 223605 248910 272466 151479 141762 ... slowest runs (cycles): ... 261447 262872 264102 266064 269529 272010 272466 280821 280881 321306 min: 140955 cycles q1: 229272 cycles median: 244809 cycles q3: 250851 cycles max: 321306 cycles RESULT TestThreadCreateAndJoin_CycleCount: gn_trusted_mac_x86-64= {244809, 21579} count Apparent clock speed: 3010 MHz TestThreadWakeup: Measuring real time: 21.540 usec (2.154e-05 sec) per iteration: 0.002154 sec for 100 iterations 20.766 usec (2.07658e-05 sec) per iteration: 0.096395 sec for 4642 iterations 20.233 usec (2.02331e-05 sec) per iteration: 0.093922 sec for 4642 iterations 20.534 usec (2.05345e-05 sec) per iteration: 0.095321 sec for 4642 iterations 20.657 usec (2.06566e-05 sec) per iteration: 0.095888 sec for 4642 iterations 19.976 usec (1.99757e-05 sec) per iteration: 0.092727 sec for 4642 iterations mean: 20.433132 usec stddev: 0.289898 usec relative stddev: 1.42% RESULT TestThreadWakeup: gn_trusted_mac_x86-64= {20.433132, 0.289898} us Measuring clock cycles: first runs (cycles): 66417 54969 58203 61488 52488 54720 83289 65268 104328 69957 ... slowest runs (cycles): ... 76845 79194 83289 83604 85881 100689 102771 104328 105288 108381 min: 49665 cycles q1: 51537 cycles median: 52146 cycles q3: 61308 cycles max: 108381 cycles RESULT TestThreadWakeup_CycleCount: gn_trusted_mac_x86-64= {52146, 9771} count Apparent clock speed: 2552 MHz WARNING: should have taken less than 2.000000 secs [ OK ] nacl_newlib.run_trusted_performance_test (3890 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