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

Running command: /b/s/w/ir/cache/vpython/7c7ecd/bin/python scons.py --verbose -k -j1 --mode=nacl,dbg-host platform=x86-64 --clang large_tests scons: Reading SConscript files ... ====================================================================== SCONS ARGS:['scons.py', '--verbose', '-k', '-j1', '--mode=nacl,dbg-host', 'platform=x86-64', '--clang', 'large_tests'] ====================================================================== ====================================================================== Python Info: ====================================================================== darwin 2.7.14+chromium14 (6cc0aad35b-dirty:6cc0aad35b, Oct 3 2017, 17:23:56) [GCC 4.2.1 Compatible Apple LLVM 8.0.0 (clang-800.0.38)] ====================================================================== ENV: ====================================================================== PATH /b/s/w/ir/cache/vpython/7c7ecd/bin:/b/s/w/ir/cipd_bin_packages:/b/s/w/ir/cipd_bin_packages/bin:/b/s/cipd_cache/bin:/opt/local/bin:/opt/local/sbin:/usr/local/sbin:/usr/local/git/bin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/b/s/w/ir/kitchen-checkout/depot_tools ====================================================================== OS: ====================================================================== kern.ostype: Darwin kern.osrelease: 17.7.0 kern.osrevision: 199506 kern.version: Darwin Kernel Version 17.7.0: Thu Jun 21 22:53:14 PDT 2018; root:xnu-4570.71.2~1/RELEASE_X86_64 kern.posix1version: 200112 kern.osversion: 17G65 kern.osproductversion: 10.13.6 ====================================================================== CPU: ====================================================================== hw.machine: x86_64 hw.model: Macmini7,1 hw.ncpu: 4 hw.ncpu: 4 hw.activecpu: 4 hw.physicalcpu: 2 hw.physicalcpu_max: 2 hw.logicalcpu: 4 hw.logicalcpu_max: 4 hw.cputype: 7 hw.cpusubtype: 8 hw.cpu64bit_capable: 1 hw.cpufamily: 280134364 hw.cpufrequency: 3000000000 hw.cpufrequency_min: 3000000000 hw.cpufrequency_max: 3000000000 hw.cputhreadtype: 1 ====================================================================== RAM: ====================================================================== hw.memsize: 17179869184 ====================================================================== LOAD: ====================================================================== TBD ====================================================================== UPTIME: ====================================================================== kern.boottime: { sec = 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 x86-64_nnacl_newlib_static --subarch 64 --arch x86 --capture_output 0 --output_stamp /b/s/w/ir/k/native_client/scons-out/nacl-x86-64/test_results/benchmark_test.out scons-out/dbg-mac-x86-64/staging/sel_ldr -- scons-out/nacl-x86-64/obj/tests/benchmark/benchmark_test.nexe x86-64_nnacl_newlib_static [ RUN ] nacl_newlib.run_benchmark_test scons-out/dbg-mac-x86-64/staging/sel_ldr -- scons-out/nacl-x86-64/obj/tests/benchmark/benchmark_test.nexe x86-64_nnacl_newlib_static [17124,2962969472:12:28:44.546246] Native Client module will be loaded at base address 0x000072a600000000 Running suite of 1 benchmarks: Running Benchmark: Life (SIMD version)... RESULT BenchmarkLife: x86-64_nnacl_newlib_static= {0.131310, 0.004220} seconds --------------------------------------------------------------- Done running benchmark suite. [ OK ] nacl_newlib.run_benchmark_test (1250 ms) /b/s/w/ir/cache/vpython/7c7ecd/bin/python tools/command_tester.py --name nacl_newlib.run_clock_cputime_test --time_warning 60 --time_error 600 --perf_env_description x86-64_nnacl_newlib_static --subarch 64 --arch x86 --output_stamp /b/s/w/ir/k/native_client/scons-out/nacl-x86-64/test_results/clock_cputime_test.out scons-out/dbg-mac-x86-64/staging/sel_ldr -- scons-out/nacl-x86-64/obj/tests/clock/clock_test.nexe -c [ RUN ] nacl_newlib.run_clock_cputime_test scons-out/dbg-mac-x86-64/staging/sel_ldr -- scons-out/nacl-x86-64/obj/tests/clock/clock_test.nexe -c [ OK ] nacl_newlib.run_clock_cputime_test (59180 ms) doSizeCheck(["scons-out/nacl-x86-64/obj/tests/hello_world/hello_world_size.out"], ["scons-out/nacl-x86-64/obj/tests/hello_world/hello_world.nexe"]) RESULT hello_world_size.out: x86-64_nnacl_newlib_static= 524.896 KB RESULT hello_world_size.out: ZIPPED_x86-64_nnacl_newlib_static= 187.825 KB /b/s/w/ir/cache/vpython/7c7ecd/bin/python tools/command_tester.py --name nacl_newlib.run_performance_test --time_warning 10 --time_error 100 --perf_env_description x86-64_nnacl_newlib_static --subarch 64 --arch x86 --capture_output 0 --output_stamp /b/s/w/ir/k/native_client/scons-out/nacl-x86-64/test_results/performance_test.out scons-out/dbg-mac-x86-64/staging/sel_ldr -e -- scons-out/nacl-x86-64/obj/tests/performance/performance_test.nexe x86-64_nnacl_newlib_static [ RUN ] nacl_newlib.run_performance_test scons-out/dbg-mac-x86-64/staging/sel_ldr -e -- scons-out/nacl-x86-64/obj/tests/performance/performance_test.nexe x86-64_nnacl_newlib_static [17134,2962969472:12:29:02.079778] Native Client module will be loaded at base address 0x00006a3a00000000 TestNull: Measuring real time: 0.007 usec (6.64e-09 sec) per iteration: 6.64e-07 sec for 100 iterations 0.002 usec (1.769e-09 sec) per iteration: 1.769e-06 sec for 1000 iterations 0.002 usec (1.5112e-09 sec) per iteration: 1.5112e-05 sec for 10000 iterations 0.001 usec (1.4628e-09 sec) per iteration: 0.0967972 sec for 66172578 iterations 0.001 usec (1.46198e-09 sec) per iteration: 0.096743 sec for 66172578 iterations 0.001 usec (1.47028e-09 sec) per iteration: 0.0972925 sec for 66172578 iterations 0.001 usec (1.45549e-09 sec) per iteration: 0.0963133 sec for 66172578 iterations 0.001 usec (1.46206e-09 sec) per iteration: 0.0967482 sec for 66172578 iterations mean: 0.001463 usec stddev: 0.000005 usec relative stddev: 0.32% RESULT TestNull: x86-64_nnacl_newlib_static= {0.001463, 0.000005} us Measuring clock cycles: first runs (cycles): 144 30 18 39 27 18 18 27 18 18 ... slowest runs (cycles): ... 27 27 27 27 27 27 27 30 39 144 min: 18 cycles q1: 18 cycles median: 18 cycles q3: 27 cycles max: 144 cycles RESULT TestNull_CycleCount: x86-64_nnacl_newlib_static= {18, 9} count Apparent clock speed: 12308 MHz TestNaClSyscall: Measuring real time: 0.230 usec (2.3007e-07 sec) per iteration: 2.3007e-05 sec for 100 iterations 0.153 usec (1.52504e-07 sec) per iteration: 0.066286 sec for 434650 iterations 0.151 usec (1.51193e-07 sec) per iteration: 0.0657159 sec for 434650 iterations 0.150 usec (1.50123e-07 sec) per iteration: 0.0652511 sec for 434650 iterations 0.151 usec (1.5142e-07 sec) per iteration: 0.0658148 sec for 434650 iterations 0.153 usec (1.52564e-07 sec) per iteration: 0.0663119 sec for 434650 iterations mean: 0.151561 usec stddev: 0.000908 usec relative stddev: 0.60% RESULT TestNaClSyscall: x86-64_nnacl_newlib_static= {0.151561, 0.000908} us Measuring clock cycles: first runs (cycles): 699 525 495 492 468 468 471 459 456 465 ... slowest runs (cycles): ... 471 471 474 492 495 516 516 525 558 699 min: 456 cycles q1: 462 cycles median: 465 cycles q3: 468 cycles max: 699 cycles RESULT TestNaClSyscall_CycleCount: x86-64_nnacl_newlib_static= {465, 6} count Apparent clock speed: 3068 MHz TestSetjmpLongjmp: Measuring real time: 0.015 usec (1.482e-08 sec) per iteration: 1.482e-06 sec for 100 iterations 0.010 usec (1.0291e-08 sec) per iteration: 1.0291e-05 sec for 1000 iterations 0.010 usec (9.82996e-09 sec) per iteration: 0.0955199 sec for 9717228 iterations 0.010 usec (9.85281e-09 sec) per iteration: 0.095742 sec for 9717228 iterations 0.010 usec (9.87467e-09 sec) per iteration: 0.0959544 sec for 9717228 iterations 0.010 usec (9.87772e-09 sec) per iteration: 0.095984 sec for 9717228 iterations 0.010 usec (9.80747e-09 sec) per iteration: 0.0953015 sec for 9717228 iterations mean: 0.009849 usec stddev: 0.000027 usec relative stddev: 0.27% RESULT TestSetjmpLongjmp: x86-64_nnacl_newlib_static= {0.009849, 0.000027} us Measuring clock cycles: first runs (cycles): 222 48 36 21 18 18 21 18 30 27 ... slowest runs (cycles): ... 30 30 30 30 30 30 30 36 48 222 min: 18 cycles q1: 18 cycles median: 21 cycles q3: 27 cycles max: 222 cycles RESULT TestSetjmpLongjmp_CycleCount: x86-64_nnacl_newlib_static= {21, 9} count Apparent clock speed: 2132 MHz TestClockGetTime: Measuring real time: 0.311 usec (3.113e-07 sec) per iteration: 3.113e-05 sec for 100 iterations 0.254 usec (2.53748e-07 sec) per iteration: 0.0815121 sec for 321233 iterations 0.253 usec (2.53492e-07 sec) per iteration: 0.0814299 sec for 321233 iterations 0.258 usec (2.57811e-07 sec) per iteration: 0.0828174 sec for 321233 iterations 0.254 usec (2.53794e-07 sec) per iteration: 0.081527 sec for 321233 iterations 0.251 usec (2.50613e-07 sec) per iteration: 0.0805051 sec for 321233 iterations mean: 0.253891 usec stddev: 0.002294 usec relative stddev: 0.90% RESULT TestClockGetTime: x86-64_nnacl_newlib_static= {0.253891, 0.002294} us Measuring clock cycles: first runs (cycles): 1386 825 813 777 783 822 771 774 777 759 ... slowest runs (cycles): ... 813 816 822 825 825 831 834 840 864 1386 min: 753 cycles q1: 765 cycles median: 774 cycles q3: 780 cycles max: 1386 cycles RESULT TestClockGetTime_CycleCount: x86-64_nnacl_newlib_static= {774, 15} count Apparent clock speed: 3049 MHz TestTlsVariable: Measuring real time: 0.013 usec (1.3e-08 sec) per iteration: 1.3e-06 sec for 100 iterations 0.008 usec (8.171e-09 sec) per iteration: 8.171e-06 sec for 1000 iterations 0.007 usec (7.2524e-09 sec) per iteration: 7.2524e-05 sec for 10000 iterations 0.004 usec (4.39282e-09 sec) per iteration: 0.0605705 sec for 13788538 iterations 0.004 usec (4.40518e-09 sec) per iteration: 0.0607409 sec for 13788538 iterations 0.004 usec (4.40523e-09 sec) per iteration: 0.0607417 sec for 13788538 iterations 0.004 usec (4.37621e-09 sec) per iteration: 0.0603415 sec for 13788538 iterations 0.004 usec (4.37648e-09 sec) per iteration: 0.0603453 sec for 13788538 iterations mean: 0.004391 usec stddev: 0.000013 usec relative stddev: 0.29% RESULT TestTlsVariable: x86-64_nnacl_newlib_static= {0.004391, 0.000013} us Measuring clock cycles: first runs (cycles): 324 63 57 33 36 45 18 18 27 18 ... slowest runs (cycles): ... 27 27 27 27 33 36 45 57 63 324 min: 18 cycles q1: 18 cycles median: 18 cycles q3: 27 cycles max: 324 cycles RESULT TestTlsVariable_CycleCount: x86-64_nnacl_newlib_static= {18, 9} count Apparent clock speed: 4099 MHz TestMmapAnonymous: Measuring real time: 7.610 usec (7.60989e-06 sec) per iteration: 0.000760989 sec for 100 iterations 5.094 usec (5.09405e-06 sec) per iteration: 0.0669359 sec for 13140 iterations 5.045 usec (5.04505e-06 sec) per iteration: 0.066292 sec for 13140 iterations 5.075 usec (5.07519e-06 sec) per iteration: 0.066688 sec for 13140 iterations 5.108 usec (5.10764e-06 sec) per iteration: 0.0671144 sec for 13140 iterations 5.046 usec (5.04614e-06 sec) per iteration: 0.0663063 sec for 13140 iterations mean: 5.073617 usec stddev: 0.025095 usec relative stddev: 0.49% RESULT TestMmapAnonymous: x86-64_nnacl_newlib_static= {5.073617, 0.025095} us Measuring clock cycles: first runs (cycles): 18726 15438 15369 15375 15447 15375 15330 56994 91623 33708 ... slowest runs (cycles): ... 33708 36870 40821 41202 45639 46245 56994 65502 80946 91623 min: 14550 cycles q1: 14688 cycles median: 14856 cycles q3: 15375 cycles max: 91623 cycles RESULT TestMmapAnonymous_CycleCount: x86-64_nnacl_newlib_static= {14856, 687} count Apparent clock speed: 2928 MHz TestAtomicIncrement: Measuring real time: 0.015 usec (1.472e-08 sec) per iteration: 1.472e-06 sec for 100 iterations 0.008 usec (7.955e-09 sec) per iteration: 7.955e-06 sec for 1000 iterations 0.019 usec (1.87972e-08 sec) per iteration: 0.000187972 sec for 10000 iterations 0.008 usec (7.5103e-09 sec) per iteration: 0.0399544 sec for 5319941 iterations 0.008 usec (7.59864e-09 sec) per iteration: 0.0404243 sec for 5319941 iterations 0.008 usec (7.54465e-09 sec) per iteration: 0.0401371 sec for 5319941 iterations 0.008 usec (7.7794e-09 sec) per iteration: 0.041386 sec for 5319941 iterations 0.008 usec (7.611e-09 sec) per iteration: 0.0404901 sec for 5319941 iterations mean: 0.007609 usec stddev: 0.000093 usec relative stddev: 1.22% RESULT TestAtomicIncrement: x86-64_nnacl_newlib_static= {0.007609, 0.000093} us Measuring clock cycles: first runs (cycles): 159 51 48 39 39 48 48 48 48 48 ... slowest runs (cycles): ... 48 48 48 48 48 48 48 48 51 159 min: 39 cycles q1: 48 cycles median: 48 cycles q3: 48 cycles max: 159 cycles RESULT TestAtomicIncrement_CycleCount: x86-64_nnacl_newlib_static= {48, 0} count Apparent clock speed: 6308 MHz TestUncontendedMutexLock: Measuring real time: 0.032 usec (3.197e-08 sec) per iteration: 3.197e-06 sec for 100 iterations 0.131 usec (1.30917e-07 sec) per iteration: 0.000130917 sec for 1000 iterations 0.019 usec (1.89937e-08 sec) per iteration: 0.0145082 sec for 763842 iterations 0.019 usec (1.86979e-08 sec) per iteration: 0.0142822 sec for 763842 iterations 0.019 usec (1.89303e-08 sec) per iteration: 0.0144597 sec for 763842 iterations 0.019 usec (1.89635e-08 sec) per iteration: 0.0144851 sec for 763842 iterations 0.019 usec (1.87956e-08 sec) per iteration: 0.0143569 sec for 763842 iterations mean: 0.018876 usec stddev: 0.000112 usec relative stddev: 0.59% RESULT TestUncontendedMutexLock: x86-64_nnacl_newlib_static= {0.018876, 0.000112} us Measuring clock cycles: first runs (cycles): 279 105 78 75 87 75 78 84 78 75 ... slowest runs (cycles): ... 87 87 87 87 87 87 87 87 105 279 min: 75 cycles q1: 75 cycles median: 78 cycles q3: 84 cycles max: 279 cycles RESULT TestUncontendedMutexLock_CycleCount: x86-64_nnacl_newlib_static= {78, 9} count Apparent clock speed: 4132 MHz TestCondvarSignalNoOp: Measuring real time: 0.281 usec (2.8088e-07 sec) per iteration: 2.8088e-05 sec for 100 iterations 0.204 usec (2.04235e-07 sec) per iteration: 0.0727123 sec for 356023 iterations 0.205 usec (2.04786e-07 sec) per iteration: 0.0729086 sec for 356023 iterations 0.205 usec (2.04673e-07 sec) per iteration: 0.0728683 sec for 356023 iterations 0.207 usec (2.06932e-07 sec) per iteration: 0.0736726 sec for 356023 iterations 0.204 usec (2.03692e-07 sec) per iteration: 0.072519 sec for 356023 iterations mean: 0.204864 usec stddev: 0.001104 usec relative stddev: 0.54% RESULT TestCondvarSignalNoOp: x86-64_nnacl_newlib_static= {0.204864, 0.001104} us Measuring clock cycles: first runs (cycles): 1056 711 720 672 645 627 603 621 606 615 ... slowest runs (cycles): ... 630 645 660 666 666 672 687 711 720 1056 min: 603 cycles q1: 609 cycles median: 615 cycles q3: 621 cycles max: 1056 cycles RESULT TestCondvarSignalNoOp_CycleCount: x86-64_nnacl_newlib_static= {615, 12} count Apparent clock speed: 3002 MHz TestThreadCreateAndJoin: Measuring real time: 77.001 usec (7.70008e-05 sec) per iteration: 0.00770008 sec for 100 iterations 46.048 usec (4.60477e-05 sec) per iteration: 0.0597699 sec for 1298 iterations 45.793 usec (4.57934e-05 sec) per iteration: 0.0594399 sec for 1298 iterations 46.229 usec (4.62286e-05 sec) per iteration: 0.0600047 sec for 1298 iterations 45.868 usec (4.58683e-05 sec) per iteration: 0.059537 sec for 1298 iterations 45.569 usec (4.55686e-05 sec) per iteration: 0.059148 sec for 1298 iterations mean: 45.901298 usec stddev: 0.224488 usec relative stddev: 0.49% RESULT TestThreadCreateAndJoin: x86-64_nnacl_newlib_static= {45.901298, 0.224488} us Measuring clock cycles: first runs (cycles): 153927 224526 186135 203223 218151 141402 145299 134850 138312 133020 ... slowest runs (cycles): ... 178737 179634 186135 190056 193698 203223 218151 224526 247188 248805 min: 128694 cycles q1: 130896 cycles median: 135825 cycles q3: 139959 cycles max: 248805 cycles RESULT TestThreadCreateAndJoin_CycleCount: x86-64_nnacl_newlib_static= {135825, 9063} count Apparent clock speed: 2959 MHz TestThreadWakeup: Measuring real time: 12.111 usec (1.21114e-05 sec) per iteration: 0.00121114 sec for 100 iterations 9.962 usec (9.96229e-06 sec) per iteration: 0.0822487 sec for 8256 iterations 10.080 usec (1.00797e-05 sec) per iteration: 0.0832176 sec for 8256 iterations 9.961 usec (9.96135e-06 sec) per iteration: 0.0822409 sec for 8256 iterations 9.885 usec (9.88513e-06 sec) per iteration: 0.0816116 sec for 8256 iterations 9.926 usec (9.9263e-06 sec) per iteration: 0.0819516 sec for 8256 iterations mean: 9.962947 usec stddev: 0.064841 usec relative stddev: 0.65% RESULT TestThreadWakeup: x86-64_nnacl_newlib_static= {9.962947, 0.064841} us Measuring clock cycles: first runs (cycles): 58563 51516 49884 135372 92265 44937 40902 38730 59514 43455 ... slowest runs (cycles): ... 49884 50295 51516 58563 59514 70746 80244 92265 117816 135372 min: 28071 cycles q1: 28647 cycles median: 29397 cycles q3: 30333 cycles max: 135372 cycles RESULT TestThreadWakeup_CycleCount: x86-64_nnacl_newlib_static= {29397, 1686} count Apparent clock speed: 2951 MHz TestCatchingFault: Measuring real time: 16.363 usec (1.63628e-05 sec) per iteration: 0.00163628 sec for 100 iterations 14.281 usec (1.42811e-05 sec) per iteration: 0.0872719 sec for 6111 iterations 14.245 usec (1.4245e-05 sec) per iteration: 0.087051 sec for 6111 iterations 14.274 usec (1.4274e-05 sec) per iteration: 0.0872281 sec for 6111 iterations 14.246 usec (1.42459e-05 sec) per iteration: 0.0870564 sec for 6111 iterations 14.195 usec (1.41952e-05 sec) per iteration: 0.0867471 sec for 6111 iterations mean: 14.248227 usec stddev: 0.030221 usec relative stddev: 0.21% RESULT TestCatchingFault: x86-64_nnacl_newlib_static= {14.248227, 0.030221} us Measuring clock cycles: first runs (cycles): 49923 60366 79773 96564 68772 63159 65580 60216 72807 71904 ... slowest runs (cycles): ... 49923 60216 60366 63159 65580 68772 71904 72807 79773 96564 min: 41820 cycles q1: 42255 cycles median: 42360 cycles q3: 42585 cycles max: 96564 cycles RESULT TestCatchingFault_CycleCount: x86-64_nnacl_newlib_static= {42360, 330} count Apparent clock speed: 2973 MHz TestThreadCreateAndJoinAfterSettingFaultHandler: Measuring real time: 49.134 usec (4.91343e-05 sec) per iteration: 0.00491343 sec for 100 iterations 46.444 usec (4.64442e-05 sec) per iteration: 0.094514 sec for 2035 iterations 45.863 usec (4.58633e-05 sec) per iteration: 0.0933318 sec for 2035 iterations 46.057 usec (4.60575e-05 sec) per iteration: 0.093727 sec for 2035 iterations 46.342 usec (4.63418e-05 sec) per iteration: 0.0943055 sec for 2035 iterations 46.528 usec (4.65278e-05 sec) per iteration: 0.0946841 sec for 2035 iterations mean: 46.246913 usec stddev: 0.248951 usec relative stddev: 0.54% RESULT TestThreadCreateAndJoinAfterSettingFaultHandler: x86-64_nnacl_newlib_static= {46.246913, 0.248951} us Measuring clock cycles: first runs (cycles): 133848 339747 223128 158244 191757 204039 146004 145875 135036 136485 ... slowest runs (cycles): ... 174825 178185 179994 180942 191757 204039 223128 294015 299079 339747 min: 129270 cycles q1: 131280 cycles median: 136440 cycles q3: 141240 cycles max: 339747 cycles RESULT TestThreadCreateAndJoinAfterSettingFaultHandler_CycleCount: x86-64_nnacl_newlib_static= {136440, 9960} count Apparent clock speed: 2950 MHz [ OK ] nacl_newlib.run_performance_test (5290 ms) /b/s/w/ir/cache/vpython/7c7ecd/bin/python /b/s/w/ir/k/native_client/tools/command_tester.py --name nacl_newlib.run_nacl_clock_cputime_test --time_warning 60 --time_error 600 --perf_env_description trusted_mac_x86-64 --subarch 64 --arch x86 --output_stamp /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/test_results/nacl_clock_cputime_test.out /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/src/shared/platform/nacl_clock_test -c [ RUN ] nacl_newlib.run_nacl_clock_cputime_test /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/src/shared/platform/nacl_clock_test -c [ OK ] nacl_newlib.run_nacl_clock_cputime_test (11250 ms) /b/s/w/ir/cache/vpython/7c7ecd/bin/python /b/s/w/ir/k/native_client/tools/command_tester.py --name nacl_newlib.run_nacl_interval_multi_reg_test --time_warning 60 --time_error 600 --perf_env_description trusted_mac_x86-64 --subarch 64 --arch x86 --output_stamp /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/test_results/nacl_interval_multi_reg_test.out /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/src/trusted/interval_multiset/nacl_interval_test -k NaClIntervalListMultiset -k NaClIntervalRangeTree -c 1000000 [ RUN ] nacl_newlib.run_nacl_interval_multi_reg_test /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/src/trusted/interval_multiset/nacl_interval_test -k NaClIntervalListMultiset -k NaClIntervalRangeTree -c 1000000 [ OK ] nacl_newlib.run_nacl_interval_multi_reg_test (1120 ms) /b/s/w/ir/cache/vpython/7c7ecd/bin/python /b/s/w/ir/k/native_client/tools/command_tester.py --name nacl_newlib.run_trusted_performance_test --time_warning 2 --time_error 20 --perf_env_description trusted_mac_x86-64 --subarch 64 --arch x86 --capture_output 0 --output_stamp /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/test_results/performance_test.out /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/tests/performance/performance_test trusted_mac_x86-64 [ RUN ] nacl_newlib.run_trusted_performance_test /b/s/w/ir/k/native_client/scons-out/dbg-mac-x86-64/obj/tests/performance/performance_test trusted_mac_x86-64 TestNull: Measuring real time: 0.030 usec (3e-08 sec) per iteration: 3e-06 sec for 100 iterations 0.003 usec (3e-09 sec) per iteration: 3e-06 sec for 1000 iterations 0.002 usec (2.2e-09 sec) per iteration: 2.2e-05 sec for 10000 iterations 0.002 usec (2.20308e-09 sec) per iteration: 0.10014 sec for 45454545 iterations 0.002 usec (2.21234e-09 sec) per iteration: 0.100561 sec for 45454545 iterations 0.002 usec (2.23208e-09 sec) per iteration: 0.101458 sec for 45454545 iterations 0.002 usec (2.22438e-09 sec) per iteration: 0.101108 sec for 45454545 iterations 0.002 usec (2.22358e-09 sec) per iteration: 0.101072 sec for 45454545 iterations mean: 0.002219 usec stddev: 0.000010 usec relative stddev: 0.46% RESULT TestNull: trusted_mac_x86-64= {0.002219, 0.000010} us Measuring clock cycles: first runs (cycles): 135 27 18 18 27 18 18 27 27 18 ... slowest runs (cycles): ... 27 27 27 27 27 27 27 27 27 135 min: 18 cycles q1: 18 cycles median: 18 cycles q3: 27 cycles max: 135 cycles RESULT TestNull_CycleCount: trusted_mac_x86-64= {18, 9} count Apparent clock speed: 8111 MHz TestHostSyscall: Measuring real time: 0.720 usec (7.2e-07 sec) per iteration: 7.2e-05 sec for 100 iterations 0.496 usec (4.95608e-07 sec) per iteration: 0.068834 sec for 138888 iterations 0.498 usec (4.97818e-07 sec) per iteration: 0.069141 sec for 138888 iterations 0.494 usec (4.94254e-07 sec) per iteration: 0.068646 sec for 138888 iterations 0.506 usec (5.0617e-07 sec) per iteration: 0.070301 sec for 138888 iterations 0.495 usec (4.94528e-07 sec) per iteration: 0.068684 sec for 138888 iterations mean: 0.497676 usec stddev: 0.004429 usec relative stddev: 0.89% RESULT TestHostSyscall: trusted_mac_x86-64= {0.497676, 0.004429} us Measuring clock cycles: first runs (cycles): 1722 1575 1527 1518 1539 1515 1521 1521 1530 1518 ... slowest runs (cycles): ... 1539 1539 1539 1539 1575 1722 1794 1896 1926 2280 min: 1515 cycles q1: 1524 cycles median: 1530 cycles q3: 1533 cycles max: 2280 cycles RESULT TestHostSyscall_CycleCount: trusted_mac_x86-64= {1530, 9} count Apparent clock speed: 3074 MHz TestSetjmpLongjmp: Measuring real time: 4.870 usec (4.87e-06 sec) per iteration: 0.000487 sec for 100 iterations 2.394 usec (2.39376e-06 sec) per iteration: 0.049151 sec for 20533 iterations 2.394 usec (2.39381e-06 sec) per iteration: 0.049152 sec for 20533 iterations 2.395 usec (2.39458e-06 sec) per iteration: 0.049168 sec for 20533 iterations 2.415 usec (2.41514e-06 sec) per iteration: 0.04959 sec for 20533 iterations 2.441 usec (2.44148e-06 sec) per iteration: 0.050131 sec for 20533 iterations mean: 2.407753 usec stddev: 0.018741 usec relative stddev: 0.78% RESULT TestSetjmpLongjmp: trusted_mac_x86-64= {2.407753, 0.018741} us Measuring clock cycles: first runs (cycles): 7557 7233 7212 7254 7245 7236 7233 7236 7239 7248 ... slowest runs (cycles): ... 9867 18891 26139 27168 29709 33264 41523 43344 49317 150408 min: 7050 cycles q1: 7095 cycles median: 7245 cycles q3: 7557 cycles max: 150408 cycles RESULT TestSetjmpLongjmp_CycleCount: trusted_mac_x86-64= {7245, 462} count Apparent clock speed: 3009 MHz TestClockGetTime: Measuring real time: 0.230 usec (2.3e-07 sec) per iteration: 2.3e-05 sec for 100 iterations 0.064 usec (6.41494e-08 sec) per iteration: 0.027891 sec for 434782 iterations 0.064 usec (6.37929e-08 sec) per iteration: 0.027736 sec for 434782 iterations 0.064 usec (6.40988e-08 sec) per iteration: 0.027869 sec for 434782 iterations 0.065 usec (6.52603e-08 sec) per iteration: 0.028374 sec for 434782 iterations 0.064 usec (6.4131e-08 sec) per iteration: 0.027883 sec for 434782 iterations mean: 0.064286 usec stddev: 0.000504 usec relative stddev: 0.78% RESULT TestClockGetTime: trusted_mac_x86-64= {0.064286, 0.000504} us Measuring clock cycles: first runs (cycles): 615 222 198 201 201 210 207 207 198 198 ... slowest runs (cycles): ... 210 210 210 210 210 210 210 210 222 615 min: 198 cycles q1: 201 cycles median: 201 cycles q3: 210 cycles max: 615 cycles RESULT TestClockGetTime_CycleCount: trusted_mac_x86-64= {201, 9} count Apparent clock speed: 3127 MHz TestMmapAnonymous: Measuring real time: 4.000 usec (4e-06 sec) per iteration: 0.0004 sec for 100 iterations 1.604 usec (1.60428e-06 sec) per iteration: 0.040107 sec for 25000 iterations 1.624 usec (1.62376e-06 sec) per iteration: 0.040594 sec for 25000 iterations 1.593 usec (1.59268e-06 sec) per iteration: 0.039817 sec for 25000 iterations 1.628 usec (1.62752e-06 sec) per iteration: 0.040688 sec for 25000 iterations 1.619 usec (1.61868e-06 sec) per iteration: 0.040467 sec for 25000 iterations mean: 1.613384 usec stddev: 0.013016 usec relative stddev: 0.81% RESULT TestMmapAnonymous: trusted_mac_x86-64= {1.613384, 0.013016} us Measuring clock cycles: first runs (cycles): 5376 4794 4776 4764 4773 4908 4800 4803 4773 4794 ... slowest runs (cycles): ... 7257 7263 7323 7410 7428 7434 7551 7677 7998 36162 min: 4752 cycles q1: 4794 cycles median: 4848 cycles q3: 6669 cycles max: 36162 cycles RESULT TestMmapAnonymous_CycleCount: trusted_mac_x86-64= {4848, 1875} count Apparent clock speed: 3005 MHz TestAtomicIncrement: Measuring real time: 0.010 usec (1e-08 sec) per iteration: 1e-06 sec for 100 iterations 0.012 usec (1.2e-08 sec) per iteration: 1.2e-05 sec for 1000 iterations 0.008 usec (7.56084e-09 sec) per iteration: 0.063007 sec for 8333333 iterations 0.008 usec (7.60176e-09 sec) per iteration: 0.063348 sec for 8333333 iterations 0.008 usec (7.63584e-09 sec) per iteration: 0.063632 sec for 8333333 iterations 0.008 usec (7.569e-09 sec) per iteration: 0.063075 sec for 8333333 iterations 0.008 usec (7.59684e-09 sec) per iteration: 0.063307 sec for 8333333 iterations mean: 0.007593 usec stddev: 0.000027 usec relative stddev: 0.35% RESULT TestAtomicIncrement: trusted_mac_x86-64= {0.007593, 0.000027} us Measuring clock cycles: first runs (cycles): 174 54 45 51 51 54 54 54 51 51 ... slowest runs (cycles): ... 54 54 54 54 54 54 57 60 66 174 min: 42 cycles q1: 51 cycles median: 51 cycles q3: 54 cycles max: 174 cycles RESULT TestAtomicIncrement_CycleCount: trusted_mac_x86-64= {51, 3} count Apparent clock speed: 6717 MHz TestUncontendedMutexLock: Measuring real time: 0.350 usec (3.5e-07 sec) per iteration: 3.5e-05 sec for 100 iterations 0.023 usec (2.29775e-08 sec) per iteration: 0.006565 sec for 285714 iterations 0.023 usec (2.25085e-08 sec) per iteration: 0.006431 sec for 285714 iterations 0.022 usec (2.21585e-08 sec) per iteration: 0.006331 sec for 285714 iterations 0.022 usec (2.20255e-08 sec) per iteration: 0.006293 sec for 285714 iterations 0.023 usec (2.2925e-08 sec) per iteration: 0.00655 sec for 285714 iterations mean: 0.022519 usec stddev: 0.000387 usec relative stddev: 1.72% RESULT TestUncontendedMutexLock: trusted_mac_x86-64= {0.022519, 0.000387} us Measuring clock cycles: first runs (cycles): 282 102 96 96 93 96 102 90 93 90 ... slowest runs (cycles): ... 102 102 102 102 102 102 102 102 105 282 min: 90 cycles q1: 93 cycles median: 99 cycles q3: 102 cycles max: 282 cycles RESULT TestUncontendedMutexLock_CycleCount: trusted_mac_x86-64= {99, 9} count Apparent clock speed: 4396 MHz TestCondvarSignalNoOp: Measuring real time: 0.120 usec (1.2e-07 sec) per iteration: 1.2e-05 sec for 100 iterations 0.013 usec (1.26372e-08 sec) per iteration: 0.010531 sec for 833333 iterations 0.013 usec (1.33212e-08 sec) per iteration: 0.011101 sec for 833333 iterations 0.013 usec (1.2564e-08 sec) per iteration: 0.01047 sec for 833333 iterations 0.013 usec (1.27788e-08 sec) per iteration: 0.010649 sec for 833333 iterations 0.013 usec (1.25376e-08 sec) per iteration: 0.010448 sec for 833333 iterations mean: 0.012768 usec stddev: 0.000289 usec relative stddev: 2.26% RESULT TestCondvarSignalNoOp: trusted_mac_x86-64= {0.012768, 0.000289} us Measuring clock cycles: first runs (cycles): 285 78 60 63 63 63 60 69 66 63 ... slowest runs (cycles): ... 69 69 69 69 69 72 75 78 78 285 min: 60 cycles q1: 63 cycles median: 63 cycles q3: 66 cycles max: 285 cycles RESULT TestCondvarSignalNoOp_CycleCount: trusted_mac_x86-64= {63, 3} count Apparent clock speed: 4934 MHz TestThreadCreateAndJoin: Measuring real time: 35.730 usec (3.573e-05 sec) per iteration: 0.003573 sec for 100 iterations 18.939 usec (1.89385e-05 sec) per iteration: 0.05299 sec for 2798 iterations 18.460 usec (1.84596e-05 sec) per iteration: 0.05165 sec for 2798 iterations 18.120 usec (1.81204e-05 sec) per iteration: 0.050701 sec for 2798 iterations 17.877 usec (1.78774e-05 sec) per iteration: 0.050021 sec for 2798 iterations 18.153 usec (1.81526e-05 sec) per iteration: 0.050791 sec for 2798 iterations mean: 18.309721 usec stddev: 0.364765 usec relative stddev: 1.99% RESULT TestThreadCreateAndJoin: trusted_mac_x86-64= {18.309721, 0.364765} us Measuring clock cycles: first runs (cycles): 98019 82710 66330 139173 165411 111300 116061 100938 148863 67389 ... slowest runs (cycles): ... 66330 67389 82710 98019 100938 111300 116061 139173 148863 165411 min: 52482 cycles q1: 52845 cycles median: 52995 cycles q3: 53232 cycles max: 165411 cycles RESULT TestThreadCreateAndJoin_CycleCount: trusted_mac_x86-64= {52995, 387} count Apparent clock speed: 2894 MHz TestThreadWakeup: Measuring real time: 9.100 usec (9.1e-06 sec) per iteration: 0.00091 sec for 100 iterations 6.868 usec (6.86778e-06 sec) per iteration: 0.07547 sec for 10989 iterations 9.073 usec (9.07344e-06 sec) per iteration: 0.099708 sec for 10989 iterations 8.987 usec (8.98662e-06 sec) per iteration: 0.098754 sec for 10989 iterations 8.941 usec (8.94085e-06 sec) per iteration: 0.098251 sec for 10989 iterations 8.991 usec (8.99126e-06 sec) per iteration: 0.098805 sec for 10989 iterations mean: 8.571990 usec stddev: 0.853178 usec relative stddev: 9.95% RESULT TestThreadWakeup: trusted_mac_x86-64= {8.571990, 0.853178} us Measuring clock cycles: first runs (cycles): 35736 31695 31017 30837 58695 51528 48624 66354 30666 75273 ... slowest runs (cycles): ... 58695 61149 66354 72282 75273 86916 91383 106788 110448 114618 min: 21018 cycles q1: 24075 cycles median: 25218 cycles q3: 32484 cycles max: 114618 cycles RESULT TestThreadWakeup_CycleCount: trusted_mac_x86-64= {25218, 8409} count Apparent clock speed: 2942 MHz WARNING: should have taken less than 2.000000 secs [ OK ] nacl_newlib.run_trusted_performance_test (2680 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