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 force_sel_ldr=../out_32/sel_ldr force_irt=../out_32/irt_x86/irt_core.nexe perf_prefix=gn_ force_bootstrap=../out_32/nacl_helper_bootstrap 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', 'force_sel_ldr=../out_32/sel_ldr', 'force_irt=../out_32/irt_x86/irt_core.nexe', 'perf_prefix=gn_', 'force_bootstrap=../out_32/nacl_helper_bootstrap'] ====================================================================== ====================================================================== 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-0r4g 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: 23012052 kB MemAvailable: 29453860 kB ====================================================================== LOAD: ====================================================================== 1.12 1.69 1.88 1/443 24477 ====================================================================== UPTIME: ====================================================================== 18304.28 139271.18 ====================================================================== 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='84' BUILDBOT_GOT_REVISION='f701a90597fc85979319447c0cd44c3b52201c78' BUILDBOT_MASTERNAME='client.nacl' BUILDBOT_REVISION='f701a90597fc85979319447c0cd44c3b52201c78' BUILDBOT_SLAVE_TYPE='BuilderTester' BUILDBUCKET_EXPERIMENTAL='FALSE' CIPD_CACHE_DIR='/b/s/cipd_cache/cache' CIPD_PROTOCOL='v2' CYGWIN='nodosfilewarning' DEVSHELL_CLIENT_PORT='38474' 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/8929197227161560512' LOGDOG_STREAM_PROJECT='nacl' LOGDOG_STREAM_SERVER_PATH='unix:/b/s/w/ir/tmp/ld.sock' LOGNAME='chrome-bot' LUCI_CONTEXT='/b/s/w/itsgD4Kr/luci_context.131800827' 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='24450' 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-0r4g' SWARMING_EXTERNAL_BOT_SETUP='1' SWARMING_HEADLESS='1' SWARMING_SERVER='https://chromium-swarm.appspot.com' SWARMING_TASK_ID='4151e6e603871f11' 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 gn_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 gn_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 gn_x86-32_nnacl_newlib_static [24492,4148188928:18:19:38.952784] Native Client module will be loaded at base address 0x00000000b7404000 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: gn_x86-32_nnacl_newlib_static= 610 count RESULT InstructionBytesPerSyscall: gn_x86-32_nnacl_newlib_static= 1430 count RESULT JumpsPerSyscall: gn_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 gn_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 /b/s/w/ir/kitchen-workdir/out_32/nacl_helper_bootstrap /b/s/w/ir/kitchen-workdir/out_32/sel_ldr --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -- scons-out/nacl-x86-32/obj/tests/benchmark/benchmark_test.nexe gn_x86-32_nnacl_newlib_static [ RUN ] nacl_newlib.run_benchmark_test /b/s/w/ir/kitchen-workdir/out_32/nacl_helper_bootstrap /b/s/w/ir/kitchen-workdir/out_32/sel_ldr --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -- scons-out/nacl-x86-32/obj/tests/benchmark/benchmark_test.nexe gn_x86-32_nnacl_newlib_static [24497,4147402496:18:19:39.144736] Native Client module will be loaded at base address 0x0000000000000000 Running suite of 1 benchmarks: Running Benchmark: Life (SIMD version)... RESULT BenchmarkLife: gn_x86-32_nnacl_newlib_static= {0.110850, 0.001940} seconds --------------------------------------------------------------- Done running benchmark suite. [ OK ] nacl_newlib.run_benchmark_test (1910 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 gn_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 /b/s/w/ir/kitchen-workdir/out_32/nacl_helper_bootstrap /b/s/w/ir/kitchen-workdir/out_32/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 /b/s/w/ir/kitchen-workdir/out_32/nacl_helper_bootstrap /b/s/w/ir/kitchen-workdir/out_32/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 (70430 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: gn_x86-32_nnacl_newlib_static= 512.216 KB RESULT hello_world_size.out: ZIPPED_gn_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 gn_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 /b/s/w/ir/kitchen-workdir/out_32/nacl_helper_bootstrap /b/s/w/ir/kitchen-workdir/out_32/sel_ldr --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -e -- scons-out/nacl-x86-32/obj/tests/performance/performance_test.nexe gn_x86-32_nnacl_newlib_static [ RUN ] nacl_newlib.run_performance_test /b/s/w/ir/kitchen-workdir/out_32/nacl_helper_bootstrap /b/s/w/ir/kitchen-workdir/out_32/sel_ldr --r_debug=0xXXXXXXXXXXXXXXXX --reserved_at_zero=0xXXXXXXXXXXXXXXXX -e -- scons-out/nacl-x86-32/obj/tests/performance/performance_test.nexe gn_x86-32_nnacl_newlib_static [24525,4147574528:18:19:54.315984] Native Client module will be loaded at base address 0x0000000000000000 TestNull: Measuring real time: 0.016 usec (1.633e-08 sec) per iteration: 1.633e-06 sec for 100 iterations 0.003 usec (2.956e-09 sec) per iteration: 2.956e-06 sec for 1000 iterations 0.002 usec (2.2992e-09 sec) per iteration: 2.2992e-05 sec for 10000 iterations 0.002 usec (2.28579e-09 sec) per iteration: 0.0994166 sec for 43493389 iterations 0.002 usec (2.28217e-09 sec) per iteration: 0.0992592 sec for 43493389 iterations 0.002 usec (2.27048e-09 sec) per iteration: 0.0987507 sec for 43493389 iterations 0.002 usec (2.27495e-09 sec) per iteration: 0.0989454 sec for 43493389 iterations 0.002 usec (2.26998e-09 sec) per iteration: 0.098729 sec for 43493389 iterations mean: 0.002277 usec stddev: 0.000006 usec relative stddev: 0.28% RESULT TestNull: gn_x86-32_nnacl_newlib_static= {0.002277, 0.000006} us Measuring clock cycles: first runs (cycles): 88 64 24 24 24 24 22 24 24 24 ... slowest runs (cycles): ... 26 26 26 26 26 26 27 27 64 88 min: 21 cycles q1: 22 cycles median: 24 cycles q3: 25 cycles max: 88 cycles RESULT TestNull_CycleCount: gn_x86-32_nnacl_newlib_static= {24, 3} count Apparent clock speed: 10542 MHz TestNaClSyscall: Measuring real time: 0.340 usec (3.3978e-07 sec) per iteration: 3.3978e-05 sec for 100 iterations 0.336 usec (3.36365e-07 sec) per iteration: 0.0989948 sec for 294308 iterations 0.343 usec (3.43284e-07 sec) per iteration: 0.101031 sec for 294308 iterations 0.340 usec (3.3957e-07 sec) per iteration: 0.0999381 sec for 294308 iterations 0.337 usec (3.36681e-07 sec) per iteration: 0.0990878 sec for 294308 iterations 0.344 usec (3.44417e-07 sec) per iteration: 0.101365 sec for 294308 iterations mean: 0.340063 usec stddev: 0.003307 usec relative stddev: 0.97% RESULT TestNaClSyscall: gn_x86-32_nnacl_newlib_static= {0.340063, 0.003307} us Measuring clock cycles: first runs (cycles): 841 774 744 732 733 735 736 735 735 739 ... slowest runs (cycles): ... 761 772 772 774 776 779 783 805 821 841 min: 724 cycles q1: 731 cycles median: 735 cycles q3: 736 cycles max: 841 cycles RESULT TestNaClSyscall_CycleCount: gn_x86-32_nnacl_newlib_static= {735, 5} count Apparent clock speed: 2161 MHz TestSetjmpLongjmp: Measuring real time: 0.022 usec (2.189e-08 sec) per iteration: 2.189e-06 sec for 100 iterations 0.017 usec (1.6789e-08 sec) per iteration: 1.6789e-05 sec for 1000 iterations 0.013 usec (1.25308e-08 sec) per iteration: 0.0746369 sec for 5956280 iterations 0.012 usec (1.22273e-08 sec) per iteration: 0.0728289 sec for 5956280 iterations 0.012 usec (1.24734e-08 sec) per iteration: 0.0742949 sec for 5956280 iterations 0.012 usec (1.21835e-08 sec) per iteration: 0.0725682 sec for 5956280 iterations 0.012 usec (1.24287e-08 sec) per iteration: 0.0740286 sec for 5956280 iterations mean: 0.012369 usec stddev: 0.000138 usec relative stddev: 1.12% RESULT TestSetjmpLongjmp: gn_x86-32_nnacl_newlib_static= {0.012369, 0.000138} us Measuring clock cycles: first runs (cycles): 141 83 64 42 39 35 36 39 40 42 ... slowest runs (cycles): ... 42 42 42 42 42 44 64 83 125 141 min: 33 cycles q1: 36 cycles median: 39 cycles q3: 41 cycles max: 141 cycles RESULT TestSetjmpLongjmp_CycleCount: gn_x86-32_nnacl_newlib_static= {39, 5} count Apparent clock speed: 3153 MHz TestClockGetTime: Measuring real time: 0.643 usec (6.429e-07 sec) per iteration: 6.429e-05 sec for 100 iterations 0.648 usec (6.48391e-07 sec) per iteration: 0.100854 sec for 155545 iterations 0.647 usec (6.47434e-07 sec) per iteration: 0.100705 sec for 155545 iterations 0.651 usec (6.51465e-07 sec) per iteration: 0.101332 sec for 155545 iterations 0.648 usec (6.48324e-07 sec) per iteration: 0.100844 sec for 155545 iterations 0.648 usec (6.47981e-07 sec) per iteration: 0.10079 sec for 155545 iterations mean: 0.648719 usec stddev: 0.001414 usec relative stddev: 0.22% RESULT TestClockGetTime: gn_x86-32_nnacl_newlib_static= {0.648719, 0.001414} us Measuring clock cycles: first runs (cycles): 1659 1435 1405 1496 1403 1415 1410 1406 1403 1441 ... slowest runs (cycles): ... 1454 1465 1465 1465 1487 1490 1492 1496 1659 9923 min: 1390 cycles q1: 1406 cycles median: 1415 cycles q3: 1425 cycles max: 9923 cycles RESULT TestClockGetTime_CycleCount: gn_x86-32_nnacl_newlib_static= {1415, 19} count Apparent clock speed: 2181 MHz TestTlsVariable: Measuring real time: 0.011 usec (1.149e-08 sec) per iteration: 1.149e-06 sec for 100 iterations 0.004 usec (3.666e-09 sec) per iteration: 3.666e-06 sec for 1000 iterations 0.003 usec (3.0411e-09 sec) per iteration: 3.0411e-05 sec for 10000 iterations 0.003 usec (3.04556e-09 sec) per iteration: 0.100147 sec for 32882838 iterations 0.003 usec (3.0377e-09 sec) per iteration: 0.0998882 sec for 32882838 iterations 0.003 usec (3.04008e-09 sec) per iteration: 0.0999666 sec for 32882838 iterations 0.003 usec (3.0175e-09 sec) per iteration: 0.099224 sec for 32882838 iterations 0.003 usec (3.01875e-09 sec) per iteration: 0.099265 sec for 32882838 iterations mean: 0.003032 usec stddev: 0.000012 usec relative stddev: 0.38% RESULT TestTlsVariable: gn_x86-32_nnacl_newlib_static= {0.003032, 0.000012} us Measuring clock cycles: first runs (cycles): 104 48 28 27 29 26 29 27 28 26 ... slowest runs (cycles): ... 29 29 29 29 29 29 29 29 48 104 min: 26 cycles q1: 27 cycles median: 28 cycles q3: 29 cycles max: 104 cycles RESULT TestTlsVariable_CycleCount: gn_x86-32_nnacl_newlib_static= {28, 2} count Apparent clock speed: 9235 MHz TestMmapAnonymous: Measuring real time: 3.800 usec (3.7999e-06 sec) per iteration: 0.00037999 sec for 100 iterations 3.594 usec (3.59378e-06 sec) per iteration: 0.0945739 sec for 26316 iterations 3.571 usec (3.57133e-06 sec) per iteration: 0.093983 sec for 26316 iterations 3.537 usec (3.53717e-06 sec) per iteration: 0.0930842 sec for 26316 iterations 3.566 usec (3.56557e-06 sec) per iteration: 0.0938315 sec for 26316 iterations 3.575 usec (3.57479e-06 sec) per iteration: 0.0940743 sec for 26316 iterations mean: 3.568529 usec stddev: 0.018312 usec relative stddev: 0.51% RESULT TestMmapAnonymous: gn_x86-32_nnacl_newlib_static= {3.568529, 0.018312} us Measuring clock cycles: first runs (cycles): 9389 7820 7642 7585 7578 7629 7550 7724 7589 7497 ... slowest runs (cycles): ... 7669 7675 7686 7703 7706 7708 7724 7820 7820 9389 min: 7446 cycles q1: 7535 cycles median: 7574 cycles q3: 7615 cycles max: 9389 cycles RESULT TestMmapAnonymous_CycleCount: gn_x86-32_nnacl_newlib_static= {7574, 80} count Apparent clock speed: 2122 MHz TestAtomicIncrement: Measuring real time: 0.018 usec (1.803e-08 sec) per iteration: 1.803e-06 sec for 100 iterations 0.010 usec (9.932e-09 sec) per iteration: 9.932e-06 sec for 1000 iterations 0.009 usec (9.3369e-09 sec) per iteration: 9.3369e-05 sec for 10000 iterations 0.009 usec (9.4315e-09 sec) per iteration: 0.101013 sec for 10710192 iterations 0.009 usec (9.44546e-09 sec) per iteration: 0.101163 sec for 10710192 iterations 0.009 usec (9.42043e-09 sec) per iteration: 0.100895 sec for 10710192 iterations 0.009 usec (9.49382e-09 sec) per iteration: 0.101681 sec for 10710192 iterations 0.010 usec (9.53295e-09 sec) per iteration: 0.1021 sec for 10710192 iterations mean: 0.009465 usec stddev: 0.000042 usec relative stddev: 0.45% RESULT TestAtomicIncrement: gn_x86-32_nnacl_newlib_static= {0.009465, 0.000042} us Measuring clock cycles: first runs (cycles): 114 70 51 50 51 51 48 51 50 51 ... slowest runs (cycles): ... 51 51 51 51 51 51 51 51 70 114 min: 48 cycles q1: 49 cycles median: 50 cycles q3: 51 cycles max: 114 cycles RESULT TestAtomicIncrement_CycleCount: gn_x86-32_nnacl_newlib_static= {50, 2} count Apparent clock speed: 5283 MHz TestUncontendedMutexLock: Measuring real time: 0.032 usec (3.188e-08 sec) per iteration: 3.188e-06 sec for 100 iterations 0.023 usec (2.2592e-08 sec) per iteration: 2.2592e-05 sec for 1000 iterations 0.022 usec (2.22503e-08 sec) per iteration: 0.0984876 sec for 4426345 iterations 0.022 usec (2.22221e-08 sec) per iteration: 0.0983628 sec for 4426345 iterations 0.022 usec (2.2198e-08 sec) per iteration: 0.0982558 sec for 4426345 iterations 0.022 usec (2.225e-08 sec) per iteration: 0.0984862 sec for 4426345 iterations 0.022 usec (2.22674e-08 sec) per iteration: 0.0985633 sec for 4426345 iterations mean: 0.022238 usec stddev: 0.000025 usec relative stddev: 0.11% RESULT TestUncontendedMutexLock: gn_x86-32_nnacl_newlib_static= {0.022238, 0.000025} us Measuring clock cycles: first runs (cycles): 235 137 82 81 81 81 79 79 79 79 ... slowest runs (cycles): ... 82 82 82 82 82 82 82 82 137 235 min: 79 cycles q1: 79 cycles median: 79 cycles q3: 80 cycles max: 235 cycles RESULT TestUncontendedMutexLock_CycleCount: gn_x86-32_nnacl_newlib_static= {79, 1} count Apparent clock speed: 3553 MHz TestCondvarSignalNoOp: Measuring real time: 0.581 usec (5.8144e-07 sec) per iteration: 5.8144e-05 sec for 100 iterations 0.534 usec (5.34149e-07 sec) per iteration: 0.0918661 sec for 171986 iterations 0.533 usec (5.33098e-07 sec) per iteration: 0.0916854 sec for 171986 iterations 0.532 usec (5.31849e-07 sec) per iteration: 0.0914706 sec for 171986 iterations 0.531 usec (5.31143e-07 sec) per iteration: 0.0913491 sec for 171986 iterations 0.531 usec (5.31058e-07 sec) per iteration: 0.0913346 sec for 171986 iterations mean: 0.532259 usec stddev: 0.001194 usec relative stddev: 0.22% RESULT TestCondvarSignalNoOp: gn_x86-32_nnacl_newlib_static= {0.532259, 0.001194} us Measuring clock cycles: first runs (cycles): 1318 1221 1150 1151 1163 1151 1155 1153 1159 1151 ... slowest runs (cycles): ... 1193 1195 1201 1204 1208 1210 1213 1221 1223 1318 min: 1144 cycles q1: 1152 cycles median: 1155 cycles q3: 1163 cycles max: 1318 cycles RESULT TestCondvarSignalNoOp_CycleCount: gn_x86-32_nnacl_newlib_static= {1155, 11} count Apparent clock speed: 2170 MHz TestThreadCreateAndJoin: Measuring real time: 112.923 usec (0.000112923 sec) per iteration: 0.0112923 sec for 100 iterations 90.163 usec (9.01631e-05 sec) per iteration: 0.0797943 sec for 885 iterations 83.215 usec (8.32149e-05 sec) per iteration: 0.0736452 sec for 885 iterations 85.907 usec (8.59072e-05 sec) per iteration: 0.0760278 sec for 885 iterations 88.057 usec (8.80573e-05 sec) per iteration: 0.0779307 sec for 885 iterations 83.447 usec (8.34475e-05 sec) per iteration: 0.073851 sec for 885 iterations mean: 86.157987 usec stddev: 2.672814 usec relative stddev: 3.10% RESULT TestThreadCreateAndJoin: gn_x86-32_nnacl_newlib_static= {86.157987, 2.672814} us Measuring clock cycles: first runs (cycles): 118268 181772 192386 184242 194458 226831 188026 191423 183111 177328 ... slowest runs (cycles): ... 218969 221500 222928 226831 228549 237480 245115 250856 290038 379345 min: 118268 cycles q1: 176495 cycles median: 180474 cycles q3: 190376 cycles max: 379345 cycles RESULT TestThreadCreateAndJoin_CycleCount: gn_x86-32_nnacl_newlib_static= {180474, 13881} count Apparent clock speed: 2095 MHz TestThreadWakeup: Measuring real time: 10.168 usec (1.01679e-05 sec) per iteration: 0.00101679 sec for 100 iterations 13.804 usec (1.38038e-05 sec) per iteration: 0.135747 sec for 9834 iterations 13.576 usec (1.3576e-05 sec) per iteration: 0.133506 sec for 9834 iterations 13.447 usec (1.3447e-05 sec) per iteration: 0.132237 sec for 9834 iterations 18.209 usec (1.82095e-05 sec) per iteration: 0.179072 sec for 9834 iterations 15.129 usec (1.51295e-05 sec) per iteration: 0.148783 sec for 9834 iterations mean: 14.833135 usec stddev: 1.791583 usec relative stddev: 12.08% RESULT TestThreadWakeup: gn_x86-32_nnacl_newlib_static= {14.833135, 1.791583} us Measuring clock cycles: first runs (cycles): 56064 29957 32483 29726 33347 62936 29308 31404 28971 29601 ... slowest runs (cycles): ... 31404 31552 31768 32412 32483 33347 39786 56064 62936 71230 min: 28540 cycles q1: 29179 cycles median: 29608 cycles q3: 30212 cycles max: 71230 cycles RESULT TestThreadWakeup_CycleCount: gn_x86-32_nnacl_newlib_static= {29608, 1033} count Apparent clock speed: 1996 MHz TestCatchingFault: Measuring real time: 4.023 usec (4.02298e-06 sec) per iteration: 0.000402298 sec for 100 iterations 2.474 usec (2.47359e-06 sec) per iteration: 0.0614859 sec for 24857 iterations 2.466 usec (2.46552e-06 sec) per iteration: 0.0612855 sec for 24857 iterations 2.464 usec (2.46378e-06 sec) per iteration: 0.0612422 sec for 24857 iterations 2.467 usec (2.46695e-06 sec) per iteration: 0.0613211 sec for 24857 iterations 2.486 usec (2.48582e-06 sec) per iteration: 0.0617899 sec for 24857 iterations mean: 2.471132 usec stddev: 0.008057 usec relative stddev: 0.33% RESULT TestCatchingFault: gn_x86-32_nnacl_newlib_static= {2.471132, 0.008057} us Measuring clock cycles: first runs (cycles): 6175 5566 5519 5508 5513 5446 5445 5405 5433 5436 ... slowest runs (cycles): ... 5627 5671 5693 5776 6175 6395 6624 6657 6877 21712 min: 5405 cycles q1: 5449 cycles median: 5469 cycles q3: 5513 cycles max: 21712 cycles RESULT TestCatchingFault_CycleCount: gn_x86-32_nnacl_newlib_static= {5469, 64} count Apparent clock speed: 2213 MHz TestThreadCreateAndJoinAfterSettingFaultHandler: Measuring real time: 155.600 usec (0.0001556 sec) per iteration: 0.01556 sec for 100 iterations 143.045 usec (0.000143045 sec) per iteration: 0.0918351 sec for 642 iterations 102.927 usec (0.000102927 sec) per iteration: 0.066079 sec for 642 iterations 90.887 usec (9.08874e-05 sec) per iteration: 0.0583497 sec for 642 iterations 102.829 usec (0.000102829 sec) per iteration: 0.0660163 sec for 642 iterations 92.751 usec (9.27515e-05 sec) per iteration: 0.0595465 sec for 642 iterations mean: 106.488022 usec stddev: 18.945101 usec relative stddev: 17.79% RESULT TestThreadCreateAndJoinAfterSettingFaultHandler: gn_x86-32_nnacl_newlib_static= {106.488022, 18.945101} us Measuring clock cycles: first runs (cycles): 115151 175743 174775 173727 175887 173377 171213 178651 170614 164281 ... slowest runs (cycles): ... 221412 226903 230590 230742 231584 235595 241377 267129 284910 519585 min: 115151 cycles q1: 170401 cycles median: 173857 cycles q3: 184528 cycles max: 519585 cycles RESULT TestThreadCreateAndJoinAfterSettingFaultHandler_CycleCount: gn_x86-32_nnacl_newlib_static= {173857, 14127} count Apparent clock speed: 1633 MHz [ OK ] nacl_newlib.run_performance_test (6189 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 gn_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 (10000 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 gn_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 (1130 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 gn_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 gn_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 gn_trusted_linux_x86-32 TestNull: Measuring real time: 0.021 usec (2.142e-08 sec) per iteration: 2.142e-06 sec for 100 iterations 0.017 usec (1.69e-08 sec) per iteration: 1.69e-05 sec for 1000 iterations 0.003 usec (2.87375e-09 sec) per iteration: 0.0170045 sec for 5917159 iterations 0.003 usec (2.85938e-09 sec) per iteration: 0.0169194 sec for 5917159 iterations 0.003 usec (2.85913e-09 sec) per iteration: 0.0169179 sec for 5917159 iterations 0.003 usec (2.86776e-09 sec) per iteration: 0.016969 sec for 5917159 iterations 0.003 usec (2.85389e-09 sec) per iteration: 0.0168869 sec for 5917159 iterations mean: 0.002863 usec stddev: 0.000007 usec relative stddev: 0.25% RESULT TestNull: gn_trusted_linux_x86-32= {0.002863, 0.000007} us Measuring clock cycles: first runs (cycles): 114 31 44 29 31 31 30 29 28 31 ... slowest runs (cycles): ... 31 31 31 31 31 31 31 33 44 114 min: 20 cycles q1: 28 cycles median: 29 cycles q3: 31 cycles max: 114 cycles RESULT TestNull_CycleCount: gn_trusted_linux_x86-32= {29, 3} count Apparent clock speed: 10130 MHz TestHostSyscall: Measuring real time: 0.126 usec (1.2575e-07 sec) per iteration: 1.2575e-05 sec for 100 iterations 0.104 usec (1.03733e-07 sec) per iteration: 0.082491 sec for 795228 iterations 0.104 usec (1.03667e-07 sec) per iteration: 0.0824386 sec for 795228 iterations 0.104 usec (1.03803e-07 sec) per iteration: 0.0825474 sec for 795228 iterations 0.105 usec (1.04836e-07 sec) per iteration: 0.0833686 sec for 795228 iterations 0.104 usec (1.03667e-07 sec) per iteration: 0.0824389 sec for 795228 iterations mean: 0.103941 usec stddev: 0.000450 usec relative stddev: 0.43% RESULT TestHostSyscall: gn_trusted_linux_x86-32= {0.103941, 0.000450} us Measuring clock cycles: first runs (cycles): 435 260 253 258 1144 255 253 255 253 258 ... slowest runs (cycles): ... 258 258 258 260 260 311 317 328 435 1144 min: 251 cycles q1: 253 cycles median: 255 cycles q3: 255 cycles max: 1144 cycles RESULT TestHostSyscall_CycleCount: gn_trusted_linux_x86-32= {255, 2} count Apparent clock speed: 2453 MHz TestSetjmpLongjmp: Measuring real time: 0.180 usec (1.7954e-07 sec) per iteration: 1.7954e-05 sec for 100 iterations 0.035 usec (3.52095e-08 sec) per iteration: 0.0196109 sec for 556978 iterations 0.035 usec (3.52528e-08 sec) per iteration: 0.019635 sec for 556978 iterations 0.035 usec (3.53296e-08 sec) per iteration: 0.0196778 sec for 556978 iterations 0.035 usec (3.5395e-08 sec) per iteration: 0.0197142 sec for 556978 iterations 0.035 usec (3.5306e-08 sec) per iteration: 0.0196647 sec for 556978 iterations mean: 0.035299 usec stddev: 0.000064 usec relative stddev: 0.18% RESULT TestSetjmpLongjmp: gn_trusted_linux_x86-32= {0.035299, 0.000064} us Measuring clock cycles: first runs (cycles): 174 139 114 110 115 112 112 110 105 110 ... slowest runs (cycles): ... 116 116 139 143 147 149 149 165 174 253 min: 105 cycles q1: 110 cycles median: 113 cycles q3: 114 cycles max: 253 cycles RESULT TestSetjmpLongjmp_CycleCount: gn_trusted_linux_x86-32= {113, 4} count Apparent clock speed: 3201 MHz TestClockGetTime: Measuring real time: 0.197 usec (1.9663e-07 sec) per iteration: 1.9663e-05 sec for 100 iterations 0.197 usec (1.96622e-07 sec) per iteration: 0.0999957 sec for 508569 iterations 0.197 usec (1.96718e-07 sec) per iteration: 0.100045 sec for 508569 iterations 0.197 usec (1.9671e-07 sec) per iteration: 0.10004 sec for 508569 iterations 0.197 usec (1.97026e-07 sec) per iteration: 0.100201 sec for 508569 iterations 0.197 usec (1.97148e-07 sec) per iteration: 0.100264 sec for 508569 iterations mean: 0.196845 usec stddev: 0.000204 usec relative stddev: 0.10% RESULT TestClockGetTime: gn_trusted_linux_x86-32= {0.196845, 0.000204} us Measuring clock cycles: first runs (cycles): 576 460 455 453 451 455 457 453 458 453 ... slowest runs (cycles): ... 458 458 458 458 458 458 460 532 557 576 min: 451 cycles q1: 453 cycles median: 453 cycles q3: 456 cycles max: 576 cycles RESULT TestClockGetTime_CycleCount: gn_trusted_linux_x86-32= {453, 3} count Apparent clock speed: 2301 MHz TestTlsVariable: Measuring real time: 0.007 usec (7.11e-09 sec) per iteration: 7.11e-07 sec for 100 iterations 0.004 usec (3.976e-09 sec) per iteration: 3.976e-06 sec for 1000 iterations 0.004 usec (3.7841e-09 sec) per iteration: 3.7841e-05 sec for 10000 iterations 0.004 usec (3.80738e-09 sec) per iteration: 0.100615 sec for 26426362 iterations 0.004 usec (3.80456e-09 sec) per iteration: 0.100541 sec for 26426362 iterations 0.004 usec (3.80707e-09 sec) per iteration: 0.100607 sec for 26426362 iterations 0.004 usec (3.80778e-09 sec) per iteration: 0.100626 sec for 26426362 iterations 0.004 usec (3.85181e-09 sec) per iteration: 0.101789 sec for 26426362 iterations mean: 0.003816 usec stddev: 0.000018 usec relative stddev: 0.47% RESULT TestTlsVariable: gn_trusted_linux_x86-32= {0.003816, 0.000018} us Measuring clock cycles: first runs (cycles): 101 35 101 35 35 35 37 35 29 31 ... slowest runs (cycles): ... 35 35 35 36 36 36 37 37 101 101 min: 24 cycles q1: 33 cycles median: 33 cycles q3: 35 cycles max: 101 cycles RESULT TestTlsVariable_CycleCount: gn_trusted_linux_x86-32= {33, 2} count Apparent clock speed: 8648 MHz TestMmapAnonymous: Measuring real time: 1.017 usec (1.01681e-06 sec) per iteration: 0.000101681 sec for 100 iterations 0.791 usec (7.90866e-07 sec) per iteration: 0.0777785 sec for 98346 iterations 0.791 usec (7.90713e-07 sec) per iteration: 0.0777634 sec for 98346 iterations 0.791 usec (7.9114e-07 sec) per iteration: 0.0778054 sec for 98346 iterations 0.790 usec (7.89974e-07 sec) per iteration: 0.0776908 sec for 98346 iterations 0.791 usec (7.90709e-07 sec) per iteration: 0.0777631 sec for 98346 iterations mean: 0.790680 usec stddev: 0.000386 usec relative stddev: 0.05% RESULT TestMmapAnonymous: gn_trusted_linux_x86-32= {0.790680, 0.000386} us Measuring clock cycles: first runs (cycles): 2154 1778 1756 1740 1725 1733 1751 1742 1742 1744 ... slowest runs (cycles): ... 1782 1782 1792 1800 1841 1842 1848 1885 2154 2413 min: 1720 cycles q1: 1734 cycles median: 1740 cycles q3: 1755 cycles max: 2413 cycles RESULT TestMmapAnonymous_CycleCount: gn_trusted_linux_x86-32= {1740, 21} count Apparent clock speed: 2201 MHz TestAtomicIncrement: Measuring real time: 0.012 usec (1.244e-08 sec) per iteration: 1.244e-06 sec for 100 iterations 0.009 usec (9.461e-09 sec) per iteration: 9.461e-06 sec for 1000 iterations 0.009 usec (9.2927e-09 sec) per iteration: 9.2927e-05 sec for 10000 iterations 0.009 usec (9.4199e-09 sec) per iteration: 0.101369 sec for 10761135 iterations 0.009 usec (9.42429e-09 sec) per iteration: 0.101416 sec for 10761135 iterations 0.009 usec (9.39861e-09 sec) per iteration: 0.10114 sec for 10761135 iterations 0.009 usec (9.41961e-09 sec) per iteration: 0.101366 sec for 10761135 iterations 0.009 usec (9.4953e-09 sec) per iteration: 0.10218 sec for 10761135 iterations mean: 0.009432 usec stddev: 0.000033 usec relative stddev: 0.35% RESULT TestAtomicIncrement: gn_trusted_linux_x86-32= {0.009432, 0.000033} us Measuring clock cycles: first runs (cycles): 308 61 64 61 915 64 63 64 62 59 ... slowest runs (cycles): ... 66 68 68 68 68 251 253 308 317 915 min: 59 cycles q1: 61 cycles median: 62 cycles q3: 62 cycles max: 915 cycles RESULT TestAtomicIncrement_CycleCount: gn_trusted_linux_x86-32= {62, 1} count Apparent clock speed: 6574 MHz TestUncontendedMutexLock: Measuring real time: 0.036 usec (3.59e-08 sec) per iteration: 3.59e-06 sec for 100 iterations 0.027 usec (2.6917e-08 sec) per iteration: 2.6917e-05 sec for 1000 iterations 0.027 usec (2.70839e-08 sec) per iteration: 0.10062 sec for 3715124 iterations 0.027 usec (2.70487e-08 sec) per iteration: 0.100489 sec for 3715124 iterations 0.027 usec (2.70505e-08 sec) per iteration: 0.100496 sec for 3715124 iterations 0.027 usec (2.70559e-08 sec) per iteration: 0.100516 sec for 3715124 iterations 0.027 usec (2.70645e-08 sec) per iteration: 0.100548 sec for 3715124 iterations mean: 0.027061 usec stddev: 0.000013 usec relative stddev: 0.05% RESULT TestUncontendedMutexLock: gn_trusted_linux_x86-32= {0.027061, 0.000013} us Measuring clock cycles: first runs (cycles): 172 101 101 105 288 110 108 110 107 112 ... slowest runs (cycles): ... 112 112 113 119 172 264 275 284 286 288 min: 101 cycles q1: 108 cycles median: 110 cycles q3: 110 cycles max: 288 cycles RESULT TestUncontendedMutexLock_CycleCount: gn_trusted_linux_x86-32= {110, 2} count Apparent clock speed: 4065 MHz TestCondvarSignalNoOp: Measuring real time: 0.059 usec (5.927e-08 sec) per iteration: 5.927e-06 sec for 100 iterations 0.023 usec (2.3262e-08 sec) per iteration: 2.3262e-05 sec for 1000 iterations 0.021 usec (2.14204e-08 sec) per iteration: 0.0920833 sec for 4298856 iterations 0.021 usec (2.14513e-08 sec) per iteration: 0.0922159 sec for 4298856 iterations 0.021 usec (2.14031e-08 sec) per iteration: 0.0920087 sec for 4298856 iterations 0.021 usec (2.14576e-08 sec) per iteration: 0.092243 sec for 4298856 iterations 0.021 usec (2.1416e-08 sec) per iteration: 0.0920642 sec for 4298856 iterations mean: 0.021430 usec stddev: 0.000021 usec relative stddev: 0.10% RESULT TestCondvarSignalNoOp: gn_trusted_linux_x86-32= {0.021430, 0.000021} us Measuring clock cycles: first runs (cycles): 328 92 88 88 293 90 90 90 91 93 ... slowest runs (cycles): ... 93 93 95 95 275 281 292 293 295 328 min: 88 cycles q1: 88 cycles median: 90 cycles q3: 92 cycles max: 328 cycles RESULT TestCondvarSignalNoOp_CycleCount: gn_trusted_linux_x86-32= {90, 4} count Apparent clock speed: 4200 MHz TestThreadCreateAndJoin: Measuring real time: 31.165 usec (3.11654e-05 sec) per iteration: 0.00311654 sec for 100 iterations 22.692 usec (2.26915e-05 sec) per iteration: 0.0727945 sec for 3208 iterations 22.479 usec (2.24789e-05 sec) per iteration: 0.0721123 sec for 3208 iterations 21.613 usec (2.16125e-05 sec) per iteration: 0.0693329 sec for 3208 iterations 21.528 usec (2.1528e-05 sec) per iteration: 0.0690618 sec for 3208 iterations 21.424 usec (2.14243e-05 sec) per iteration: 0.0687291 sec for 3208 iterations mean: 21.947046 usec stddev: 0.528765 usec relative stddev: 2.41% RESULT TestThreadCreateAndJoin: gn_trusted_linux_x86-32= {21.947046, 0.528765} us Measuring clock cycles: first runs (cycles): 69841 69089 50677 51005 50600 49850 49471 50059 48253 49064 ... slowest runs (cycles): ... 50600 50677 51005 51143 53930 55441 69089 69841 81734 118171 min: 38499 cycles q1: 40271 cycles median: 41918 cycles q3: 45743 cycles max: 118171 cycles RESULT TestThreadCreateAndJoin_CycleCount: gn_trusted_linux_x86-32= {41918, 5472} count Apparent clock speed: 1910 MHz TestThreadWakeup: Measuring real time: 13.424 usec (1.34243e-05 sec) per iteration: 0.00134243 sec for 100 iterations 14.535 usec (1.45352e-05 sec) per iteration: 0.108273 sec for 7449 iterations 14.832 usec (1.48318e-05 sec) per iteration: 0.110482 sec for 7449 iterations 14.718 usec (1.47182e-05 sec) per iteration: 0.109636 sec for 7449 iterations 14.552 usec (1.45517e-05 sec) per iteration: 0.108396 sec for 7449 iterations 14.705 usec (1.47054e-05 sec) per iteration: 0.109541 sec for 7449 iterations mean: 14.668469 usec stddev: 0.111270 usec relative stddev: 0.76% RESULT TestThreadWakeup: gn_trusted_linux_x86-32= {14.668469, 0.111270} us Measuring clock cycles: first runs (cycles): 37223 34411 33135 34981 37887 35254 34530 33379 34198 33290 ... slowest runs (cycles): ... 54205 54689 61097 73242 73431 81355 90902 98111 213986 278975 min: 24310 cycles q1: 31103 cycles median: 31905 cycles q3: 34931 cycles max: 278975 cycles RESULT TestThreadWakeup_CycleCount: gn_trusted_linux_x86-32= {31905, 3828} count Apparent clock speed: 2175 MHz WARNING: should have taken less than 2.000000 secs [ OK ] nacl_newlib.run_trusted_performance_test (4460 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