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

Running command: /b/s/w/ir/cache/vpython/4b93a2/bin/python scons.py --verbose -k -j1 --mode=nacl,dbg-host platform=x86-32 breakpad_tools_dir=breakpad-out large_tests scons: Reading SConscript files ... ====================================================================== SCONS ARGS:['scons.py', '--verbose', '-k', '-j1', '--mode=nacl,dbg-host', 'platform=x86-32', 'breakpad_tools_dir=breakpad-out', 'large_tests'] ====================================================================== ====================================================================== Python Info: ====================================================================== linux2 2.7.14+chromium14 (df075345c7-dirty:df075345c7, Oct 3 2017, 17:29:00) [GCC 4.8.4] ====================================================================== ENV: ====================================================================== PATH /b/s/w/ir/cache/vpython/4b93a2/bin:/b/s/w/ir/cipd_bin_packages:/b/s/w/ir/cipd_bin_packages/bin:/b/s/cipd_cache/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin:/b/s/w/ir/kitchen-checkout/depot_tools ====================================================================== OS: ====================================================================== Linux gce-trusty-e833d7b0-us-east1-b-g34h 4.4.0-78-generic #99~14.04.2-Ubuntu SMP Thu Apr 27 18:49:46 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux ====================================================================== CPU: ====================================================================== model name : Intel(R) Xeon(R) CPU @ 2.20GHz stepping : 0 cpu MHz : 2200.000 model name : Intel(R) Xeon(R) CPU @ 2.20GHz stepping : 0 cpu MHz : 2200.000 model name : Intel(R) Xeon(R) CPU @ 2.20GHz stepping : 0 cpu MHz : 2200.000 model name : Intel(R) Xeon(R) CPU @ 2.20GHz stepping : 0 cpu MHz : 2200.000 model name : Intel(R) Xeon(R) CPU @ 2.20GHz stepping : 0 cpu MHz : 2200.000 model name : Intel(R) Xeon(R) CPU @ 2.20GHz stepping : 0 cpu MHz : 2200.000 model name : Intel(R) Xeon(R) CPU @ 2.20GHz stepping : 0 cpu MHz : 2200.000 model name : Intel(R) Xeon(R) CPU @ 2.20GHz stepping : 0 cpu MHz : 2200.000 ====================================================================== RAM: ====================================================================== MemTotal: 30882896 kB MemFree: 14153604 kB MemAvailable: 29421568 kB ====================================================================== LOAD: ====================================================================== 1.40 2.42 2.03 1/438 11564 ====================================================================== UPTIME: ====================================================================== 9346.46 62683.23 ====================================================================== The following environments have been configured ====================================================================== NACL_BUILD_FAMILY: UNTRUSTED BUILD_TYPE: nacl TARGET_ROOT: /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32 OBJ_ROOT: /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32/obj BUILD_TYPE_DESCRIPTION: NaCl module build BUILD_OS: BUILD_ARCHITECTURE: x86 BUILD_SUBARCH: 32 TARGET_OS: TARGET_ARCHITECTURE: x86 TARGET_SUBARCH: 32 CC: /b/s/w/ir/kitchen-workdir/native_client/toolchain/linux_x86/pnacl_newlib_raw/bin/x86_64-nacl-clang ASPPCOM: /b/s/w/ir/kitchen-workdir/native_client/toolchain/linux_x86/pnacl_newlib_raw/bin/x86_64-nacl-clang -m32 -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=32 -I/b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32/include -I/b/s/w/ir/kitchen-workdir -c -o UNKNOWN COMPILER NACL_BUILD_FAMILY: TRUSTED BUILD_TYPE: dbg-linux TARGET_ROOT: /b/s/w/ir/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32 OBJ_ROOT: /b/s/w/ir/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32/obj BUILD_TYPE_DESCRIPTION: Linux dbg build BUILD_OS: BUILD_ARCHITECTURE: x86 BUILD_SUBARCH: 32 TARGET_OS: TARGET_ARCHITECTURE: x86 TARGET_SUBARCH: 32 CC: gcc ASPPCOM: gcc -fPIE -m32 -Wall -pedantic -Wextra -Wno-long-long -Wswitch-enum -Wsign-compare -Wundef -fdiagnostics-show-option -fvisibility=hidden -fstack-protector -Werror -Wno-variadic-macros --param ssp-buffer-size=4 -O0 -g -D_FORTIFY_SOURCE=2 -D_POSIX_C_SOURCE=199506 -D_XOPEN_SOURCE=600 -D_GNU_SOURCE=1 -D_LARGEFILE64_SOURCE=1 -D__STDC_LIMIT_MACROS=1 -D__STDC_FORMAT_MACROS=1 -D_DEBUG -I/b/s/w/ir/kitchen-workdir -c -o set BOTO_CONFIG='/home/chrome-bot/.boto' BUILDBOT_BUILDERNAME='linux-32-newlib-dbg' BUILDBOT_BUILDNUMBER='87' BUILDBOT_GOT_REVISION='8e13fe5e85640b063aefcb88a3ccb52abf6e28e8' BUILDBOT_MASTERNAME='client.nacl' BUILDBOT_REVISION='8e13fe5e85640b063aefcb88a3ccb52abf6e28e8' BUILDBOT_SLAVE_TYPE='BuilderTester' BUILDBUCKET_EXPERIMENTAL='FALSE' CIPD_CACHE_DIR='/b/s/cipd_cache/cache' CIPD_PROTOCOL='v2' CYGWIN='nodosfilewarning' DEVSHELL_CLIENT_PORT='46852' DOCKER_CONFIG='/b/s/w/ir/tmp/docker_cfg_task' DOCKER_TMPDIR='/b/s/w/ir/tmp/docker_tmp_task' GIT_CONFIG_NOSYSTEM='1' GIT_TERMINAL_PROMPT='0' GOMA_DIR='/b/s/w/ir/cache/goma/client' GOMA_TMP_DIR='/b/s/w/ir/tmp/rt/goma' GSUTIL='/b/s/w/ir/kitchen-checkout/depot_tools/gsutil.py' HOME='/home/chrome-bot' IFS=' ' INFRA_GIT_WRAPPER_HOME='/b/s/w/ir/tmp/git_home_task' LOGDOG_COORDINATOR_HOST='logs.chromium.org' LOGDOG_STREAM_PREFIX='buildbucket/cr-buildbucket.appspot.com/8927838581177241648' LOGDOG_STREAM_PROJECT='nacl' LOGDOG_STREAM_SERVER_PATH='unix:/b/s/w/ir/tmp/ld.sock' LOGNAME='chrome-bot' LUCI_CONTEXT='/b/s/w/itQriU2T/luci_context.801948804' MAC_CHROMIUM_TMPDIR='/b/s/w/ir/tmp/t' MAIL='/var/mail/chrome-bot' NATIVE_PYTHON='python' NOCONTROL_GOMA='1' NO_GCE_CHECK='False' OPTIND='1' PATH='/b/s/w/ir/cache/vpython/4b93a2/bin:/b/s/w/ir/cipd_bin_packages:/b/s/w/ir/cipd_bin_packages/bin:/b/s/cipd_cache/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin:/b/s/w/ir/kitchen-checkout/depot_tools' PPID='11537' PS1='$ ' PS2='> ' PS4='+ ' PWD='/b/s/w/ir/kitchen-workdir/native_client' PYTHONDONTWRITEBYTECODE='1' PYTHONIOENCODING='UTF-8' PYTHONNOUSERSITE='1' PYTHONPATH='/b/s/w/ir/kitchen-checkout/build/scripts:/b/s/w/ir/kitchen-checkout/build/site_config' PYTHONUNBUFFERED='1' QEMU_PREFIX_HOOK='' RUNTEST='/b/s/w/ir/kitchen-checkout/build/scripts/slave/runtest.py' SHELL='/bin/bash' SHLVL='1' SUDO_COMMAND='/usr/bin/python /b/s/swarming_bot.zip start_bot' SUDO_GID='0' SUDO_UID='0' SUDO_USER='root' SWARMING_BOT_ID='gce-trusty-e833d7b0-us-east1-b-g34h' SWARMING_EXTERNAL_BOT_SETUP='1' SWARMING_HEADLESS='1' SWARMING_SERVER='https://chromium-swarm.appspot.com' SWARMING_TASK_ID='419f21cd8223dc11' TEMP='/b/s/w/ir/tmp/t/nacl_tmp/linux-32-newlib-dbg' TEMPDIR='/b/s/w/ir/tmp/t' TERM='linux' TMP='/b/s/w/ir/tmp/t/nacl_tmp/linux-32-newlib-dbg' TMPDIR='/b/s/w/ir/tmp/t/nacl_tmp/linux-32-newlib-dbg' USER='chrome-bot' USERNAME='chrome-bot' VIRTUAL_ENV='/b/s/w/ir/cache/vpython/4b93a2' VPYTHON_VIRTUALENV_ROOT='/b/s/w/ir/cache/vpython' _='/b/s/w/ir/cipd_bin_packages/vpython' gcc -v -c Using built-in specs. COLLECT_GCC=gcc Target: x86_64-linux-gnu Configured with: ../src/configure -v --with-pkgversion='Ubuntu 4.8.4-2ubuntu1~14.04.4' --with-bugurl=file:///usr/share/doc/gcc-4.8/README.Bugs --enable-languages=c,c++,java,go,d,fortran,objc,obj-c++ --prefix=/usr --program-suffix=-4.8 --enable-shared --enable-linker-build-id --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --with-gxx-include-dir=/usr/include/c++/4.8 --libdir=/usr/lib --enable-nls --with-sysroot=/ --enable-clocale=gnu --enable-libstdcxx-debug --enable-libstdcxx-time=yes --enable-gnu-unique-object --disable-libmudflap --enable-plugin --with-system-zlib --disable-browser-plugin --enable-java-awt=gtk --enable-gtk-cairo --with-java-home=/usr/lib/jvm/java-1.5.0-gcj-4.8-amd64/jre --enable-java-home --with-jvm-root-dir=/usr/lib/jvm/java-1.5.0-gcj-4.8-amd64 --with-jvm-jar-dir=/usr/lib/jvm-exports/java-1.5.0-gcj-4.8-amd64 --with-arch-directory=amd64 --with-ecj-jar=/usr/share/java/eclipse-ecj.jar --enable-objc-gc --enable-multiarch --disable-werror --with-arch-32=i686 --with-abi=m64 --with-multilib-list=m32,m64,mx32 --with-tune=generic --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu Thread model: posix gcc version 4.8.4 (Ubuntu 4.8.4-2ubuntu1~14.04.4) gcc -print-search-dirs install: /usr/lib/gcc/x86_64-linux-gnu/4.8/ programs: =/usr/lib/gcc/x86_64-linux-gnu/4.8/:/usr/lib/gcc/x86_64-linux-gnu/4.8/:/usr/lib/gcc/x86_64-linux-gnu/:/usr/lib/gcc/x86_64-linux-gnu/4.8/:/usr/lib/gcc/x86_64-linux-gnu/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../x86_64-linux-gnu/bin/x86_64-linux-gnu/4.8/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../x86_64-linux-gnu/bin/x86_64-linux-gnu/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../x86_64-linux-gnu/bin/ libraries: =/usr/lib/gcc/x86_64-linux-gnu/4.8/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../x86_64-linux-gnu/lib/x86_64-linux-gnu/4.8/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../x86_64-linux-gnu/lib/x86_64-linux-gnu/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../x86_64-linux-gnu/lib/../lib/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../x86_64-linux-gnu/4.8/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../x86_64-linux-gnu/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../lib/:/lib/x86_64-linux-gnu/4.8/:/lib/x86_64-linux-gnu/:/lib/../lib/:/usr/lib/x86_64-linux-gnu/4.8/:/usr/lib/x86_64-linux-gnu/:/usr/lib/../lib/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../../x86_64-linux-gnu/lib/:/usr/lib/gcc/x86_64-linux-gnu/4.8/../../../:/lib/:/usr/lib/ gcc -print-libgcc-file-name /usr/lib/gcc/x86_64-linux-gnu/4.8/libgcc.a NACL_BUILD_FAMILY: UNTRUSTED_IRT BUILD_TYPE: nacl_irt TARGET_ROOT: /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl_irt-x86-32 OBJ_ROOT: /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl_irt-x86-32/obj BUILD_TYPE_DESCRIPTION: NaCl IRT build BUILD_OS: BUILD_ARCHITECTURE: x86 BUILD_SUBARCH: 32 TARGET_OS: TARGET_ARCHITECTURE: x86 TARGET_SUBARCH: 32 CC: /b/s/w/ir/kitchen-workdir/native_client/toolchain/linux_x86/pnacl_newlib_raw/bin/x86_64-nacl-clang ASPPCOM: /b/s/w/ir/kitchen-workdir/native_client/toolchain/linux_x86/pnacl_newlib_raw/bin/x86_64-nacl-clang -m32 -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=32 -I/b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl_irt-x86-32/include -I/b/s/w/ir/kitchen-workdir -I/b/s/w/ir/kitchen-workdir/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_nacl_sync_cond_test There are 12 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/4b93a2/bin/python /b/s/w/ir/kitchen-workdir/native_client/tools/command_tester.py --name nacl_newlib.run_signal_handler_single_step_test --time_warning 2 --time_error 20 --perf_env_description x86-32_nnacl_newlib_static --subarch 32 --arch x86 --capture_output 0 --output_stamp /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32/test_results/signal_handler_single_step.out /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32/obj/tests/signal_handler_single_step/step_test_host /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32/obj/tests/signal_handler_single_step/step_test_guest.nexe x86-32_nnacl_newlib_static [ RUN ] nacl_newlib.run_signal_handler_single_step_test /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32/obj/tests/signal_handler_single_step/step_test_host /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32/obj/tests/signal_handler_single_step/step_test_guest.nexe x86-32_nnacl_newlib_static [11591,4148262656:18:09:05.035101] Native Client module will be loaded at base address 0x000000006de10000 Switching to untrusted: since previous switch: 154 instructions, 376 instruction bytes, 27 jumps Switching to trusted: since previous switch: 12 instructions, 39 instruction bytes, 3 jumps Switching to untrusted: since previous switch: 610 instructions, 1430 instruction bytes, 109 jumps Switching to trusted: since previous switch: 10 instructions, 23 instruction bytes, 4 jumps Switching to untrusted: since previous switch: 610 instructions, 1430 instruction bytes, 109 jumps Switching to trusted: since previous switch: 10 instructions, 23 instruction bytes, 4 jumps Switching to untrusted: since previous switch: 610 instructions, 1430 instruction bytes, 109 jumps Switching to trusted: since previous switch: 10 instructions, 23 instruction bytes, 4 jumps Switching to untrusted: since previous switch: 610 instructions, 1430 instruction bytes, 109 jumps RESULT InstructionsPerSyscall: x86-32_nnacl_newlib_static= 610 count RESULT InstructionBytesPerSyscall: x86-32_nnacl_newlib_static= 1430 count RESULT JumpsPerSyscall: x86-32_nnacl_newlib_static= 109 count Switching to trusted: since previous switch: 10 instructions, 23 instruction bytes, 4 jumps [ OK ] nacl_newlib.run_signal_handler_single_step_test (10 ms) /b/s/w/ir/cache/vpython/4b93a2/bin/python tools/command_tester.py --name nacl_newlib.run_benchmark_test --time_warning 10 --time_error 100 --perf_env_description x86-32_nnacl_newlib_static --using_nacl_signal_handler True --subarch 32 --arch x86 --capture_output 0 --output_stamp /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32/test_results/benchmark_test.out scons-out/dbg-linux-x86-32/staging/nacl_helper_bootstrap scons-out/dbg-linux-x86-32/staging/sel_ldr --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -- scons-out/nacl-x86-32/obj/tests/benchmark/benchmark_test.nexe x86-32_nnacl_newlib_static [ RUN ] nacl_newlib.run_benchmark_test scons-out/dbg-linux-x86-32/staging/nacl_helper_bootstrap scons-out/dbg-linux-x86-32/staging/sel_ldr --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -- scons-out/nacl-x86-32/obj/tests/benchmark/benchmark_test.nexe x86-32_nnacl_newlib_static [11596,4147750656:18:09:05.381107] Native Client module will be loaded at base address 0x0000000000000000 Running suite of 1 benchmarks: Running Benchmark: Life (SIMD version)... RESULT BenchmarkLife: x86-32_nnacl_newlib_static= {0.115320, 0.007460} seconds --------------------------------------------------------------- Done running benchmark suite. [ OK ] nacl_newlib.run_benchmark_test (1880 ms) /b/s/w/ir/cache/vpython/4b93a2/bin/python tools/command_tester.py --name nacl_newlib.run_clock_cputime_test --time_warning 60 --time_error 600 --perf_env_description x86-32_nnacl_newlib_static --using_nacl_signal_handler True --subarch 32 --arch x86 --output_stamp /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32/test_results/clock_cputime_test.out scons-out/dbg-linux-x86-32/staging/nacl_helper_bootstrap scons-out/dbg-linux-x86-32/staging/sel_ldr --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -- scons-out/nacl-x86-32/obj/tests/clock/clock_test.nexe -c [ RUN ] nacl_newlib.run_clock_cputime_test scons-out/dbg-linux-x86-32/staging/nacl_helper_bootstrap scons-out/dbg-linux-x86-32/staging/sel_ldr --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -- scons-out/nacl-x86-32/obj/tests/clock/clock_test.nexe -c WARNING: should have taken less than 60.000000 secs [ OK ] nacl_newlib.run_clock_cputime_test (70610 ms) doSizeCheck(["scons-out/nacl-x86-32/obj/tests/hello_world/hello_world_size.out"], ["scons-out/nacl-x86-32/obj/tests/hello_world/hello_world.nexe"]) RESULT hello_world_size.out: x86-32_nnacl_newlib_static= 512.216 KB RESULT hello_world_size.out: ZIPPED_x86-32_nnacl_newlib_static= 171.095 KB /b/s/w/ir/cache/vpython/4b93a2/bin/python tools/command_tester.py --name nacl_newlib.run_performance_test --time_warning 10 --time_error 100 --perf_env_description x86-32_nnacl_newlib_static --using_nacl_signal_handler True --subarch 32 --arch x86 --capture_output 0 --output_stamp /b/s/w/ir/kitchen-workdir/native_client/scons-out/nacl-x86-32/test_results/performance_test.out scons-out/dbg-linux-x86-32/staging/nacl_helper_bootstrap scons-out/dbg-linux-x86-32/staging/sel_ldr --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -e -- scons-out/nacl-x86-32/obj/tests/performance/performance_test.nexe x86-32_nnacl_newlib_static [ RUN ] nacl_newlib.run_performance_test scons-out/dbg-linux-x86-32/staging/nacl_helper_bootstrap scons-out/dbg-linux-x86-32/staging/sel_ldr --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -e -- scons-out/nacl-x86-32/obj/tests/performance/performance_test.nexe x86-32_nnacl_newlib_static [11624,4147590912:18:09:19.885741] Native Client module will be loaded at base address 0x0000000000000000 TestNull: Measuring real time: 0.014 usec (1.441e-08 sec) per iteration: 1.441e-06 sec for 100 iterations 0.003 usec (2.895e-09 sec) per iteration: 2.895e-06 sec for 1000 iterations 0.002 usec (2.2909e-09 sec) per iteration: 2.2909e-05 sec for 10000 iterations 0.002 usec (2.32284e-09 sec) per iteration: 0.101394 sec for 43650966 iterations 0.002 usec (2.31999e-09 sec) per iteration: 0.10127 sec for 43650966 iterations 0.002 usec (2.29395e-09 sec) per iteration: 0.100133 sec for 43650966 iterations 0.002 usec (2.29599e-09 sec) per iteration: 0.100222 sec for 43650966 iterations 0.002 usec (2.36548e-09 sec) per iteration: 0.103256 sec for 43650966 iterations mean: 0.002320 usec stddev: 0.000026 usec relative stddev: 1.11% RESULT TestNull: x86-32_nnacl_newlib_static= {0.002320, 0.000026} us Measuring clock cycles: first runs (cycles): 88 47 22 24 22 25 25 27 24 24 ... slowest runs (cycles): ... 25 26 26 26 26 27 27 27 47 88 min: 22 cycles q1: 22 cycles median: 24 cycles q3: 24 cycles max: 88 cycles RESULT TestNull_CycleCount: x86-32_nnacl_newlib_static= {24, 2} count Apparent clock speed: 10346 MHz TestNaClSyscall: Measuring real time: 0.323 usec (3.2349e-07 sec) per iteration: 3.2349e-05 sec for 100 iterations 0.323 usec (3.22801e-07 sec) per iteration: 0.0997867 sec for 309128 iterations 0.323 usec (3.22699e-07 sec) per iteration: 0.0997552 sec for 309128 iterations 0.324 usec (3.23812e-07 sec) per iteration: 0.100099 sec for 309128 iterations 0.327 usec (3.26551e-07 sec) per iteration: 0.100946 sec for 309128 iterations 0.322 usec (3.22342e-07 sec) per iteration: 0.0996449 sec for 309128 iterations mean: 0.323641 usec stddev: 0.001535 usec relative stddev: 0.47% RESULT TestNaClSyscall: x86-32_nnacl_newlib_static= {0.323641, 0.001535} us Measuring clock cycles: first runs (cycles): 816 761 699 739 697 704 695 700 704 704 ... slowest runs (cycles): ... 708 708 722 737 739 739 755 761 816 16380 min: 690 cycles q1: 696 cycles median: 698 cycles q3: 702 cycles max: 16380 cycles RESULT TestNaClSyscall_CycleCount: x86-32_nnacl_newlib_static= {698, 6} count Apparent clock speed: 2157 MHz TestSetjmpLongjmp: Measuring real time: 0.022 usec (2.185e-08 sec) per iteration: 2.185e-06 sec for 100 iterations 0.013 usec (1.2681e-08 sec) per iteration: 1.2681e-05 sec for 1000 iterations 0.012 usec (1.23296e-08 sec) per iteration: 0.0972289 sec for 7885813 iterations 0.012 usec (1.2343e-08 sec) per iteration: 0.0973342 sec for 7885813 iterations 0.012 usec (1.24247e-08 sec) per iteration: 0.0979788 sec for 7885813 iterations 0.012 usec (1.2425e-08 sec) per iteration: 0.0979809 sec for 7885813 iterations 0.012 usec (1.23707e-08 sec) per iteration: 0.097553 sec for 7885813 iterations mean: 0.012379 usec stddev: 0.000040 usec relative stddev: 0.32% RESULT TestSetjmpLongjmp: x86-32_nnacl_newlib_static= {0.012379, 0.000040} us Measuring clock cycles: first runs (cycles): 158 86 41 39 35 40 35 35 36 39 ... slowest runs (cycles): ... 41 41 42 42 42 42 42 42 86 158 min: 33 cycles q1: 36 cycles median: 39 cycles q3: 40 cycles max: 158 cycles RESULT TestSetjmpLongjmp_CycleCount: x86-32_nnacl_newlib_static= {39, 4} count Apparent clock speed: 3151 MHz TestClockGetTime: Measuring real time: 0.609 usec (6.0885e-07 sec) per iteration: 6.0885e-05 sec for 100 iterations 0.615 usec (6.14663e-07 sec) per iteration: 0.100955 sec for 164244 iterations 0.620 usec (6.19912e-07 sec) per iteration: 0.101817 sec for 164244 iterations 0.618 usec (6.18308e-07 sec) per iteration: 0.101553 sec for 164244 iterations 0.613 usec (6.13401e-07 sec) per iteration: 0.100747 sec for 164244 iterations 0.621 usec (6.21468e-07 sec) per iteration: 0.102072 sec for 164244 iterations mean: 0.617551 usec stddev: 0.003068 usec relative stddev: 0.50% RESULT TestClockGetTime: x86-32_nnacl_newlib_static= {0.617551, 0.003068} us Measuring clock cycles: first runs (cycles): 1671 1413 1335 1326 1325 1337 1335 1386 1373 1368 ... slowest runs (cycles): ... 1384 1386 1386 1397 1399 1413 1463 1639 1671 1687 min: 1315 cycles q1: 1327 cycles median: 1331 cycles q3: 1338 cycles max: 1687 cycles RESULT TestClockGetTime_CycleCount: x86-32_nnacl_newlib_static= {1331, 11} count Apparent clock speed: 2155 MHz TestTlsVariable: Measuring real time: 0.011 usec (1.134e-08 sec) per iteration: 1.134e-06 sec for 100 iterations 0.004 usec (3.633e-09 sec) per iteration: 3.633e-06 sec for 1000 iterations 0.003 usec (3.0361e-09 sec) per iteration: 3.0361e-05 sec for 10000 iterations 0.003 usec (3.0624e-09 sec) per iteration: 0.100866 sec for 32936991 iterations 0.003 usec (3.08545e-09 sec) per iteration: 0.101626 sec for 32936991 iterations 0.003 usec (3.07939e-09 sec) per iteration: 0.101426 sec for 32936991 iterations 0.003 usec (3.0909e-09 sec) per iteration: 0.101805 sec for 32936991 iterations 0.003 usec (3.16238e-09 sec) per iteration: 0.104159 sec for 32936991 iterations mean: 0.003096 usec stddev: 0.000034 usec relative stddev: 1.11% RESULT TestTlsVariable: x86-32_nnacl_newlib_static= {0.003096, 0.000034} us Measuring clock cycles: first runs (cycles): 101 49 26 26 27 26 26 27 27 26 ... slowest runs (cycles): ... 27 27 27 27 27 27 27 28 49 101 min: 24 cycles q1: 26 cycles median: 26 cycles q3: 27 cycles max: 101 cycles RESULT TestTlsVariable_CycleCount: x86-32_nnacl_newlib_static= {26, 1} count Apparent clock speed: 8398 MHz TestMmapAnonymous: Measuring real time: 3.633 usec (3.63256e-06 sec) per iteration: 0.000363256 sec for 100 iterations 3.310 usec (3.30958e-06 sec) per iteration: 0.0911061 sec for 27528 iterations 3.288 usec (3.28849e-06 sec) per iteration: 0.0905256 sec for 27528 iterations 3.287 usec (3.28697e-06 sec) per iteration: 0.0904838 sec for 27528 iterations 3.285 usec (3.28515e-06 sec) per iteration: 0.0904335 sec for 27528 iterations 3.301 usec (3.3006e-06 sec) per iteration: 0.0908588 sec for 27528 iterations mean: 3.294157 usec stddev: 0.009426 usec relative stddev: 0.29% RESULT TestMmapAnonymous: x86-32_nnacl_newlib_static= {3.294157, 0.009426} us Measuring clock cycles: first runs (cycles): 9769 7247 7005 7015 6996 7066 6941 7057 6969 6905 ... slowest runs (cycles): ... 7066 7079 7079 7085 7095 7136 7143 7238 7247 9769 min: 6872 cycles q1: 6931 cycles median: 6962 cycles q3: 7000 cycles max: 9769 cycles RESULT TestMmapAnonymous_CycleCount: x86-32_nnacl_newlib_static= {6962, 69} count Apparent clock speed: 2113 MHz TestAtomicIncrement: Measuring real time: 0.018 usec (1.842e-08 sec) per iteration: 1.842e-06 sec for 100 iterations 0.010 usec (9.994e-09 sec) per iteration: 9.994e-06 sec for 1000 iterations 0.010 usec (1.00416e-08 sec) per iteration: 0.000100416 sec for 10000 iterations 0.010 usec (9.50703e-09 sec) per iteration: 0.0946765 sec for 9958572 iterations 0.010 usec (9.51528e-09 sec) per iteration: 0.0947586 sec for 9958572 iterations 0.009 usec (9.47308e-09 sec) per iteration: 0.0943383 sec for 9958572 iterations 0.010 usec (9.52181e-09 sec) per iteration: 0.0948237 sec for 9958572 iterations 0.010 usec (9.50801e-09 sec) per iteration: 0.0946862 sec for 9958572 iterations mean: 0.009505 usec stddev: 0.000017 usec relative stddev: 0.18% RESULT TestAtomicIncrement: x86-32_nnacl_newlib_static= {0.009505, 0.000017} us Measuring clock cycles: first runs (cycles): 101 69 51 50 49 50 49 50 49 48 ... slowest runs (cycles): ... 51 51 51 51 51 51 51 51 69 101 min: 48 cycles q1: 48 cycles median: 50 cycles q3: 51 cycles max: 101 cycles RESULT TestAtomicIncrement_CycleCount: x86-32_nnacl_newlib_static= {50, 3} count Apparent clock speed: 5260 MHz TestUncontendedMutexLock: Measuring real time: 0.031 usec (3.094e-08 sec) per iteration: 3.094e-06 sec for 100 iterations 0.023 usec (2.2567e-08 sec) per iteration: 2.2567e-05 sec for 1000 iterations 0.022 usec (2.24385e-08 sec) per iteration: 0.0994304 sec for 4431249 iterations 0.022 usec (2.24151e-08 sec) per iteration: 0.0993268 sec for 4431249 iterations 0.022 usec (2.23994e-08 sec) per iteration: 0.0992573 sec for 4431249 iterations 0.022 usec (2.24889e-08 sec) per iteration: 0.0996537 sec for 4431249 iterations 0.022 usec (2.24598e-08 sec) per iteration: 0.099525 sec for 4431249 iterations mean: 0.022440 usec stddev: 0.000032 usec relative stddev: 0.14% RESULT TestUncontendedMutexLock: x86-32_nnacl_newlib_static= {0.022440, 0.000032} us Measuring clock cycles: first runs (cycles): 231 147 80 80 82 81 81 81 79 81 ... slowest runs (cycles): ... 82 82 82 82 82 82 82 82 147 231 min: 79 cycles q1: 79 cycles median: 79 cycles q3: 81 cycles max: 231 cycles RESULT TestUncontendedMutexLock_CycleCount: x86-32_nnacl_newlib_static= {79, 2} count Apparent clock speed: 3520 MHz TestCondvarSignalNoOp: Measuring real time: 0.547 usec (5.4727e-07 sec) per iteration: 5.4727e-05 sec for 100 iterations 0.512 usec (5.11554e-07 sec) per iteration: 0.0934736 sec for 182725 iterations 0.514 usec (5.13846e-07 sec) per iteration: 0.0938925 sec for 182725 iterations 0.511 usec (5.10975e-07 sec) per iteration: 0.0933678 sec for 182725 iterations 0.541 usec (5.41008e-07 sec) per iteration: 0.0988556 sec for 182725 iterations 0.510 usec (5.10246e-07 sec) per iteration: 0.0932347 sec for 182725 iterations mean: 0.517526 usec stddev: 0.011803 usec relative stddev: 2.28% RESULT TestCondvarSignalNoOp: x86-32_nnacl_newlib_static= {0.517526, 0.011803} us Measuring clock cycles: first runs (cycles): 1390 1199 1096 1164 1095 1093 1102 1091 1104 1100 ... slowest runs (cycles): ... 1155 1161 1164 1170 1199 1212 1238 1357 1390 16109 min: 1091 cycles q1: 1100 cycles median: 1102 cycles q3: 1106 cycles max: 16109 cycles RESULT TestCondvarSignalNoOp_CycleCount: x86-32_nnacl_newlib_static= {1102, 6} count Apparent clock speed: 2129 MHz TestThreadCreateAndJoin: Measuring real time: 230.287 usec (0.000230287 sec) per iteration: 0.0230287 sec for 100 iterations 161.498 usec (0.000161498 sec) per iteration: 0.07009 sec for 434 iterations 137.199 usec (0.000137199 sec) per iteration: 0.0595445 sec for 434 iterations 266.002 usec (0.000266002 sec) per iteration: 0.115445 sec for 434 iterations 115.902 usec (0.000115902 sec) per iteration: 0.0503015 sec for 434 iterations 150.109 usec (0.000150109 sec) per iteration: 0.0651475 sec for 434 iterations mean: 166.142194 usec stddev: 52.177466 usec relative stddev: 31.41% RESULT TestThreadCreateAndJoin: x86-32_nnacl_newlib_static= {166.142194, 52.177466} us Measuring clock cycles: first runs (cycles): 168923 262894 352184 226041 203827 231122 191697 197653 186944 184779 ... slowest runs (cycles): ... 445319 456286 481643 570196 581932 604440 661860 1383237 1514990 1843284 min: 128240 cycles q1: 189800 cycles median: 207056 cycles q3: 244687 cycles max: 1843284 cycles RESULT TestThreadCreateAndJoin_CycleCount: x86-32_nnacl_newlib_static= {207056, 54887} count Apparent clock speed: 1246 MHz TestThreadWakeup: Measuring real time: 18.196 usec (1.81958e-05 sec) per iteration: 0.00181958 sec for 100 iterations 17.838 usec (1.78375e-05 sec) per iteration: 0.0980173 sec for 5495 iterations 16.443 usec (1.64434e-05 sec) per iteration: 0.0903564 sec for 5495 iterations 17.294 usec (1.72943e-05 sec) per iteration: 0.095032 sec for 5495 iterations 18.521 usec (1.85207e-05 sec) per iteration: 0.101771 sec for 5495 iterations 36.266 usec (3.62656e-05 sec) per iteration: 0.199279 sec for 5495 iterations mean: 21.272286 usec stddev: 7.527419 usec relative stddev: 35.39% RESULT TestThreadWakeup: x86-32_nnacl_newlib_static= {21.272286, 7.527419} us Measuring clock cycles: first runs (cycles): 129930 40593 39007 36976 36972 35995 60017 35456 35936 538765 ... slowest runs (cycles): ... 56396 56396 60017 62235 70373 108978 129930 230322 443665 538765 min: 31371 cycles q1: 35875 cycles median: 36514 cycles q3: 40324 cycles max: 538765 cycles RESULT TestThreadWakeup_CycleCount: x86-32_nnacl_newlib_static= {36514, 4449} count Apparent clock speed: 1717 MHz TestCatchingFault: Measuring real time: 3.818 usec (3.8182e-06 sec) per iteration: 0.00038182 sec for 100 iterations 2.515 usec (2.51514e-06 sec) per iteration: 0.0658714 sec for 26190 iterations 2.495 usec (2.49526e-06 sec) per iteration: 0.0653508 sec for 26190 iterations 2.486 usec (2.48603e-06 sec) per iteration: 0.0651092 sec for 26190 iterations 2.481 usec (2.48092e-06 sec) per iteration: 0.0649752 sec for 26190 iterations 2.449 usec (2.44941e-06 sec) per iteration: 0.0641501 sec for 26190 iterations mean: 2.485352 usec stddev: 0.021434 usec relative stddev: 0.86% RESULT TestCatchingFault: x86-32_nnacl_newlib_static= {2.485352, 0.021434} us Measuring clock cycles: first runs (cycles): 6283 5849 6274 6325 6474 5492 5273 5269 5385 5306 ... slowest runs (cycles): ... 5350 5385 5405 5492 5849 6274 6283 6325 6474 20293 min: 5236 cycles q1: 5258 cycles median: 5268 cycles q3: 5290 cycles max: 20293 cycles RESULT TestCatchingFault_CycleCount: x86-32_nnacl_newlib_static= {5268, 32} count Apparent clock speed: 2120 MHz TestThreadCreateAndJoinAfterSettingFaultHandler: Measuring real time: 364.706 usec (0.000364706 sec) per iteration: 0.0364706 sec for 100 iterations 319.706 usec (0.000319706 sec) per iteration: 0.0875995 sec for 274 iterations 400.871 usec (0.000400871 sec) per iteration: 0.109839 sec for 274 iterations 440.458 usec (0.000440458 sec) per iteration: 0.120685 sec for 274 iterations 549.725 usec (0.000549725 sec) per iteration: 0.150625 sec for 274 iterations 561.783 usec (0.000561783 sec) per iteration: 0.153929 sec for 274 iterations mean: 454.508598 usec stddev: 91.455030 usec relative stddev: 20.12% RESULT TestThreadCreateAndJoinAfterSettingFaultHandler: x86-32_nnacl_newlib_static= {454.508598, 91.455030} us Measuring clock cycles: first runs (cycles): 513784 1226918 1242046 943936 1238144 693906 744311 1255488 1666345 1308984 ... slowest runs (cycles): ... 1634582 1666345 1731659 1751981 1799798 1837013 1934494 2246015 2361017 2664155 min: 342935 cycles q1: 740971 cycles median: 991868 cycles q3: 1242046 cycles max: 2664155 cycles RESULT TestThreadCreateAndJoinAfterSettingFaultHandler_CycleCount: x86-32_nnacl_newlib_static= {991868, 501075} count Apparent clock speed: 2182 MHz [ OK ] nacl_newlib.run_performance_test (6340 ms) /b/s/w/ir/cache/vpython/4b93a2/bin/python /b/s/w/ir/kitchen-workdir/native_client/tools/command_tester.py --name nacl_newlib.run_nacl_clock_cputime_test --time_warning 60 --time_error 600 --perf_env_description trusted_linux_x86-32 --subarch 32 --arch x86 --output_stamp /b/s/w/ir/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32/test_results/nacl_clock_cputime_test.out /b/s/w/ir/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32/obj/src/shared/platform/nacl_clock_test -c [ RUN ] nacl_newlib.run_nacl_clock_cputime_test /b/s/w/ir/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32/obj/src/shared/platform/nacl_clock_test -c [ OK ] nacl_newlib.run_nacl_clock_cputime_test (9430 ms) /b/s/w/ir/cache/vpython/4b93a2/bin/python /b/s/w/ir/kitchen-workdir/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_linux_x86-32 --subarch 32 --arch x86 --output_stamp /b/s/w/ir/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32/test_results/nacl_interval_multi_reg_test.out /b/s/w/ir/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32/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/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32/obj/src/trusted/interval_multiset/nacl_interval_test -k NaClIntervalListMultiset -k NaClIntervalRangeTree -c 1000000 [ OK ] nacl_newlib.run_nacl_interval_multi_reg_test (2350 ms) /b/s/w/ir/cache/vpython/4b93a2/bin/python /b/s/w/ir/kitchen-workdir/native_client/tools/command_tester.py --name nacl_newlib.run_trusted_performance_test --time_warning 2 --time_error 20 --perf_env_description trusted_linux_x86-32 --subarch 32 --arch x86 --capture_output 0 --output_stamp /b/s/w/ir/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32/test_results/performance_test.out /b/s/w/ir/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32/obj/tests/performance/performance_test trusted_linux_x86-32 [ RUN ] nacl_newlib.run_trusted_performance_test /b/s/w/ir/kitchen-workdir/native_client/scons-out/dbg-linux-x86-32/obj/tests/performance/performance_test trusted_linux_x86-32 TestNull: Measuring real time: 0.008 usec (8.35e-09 sec) per iteration: 8.35e-07 sec for 100 iterations 0.003 usec (3.081e-09 sec) per iteration: 3.081e-06 sec for 1000 iterations 0.003 usec (2.843e-09 sec) per iteration: 2.843e-05 sec for 10000 iterations 0.003 usec (2.89317e-09 sec) per iteration: 0.101765 sec for 35174111 iterations 0.003 usec (2.89699e-09 sec) per iteration: 0.101899 sec for 35174111 iterations 0.003 usec (2.89505e-09 sec) per iteration: 0.101831 sec for 35174111 iterations 0.003 usec (2.90725e-09 sec) per iteration: 0.10226 sec for 35174111 iterations 0.003 usec (2.91241e-09 sec) per iteration: 0.102442 sec for 35174111 iterations mean: 0.002901 usec stddev: 0.000008 usec relative stddev: 0.26% RESULT TestNull: trusted_linux_x86-32= {0.002901, 0.000008} us Measuring clock cycles: first runs (cycles): 106 36 31 20 29 31 31 31 20 30 ... slowest runs (cycles): ... 31 31 31 33 33 33 33 33 36 106 min: 20 cycles q1: 29 cycles median: 30 cycles q3: 31 cycles max: 106 cycles RESULT TestNull_CycleCount: trusted_linux_x86-32= {30, 2} count Apparent clock speed: 10341 MHz TestHostSyscall: Measuring real time: 0.119 usec (1.1917e-07 sec) per iteration: 1.1917e-05 sec for 100 iterations 0.105 usec (1.04819e-07 sec) per iteration: 0.0879578 sec for 839137 iterations 0.105 usec (1.05044e-07 sec) per iteration: 0.088146 sec for 839137 iterations 0.107 usec (1.06535e-07 sec) per iteration: 0.0893978 sec for 839137 iterations 0.104 usec (1.0443e-07 sec) per iteration: 0.0876309 sec for 839137 iterations 0.106 usec (1.05873e-07 sec) per iteration: 0.088842 sec for 839137 iterations mean: 0.105340 usec stddev: 0.000762 usec relative stddev: 0.72% RESULT TestHostSyscall: trusted_linux_x86-32= {0.105340, 0.000762} us Measuring clock cycles: first runs (cycles): 363 328 257 253 255 250 334 253 257 250 ... slowest runs (cycles): ... 258 258 258 258 328 332 334 355 363 687 min: 250 cycles q1: 255 cycles median: 255 cycles q3: 257 cycles max: 687 cycles RESULT TestHostSyscall_CycleCount: trusted_linux_x86-32= {255, 2} count Apparent clock speed: 2421 MHz TestSetjmpLongjmp: Measuring real time: 0.113 usec (1.1259e-07 sec) per iteration: 1.1259e-05 sec for 100 iterations 0.036 usec (3.60762e-08 sec) per iteration: 0.0320421 sec for 888178 iterations 0.036 usec (3.61969e-08 sec) per iteration: 0.0321493 sec for 888178 iterations 0.036 usec (3.61587e-08 sec) per iteration: 0.0321154 sec for 888178 iterations 0.035 usec (3.5479e-08 sec) per iteration: 0.0315117 sec for 888178 iterations 0.036 usec (3.56796e-08 sec) per iteration: 0.0316899 sec for 888178 iterations mean: 0.035918 usec stddev: 0.000286 usec relative stddev: 0.80% RESULT TestSetjmpLongjmp: trusted_linux_x86-32= {0.035918, 0.000286} us Measuring clock cycles: first runs (cycles): 179 116 117 110 115 110 284 110 113 108 ... slowest runs (cycles): ... 114 114 115 115 116 117 117 179 284 284 min: 99 cycles q1: 105 cycles median: 108 cycles q3: 110 cycles max: 284 cycles RESULT TestSetjmpLongjmp_CycleCount: trusted_linux_x86-32= {108, 5} count Apparent clock speed: 3007 MHz TestClockGetTime: Measuring real time: 0.197 usec (1.9722e-07 sec) per iteration: 1.9722e-05 sec for 100 iterations 0.203 usec (2.02602e-07 sec) per iteration: 0.102729 sec for 507047 iterations 0.199 usec (1.99455e-07 sec) per iteration: 0.101133 sec for 507047 iterations 0.205 usec (2.04606e-07 sec) per iteration: 0.103745 sec for 507047 iterations 0.199 usec (1.98547e-07 sec) per iteration: 0.100673 sec for 507047 iterations 0.200 usec (1.99646e-07 sec) per iteration: 0.10123 sec for 507047 iterations mean: 0.200971 usec stddev: 0.002272 usec relative stddev: 1.13% RESULT TestClockGetTime: trusted_linux_x86-32= {0.200971, 0.002272} us Measuring clock cycles: first runs (cycles): 554 455 460 455 457 453 539 462 453 460 ... slowest runs (cycles): ... 458 458 460 460 462 523 539 541 554 585 min: 450 cycles q1: 453 cycles median: 455 cycles q3: 456 cycles max: 585 cycles RESULT TestClockGetTime_CycleCount: trusted_linux_x86-32= {455, 3} count Apparent clock speed: 2264 MHz TestTlsVariable: Measuring real time: 0.008 usec (8.43e-09 sec) per iteration: 8.43e-07 sec for 100 iterations 0.004 usec (3.962e-09 sec) per iteration: 3.962e-06 sec for 1000 iterations 0.004 usec (3.7795e-09 sec) per iteration: 3.7795e-05 sec for 10000 iterations 0.004 usec (3.91356e-09 sec) per iteration: 0.103547 sec for 26458526 iterations 0.004 usec (3.91223e-09 sec) per iteration: 0.103512 sec for 26458526 iterations 0.004 usec (3.91289e-09 sec) per iteration: 0.103529 sec for 26458526 iterations 0.004 usec (3.89505e-09 sec) per iteration: 0.103057 sec for 26458526 iterations 0.004 usec (3.88292e-09 sec) per iteration: 0.102736 sec for 26458526 iterations mean: 0.003903 usec stddev: 0.000012 usec relative stddev: 0.32% RESULT TestTlsVariable: trusted_linux_x86-32= {0.003903, 0.000012} us Measuring clock cycles: first runs (cycles): 112 33 35 24 35 35 31 33 20 28 ... slowest runs (cycles): ... 35 35 35 35 35 35 35 36 36 112 min: 20 cycles q1: 33 cycles median: 33 cycles q3: 33 cycles max: 112 cycles RESULT TestTlsVariable_CycleCount: trusted_linux_x86-32= {33, 0} count Apparent clock speed: 8454 MHz TestMmapAnonymous: Measuring real time: 1.016 usec (1.0161e-06 sec) per iteration: 0.00010161 sec for 100 iterations 0.814 usec (8.13599e-07 sec) per iteration: 0.0800703 sec for 98415 iterations 0.819 usec (8.19227e-07 sec) per iteration: 0.0806242 sec for 98415 iterations 0.812 usec (8.12112e-07 sec) per iteration: 0.079924 sec for 98415 iterations 0.816 usec (8.16103e-07 sec) per iteration: 0.0803168 sec for 98415 iterations 0.806 usec (8.05683e-07 sec) per iteration: 0.0792913 sec for 98415 iterations mean: 0.813345 usec stddev: 0.004528 usec relative stddev: 0.56% RESULT TestMmapAnonymous: trusted_linux_x86-32= {0.813345, 0.004528} us Measuring clock cycles: first runs (cycles): 2319 1762 1751 1747 1743 1736 1856 1749 1757 1751 ... slowest runs (cycles): ... 1777 1778 1786 1837 1856 1879 1892 1938 1993 2319 min: 1709 cycles q1: 1730 cycles median: 1736 cycles q3: 1749 cycles max: 2319 cycles RESULT TestMmapAnonymous_CycleCount: trusted_linux_x86-32= {1736, 19} count Apparent clock speed: 2134 MHz TestAtomicIncrement: Measuring real time: 0.012 usec (1.235e-08 sec) per iteration: 1.235e-06 sec for 100 iterations 0.009 usec (9.474e-09 sec) per iteration: 9.474e-06 sec for 1000 iterations 0.009 usec (9.3027e-09 sec) per iteration: 9.3027e-05 sec for 10000 iterations 0.010 usec (9.55993e-09 sec) per iteration: 0.102765 sec for 10749567 iterations 0.010 usec (9.50005e-09 sec) per iteration: 0.102121 sec for 10749567 iterations 0.009 usec (9.49835e-09 sec) per iteration: 0.102103 sec for 10749567 iterations 0.010 usec (9.52186e-09 sec) per iteration: 0.102356 sec for 10749567 iterations 0.010 usec (9.5443e-09 sec) per iteration: 0.102597 sec for 10749567 iterations mean: 0.009525 usec stddev: 0.000024 usec relative stddev: 0.25% RESULT TestAtomicIncrement: trusted_linux_x86-32= {0.009525, 0.000024} us Measuring clock cycles: first runs (cycles): 132 310 64 63 64 64 279 61 62 61 ... slowest runs (cycles): ... 64 66 68 68 132 279 284 302 310 317 min: 59 cycles q1: 60 cycles median: 61 cycles q3: 63 cycles max: 317 cycles RESULT TestAtomicIncrement_CycleCount: trusted_linux_x86-32= {61, 3} count Apparent clock speed: 6404 MHz TestUncontendedMutexLock: Measuring real time: 0.049 usec (4.919e-08 sec) per iteration: 4.919e-06 sec for 100 iterations 0.027 usec (2.7269e-08 sec) per iteration: 2.7269e-05 sec for 1000 iterations 0.027 usec (2.73603e-08 sec) per iteration: 0.100335 sec for 3667167 iterations 0.027 usec (2.74119e-08 sec) per iteration: 0.100524 sec for 3667167 iterations 0.028 usec (2.81628e-08 sec) per iteration: 0.103278 sec for 3667167 iterations 0.027 usec (2.74772e-08 sec) per iteration: 0.100763 sec for 3667167 iterations 0.027 usec (2.73089e-08 sec) per iteration: 0.100146 sec for 3667167 iterations mean: 0.027544 usec stddev: 0.000314 usec relative stddev: 1.14% RESULT TestUncontendedMutexLock: trusted_linux_x86-32= {0.027544, 0.000314} us Measuring clock cycles: first runs (cycles): 182 574 107 106 103 110 332 110 110 105 ... slowest runs (cycles): ... 110 110 110 110 110 182 332 341 417 574 min: 99 cycles q1: 105 cycles median: 107 cycles q3: 108 cycles max: 574 cycles RESULT TestUncontendedMutexLock_CycleCount: trusted_linux_x86-32= {107, 3} count Apparent clock speed: 3885 MHz TestCondvarSignalNoOp: Measuring real time: 0.027 usec (2.686e-08 sec) per iteration: 2.686e-06 sec for 100 iterations 0.021 usec (2.1325e-08 sec) per iteration: 2.1325e-05 sec for 1000 iterations 0.022 usec (2.17161e-08 sec) per iteration: 0.101834 sec for 4689331 iterations 0.022 usec (2.15591e-08 sec) per iteration: 0.101098 sec for 4689331 iterations 0.022 usec (2.1578e-08 sec) per iteration: 0.101187 sec for 4689331 iterations 0.022 usec (2.16091e-08 sec) per iteration: 0.101332 sec for 4689331 iterations 0.022 usec (2.16188e-08 sec) per iteration: 0.101378 sec for 4689331 iterations mean: 0.021616 usec stddev: 0.000054 usec relative stddev: 0.25% RESULT TestCondvarSignalNoOp: trusted_linux_x86-32= {0.021616, 0.000054} us Measuring clock cycles: first runs (cycles): 187 295 88 90 88 92 299 88 88 86 ... slowest runs (cycles): ... 95 95 99 123 125 187 295 299 315 361 min: 83 cycles q1: 86 cycles median: 88 cycles q3: 90 cycles max: 361 cycles RESULT TestCondvarSignalNoOp_CycleCount: trusted_linux_x86-32= {88, 4} count Apparent clock speed: 4071 MHz TestThreadCreateAndJoin: Measuring real time: 47.891 usec (4.78909e-05 sec) per iteration: 0.00478909 sec for 100 iterations 35.204 usec (3.52039e-05 sec) per iteration: 0.0735058 sec for 2088 iterations 26.116 usec (2.61161e-05 sec) per iteration: 0.0545303 sec for 2088 iterations 28.064 usec (2.80644e-05 sec) per iteration: 0.0585985 sec for 2088 iterations 31.863 usec (3.18633e-05 sec) per iteration: 0.0665305 sec for 2088 iterations 30.392 usec (3.03922e-05 sec) per iteration: 0.063459 sec for 2088 iterations mean: 30.327982 usec stddev: 3.130487 usec relative stddev: 10.32% RESULT TestThreadCreateAndJoin: trusted_linux_x86-32= {30.327982, 3.130487} us Measuring clock cycles: first runs (cycles): 301989 47051 61419 54682 66509 51427 48657 71989 58880 46981 ... slowest runs (cycles): ... 85128 91811 111627 113490 190517 270107 301989 306100 332507 670897 min: 39255 cycles q1: 43121 cycles median: 47096 cycles q3: 61419 cycles max: 670897 cycles RESULT TestThreadCreateAndJoin_CycleCount: trusted_linux_x86-32= {47096, 18298} count Apparent clock speed: 1553 MHz TestThreadWakeup: Measuring real time: 12.922 usec (1.29218e-05 sec) per iteration: 0.00129218 sec for 100 iterations 17.386 usec (1.73865e-05 sec) per iteration: 0.134537 sec for 7738 iterations 16.337 usec (1.63366e-05 sec) per iteration: 0.126412 sec for 7738 iterations 15.939 usec (1.5939e-05 sec) per iteration: 0.123336 sec for 7738 iterations 16.013 usec (1.6013e-05 sec) per iteration: 0.123909 sec for 7738 iterations 13.394 usec (1.33939e-05 sec) per iteration: 0.103642 sec for 7738 iterations mean: 15.813812 usec stddev: 1.315883 usec relative stddev: 8.32% RESULT TestThreadWakeup: trusted_linux_x86-32= {15.813812, 1.315883} us Measuring clock cycles: first runs (cycles): 47999 20551 20482 20058 20403 20485 19833 20262 20058 19897 ... slowest runs (cycles): ... 30423 30560 31196 31604 32579 33877 35921 47925 47999 68623 min: 19833 cycles q1: 28066 cycles median: 28433 cycles q3: 28848 cycles max: 68623 cycles RESULT TestThreadWakeup_CycleCount: trusted_linux_x86-32= {28433, 782} count Apparent clock speed: 1798 MHz WARNING: should have taken less than 2.000000 secs [ OK ] nacl_newlib.run_trusted_performance_test (5120 ms) scons: done building targets. ********************************************************************** COMMAND EXECUTION REPORT ********************************************************************** 7 command_tester.py 1 doSizeCheck 3 gcc 1 set ********************************************************************** ENVIRONMENT USAGE REPORT ********************************************************************** 7 dbg-linux-x86-32 5 nacl-x86-32 Command return code: 0