(INFO) 2018-07-06 02:41:32,405 timeout_retry.WaitFor:105 condition '<lambda>' met
(INFO) 2018-07-06 02:41:32,406 timeout_retry.WaitFor:105 condition '<lambda>' met
(WARNING) 2018-07-06 02:41:32,406 desktop_browser_finder.FindAllAvailableBrowsers:274 Chrome build location for mac_x86_64 not found. Browser will be run without Flash.
(INFO) 2018-07-06 02:41:32,575 browser_finder.FindBrowser:123 Chose browser: PossibleDesktopBrowser(type=reference, executable=/b/s/w/ir/third_party/catapult/common/py_utils/py_utils/bin/reference_builds/chrome_stable_mac_x86_64_c8bef32ba36d46afed8fc8483aeb72ce65656986/chrome-mac/Google Chrome.app/Contents/MacOS/Google Chrome, flash=None)
(INFO) 2018-07-06 02:41:32,576 archive_info.DownloadArchivesIfNeeded:68 Downloading WPR archives. This can take a long time.
(INFO) 2018-07-06 02:41:32,577 archive_info.DownloadArchivesIfNeeded:110 All WPR archives are downloaded, took 0.000296115875244 seconds.
(INFO) 2018-07-06 02:41:32,578 timeout_retry.WaitFor:105 condition '<lambda>' met
(INFO) 2018-07-06 02:41:32,578 timeout_retry.WaitFor:105 condition '<lambda>' met
(WARNING) 2018-07-06 02:41:32,578 desktop_browser_finder.FindAllAvailableBrowsers:274 Chrome build location for mac_x86_64 not found. Browser will be run without Flash.
(INFO) 2018-07-06 02:41:32,738 browser_finder.FindBrowser:123 Chose browser: PossibleDesktopBrowser(type=reference, executable=/b/s/w/ir/third_party/catapult/common/py_utils/py_utils/bin/reference_builds/chrome_stable_mac_x86_64_c8bef32ba36d46afed8fc8483aeb72ce65656986/chrome-mac/Google Chrome.app/Contents/MacOS/Google Chrome, flash=None)
(INFO) 2018-07-06 02:41:32,739 ts_proxy_server.StartServer:68 Tsproxy commandline: ['/b/s/w/ir/.swarming_module_cache/vpython/fe1f6b/bin/python', '/b/s/w/ir/third_party/catapult/telemetry/third_party/tsproxy/tsproxy.py', '--port=0', '--desthost=127.0.0.1']
(INFO) 2018-07-06 02:41:32,820 ts_proxy_server.StartServer:75 TsProxy port: 65419
(INFO) 2018-07-06 02:41:32,820 __init__._StartedForwarding:47 DoNothingForwarder started between 127.0.0.1:65419 and 65419
[ RUN ] octane/http://chromium.github.io/octane/index.html?auto=1
(INFO) 2018-07-06 02:41:32,841 webpagereplay_go_server.StartServer:222 Starting Web-Page-Replay: [u'/b/s/w/ir/third_party/catapult/telemetry/telemetry/internal/bin/mac/x86_64/wpr', 'replay', '--http_port=0', '--https_port=0', '--https_key_file=/b/s/w/ir/third_party/catapult/web_page_replay_go/wpr_key.pem', '--https_cert_file=/b/s/w/ir/third_party/catapult/web_page_replay_go/wpr_cert.pem', '--inject_scripts=', u'/b/s/w/ir/tools/perf/page_sets/data/octane_002.wprgo']
(INFO) 2018-07-06 02:41:33,008 webpagereplay_go_server.StartServer:232 WPR ports: {'http': 65422, 'https': 65423}
(INFO) 2018-07-06 02:41:33,008 ts_proxy_server._IssueCommand:97 Issuing command to ts_proxy_server: set mapports 443:65423,*:65422
(INFO) 2018-07-06 02:41:33,034 desktop_browser_backend.Start:239 Starting Chrome [u'/b/s/w/ir/third_party/catapult/common/py_utils/py_utils/bin/reference_builds/chrome_stable_mac_x86_64_c8bef32ba36d46afed8fc8483aeb72ce65656986/chrome-mac/Google Chrome.app/Contents/MacOS/Google Chrome', '--enable-net-benchmarking', '--metrics-recording-only', '--no-default-browser-check', '--no-first-run', '--enable-gpu-benchmarking', '--deny-permission-prompts', '--autoplay-policy=no-user-gesture-required', '--disable-background-networking', '--disable-component-extensions-with-background-pages', '--disable-default-apps', '--disable-search-geolocation-disclosure', '--proxy-server=socks://localhost:65419', '--ignore-certificate-errors-spki-list=PhrPvGIaAMmd29hj8BCZOq096yj7uMpRNHpn5PDxI6I=', '--remote-debugging-port=0', '--enable-crash-reporter-for-testing', '--disable-component-update', '--window-size=1280,1024', '--user-data-dir=/b/s/w/itO80c0O/tmpigYXjk', 'about:blank']
(INFO) 2018-07-06 02:41:33,176 __init__._StartedForwarding:47 DoNothingForwarder started between 127.0.0.1:65426 and 65426
(INFO) 2018-07-06 02:41:33,177 chrome_browser_backend._GetDevToolsClient:118 Got devtools config: ws://127.0.0.1:65426/devtools/browser/23eede87-5fad-437a-a060-3d9a62fa7c2b
(INFO) 2018-07-06 02:41:33,536 browser._LogBrowserInfo:99 Browser started (pid=21040).
(INFO) 2018-07-06 02:41:33,536 browser._LogBrowserInfo:102 OS: mac highsierra
(INFO) 2018-07-06 02:41:33,560 browser._LogBrowserInfo:105 Detailed OS version: 10.13.3 17D47
(INFO) 2018-07-06 02:41:33,904 browser._LogBrowserInfo:109 Model: MacBookPro 11.5
(INFO) 2018-07-06 02:41:33,904 browser._LogBrowserInfo:111 Browser command line: /b/s/w/ir/third_party/catapult/common/py_utils/py_utils/bin/reference_builds/chrome_stable_mac_x86_64_c8bef32ba36d46afed8fc8483aeb72ce65656986/chrome-mac/Google Chrome.app/Contents/MacOS/Google Chrome --enable-net-benchmarking --metrics-recording-only --no-default-browser-check --no-first-run --enable-gpu-benchmarking --deny-permission-prompts --autoplay-policy=no-user-gesture-required --disable-background-networking --disable-component-extensions-with-background-pages --disable-default-apps --disable-search-geolocation-disclosure --proxy-server=socks://localhost:65419 --ignore-certificate-errors-spki-list=PhrPvGIaAMmd29hj8BCZOq096yj7uMpRNHpn5PDxI6I= --remote-debugging-port=0 --enable-crash-reporter-for-testing --disable-component-update --window-size=1280,1024 --user-data-dir=/b/s/w/itO80c0O/tmpigYXjk --flag-switches-begin --flag-switches-end about:blank
(INFO) 2018-07-06 02:41:33,904 browser._LogBrowserInfo:114 GPU device 0: VENDOR = 0x1002 (ATI), DEVICE = 0x6821
(INFO) 2018-07-06 02:41:33,904 browser._LogBrowserInfo:114 GPU device 1: VENDOR = 0x8086 (Intel), DEVICE = 0xd26
(INFO) 2018-07-06 02:41:33,904 browser._LogBrowserInfo:116 GPU Attributes:
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 amd_switchable : True
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 can_support_threaded_texture_mailbox: False
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 direct_composition : False
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 direct_rendering : True
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 driver_date :
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 driver_vendor :
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 driver_version :
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 encrypted_only : False
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 gl_extensions :
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 gl_renderer :
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 gl_reset_notification_strategy: 0
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 gl_vendor :
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 gl_version :
(INFO) 2018-07-06 02:41:33,905 browser._LogBrowserInfo:118 gl_ws_extensions :
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 gl_ws_vendor :
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 gl_ws_version :
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 in_process_gpu : False
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 initialization_time : 0.025577
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 jpeg_decode_accelerator_supported: False
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 max_framerate_denominator: 1
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 max_framerate_numerator: 30
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 max_msaa_samples :
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 max_resolution_height: 2160
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 max_resolution_width: 4096
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 min_resolution_height: 16
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 min_resolution_width: 16
(INFO) 2018-07-06 02:41:33,906 browser._LogBrowserInfo:118 optimus : False
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:118 passthrough_cmd_decoder: False
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:118 pixel_shader_version:
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:118 process_crash_count : 0
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:118 profile : 3
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:118 sandboxed : True
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:118 software_rendering : False
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:118 supports_overlays : False
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:118 vertex_shader_version:
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:118 video_decode_accelerator_flags: 0
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:120 Feature Status:
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:122 2d_canvas : enabled
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:122 checker_imaging : disabled_off
(INFO) 2018-07-06 02:41:33,907 browser._LogBrowserInfo:122 flash_3d : enabled
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:122 flash_stage3d : enabled
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:122 flash_stage3d_baseline: enabled
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:122 gpu_compositing : enabled
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:122 multiple_raster_threads: enabled_on
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:122 native_gpu_memory_buffers: enabled
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:122 rasterization : enabled
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:122 surface_synchronization: enabled_on
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:122 video_decode : enabled
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:122 webgl : enabled
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:122 webgl2 : enabled
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:124 Driver Bug Workarounds:
(INFO) 2018-07-06 02:41:33,908 browser._LogBrowserInfo:126 add_and_true_to_loop_condition
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 adjust_src_dst_region_for_blitframebuffer
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 avoid_stencil_buffers
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 decode_encode_srgb_for_generatemipmap
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 disable_framebuffer_cmaa
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 disable_webgl_rgb_multisampling_usage
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 dont_use_loops_to_initialize_variables
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 emulate_abs_int_function
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 get_frag_data_info_bug
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 init_two_cube_map_levels_before_copyteximage
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 msaa_is_slow
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 pack_parameters_workaround_with_pack_buffer
(INFO) 2018-07-06 02:41:33,909 browser._LogBrowserInfo:126 rebind_transform_feedback_before_resume
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 regenerate_struct_names
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 remove_invariant_and_centroid_for_essl3
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 reset_teximage2d_base_level
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 rewrite_texelfetchoffset_to_texelfetch
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 scalarize_vec_and_mat_constructor_args
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 set_zero_level_before_generating_mipmap
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 unfold_short_circuit_as_ternary_operation
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 unpack_alignment_workaround_with_unpack_buffer
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 unpack_image_height_workaround_with_unpack_buffer
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 use_intermediary_for_copy_texture_image
(INFO) 2018-07-06 02:41:33,910 browser._LogBrowserInfo:126 use_unused_standard_shared_blocks
(INFO) 2018-07-06 02:41:33,925 ts_proxy_server._IssueCommand:97 Issuing command to ts_proxy_server: set rtt 0
(INFO) 2018-07-06 02:41:33,926 ts_proxy_server._IssueCommand:97 Issuing command to ts_proxy_server: set inkbps 0
(INFO) 2018-07-06 02:41:33,926 ts_proxy_server._IssueCommand:97 Issuing command to ts_proxy_server: set outkbps 0
(INFO) 2018-07-06 02:41:33,927 cache_temperature.EnsurePageCacheTemperature:179 PageCacheTemperature: any
(INFO) 2018-07-06 02:42:10,551 browser.Close:207 Closing browser (pid=21040) ...
(INFO) 2018-07-06 02:42:10,719 browser.Close:220 Browser is closed.
[ OK ] octane/http://chromium.github.io/octane/index.html?auto=1 (37908 ms)
(INFO) 2018-07-06 02:42:11,308 cloud_storage.Insert:378 Uploading /b/s/w/itO80c0O/tmpdjUyD9telemetry/artifacts/telemetry_testCAXB9B to gs://chrome-telemetry-output/db3d6ac0-8100-11e8-8ba1-787b8ab93ad2
Uploading logs of page http://chromium.github.io/octane/index.html?auto=1 to https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/db3d6ac0-8100-11e8-8ba1-787b8ab93ad2 (1 out of 1)
(INFO) 2018-07-06 02:42:12,851 memory_debug.LogHostMemoryUsage:60 Used 4.2 GiB out of 16.0 GiB memory available.
(INFO) 2018-07-06 02:42:12,851 memory_debug.LogHostMemoryUsage:61 Memory usage of top 10 processes groups
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:77 - Python - 104.5 MiB - pids: ['291', '18005', '18006']
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:77 - python2.7 - 100.4 MiB - pids: ['18011', '18016', '21026']
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:77 - NotificationCenter - 46.0 MiB - pids: ['293']
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:77 - Finder - 43.4 MiB - pids: ['254']
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:77 - python - 36.8 MiB - pids: ['301']
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:77 - routined - 33.2 MiB - pids: ['286']
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:77 - suggestd - 32.9 MiB - pids: ['344']
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:77 - SystemUIServer - 32.9 MiB - pids: ['252']
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:77 - CalendarAgent - 32.6 MiB - pids: ['298']
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:77 - soagent - 30.8 MiB - pids: ['307']
(INFO) 2018-07-06 02:42:12,866 memory_debug.LogHostMemoryUsage:78 Current process:
(INFO) 2018-07-06 02:42:12,866 memory_debug._LogProcessInfo:41 55.5 MiB (pid=21026)
[ PASSED ] 1 test.
(WARNING) 2018-07-06 02:42:12,869 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,871 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,873 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,875 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,877 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,879 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,880 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,882 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,884 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,886 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,888 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,890 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,892 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,894 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,896 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,898 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,900 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,902 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,904 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,905 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
(WARNING) 2018-07-06 02:42:12,907 histogram_set_json_output_formatter.Format:27 Found existing histograms json but failed to parse it.
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/histograms.json
View result at file:///b/s/w/itO80c0O/tmpdjUyD9telemetry/test-results.json