builder: mozilla-inbound_ubuntu64_hw_test-other slave: talos-linux64-ix-037 starttime: 1446505037.31 results: success (0) buildid: 20151102135706 builduid: 6d7211a371c4417c8c08127c901046af revision: 11dd4cfb65639257a3c3e87886c0b6157be5b876 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.309299) ========= master: http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.310081) ========= ========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.310376) ========= bash -c pwd in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'pwd'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False /builds/slave/test program finished with exit code 0 elapsedTime=0.006483 basedir: '/builds/slave/test' ========= master_lag: 0.02 ========= ========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.340635) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.343989) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.432033) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.432288) ========= rm -rf properties in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'properties'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004753 ========= master_lag: 0.07 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.507695) ========= ========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.507975) ========= script_repo_url: https://hg.mozilla.org/build/mozharness ========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.508321) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.508625) ========= bash -c 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py' in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2015-11-02 14:57:17-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.25, 63.245.215.102 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.25|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12141 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 84.2M=0s 2015-11-02 14:57:17 (84.2 MB/s) - `archiver_client.py' saved [12141/12141] program finished with exit code 0 elapsedTime=0.190456 ========= master_lag: 0.04 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.736777) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.737078) ========= rm -rf scripts in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'scripts'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.015777 ========= master_lag: 0.04 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:17.792316) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-11-02 14:57:17.792637) ========= bash -c 'python archiver_client.py mozharness --repo integration/mozilla-inbound --rev 11dd4cfb65639257a3c3e87886c0b6157be5b876 --destination scripts --debug' in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', u'python archiver_client.py mozharness --repo integration/mozilla-inbound --rev 11dd4cfb65639257a3c3e87886c0b6157be5b876 --destination scripts --debug'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2015-11-02 14:57:17,895 truncating revision to first 12 chars 2015-11-02 14:57:17,895 Setting DEBUG logging. 2015-11-02 14:57:17,895 attempt 1/10 2015-11-02 14:57:17,895 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/mozilla-inbound/11dd4cfb6563?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2015-11-02 14:57:18,760 unpacking tar archive at: mozilla-inbound-11dd4cfb6563/testing/mozharness/ program finished with exit code 0 elapsedTime=1.164675 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-11-02 14:57:18.973255) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:18.973556) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:18.981799) ========= ========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:18.982089) ========= TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production ========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-02 14:57:18.982495) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 7 mins, 30 secs) (at 2015-11-02 14:57:18.982836) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Inbound-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Inbound-Non-PGO in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'other', '--add-option', '--webServer,localhost', '--branch-name', 'Mozilla-Inbound-Non-PGO', '--system-bits', '64', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Mozilla-Inbound-Non-PGO'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 14:57:19 INFO - MultiFileLogger online at 20151102 14:57:19 in /builds/slave/test 14:57:19 INFO - Run as scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Inbound-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Inbound-Non-PGO 14:57:19 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 14:57:19 INFO - {'append_to_log': False, 14:57:19 INFO - 'base_work_dir': '/builds/slave/test', 14:57:19 INFO - 'blob_upload_branch': 'Mozilla-Inbound-Non-PGO', 14:57:19 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 14:57:19 INFO - 'branch': 'Mozilla-Inbound-Non-PGO', 14:57:19 INFO - 'buildbot_json_path': 'buildprops.json', 14:57:19 INFO - 'config_files': ('talos/linux_config.py',), 14:57:19 INFO - 'default_actions': ('clobber', 14:57:19 INFO - 'read-buildbot-config', 14:57:19 INFO - 'download-and-extract', 14:57:19 INFO - 'populate-webroot', 14:57:19 INFO - 'create-virtualenv', 14:57:19 INFO - 'install', 14:57:19 INFO - 'run-tests'), 14:57:19 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 14:57:19 INFO - 'download_minidump_stackwalk': True, 14:57:19 INFO - 'download_symbols': 'ondemand', 14:57:19 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 14:57:19 INFO - 'tooltool.py': '/tools/tooltool.py', 14:57:19 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 14:57:19 INFO - '/tools/misc-python/virtualenv.py')}, 14:57:19 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 14:57:19 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 14:57:19 INFO - 'installer_path': 'installer.exe', 14:57:19 INFO - 'log_level': 'info', 14:57:19 INFO - 'log_name': 'talos', 14:57:19 INFO - 'log_to_console': True, 14:57:19 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 14:57:19 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 14:57:19 INFO - 'opt_config_files': (), 14:57:19 INFO - 'pip_index': False, 14:57:19 INFO - 'sps_profile': False, 14:57:19 INFO - 'sps_profile_interval': 0, 14:57:19 INFO - 'suite': 'other', 14:57:19 INFO - 'system_bits': '64', 14:57:19 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 14:57:19 INFO - 'title': 'talos-linux64-ix-037', 14:57:19 INFO - 'tooltool_cache': '/builds/tooltool_cache', 14:57:19 INFO - 'use_talos_json': True, 14:57:19 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 14:57:19 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 14:57:19 INFO - 'work_dir': 'build'} 14:57:19 INFO - ##### 14:57:19 INFO - ##### Running clobber step. 14:57:19 INFO - ##### 14:57:19 INFO - Running pre-action listener: _resource_record_pre_action 14:57:19 INFO - Running main action method: clobber 14:57:19 INFO - rmtree: /builds/slave/test/build 14:57:19 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 14:57:19 INFO - Running post-action listener: _resource_record_post_action 14:57:19 INFO - ##### 14:57:19 INFO - ##### Running read-buildbot-config step. 14:57:19 INFO - ##### 14:57:19 INFO - Running pre-action listener: _resource_record_pre_action 14:57:19 INFO - Running main action method: read_buildbot_config 14:57:19 INFO - Using buildbot properties: 14:57:19 INFO - { 14:57:19 INFO - "properties": { 14:57:19 INFO - "buildnumber": 721, 14:57:19 INFO - "product": "firefox", 14:57:19 INFO - "script_repo_revision": "production", 14:57:19 INFO - "builddir": "mozilla-inbound_ubuntu64_hw_test-other", 14:57:19 INFO - "repository": "", 14:57:19 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-inbound talos other", 14:57:19 INFO - "buildid": "20151102135706", 14:57:19 INFO - "slavename": "talos-linux64-ix-037", 14:57:19 INFO - "pgo_build": "False", 14:57:19 INFO - "basedir": "/builds/slave/test", 14:57:19 INFO - "project": "", 14:57:19 INFO - "platform": "ubuntu64_hw", 14:57:19 INFO - "master": "http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/", 14:57:19 INFO - "slavebuilddir": "test", 14:57:19 INFO - "scheduler": "tests-mozilla-inbound-linux64-talos", 14:57:19 INFO - "branch": "mozilla-inbound", 14:57:19 INFO - "repo_path": "integration/mozilla-inbound", 14:57:19 INFO - "stage_platform": "linux64", 14:57:19 INFO - "builduid": "6d7211a371c4417c8c08127c901046af", 14:57:19 INFO - "revision": "11dd4cfb65639257a3c3e87886c0b6157be5b876" 14:57:19 INFO - }, 14:57:19 INFO - "sourcestamp": { 14:57:19 INFO - "repository": "", 14:57:19 INFO - "hasPatch": false, 14:57:19 INFO - "project": "", 14:57:19 INFO - "branch": "mozilla-inbound-linux64-talos", 14:57:19 INFO - "changes": [ 14:57:19 INFO - { 14:57:19 INFO - "category": null, 14:57:19 INFO - "files": [ 14:57:19 INFO - { 14:57:19 INFO - "url": null, 14:57:19 INFO - "name": "https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2" 14:57:19 INFO - } 14:57:19 INFO - ], 14:57:19 INFO - "repository": "", 14:57:19 INFO - "rev": "11dd4cfb65639257a3c3e87886c0b6157be5b876", 14:57:19 INFO - "who": "nfroyd@mozilla.com", 14:57:19 INFO - "when": 1446504991, 14:57:19 INFO - "number": 6611592, 14:57:19 INFO - "comments": "Bug 1220491 - clarify ownership relationships for creators of AudioData; r=gerald\n\nThe way we pass in AudioDataValue arrays into AudioData is non-uniform:\nsometimes we have nsAutoArrayPtrs, sometimes we don't, and it's not\nimmediately obvious from the function signature of the constructor that\nwe're actually taking ownership of this array. Let's fix that by using\nUniquePtr smart pointers to hold the data prior to\ncreating AudioData values, and for passing in to AudioData's\nconstructor. Using standard-er C++ things instead of our homegrown ones\nis a good thing.", 14:57:19 INFO - "project": "", 14:57:19 INFO - "at": "Mon 02 Nov 2015 14:56:31", 14:57:19 INFO - "branch": "mozilla-inbound-linux64-talos", 14:57:19 INFO - "revlink": "", 14:57:19 INFO - "properties": [ 14:57:19 INFO - [ 14:57:19 INFO - "buildid", 14:57:19 INFO - "20151102135706", 14:57:19 INFO - "Change" 14:57:19 INFO - ], 14:57:19 INFO - [ 14:57:19 INFO - "builduid", 14:57:19 INFO - "6d7211a371c4417c8c08127c901046af", 14:57:19 INFO - "Change" 14:57:19 INFO - ], 14:57:19 INFO - [ 14:57:19 INFO - "pgo_build", 14:57:19 INFO - "False", 14:57:19 INFO - "Change" 14:57:19 INFO - ] 14:57:19 INFO - ], 14:57:19 INFO - "revision": "11dd4cfb65639257a3c3e87886c0b6157be5b876" 14:57:19 INFO - } 14:57:19 INFO - ], 14:57:19 INFO - "revision": "11dd4cfb65639257a3c3e87886c0b6157be5b876" 14:57:19 INFO - } 14:57:19 INFO - } 14:57:19 INFO - Found installer url https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2. 14:57:19 INFO - Running post-action listener: _resource_record_post_action 14:57:19 INFO - ##### 14:57:19 INFO - ##### Running download-and-extract step. 14:57:19 INFO - ##### 14:57:19 INFO - Running pre-action listener: _resource_record_pre_action 14:57:19 INFO - Running main action method: download_and_extract 14:57:19 INFO - mkdir: /builds/slave/test/build/tests 14:57:19 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:19 INFO - https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net 14:57:19 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/test_packages.json 14:57:19 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/test_packages.json 14:57:19 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json 14:57:19 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/test_packages.json', 'file_name': '/builds/slave/test/build/test_packages.json'}, attempt #1 14:57:22 INFO - Downloaded 1302 bytes. 14:57:22 INFO - Reading from file /builds/slave/test/build/test_packages.json 14:57:22 INFO - Using the following test package requirements: 14:57:22 INFO - {u'common': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 14:57:22 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 14:57:22 INFO - u'firefox-45.0a1.en-US.linux-x86_64.cppunittest.tests.zip'], 14:57:22 INFO - u'jittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 14:57:22 INFO - u'jsshell-linux-x86_64.zip'], 14:57:22 INFO - u'mochitest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 14:57:22 INFO - u'firefox-45.0a1.en-US.linux-x86_64.mochitest.tests.zip'], 14:57:22 INFO - u'mozbase': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 14:57:22 INFO - u'reftest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 14:57:22 INFO - u'firefox-45.0a1.en-US.linux-x86_64.reftest.tests.zip'], 14:57:22 INFO - u'talos': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 14:57:22 INFO - u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'], 14:57:22 INFO - u'web-platform': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 14:57:22 INFO - u'firefox-45.0a1.en-US.linux-x86_64.web-platform.tests.zip'], 14:57:22 INFO - u'webapprt': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 14:57:22 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 14:57:22 INFO - u'firefox-45.0a1.en-US.linux-x86_64.xpcshell.tests.zip']} 14:57:22 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] for test suite category: common 14:57:22 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:22 INFO - https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net 14:57:22 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 14:57:22 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 14:57:22 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 14:57:22 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'}, attempt #1 14:57:23 INFO - Downloaded 21245013 bytes. 14:57:23 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test/build/tests 14:57:23 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 14:57:23 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760 14:57:24 INFO - Return code: 0 14:57:24 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] for test suite category: talos 14:57:24 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:24 INFO - https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net 14:57:24 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 14:57:24 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 14:57:24 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 14:57:24 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'}, attempt #1 14:57:25 INFO - Downloaded 21245013 bytes. 14:57:25 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test/build/tests 14:57:25 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 14:57:25 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760 14:57:27 INFO - Return code: 0 14:57:27 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:27 INFO - https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip matches https://queue.taskcluster.net 14:57:27 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 14:57:27 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 14:57:27 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 14:57:27 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'}, attempt #1 14:57:28 INFO - Downloaded 11131307 bytes. 14:57:28 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] in /builds/slave/test/build/tests 14:57:28 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 14:57:28 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] with output_timeout 1760 14:57:28 INFO - Return code: 0 14:57:28 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:28 INFO - https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 matches https://queue.taskcluster.net 14:57:28 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 14:57:28 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 14:57:28 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 14:57:28 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2', 'file_name': '/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2'}, attempt #1 14:57:32 INFO - Downloaded 55539197 bytes. 14:57:32 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 14:57:32 INFO - mkdir: /builds/slave/test/properties 14:57:32 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 14:57:32 INFO - Writing to file /builds/slave/test/properties/build_url 14:57:32 INFO - Contents: 14:57:32 INFO - build_url:https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 14:57:32 INFO - Running post-action listener: _resource_record_post_action 14:57:32 INFO - Running post-action listener: set_extra_try_arguments 14:57:32 INFO - ##### 14:57:32 INFO - ##### Running populate-webroot step. 14:57:32 INFO - ##### 14:57:32 INFO - Running pre-action listener: _resource_record_pre_action 14:57:32 INFO - Running main action method: populate_webroot 14:57:32 INFO - Guessing talos json url... 14:57:32 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:32 INFO - https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.txt matches https://queue.taskcluster.net 14:57:32 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.txt 14:57:32 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.txt 14:57:32 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.txt to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.txt 14:57:32 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.txt', 'file_name': '/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.txt'}, attempt #1 14:57:34 INFO - Downloaded 111 bytes. 14:57:34 INFO - Reading from file /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.txt 14:57:34 INFO - Contents: 14:57:34 INFO - 20151102135706 14:57:34 INFO - https://hg.mozilla.org/integration/mozilla-inbound/rev/11dd4cfb65639257a3c3e87886c0b6157be5b876 14:57:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:34 INFO - trying https://hg.mozilla.org/integration/mozilla-inbound/raw-file/11dd4cfb65/testing/talos/talos.json 14:57:34 INFO - Downloading https://hg.mozilla.org/integration/mozilla-inbound/raw-file/11dd4cfb65/testing/talos/talos.json to /builds/slave/test/build/talos.json 14:57:34 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://hg.mozilla.org/integration/mozilla-inbound/raw-file/11dd4cfb65/testing/talos/talos.json', 'file_name': '/builds/slave/test/build/talos.json'}, attempt #1 14:57:35 INFO - Downloaded 4264 bytes. 14:57:35 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']}, 14:57:35 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']}, 14:57:35 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs', 14:57:35 INFO - '../fennec_ids.txt'], 14:57:35 INFO - 'tests': ['tcheck2']}, 14:57:35 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome', 14:57:35 INFO - '--tppagecycles', 14:57:35 INFO - '7'], 14:57:35 INFO - 'tests': ['tsvgm']}}, 14:57:35 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']}, 14:57:35 INFO - 'chromez-e10s': {'talos_options': ['--e10s'], 14:57:35 INFO - 'tests': ['tresize', 'tcanvasmark']}, 14:57:35 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 14:57:35 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'], 14:57:35 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 14:57:35 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 14:57:35 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 14:57:35 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 14:57:35 INFO - 'talos_options': ['--e10s'], 14:57:35 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 14:57:35 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 14:57:35 INFO - 'tests': ['damp', 'tps']}, 14:57:35 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 14:57:35 INFO - 'talos_options': ['--e10s'], 14:57:35 INFO - 'tests': ['damp', 'tps']}, 14:57:35 INFO - 'g3': {'tests': ['dromaeo_dom']}, 14:57:35 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 14:57:35 INFO - 'other': {'tests': ['a11yr', 14:57:35 INFO - 'ts_paint', 14:57:35 INFO - 'tpaint', 14:57:35 INFO - 'sessionrestore', 14:57:35 INFO - 'sessionrestore_no_auto_restore']}, 14:57:35 INFO - 'other-e10s': {'talos_options': ['--e10s'], 14:57:35 INFO - 'tests': ['a11yr', 14:57:35 INFO - 'ts_paint', 14:57:35 INFO - 'tpaint', 14:57:35 INFO - 'sessionrestore', 14:57:35 INFO - 'sessionrestore_no_auto_restore']}, 14:57:35 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'], 14:57:35 INFO - 'tests': ['a11yr', 14:57:35 INFO - 'ts_paint', 14:57:35 INFO - 'tpaint', 14:57:35 INFO - 'sessionrestore', 14:57:35 INFO - 'sessionrestore_no_auto_restore']}, 14:57:35 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'], 14:57:35 INFO - 'tests': ['a11yr', 14:57:35 INFO - 'ts_paint', 14:57:35 INFO - 'tpaint', 14:57:35 INFO - 'sessionrestore', 14:57:35 INFO - 'sessionrestore_no_auto_restore']}, 14:57:35 INFO - 'other_l64': {'tests': ['a11yr', 14:57:35 INFO - 'ts_paint', 14:57:35 INFO - 'tpaint', 14:57:35 INFO - 'sessionrestore', 14:57:35 INFO - 'sessionrestore_no_auto_restore']}, 14:57:35 INFO - 'other_nol64': {'tests': ['a11yr', 14:57:35 INFO - 'ts_paint', 14:57:35 INFO - 'tpaint', 14:57:35 INFO - 'sessionrestore', 14:57:35 INFO - 'sessionrestore_no_auto_restore']}, 14:57:35 INFO - 'svgr': {'tests': ['tsvgx', 14:57:35 INFO - 'tsvgr_opacity', 14:57:35 INFO - 'tart', 14:57:35 INFO - 'tscrollx', 14:57:35 INFO - 'cart']}, 14:57:35 INFO - 'svgr-e10s': {'talos_options': ['--e10s'], 14:57:35 INFO - 'tests': ['tsvgx', 14:57:35 INFO - 'tsvgr_opacity', 14:57:35 INFO - 'tart', 14:57:35 INFO - 'tscrollx', 14:57:35 INFO - 'cart']}, 14:57:35 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 14:57:35 INFO - 'tests': ['tp5o']}, 14:57:35 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 14:57:35 INFO - 'talos_options': ['--e10s'], 14:57:35 INFO - 'tests': ['tp5o']}, 14:57:35 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 14:57:35 INFO - 'talos_options': ['--xperf_path', 14:57:35 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 14:57:35 INFO - 'tests': ['tp5n']}, 14:57:35 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 14:57:35 INFO - 'talos_options': ['--e10s', 14:57:35 INFO - '--xperf_path', 14:57:35 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"', 14:57:35 INFO - 'C:/slave/talos-data/talos/xperf.config'], 14:57:35 INFO - 'tests': ['tp5n']}}, 14:57:35 INFO - 'talos.zip': {'path': '', 14:57:35 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}} 14:57:35 INFO - Running post-action listener: _resource_record_post_action 14:57:35 INFO - ##### 14:57:35 INFO - ##### Running create-virtualenv step. 14:57:35 INFO - ##### 14:57:35 INFO - Running pre-action listener: _resource_record_pre_action 14:57:35 INFO - Running main action method: create_virtualenv 14:57:35 INFO - Creating virtualenv /builds/slave/test/build/venv 14:57:35 INFO - Running command: ['/tools/buildbot/bin/python', '/tools/misc-python/virtualenv.py', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build 14:57:35 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv 14:57:35 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 14:57:35 INFO - Using real prefix '/usr' 14:57:35 INFO - New python executable in /builds/slave/test/build/venv/bin/python 14:57:35 INFO - Installing distribute.............................................................................................................................................................................................done. 14:57:37 INFO - Installing pip.................done. 14:57:37 INFO - Return code: 0 14:57:37 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 14:57:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:37 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 14:57:37 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:37 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 14:57:37 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:37 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f1ac93e8c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b027b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1bcdf80>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c649d0>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c659e0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1c65e70>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 14:57:37 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in /builds/slave/test/build 14:57:37 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5 14:57:37 INFO - Using env: {'DISPLAY': ':0', 14:57:37 INFO - 'HOME': '/home/cltbld', 14:57:37 INFO - 'LANG': 'en_US.UTF-8', 14:57:37 INFO - 'LANGUAGE': 'en_US:en', 14:57:37 INFO - 'LOGNAME': 'cltbld', 14:57:37 INFO - 'MAIL': '/var/mail/cltbld', 14:57:37 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 14:57:37 INFO - 'MOZ_NO_REMOTE': '1', 14:57:37 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 14:57:37 INFO - 'NO_EM_RESTART': '1', 14:57:37 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 14:57:37 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 14:57:37 INFO - 'PWD': '/builds/slave/test', 14:57:37 INFO - 'SHELL': '/bin/bash', 14:57:37 INFO - 'SHLVL': '1', 14:57:37 INFO - 'TERM': 'linux', 14:57:37 INFO - 'TMOUT': '86400', 14:57:37 INFO - 'USER': 'cltbld', 14:57:37 INFO - 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 14:57:37 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 14:57:37 INFO - '_': '/tools/buildbot/bin/python'} 14:57:37 INFO - Ignoring indexes: https://pypi.python.org/simple/ 14:57:37 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages/pip-1.5.5-py2.7.egg 14:57:37 INFO - Cleaning up... 14:57:37 INFO - Return code: 0 14:57:37 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv 14:57:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:37 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 14:57:37 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:37 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 14:57:37 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:37 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=0.7.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f1ac93e8c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b027b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1bcdf80>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c649d0>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c659e0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1c65e70>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 14:57:37 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=0.7.1'] in /builds/slave/test/build 14:57:37 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=0.7.1 14:57:37 INFO - Using env: {'DISPLAY': ':0', 14:57:37 INFO - 'HOME': '/home/cltbld', 14:57:37 INFO - 'LANG': 'en_US.UTF-8', 14:57:37 INFO - 'LANGUAGE': 'en_US:en', 14:57:37 INFO - 'LOGNAME': 'cltbld', 14:57:37 INFO - 'MAIL': '/var/mail/cltbld', 14:57:37 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 14:57:37 INFO - 'MOZ_NO_REMOTE': '1', 14:57:37 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 14:57:37 INFO - 'NO_EM_RESTART': '1', 14:57:37 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 14:57:37 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 14:57:37 INFO - 'PWD': '/builds/slave/test', 14:57:37 INFO - 'SHELL': '/bin/bash', 14:57:37 INFO - 'SHLVL': '1', 14:57:37 INFO - 'TERM': 'linux', 14:57:37 INFO - 'TMOUT': '86400', 14:57:37 INFO - 'USER': 'cltbld', 14:57:37 INFO - 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 14:57:37 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 14:57:37 INFO - '_': '/tools/buildbot/bin/python'} 14:57:38 INFO - Ignoring indexes: https://pypi.python.org/simple/ 14:57:38 INFO - Downloading/unpacking psutil>=0.7.1 14:57:38 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:38 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:38 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:38 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:38 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:38 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:39 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache 14:57:39 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz 14:57:39 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 14:57:39 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 14:57:39 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 14:57:39 INFO - Installing collected packages: psutil 14:57:39 INFO - Running setup.py install for psutil 14:57:39 INFO - building 'psutil._psutil_linux' extension 14:57:39 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -DPSUTIL_VERSION=311 -I/usr/include/python2.7 -c psutil/_psutil_linux.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o 14:57:40 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_linux.so 14:57:40 INFO - building 'psutil._psutil_posix' extension 14:57:40 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -I/usr/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o 14:57:40 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_posix.so 14:57:40 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 14:57:40 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 14:57:40 INFO - Successfully installed psutil 14:57:40 INFO - Cleaning up... 14:57:40 INFO - Return code: 0 14:57:40 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv 14:57:40 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:40 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 14:57:40 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:40 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:40 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 14:57:40 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:40 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.0.0']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f1ac93e8c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b027b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1bcdf80>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c649d0>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c659e0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1c65e70>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 14:57:40 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.0.0'] in /builds/slave/test/build 14:57:40 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.0.0 14:57:40 INFO - Using env: {'DISPLAY': ':0', 14:57:40 INFO - 'HOME': '/home/cltbld', 14:57:40 INFO - 'LANG': 'en_US.UTF-8', 14:57:40 INFO - 'LANGUAGE': 'en_US:en', 14:57:40 INFO - 'LOGNAME': 'cltbld', 14:57:40 INFO - 'MAIL': '/var/mail/cltbld', 14:57:40 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 14:57:40 INFO - 'MOZ_NO_REMOTE': '1', 14:57:40 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 14:57:40 INFO - 'NO_EM_RESTART': '1', 14:57:40 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 14:57:40 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 14:57:40 INFO - 'PWD': '/builds/slave/test', 14:57:40 INFO - 'SHELL': '/bin/bash', 14:57:40 INFO - 'SHLVL': '1', 14:57:40 INFO - 'TERM': 'linux', 14:57:40 INFO - 'TMOUT': '86400', 14:57:40 INFO - 'USER': 'cltbld', 14:57:40 INFO - 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 14:57:40 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 14:57:40 INFO - '_': '/tools/buildbot/bin/python'} 14:57:40 INFO - Ignoring indexes: https://pypi.python.org/simple/ 14:57:40 INFO - Downloading/unpacking mozsystemmonitor==0.0.0 14:57:40 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:40 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:40 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:40 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:40 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:40 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:42 INFO - Downloading mozsystemmonitor-0.0.tar.gz 14:57:42 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz 14:57:42 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 14:57:42 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0) 14:57:42 INFO - Installing collected packages: mozsystemmonitor 14:57:42 INFO - Running setup.py install for mozsystemmonitor 14:57:42 INFO - Successfully installed mozsystemmonitor 14:57:42 INFO - Cleaning up... 14:57:42 INFO - Return code: 0 14:57:42 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 14:57:42 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:42 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 14:57:42 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:42 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:42 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 14:57:42 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:42 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f1ac93e8c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b027b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1bcdf80>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c649d0>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c659e0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1c65e70>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 14:57:42 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in /builds/slave/test/build 14:57:42 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4 14:57:42 INFO - Using env: {'DISPLAY': ':0', 14:57:42 INFO - 'HOME': '/home/cltbld', 14:57:42 INFO - 'LANG': 'en_US.UTF-8', 14:57:42 INFO - 'LANGUAGE': 'en_US:en', 14:57:42 INFO - 'LOGNAME': 'cltbld', 14:57:42 INFO - 'MAIL': '/var/mail/cltbld', 14:57:42 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 14:57:42 INFO - 'MOZ_NO_REMOTE': '1', 14:57:42 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 14:57:42 INFO - 'NO_EM_RESTART': '1', 14:57:42 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 14:57:42 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 14:57:42 INFO - 'PWD': '/builds/slave/test', 14:57:42 INFO - 'SHELL': '/bin/bash', 14:57:42 INFO - 'SHLVL': '1', 14:57:42 INFO - 'TERM': 'linux', 14:57:42 INFO - 'TMOUT': '86400', 14:57:42 INFO - 'USER': 'cltbld', 14:57:42 INFO - 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 14:57:42 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 14:57:42 INFO - '_': '/tools/buildbot/bin/python'} 14:57:42 INFO - Ignoring indexes: https://pypi.python.org/simple/ 14:57:42 INFO - Downloading/unpacking blobuploader==1.2.4 14:57:42 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:42 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:42 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:42 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:42 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:42 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:44 INFO - Downloading blobuploader-1.2.4.tar.gz 14:57:44 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz 14:57:44 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 14:57:44 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 14:57:44 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:44 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:44 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:44 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:44 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:44 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:44 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz 14:57:44 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 14:57:44 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 14:57:44 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:44 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:44 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:44 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:44 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:44 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:45 INFO - Downloading docopt-0.6.1.tar.gz 14:57:45 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz 14:57:45 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 14:57:45 INFO - Installing collected packages: blobuploader, requests, docopt 14:57:45 INFO - Running setup.py install for blobuploader 14:57:45 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 14:57:45 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 14:57:45 INFO - Running setup.py install for requests 14:57:45 INFO - Running setup.py install for docopt 14:57:45 INFO - Successfully installed blobuploader requests docopt 14:57:45 INFO - Cleaning up... 14:57:45 INFO - Return code: 0 14:57:45 INFO - Installing None into virtualenv /builds/slave/test/build/venv 14:57:45 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:45 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 14:57:45 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:45 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:45 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 14:57:45 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:45 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f1ac93e8c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b027b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1bcdf80>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c649d0>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c659e0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1c65e70>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 14:57:45 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 14:57:45 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 14:57:45 INFO - Using env: {'DISPLAY': ':0', 14:57:45 INFO - 'HOME': '/home/cltbld', 14:57:45 INFO - 'LANG': 'en_US.UTF-8', 14:57:45 INFO - 'LANGUAGE': 'en_US:en', 14:57:45 INFO - 'LOGNAME': 'cltbld', 14:57:45 INFO - 'MAIL': '/var/mail/cltbld', 14:57:45 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 14:57:45 INFO - 'MOZ_NO_REMOTE': '1', 14:57:45 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 14:57:45 INFO - 'NO_EM_RESTART': '1', 14:57:45 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 14:57:45 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 14:57:45 INFO - 'PWD': '/builds/slave/test', 14:57:45 INFO - 'SHELL': '/bin/bash', 14:57:45 INFO - 'SHLVL': '1', 14:57:45 INFO - 'TERM': 'linux', 14:57:45 INFO - 'TMOUT': '86400', 14:57:45 INFO - 'USER': 'cltbld', 14:57:45 INFO - 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 14:57:45 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 14:57:45 INFO - '_': '/tools/buildbot/bin/python'} 14:57:45 INFO - Ignoring indexes: https://pypi.python.org/simple/ 14:57:45 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 14:57:45 INFO - Running setup.py (path:/tmp/pip-zaNXKe-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 14:57:46 INFO - Running setup.py (path:/tmp/pip-e9shyQ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 14:57:46 INFO - Running setup.py (path:/tmp/pip-w9IuFm-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 14:57:46 INFO - Running setup.py (path:/tmp/pip-iheVGC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 14:57:46 INFO - Running setup.py (path:/tmp/pip-yLQ8fQ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 14:57:46 INFO - Running setup.py (path:/tmp/pip-po9zZ_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 14:57:46 INFO - Running setup.py (path:/tmp/pip-YLDjaY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 14:57:46 INFO - Running setup.py (path:/tmp/pip-6rAsUg-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 14:57:46 INFO - Running setup.py (path:/tmp/pip-GzSjfi-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 14:57:46 INFO - Running setup.py (path:/tmp/pip-zRjEMX-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 14:57:46 INFO - Running setup.py (path:/tmp/pip-gRPl6q-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 14:57:46 INFO - Running setup.py (path:/tmp/pip-RxxTCL-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 14:57:46 INFO - Running setup.py (path:/tmp/pip-qoKfkd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 14:57:46 INFO - Running setup.py (path:/tmp/pip-NlAzh6-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 14:57:46 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 14:57:46 INFO - Running setup.py (path:/tmp/pip-eBQsOF-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 14:57:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 14:57:47 INFO - Running setup.py (path:/tmp/pip-EZLKUB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 14:57:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 14:57:47 INFO - Running setup.py (path:/tmp/pip-f3edy3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 14:57:47 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 14:57:47 INFO - Running setup.py install for manifestparser 14:57:47 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 14:57:47 INFO - Running setup.py install for mozcrash 14:57:47 INFO - Running setup.py install for mozdebug 14:57:47 INFO - Running setup.py install for mozdevice 14:57:47 INFO - Installing sutini script to /builds/slave/test/build/venv/bin 14:57:47 INFO - Installing dm script to /builds/slave/test/build/venv/bin 14:57:47 INFO - Running setup.py install for mozfile 14:57:47 INFO - Running setup.py install for mozhttpd 14:57:47 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 14:57:47 INFO - Running setup.py install for mozinfo 14:57:47 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 14:57:47 INFO - Running setup.py install for mozInstall 14:57:47 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 14:57:47 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 14:57:47 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 14:57:47 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 14:57:47 INFO - Running setup.py install for mozleak 14:57:48 INFO - Running setup.py install for mozlog 14:57:48 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 14:57:48 INFO - Running setup.py install for moznetwork 14:57:48 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 14:57:48 INFO - Running setup.py install for mozprocess 14:57:48 INFO - Running setup.py install for mozprofile 14:57:48 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 14:57:48 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 14:57:48 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 14:57:48 INFO - Running setup.py install for mozrunner 14:57:48 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 14:57:48 INFO - Running setup.py install for mozscreenshot 14:57:48 INFO - Running setup.py install for moztest 14:57:48 INFO - Running setup.py install for mozversion 14:57:48 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 14:57:48 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 14:57:48 INFO - Cleaning up... 14:57:48 INFO - Return code: 0 14:57:48 INFO - Installing None into virtualenv /builds/slave/test/build/venv 14:57:48 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:48 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 14:57:48 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:48 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:48 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 14:57:48 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:48 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f1ac93e8c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b027b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1bcdf80>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c649d0>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c659e0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1c65e70>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 14:57:48 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 14:57:48 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 14:57:48 INFO - Using env: {'DISPLAY': ':0', 14:57:48 INFO - 'HOME': '/home/cltbld', 14:57:48 INFO - 'LANG': 'en_US.UTF-8', 14:57:48 INFO - 'LANGUAGE': 'en_US:en', 14:57:48 INFO - 'LOGNAME': 'cltbld', 14:57:48 INFO - 'MAIL': '/var/mail/cltbld', 14:57:48 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 14:57:48 INFO - 'MOZ_NO_REMOTE': '1', 14:57:48 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 14:57:48 INFO - 'NO_EM_RESTART': '1', 14:57:48 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 14:57:48 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 14:57:48 INFO - 'PWD': '/builds/slave/test', 14:57:48 INFO - 'SHELL': '/bin/bash', 14:57:48 INFO - 'SHLVL': '1', 14:57:48 INFO - 'TERM': 'linux', 14:57:48 INFO - 'TMOUT': '86400', 14:57:48 INFO - 'USER': 'cltbld', 14:57:48 INFO - 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 14:57:48 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 14:57:48 INFO - '_': '/tools/buildbot/bin/python'} 14:57:49 INFO - Ignoring indexes: https://pypi.python.org/simple/ 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 14:57:49 INFO - Running setup.py (path:/tmp/pip-bR1xrT-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 14:57:49 INFO - Running setup.py (path:/tmp/pip-hLrZIt-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==0.16 from file:///builds/slave/test/build/tests/mozbase/mozcrash in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 14:57:49 INFO - Running setup.py (path:/tmp/pip-1Dr74l-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///builds/slave/test/build/tests/mozbase/mozdebug in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 14:57:49 INFO - Running setup.py (path:/tmp/pip-n2cSb0-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.47 from file:///builds/slave/test/build/tests/mozbase/mozdevice in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 14:57:49 INFO - Running setup.py (path:/tmp/pip-ANCi7U-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test/build/tests/mozbase/mozfile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 5)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 14:57:49 INFO - Running setup.py (path:/tmp/pip-GVTnSl-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test/build/tests/mozbase/mozhttpd in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 6)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 14:57:49 INFO - Running setup.py (path:/tmp/pip-Q1aUPB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.9 from file:///builds/slave/test/build/tests/mozbase/mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 7)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 14:57:49 INFO - Running setup.py (path:/tmp/pip-E7vjdI-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.12 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 14:57:49 INFO - Running setup.py (path:/tmp/pip-VX8miX-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test/build/tests/mozbase/mozleak in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 9)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 14:57:49 INFO - Running setup.py (path:/tmp/pip-wTylab-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.0 from file:///builds/slave/test/build/tests/mozbase/mozlog in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 14:57:49 INFO - Running setup.py (path:/tmp/pip-bAv40r-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test/build/tests/mozbase/moznetwork in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 11)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 14:57:49 INFO - Running setup.py (path:/tmp/pip-km947b-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 14:57:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.22 from file:///builds/slave/test/build/tests/mozbase/mozprocess in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 12)) 14:57:49 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 14:57:50 INFO - Running setup.py (path:/tmp/pip-6I92Zz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 14:57:50 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.27 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13)) 14:57:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 14:57:50 INFO - Running setup.py (path:/tmp/pip-TrXlSq-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 14:57:50 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.11 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14)) 14:57:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 14:57:50 INFO - Running setup.py (path:/tmp/pip-PWlUqx-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 14:57:50 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test/build/tests/mozbase/mozscreenshot in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 15)) 14:57:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 14:57:50 INFO - Running setup.py (path:/tmp/pip-awWyyp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 14:57:50 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.7 from file:///builds/slave/test/build/tests/mozbase/moztest in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 16)) 14:57:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 14:57:50 INFO - Running setup.py (path:/tmp/pip-R9xrd8-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 14:57:50 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///builds/slave/test/build/tests/mozbase/mozversion in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 17)) 14:57:50 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 14:57:50 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 14:57:50 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 14:57:50 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.47->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 14:57:50 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.47->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 14:57:50 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 14:57:50 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:50 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:50 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:50 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 14:57:50 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 14:57:50 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 14:57:52 INFO - Downloading blessings-1.5.1.tar.gz 14:57:52 INFO - Storing download in cache at /builds/slave/test/build/venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblessings-1.5.1.tar.gz 14:57:52 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 14:57:52 INFO - Installing collected packages: blessings 14:57:52 INFO - Running setup.py install for blessings 14:57:52 INFO - Successfully installed blessings 14:57:52 INFO - Cleaning up... 14:57:52 INFO - Return code: 0 14:57:52 INFO - Done creating virtualenv /builds/slave/test/build/venv. 14:57:52 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 14:57:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 14:57:52 INFO - Reading from file tmpfile_stdout 14:57:52 INFO - Current package versions: 14:57:52 INFO - argparse == 1.2.1 14:57:52 INFO - blessings == 1.5.1 14:57:52 INFO - blobuploader == 1.2.4 14:57:52 INFO - docopt == 0.6.1 14:57:52 INFO - manifestparser == 1.1 14:57:52 INFO - mozInstall == 1.12 14:57:52 INFO - mozcrash == 0.16 14:57:52 INFO - mozdebug == 0.1 14:57:52 INFO - mozdevice == 0.47 14:57:52 INFO - mozfile == 1.2 14:57:52 INFO - mozhttpd == 0.7 14:57:52 INFO - mozinfo == 0.9 14:57:52 INFO - mozleak == 0.1 14:57:52 INFO - mozlog == 3.0 14:57:52 INFO - moznetwork == 0.27 14:57:52 INFO - mozprocess == 0.22 14:57:52 INFO - mozprofile == 0.27 14:57:52 INFO - mozrunner == 6.11 14:57:52 INFO - mozscreenshot == 0.1 14:57:52 INFO - mozsystemmonitor == 0.0 14:57:52 INFO - moztest == 0.7 14:57:52 INFO - mozversion == 1.4 14:57:52 INFO - psutil == 3.1.1 14:57:52 INFO - requests == 1.2.3 14:57:52 INFO - wsgiref == 0.1.2 14:57:52 INFO - Installing None into virtualenv /builds/slave/test/build/venv 14:57:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 14:57:52 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:57:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 14:57:52 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 14:57:52 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7f1ac93e8c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b027b0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1bcdf80>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c649d0>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c659e0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1c65e70>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/talos', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 14:57:52 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/talos 14:57:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/talos/requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 14:57:52 INFO - Using env: {'DISPLAY': ':0', 14:57:52 INFO - 'HOME': '/home/cltbld', 14:57:52 INFO - 'LANG': 'en_US.UTF-8', 14:57:52 INFO - 'LANGUAGE': 'en_US:en', 14:57:52 INFO - 'LOGNAME': 'cltbld', 14:57:52 INFO - 'MAIL': '/var/mail/cltbld', 14:57:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 14:57:52 INFO - 'MOZ_NO_REMOTE': '1', 14:57:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 14:57:52 INFO - 'NO_EM_RESTART': '1', 14:57:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 14:57:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 14:57:52 INFO - 'PWD': '/builds/slave/test', 14:57:52 INFO - 'SHELL': '/bin/bash', 14:57:52 INFO - 'SHLVL': '1', 14:57:52 INFO - 'TERM': 'linux', 14:57:52 INFO - 'TMOUT': '86400', 14:57:52 INFO - 'USER': 'cltbld', 14:57:52 INFO - 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 14:57:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 14:57:52 INFO - '_': '/tools/buildbot/bin/python'} 14:57:52 INFO - Ignoring indexes: https://pypi.python.org/simple/ 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2)) 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3)) 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5)) 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6)) 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7)) 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 3)) 14:57:52 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.0->mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 14:57:52 INFO - Cleaning up... 14:57:52 INFO - Return code: 0 14:57:52 INFO - Running post-action listener: _resource_record_post_action 14:57:52 INFO - Running post-action listener: _start_resource_monitoring 14:57:52 INFO - Starting resource monitoring. 14:57:52 INFO - ##### 14:57:52 INFO - ##### Running install step. 14:57:52 INFO - ##### 14:57:52 INFO - Running pre-action listener: _resource_record_pre_action 14:57:52 INFO - Running main action method: install 14:57:52 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 14:57:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 14:57:52 INFO - Reading from file tmpfile_stdout 14:57:52 INFO - Detecting whether we're running mozinstall >=1.0... 14:57:52 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 14:57:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 14:57:53 INFO - Reading from file tmpfile_stdout 14:57:53 INFO - Output received: 14:57:53 INFO - Usage: mozinstall [options] installer 14:57:53 INFO - Options: 14:57:53 INFO - -h, --help show this help message and exit 14:57:53 INFO - -d DEST, --destination=DEST 14:57:53 INFO - Directory to install application into. [default: 14:57:53 INFO - "/builds/slave/test"] 14:57:53 INFO - --app=APP Application being installed. [default: firefox] 14:57:53 INFO - mkdir: /builds/slave/test/build/application 14:57:53 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2', '--destination', '/builds/slave/test/build/application'] 14:57:53 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 --destination /builds/slave/test/build/application 14:58:07 INFO - Reading from file tmpfile_stdout 14:58:07 INFO - Output received: 14:58:07 INFO - /builds/slave/test/build/application/firefox/firefox 14:58:07 INFO - Running post-action listener: _resource_record_post_action 14:58:07 INFO - ##### 14:58:07 INFO - ##### Running run-tests step. 14:58:07 INFO - ##### 14:58:07 INFO - Running pre-action listener: _resource_record_pre_action 14:58:07 INFO - Running main action method: run_tests 14:58:07 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 14:58:07 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 14:58:07 INFO - Python 2.7.3 14:58:07 INFO - Return code: 0 14:58:07 INFO - grabbing minidump binary from tooltool 14:58:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 14:58:07 INFO - retry: Calling run_command with args: (['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'],), kwargs: {'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c649d0>, 'level': 'warning'}, {'substr': 'Traceback (most recent call last)', 'level': 'error'}, {'substr': 'SyntaxError: ', 'level': 'error'}, {'substr': 'TypeError: ', 'level': 'error'}, {'substr': 'NameError: ', 'level': 'error'}, {'substr': 'ZeroDivisionError: ', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1c659e0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1c65e70>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 14:58:07 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test/build 14:58:07 INFO - Copy/paste: /tools/tooltool.py --url https://api.pub.build.mozilla.org/tooltool/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest -o -c /builds/tooltool_cache 14:58:07 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 14:58:07 INFO - Return code: 0 14:58:07 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 14:58:07 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 14:58:07 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 14:58:07 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 14:58:07 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 14:58:07 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Inbound-Non-PGO', '--suite', 'other', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-037', '--webServer', 'localhost'] in /builds/slave/test/build 14:58:07 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --debug --branchName Mozilla-Inbound-Non-PGO --suite other --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip --title talos-linux64-ix-037 --webServer localhost 14:58:07 INFO - Using env: {'DISPLAY': ':0', 14:58:07 INFO - 'HOME': '/home/cltbld', 14:58:07 INFO - 'LANG': 'en_US.UTF-8', 14:58:07 INFO - 'LANGUAGE': 'en_US:en', 14:58:07 INFO - 'LOGNAME': 'cltbld', 14:58:07 INFO - 'MAIL': '/var/mail/cltbld', 14:58:07 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 14:58:07 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 14:58:07 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 14:58:07 INFO - 'MOZ_NO_REMOTE': '1', 14:58:07 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 14:58:07 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 14:58:07 INFO - 'NO_EM_RESTART': '1', 14:58:07 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 14:58:07 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 14:58:07 INFO - 'PWD': '/builds/slave/test', 14:58:07 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 14:58:07 INFO - 'SHELL': '/bin/bash', 14:58:07 INFO - 'SHLVL': '1', 14:58:07 INFO - 'TERM': 'linux', 14:58:07 INFO - 'TMOUT': '86400', 14:58:07 INFO - 'USER': 'cltbld', 14:58:07 INFO - 'XDG_SESSION_COOKIE': '6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096', 14:58:07 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 14:58:07 INFO - '_': '/tools/buildbot/bin/python'} 14:58:07 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Inbound-Non-PGO', '--suite', 'other', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-037', '--webServer', 'localhost'] with output_timeout 3600 14:58:07 INFO - mozversion INFO | application_buildid: 20151102135706 14:58:07 INFO - mozversion INFO | application_changeset: 11dd4cfb65639257a3c3e87886c0b6157be5b876 14:58:07 INFO - mozversion INFO | application_display_name: Nightly 14:58:07 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 14:58:07 INFO - mozversion INFO | application_name: Firefox 14:58:07 INFO - mozversion INFO | application_remotingname: firefox 14:58:07 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/mozilla-inbound 14:58:07 INFO - mozversion INFO | application_vendor: Mozilla 14:58:07 INFO - mozversion INFO | application_version: 45.0a1 14:58:07 INFO - mozversion INFO | platform_buildid: 20151102135706 14:58:07 INFO - mozversion INFO | platform_changeset: 11dd4cfb65639257a3c3e87886c0b6157be5b876 14:58:07 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/mozilla-inbound 14:58:07 INFO - mozversion INFO | platform_version: 45.0a1 14:58:07 INFO - 2015-11-02 14:58:07,276 DEBUG : using testdate: 1446505087 14:58:07 INFO - 2015-11-02 14:58:07,276 DEBUG : actual date: 1446505087 14:58:07 INFO - 2015-11-02 14:58:07,325 INFO : starting webserver on 'localhost:47433' 14:58:07 INFO - 2015-11-02 14:58:07,326 INFO : Starting test suite talos-linux64-ix-037 14:58:07 INFO - 2015-11-02 14:58:07,326 INFO : Starting test a11yr 14:58:07 INFO - 2015-11-02 14:58:07,327 DEBUG : operating with platform_type : linux_ 14:58:07 INFO - 2015-11-02 14:58:07,327 INFO : Initialising browser for a11yr test... 14:58:07 INFO - 2015-11-02 14:58:07,340 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpRZYcKF/profile http://localhost:47433/getInfo.html 14:58:13 INFO - 2015-11-02 14:58:13,509 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 14:58:13 INFO - 2015-11-02 14:58:13,509 DEBUG : BROWSER_OUTPUT: colorDepth:24 14:58:13 INFO - 2015-11-02 14:58:13,509 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 14:58:13 INFO - 2015-11-02 14:58:13,509 DEBUG : BROWSER_OUTPUT: __metrics 14:58:13 INFO - 2015-11-02 14:58:13,719 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 14:58:14 INFO - 2015-11-02 14:58:14,760 INFO : Browser initialized. 14:58:14 INFO - 2015-11-02 14:58:14,760 INFO : Running cycle 1/1 for a11yr test... 14:58:14 INFO - 2015-11-02 14:58:14,760 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpRZYcKF/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25 14:58:28 INFO - 2015-11-02 14:58:28,232 DEBUG : BROWSER_OUTPUT: RSS: Main: 139841536 14:58:28 INFO - 2015-11-02 14:58:28,233 DEBUG : BROWSER_OUTPUT: 14:58:29 INFO - 2015-11-02 14:58:29,702 DEBUG : BROWSER_OUTPUT: 14:58:29 INFO - 2015-11-02 14:58:29,702 DEBUG : BROWSER_OUTPUT: (firefox:11471): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 14:58:29 INFO - 2015-11-02 14:58:29,743 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:30 INFO - 2015-11-02 14:58:30,365 DEBUG : BROWSER_OUTPUT: RSS: Main: 179539968 14:58:30 INFO - 2015-11-02 14:58:30,366 DEBUG : BROWSER_OUTPUT: 14:58:31 INFO - 2015-11-02 14:58:31,895 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:32 INFO - 2015-11-02 14:58:32,582 DEBUG : BROWSER_OUTPUT: RSS: Main: 183603200 14:58:32 INFO - 2015-11-02 14:58:32,583 DEBUG : BROWSER_OUTPUT: 14:58:34 INFO - 2015-11-02 14:58:34,193 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:34 INFO - 2015-11-02 14:58:34,887 DEBUG : BROWSER_OUTPUT: RSS: Main: 181940224 14:58:34 INFO - 2015-11-02 14:58:34,887 DEBUG : BROWSER_OUTPUT: 14:58:36 INFO - 2015-11-02 14:58:36,344 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:37 INFO - 2015-11-02 14:58:37,065 DEBUG : BROWSER_OUTPUT: RSS: Main: 181399552 14:58:37 INFO - 2015-11-02 14:58:37,066 DEBUG : BROWSER_OUTPUT: 14:58:38 INFO - 2015-11-02 14:58:38,692 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:39 INFO - 2015-11-02 14:58:39,379 DEBUG : BROWSER_OUTPUT: RSS: Main: 181669888 14:58:39 INFO - 2015-11-02 14:58:39,379 DEBUG : BROWSER_OUTPUT: 14:58:40 INFO - 2015-11-02 14:58:40,809 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:41 INFO - 2015-11-02 14:58:41,515 DEBUG : BROWSER_OUTPUT: RSS: Main: 182226944 14:58:41 INFO - 2015-11-02 14:58:41,515 DEBUG : BROWSER_OUTPUT: 14:58:43 INFO - 2015-11-02 14:58:43,065 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:43 INFO - 2015-11-02 14:58:43,760 DEBUG : BROWSER_OUTPUT: RSS: Main: 183824384 14:58:43 INFO - 2015-11-02 14:58:43,760 DEBUG : BROWSER_OUTPUT: 14:58:45 INFO - 2015-11-02 14:58:45,303 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:45 INFO - 2015-11-02 14:58:45,991 DEBUG : BROWSER_OUTPUT: RSS: Main: 183578624 14:58:45 INFO - 2015-11-02 14:58:45,991 DEBUG : BROWSER_OUTPUT: 14:58:47 INFO - 2015-11-02 14:58:47,637 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:48 INFO - 2015-11-02 14:58:48,324 DEBUG : BROWSER_OUTPUT: RSS: Main: 184684544 14:58:48 INFO - 2015-11-02 14:58:48,324 DEBUG : BROWSER_OUTPUT: 14:58:49 INFO - 2015-11-02 14:58:49,889 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:50 INFO - 2015-11-02 14:58:50,583 DEBUG : BROWSER_OUTPUT: RSS: Main: 183848960 14:58:50 INFO - 2015-11-02 14:58:50,583 DEBUG : BROWSER_OUTPUT: 14:58:52 INFO - 2015-11-02 14:58:52,032 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:52 INFO - 2015-11-02 14:58:52,720 DEBUG : BROWSER_OUTPUT: RSS: Main: 183205888 14:58:52 INFO - 2015-11-02 14:58:52,720 DEBUG : BROWSER_OUTPUT: 14:58:54 INFO - 2015-11-02 14:58:54,258 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:54 INFO - 2015-11-02 14:58:54,278 DEBUG : BROWSER_OUTPUT: 14:58:54 INFO - 2015-11-02 14:58:54,278 DEBUG : BROWSER_OUTPUT: (firefox:11471): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 14:58:54 INFO - 2015-11-02 14:58:54,949 DEBUG : BROWSER_OUTPUT: RSS: Main: 184918016 14:58:54 INFO - 2015-11-02 14:58:54,950 DEBUG : BROWSER_OUTPUT: 14:58:56 INFO - 2015-11-02 14:58:56,520 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:57 INFO - 2015-11-02 14:58:57,209 DEBUG : BROWSER_OUTPUT: RSS: Main: 184041472 14:58:57 INFO - 2015-11-02 14:58:57,209 DEBUG : BROWSER_OUTPUT: 14:58:58 INFO - 2015-11-02 14:58:58,746 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:58:59 INFO - 2015-11-02 14:58:59,433 DEBUG : BROWSER_OUTPUT: RSS: Main: 185921536 14:58:59 INFO - 2015-11-02 14:58:59,433 DEBUG : BROWSER_OUTPUT: 14:59:00 INFO - 2015-11-02 14:59:00,986 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:01 INFO - 2015-11-02 14:59:01,689 DEBUG : BROWSER_OUTPUT: RSS: Main: 182259712 14:59:01 INFO - 2015-11-02 14:59:01,689 DEBUG : BROWSER_OUTPUT: 14:59:03 INFO - 2015-11-02 14:59:03,266 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:03 INFO - 2015-11-02 14:59:03,956 DEBUG : BROWSER_OUTPUT: RSS: Main: 184000512 14:59:03 INFO - 2015-11-02 14:59:03,956 DEBUG : BROWSER_OUTPUT: 14:59:05 INFO - 2015-11-02 14:59:05,506 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:06 INFO - 2015-11-02 14:59:06,196 DEBUG : BROWSER_OUTPUT: RSS: Main: 182312960 14:59:06 INFO - 2015-11-02 14:59:06,196 DEBUG : BROWSER_OUTPUT: 14:59:07 INFO - 2015-11-02 14:59:07,769 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:08 INFO - 2015-11-02 14:59:08,471 DEBUG : BROWSER_OUTPUT: RSS: Main: 184172544 14:59:08 INFO - 2015-11-02 14:59:08,471 DEBUG : BROWSER_OUTPUT: 14:59:10 INFO - 2015-11-02 14:59:10,016 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:10 INFO - 2015-11-02 14:59:10,710 DEBUG : BROWSER_OUTPUT: RSS: Main: 183382016 14:59:10 INFO - 2015-11-02 14:59:10,710 DEBUG : BROWSER_OUTPUT: 14:59:12 INFO - 2015-11-02 14:59:12,263 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:12 INFO - 2015-11-02 14:59:12,957 DEBUG : BROWSER_OUTPUT: RSS: Main: 184659968 14:59:12 INFO - 2015-11-02 14:59:12,957 DEBUG : BROWSER_OUTPUT: 14:59:14 INFO - 2015-11-02 14:59:14,515 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:15 INFO - 2015-11-02 14:59:15,209 DEBUG : BROWSER_OUTPUT: RSS: Main: 183853056 14:59:15 INFO - 2015-11-02 14:59:15,209 DEBUG : BROWSER_OUTPUT: 14:59:16 INFO - 2015-11-02 14:59:16,682 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:17 INFO - 2015-11-02 14:59:17,385 DEBUG : BROWSER_OUTPUT: RSS: Main: 193126400 14:59:17 INFO - 2015-11-02 14:59:17,385 DEBUG : BROWSER_OUTPUT: 14:59:19 INFO - 2015-11-02 14:59:19,011 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:19 INFO - 2015-11-02 14:59:19,011 DEBUG : BROWSER_OUTPUT: 1446505159009 addons.productaddons ERROR Request failed certificate checks: [Exception... "SSL is required and URI scheme is not https." nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)" location: "JS frame :: resource://gre/modules/CertUtils.jsm :: checkCert :: line 145" data: no] 14:59:19 INFO - 2015-11-02 14:59:19,713 DEBUG : BROWSER_OUTPUT: RSS: Main: 194994176 14:59:19 INFO - 2015-11-02 14:59:19,713 DEBUG : BROWSER_OUTPUT: 14:59:21 INFO - 2015-11-02 14:59:21,258 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:21 INFO - 2015-11-02 14:59:21,964 DEBUG : BROWSER_OUTPUT: RSS: Main: 195956736 14:59:21 INFO - 2015-11-02 14:59:21,964 DEBUG : BROWSER_OUTPUT: 14:59:23 INFO - 2015-11-02 14:59:23,542 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 14:59:24 INFO - 2015-11-02 14:59:24,256 DEBUG : BROWSER_OUTPUT: RSS: Main: 193646592 14:59:24 INFO - 2015-11-02 14:59:24,256 DEBUG : BROWSER_OUTPUT: 14:59:25 INFO - 2015-11-02 14:59:25,491 DEBUG : BROWSER_OUTPUT: 14:59:25 INFO - 2015-11-02 14:59:25,492 DEBUG : BROWSER_OUTPUT: (firefox:11471): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 14:59:25 INFO - 2015-11-02 14:59:25,515 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:26 INFO - 2015-11-02 14:59:26,097 DEBUG : BROWSER_OUTPUT: RSS: Main: 190164992 14:59:26 INFO - 2015-11-02 14:59:26,097 DEBUG : BROWSER_OUTPUT: 14:59:26 INFO - 2015-11-02 14:59:26,963 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:27 INFO - 2015-11-02 14:59:27,557 DEBUG : BROWSER_OUTPUT: RSS: Main: 188280832 14:59:27 INFO - 2015-11-02 14:59:27,557 DEBUG : BROWSER_OUTPUT: 14:59:28 INFO - 2015-11-02 14:59:28,451 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:29 INFO - 2015-11-02 14:59:29,044 DEBUG : BROWSER_OUTPUT: RSS: Main: 186949632 14:59:29 INFO - 2015-11-02 14:59:29,044 DEBUG : BROWSER_OUTPUT: 14:59:29 INFO - 2015-11-02 14:59:29,912 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:30 INFO - 2015-11-02 14:59:30,499 DEBUG : BROWSER_OUTPUT: RSS: Main: 182820864 14:59:30 INFO - 2015-11-02 14:59:30,499 DEBUG : BROWSER_OUTPUT: 14:59:31 INFO - 2015-11-02 14:59:31,328 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:31 INFO - 2015-11-02 14:59:31,914 DEBUG : BROWSER_OUTPUT: RSS: Main: 181108736 14:59:31 INFO - 2015-11-02 14:59:31,914 DEBUG : BROWSER_OUTPUT: 14:59:32 INFO - 2015-11-02 14:59:32,780 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:33 INFO - 2015-11-02 14:59:33,366 DEBUG : BROWSER_OUTPUT: RSS: Main: 180686848 14:59:33 INFO - 2015-11-02 14:59:33,366 DEBUG : BROWSER_OUTPUT: 14:59:34 INFO - 2015-11-02 14:59:34,234 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:34 INFO - 2015-11-02 14:59:34,820 DEBUG : BROWSER_OUTPUT: RSS: Main: 180944896 14:59:34 INFO - 2015-11-02 14:59:34,820 DEBUG : BROWSER_OUTPUT: 14:59:35 INFO - 2015-11-02 14:59:35,649 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:36 INFO - 2015-11-02 14:59:36,235 DEBUG : BROWSER_OUTPUT: RSS: Main: 181059584 14:59:36 INFO - 2015-11-02 14:59:36,235 DEBUG : BROWSER_OUTPUT: 14:59:37 INFO - 2015-11-02 14:59:37,101 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:37 INFO - 2015-11-02 14:59:37,691 DEBUG : BROWSER_OUTPUT: RSS: Main: 180555776 14:59:37 INFO - 2015-11-02 14:59:37,691 DEBUG : BROWSER_OUTPUT: 14:59:38 INFO - 2015-11-02 14:59:38,578 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:39 INFO - 2015-11-02 14:59:39,167 DEBUG : BROWSER_OUTPUT: RSS: Main: 179408896 14:59:39 INFO - 2015-11-02 14:59:39,168 DEBUG : BROWSER_OUTPUT: 14:59:39 INFO - 2015-11-02 14:59:39,994 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:40 INFO - 2015-11-02 14:59:40,584 DEBUG : BROWSER_OUTPUT: RSS: Main: 178769920 14:59:40 INFO - 2015-11-02 14:59:40,584 DEBUG : BROWSER_OUTPUT: 14:59:41 INFO - 2015-11-02 14:59:41,450 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:42 INFO - 2015-11-02 14:59:42,036 DEBUG : BROWSER_OUTPUT: RSS: Main: 180662272 14:59:42 INFO - 2015-11-02 14:59:42,036 DEBUG : BROWSER_OUTPUT: 14:59:42 INFO - 2015-11-02 14:59:42,918 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:43 INFO - 2015-11-02 14:59:43,500 DEBUG : BROWSER_OUTPUT: RSS: Main: 180027392 14:59:43 INFO - 2015-11-02 14:59:43,500 DEBUG : BROWSER_OUTPUT: 14:59:44 INFO - 2015-11-02 14:59:44,330 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:44 INFO - 2015-11-02 14:59:44,913 DEBUG : BROWSER_OUTPUT: RSS: Main: 177860608 14:59:44 INFO - 2015-11-02 14:59:44,914 DEBUG : BROWSER_OUTPUT: 14:59:45 INFO - 2015-11-02 14:59:45,781 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:46 INFO - 2015-11-02 14:59:46,367 DEBUG : BROWSER_OUTPUT: RSS: Main: 177545216 14:59:46 INFO - 2015-11-02 14:59:46,367 DEBUG : BROWSER_OUTPUT: 14:59:47 INFO - 2015-11-02 14:59:47,249 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:47 INFO - 2015-11-02 14:59:47,835 DEBUG : BROWSER_OUTPUT: RSS: Main: 177573888 14:59:47 INFO - 2015-11-02 14:59:47,836 DEBUG : BROWSER_OUTPUT: 14:59:48 INFO - 2015-11-02 14:59:48,709 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:49 INFO - 2015-11-02 14:59:49,297 DEBUG : BROWSER_OUTPUT: RSS: Main: 179552256 14:59:49 INFO - 2015-11-02 14:59:49,297 DEBUG : BROWSER_OUTPUT: 14:59:50 INFO - 2015-11-02 14:59:50,123 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:50 INFO - 2015-11-02 14:59:50,709 DEBUG : BROWSER_OUTPUT: RSS: Main: 180236288 14:59:50 INFO - 2015-11-02 14:59:50,709 DEBUG : BROWSER_OUTPUT: 14:59:51 INFO - 2015-11-02 14:59:51,575 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:52 INFO - 2015-11-02 14:59:52,161 DEBUG : BROWSER_OUTPUT: RSS: Main: 178827264 14:59:52 INFO - 2015-11-02 14:59:52,162 DEBUG : BROWSER_OUTPUT: 14:59:53 INFO - 2015-11-02 14:59:53,027 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:53 INFO - 2015-11-02 14:59:53,614 DEBUG : BROWSER_OUTPUT: RSS: Main: 180510720 14:59:53 INFO - 2015-11-02 14:59:53,614 DEBUG : BROWSER_OUTPUT: 14:59:54 INFO - 2015-11-02 14:59:54,496 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:55 INFO - 2015-11-02 14:59:55,090 DEBUG : BROWSER_OUTPUT: RSS: Main: 180084736 14:59:55 INFO - 2015-11-02 14:59:55,090 DEBUG : BROWSER_OUTPUT: 14:59:55 INFO - 2015-11-02 14:59:55,916 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:56 INFO - 2015-11-02 14:59:56,505 DEBUG : BROWSER_OUTPUT: RSS: Main: 180109312 14:59:56 INFO - 2015-11-02 14:59:56,505 DEBUG : BROWSER_OUTPUT: 14:59:57 INFO - 2015-11-02 14:59:57,371 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:57 INFO - 2015-11-02 14:59:57,957 DEBUG : BROWSER_OUTPUT: RSS: Main: 178741248 14:59:57 INFO - 2015-11-02 14:59:57,957 DEBUG : BROWSER_OUTPUT: 14:59:58 INFO - 2015-11-02 14:59:58,839 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 14:59:59 INFO - 2015-11-02 14:59:59,426 DEBUG : BROWSER_OUTPUT: RSS: Main: 179933184 14:59:59 INFO - 2015-11-02 14:59:59,426 DEBUG : BROWSER_OUTPUT: 15:00:00 INFO - 2015-11-02 15:00:00,287 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:00:00 INFO - 2015-11-02 15:00:00,537 DEBUG : BROWSER_OUTPUT: RSS: Main: 182505472 15:00:00 INFO - 2015-11-02 15:00:00,537 DEBUG : BROWSER_OUTPUT: 15:00:00 INFO - 2015-11-02 15:00:00,539 DEBUG : BROWSER_OUTPUT: __start_tp_report 15:00:00 INFO - 2015-11-02 15:00:00,539 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load 15:00:00 INFO - 2015-11-02 15:00:00,539 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details 15:00:00 INFO - 2015-11-02 15:00:00,539 DEBUG : BROWSER_OUTPUT: |i|pagename|runs| 15:00:00 INFO - 2015-11-02 15:00:00,539 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1402;1451;1538;1363;1538;1350;1457;1473;1547;1466;1369;1471;1480;1467;1469;1483;1488;1482;1471;1467;1463;1378;1530;1474;1473 15:00:00 INFO - 2015-11-02 15:00:00,539 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;335;325;327;326;324;325;327;326;326;336;326;326;327;329;326;328;330;326;325;326;329;326;325;328;325 15:00:00 INFO - 2015-11-02 15:00:00,540 DEBUG : BROWSER_OUTPUT: __end_tp_report 15:00:00 INFO - 2015-11-02 15:00:00,540 DEBUG : BROWSER_OUTPUT: __start_cc_report 15:00:00 INFO - 2015-11-02 15:00:00,540 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,6808 15:00:00 INFO - 2015-11-02 15:00:00,540 DEBUG : BROWSER_OUTPUT: __end_cc_report 15:00:00 INFO - 2015-11-02 15:00:00,540 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505200538__endTimestamp 15:00:00 INFO - 2015-11-02 15:00:00,540 DEBUG : BROWSER_OUTPUT: 15:00:00 INFO - 2015-11-02 15:00:00,541 DEBUG : BROWSER_OUTPUT: ------- Summary: start ------- 15:00:00 INFO - 2015-11-02 15:00:00,542 DEBUG : BROWSER_OUTPUT: Number of tests: 2 15:00:00 INFO - 2015-11-02 15:00:00,542 DEBUG : BROWSER_OUTPUT: 15:00:00 INFO - 2015-11-02 15:00:00,542 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1462.00 Median:1471.00 stddev:53.11 (3.6%) stddev-sans-first:52.73 15:00:00 INFO - 2015-11-02 15:00:00,542 DEBUG : BROWSER_OUTPUT: Values: 1402.0 1451.0 1538.0 1363.0 1538.0 1350.0 1457.0 1473.0 1547.0 1466.0 1369.0 1471.0 1480.0 1467.0 1469.0 1483.0 1488.0 1482.0 1471.0 1467.0 1463.0 1378.0 1530.0 1474.0 1473.0 15:00:00 INFO - 2015-11-02 15:00:00,542 DEBUG : BROWSER_OUTPUT: 15:00:00 INFO - 2015-11-02 15:00:00,542 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:327.16 Median:326.00 stddev:2.90 (0.9%) stddev-sans-first:2.44 15:00:00 INFO - 2015-11-02 15:00:00,542 DEBUG : BROWSER_OUTPUT: Values: 335.0 325.0 327.0 326.0 324.0 325.0 327.0 326.0 326.0 336.0 326.0 326.0 327.0 329.0 326.0 328.0 330.0 326.0 325.0 326.0 329.0 326.0 325.0 328.0 325.0 15:00:00 INFO - 2015-11-02 15:00:00,543 DEBUG : BROWSER_OUTPUT: -------- Summary: end -------- 15:00:00 INFO - 2015-11-02 15:00:00,543 DEBUG : BROWSER_OUTPUT: 15:00:01 INFO - 2015-11-02 15:00:01,361 INFO : Browser exited with error code: 0 15:00:01 INFO - 2015-11-02 15:00:01,377 INFO : Completed test a11yr (00:01:54) 15:00:01 INFO - 2015-11-02 15:00:01,377 INFO : Starting test ts_paint 15:00:01 INFO - 2015-11-02 15:00:01,377 DEBUG : operating with platform_type : linux_ 15:00:01 INFO - 2015-11-02 15:00:01,377 INFO : Initialising browser for ts_paint test... 15:00:01 INFO - 2015-11-02 15:00:01,383 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/getInfo.html 15:00:07 INFO - 2015-11-02 15:00:07,562 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 15:00:07 INFO - 2015-11-02 15:00:07,562 DEBUG : BROWSER_OUTPUT: colorDepth:24 15:00:07 INFO - 2015-11-02 15:00:07,562 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 15:00:07 INFO - 2015-11-02 15:00:07,563 DEBUG : BROWSER_OUTPUT: __metrics 15:00:07 INFO - 2015-11-02 15:00:07,679 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 15:00:08 INFO - 2015-11-02 15:00:08,183 DEBUG : BROWSER_OUTPUT: JavaScript error: resource://gre/modules/IndexedDBHelper.jsm, line 138: UnknownError: The operation failed for reasons unrelated to the database itself and not covered by any other error code. 15:00:08 INFO - 2015-11-02 15:00:08,853 INFO : Browser initialized. 15:00:08 INFO - 2015-11-02 15:00:08,853 INFO : Running cycle 1/20 for ts_paint test... 15:00:08 INFO - 2015-11-02 15:00:08,854 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:12 INFO - 2015-11-02 15:00:12,427 DEBUG : BROWSER_OUTPUT: __start_report3568__end_report 15:00:12 INFO - 2015-11-02 15:00:12,427 DEBUG : BROWSER_OUTPUT: 15:00:12 INFO - 2015-11-02 15:00:12,434 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505212432__endTimestamp 15:00:13 INFO - 2015-11-02 15:00:13,593 INFO : Browser exited with error code: 0 15:00:13 INFO - 2015-11-02 15:00:13,595 INFO : Running cycle 2/20 for ts_paint test... 15:00:13 INFO - 2015-11-02 15:00:13,595 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:16 INFO - 2015-11-02 15:00:16,366 DEBUG : BROWSER_OUTPUT: __start_report2765__end_report 15:00:16 INFO - 2015-11-02 15:00:16,367 DEBUG : BROWSER_OUTPUT: 15:00:16 INFO - 2015-11-02 15:00:16,370 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505216370__endTimestamp 15:00:17 INFO - 2015-11-02 15:00:17,481 INFO : Browser exited with error code: 0 15:00:17 INFO - 2015-11-02 15:00:17,483 INFO : Running cycle 3/20 for ts_paint test... 15:00:17 INFO - 2015-11-02 15:00:17,483 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:20 INFO - 2015-11-02 15:00:20,246 DEBUG : BROWSER_OUTPUT: __start_report2759__end_report 15:00:20 INFO - 2015-11-02 15:00:20,247 DEBUG : BROWSER_OUTPUT: 15:00:20 INFO - 2015-11-02 15:00:20,262 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505220255__endTimestamp 15:00:21 INFO - 2015-11-02 15:00:21,273 INFO : Browser exited with error code: 0 15:00:21 INFO - 2015-11-02 15:00:21,275 INFO : Running cycle 4/20 for ts_paint test... 15:00:21 INFO - 2015-11-02 15:00:21,275 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:24 INFO - 2015-11-02 15:00:24,015 DEBUG : BROWSER_OUTPUT: __start_report2736__end_report 15:00:24 INFO - 2015-11-02 15:00:24,015 DEBUG : BROWSER_OUTPUT: 15:00:24 INFO - 2015-11-02 15:00:24,022 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505224019__endTimestamp 15:00:25 INFO - 2015-11-02 15:00:25,015 INFO : Browser exited with error code: 0 15:00:25 INFO - 2015-11-02 15:00:25,016 INFO : Running cycle 5/20 for ts_paint test... 15:00:25 INFO - 2015-11-02 15:00:25,016 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:27 INFO - 2015-11-02 15:00:27,775 DEBUG : BROWSER_OUTPUT: __start_report2754__end_report 15:00:27 INFO - 2015-11-02 15:00:27,776 DEBUG : BROWSER_OUTPUT: 15:00:27 INFO - 2015-11-02 15:00:27,791 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505227791__endTimestamp 15:00:28 INFO - 2015-11-02 15:00:28,872 INFO : Browser exited with error code: 0 15:00:28 INFO - 2015-11-02 15:00:28,874 INFO : Running cycle 6/20 for ts_paint test... 15:00:28 INFO - 2015-11-02 15:00:28,874 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:31 INFO - 2015-11-02 15:00:31,606 DEBUG : BROWSER_OUTPUT: __start_report2727__end_report 15:00:31 INFO - 2015-11-02 15:00:31,607 DEBUG : BROWSER_OUTPUT: 15:00:31 INFO - 2015-11-02 15:00:31,610 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505231608__endTimestamp 15:00:32 INFO - 2015-11-02 15:00:32,680 INFO : Browser exited with error code: 0 15:00:32 INFO - 2015-11-02 15:00:32,682 INFO : Running cycle 7/20 for ts_paint test... 15:00:32 INFO - 2015-11-02 15:00:32,682 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:35 INFO - 2015-11-02 15:00:35,461 DEBUG : BROWSER_OUTPUT: __start_report2770__end_report 15:00:35 INFO - 2015-11-02 15:00:35,461 DEBUG : BROWSER_OUTPUT: 15:00:35 INFO - 2015-11-02 15:00:35,461 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505235460__endTimestamp 15:00:36 INFO - 2015-11-02 15:00:36,613 INFO : Browser exited with error code: 0 15:00:36 INFO - 2015-11-02 15:00:36,615 INFO : Running cycle 8/20 for ts_paint test... 15:00:36 INFO - 2015-11-02 15:00:36,615 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:39 INFO - 2015-11-02 15:00:39,320 DEBUG : BROWSER_OUTPUT: __start_report2704__end_report 15:00:39 INFO - 2015-11-02 15:00:39,320 DEBUG : BROWSER_OUTPUT: 15:00:39 INFO - 2015-11-02 15:00:39,340 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505239338__endTimestamp 15:00:40 INFO - 2015-11-02 15:00:40,422 INFO : Browser exited with error code: 0 15:00:40 INFO - 2015-11-02 15:00:40,423 INFO : Running cycle 9/20 for ts_paint test... 15:00:40 INFO - 2015-11-02 15:00:40,423 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:43 INFO - 2015-11-02 15:00:43,143 DEBUG : BROWSER_OUTPUT: __start_report2713__end_report 15:00:43 INFO - 2015-11-02 15:00:43,143 DEBUG : BROWSER_OUTPUT: 15:00:43 INFO - 2015-11-02 15:00:43,163 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505243163__endTimestamp 15:00:44 INFO - 2015-11-02 15:00:44,261 INFO : Browser exited with error code: 0 15:00:44 INFO - 2015-11-02 15:00:44,262 INFO : Running cycle 10/20 for ts_paint test... 15:00:44 INFO - 2015-11-02 15:00:44,263 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:47 INFO - 2015-11-02 15:00:47,025 DEBUG : BROWSER_OUTPUT: __start_report2753__end_report 15:00:47 INFO - 2015-11-02 15:00:47,025 DEBUG : BROWSER_OUTPUT: 15:00:47 INFO - 2015-11-02 15:00:47,028 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505247027__endTimestamp 15:00:48 INFO - 2015-11-02 15:00:48,102 INFO : Browser exited with error code: 0 15:00:48 INFO - 2015-11-02 15:00:48,103 INFO : Running cycle 11/20 for ts_paint test... 15:00:48 INFO - 2015-11-02 15:00:48,104 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:50 INFO - 2015-11-02 15:00:50,829 DEBUG : BROWSER_OUTPUT: __start_report2719__end_report 15:00:50 INFO - 2015-11-02 15:00:50,830 DEBUG : BROWSER_OUTPUT: 15:00:50 INFO - 2015-11-02 15:00:50,845 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505250838__endTimestamp 15:00:51 INFO - 2015-11-02 15:00:51,992 INFO : Browser exited with error code: 0 15:00:51 INFO - 2015-11-02 15:00:51,993 INFO : Running cycle 12/20 for ts_paint test... 15:00:51 INFO - 2015-11-02 15:00:51,993 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:54 INFO - 2015-11-02 15:00:54,776 DEBUG : BROWSER_OUTPUT: __start_report2776__end_report 15:00:54 INFO - 2015-11-02 15:00:54,776 DEBUG : BROWSER_OUTPUT: 15:00:54 INFO - 2015-11-02 15:00:54,776 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505254776__endTimestamp 15:00:55 INFO - 2015-11-02 15:00:55,946 INFO : Browser exited with error code: 0 15:00:55 INFO - 2015-11-02 15:00:55,947 INFO : Running cycle 13/20 for ts_paint test... 15:00:55 INFO - 2015-11-02 15:00:55,947 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:00:58 INFO - 2015-11-02 15:00:58,711 DEBUG : BROWSER_OUTPUT: __start_report2764__end_report 15:00:58 INFO - 2015-11-02 15:00:58,711 DEBUG : BROWSER_OUTPUT: 15:00:58 INFO - 2015-11-02 15:00:58,718 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505258717__endTimestamp 15:00:59 INFO - 2015-11-02 15:00:59,836 INFO : Browser exited with error code: 0 15:00:59 INFO - 2015-11-02 15:00:59,837 INFO : Running cycle 14/20 for ts_paint test... 15:00:59 INFO - 2015-11-02 15:00:59,837 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:01:02 INFO - 2015-11-02 15:01:02,563 DEBUG : BROWSER_OUTPUT: __start_report2722__end_report 15:01:02 INFO - 2015-11-02 15:01:02,563 DEBUG : BROWSER_OUTPUT: 15:01:02 INFO - 2015-11-02 15:01:02,579 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505262571__endTimestamp 15:01:03 INFO - 2015-11-02 15:01:03,801 INFO : Browser exited with error code: 0 15:01:03 INFO - 2015-11-02 15:01:03,803 INFO : Running cycle 15/20 for ts_paint test... 15:01:03 INFO - 2015-11-02 15:01:03,803 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:01:06 INFO - 2015-11-02 15:01:06,536 DEBUG : BROWSER_OUTPUT: __start_report2728__end_report 15:01:06 INFO - 2015-11-02 15:01:06,536 DEBUG : BROWSER_OUTPUT: 15:01:06 INFO - 2015-11-02 15:01:06,552 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505266544__endTimestamp 15:01:07 INFO - 2015-11-02 15:01:07,691 INFO : Browser exited with error code: 0 15:01:07 INFO - 2015-11-02 15:01:07,693 INFO : Running cycle 16/20 for ts_paint test... 15:01:07 INFO - 2015-11-02 15:01:07,693 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:01:10 INFO - 2015-11-02 15:01:10,484 DEBUG : BROWSER_OUTPUT: __start_report2784__end_report 15:01:10 INFO - 2015-11-02 15:01:10,484 DEBUG : BROWSER_OUTPUT: 15:01:10 INFO - 2015-11-02 15:01:10,491 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505270487__endTimestamp 15:01:11 INFO - 2015-11-02 15:01:11,581 INFO : Browser exited with error code: 0 15:01:11 INFO - 2015-11-02 15:01:11,583 INFO : Running cycle 17/20 for ts_paint test... 15:01:11 INFO - 2015-11-02 15:01:11,583 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:01:14 INFO - 2015-11-02 15:01:14,300 DEBUG : BROWSER_OUTPUT: __start_report2714__end_report 15:01:14 INFO - 2015-11-02 15:01:14,300 DEBUG : BROWSER_OUTPUT: 15:01:14 INFO - 2015-11-02 15:01:14,316 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505274310__endTimestamp 15:01:15 INFO - 2015-11-02 15:01:15,421 INFO : Browser exited with error code: 0 15:01:15 INFO - 2015-11-02 15:01:15,423 INFO : Running cycle 18/20 for ts_paint test... 15:01:15 INFO - 2015-11-02 15:01:15,423 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:01:18 INFO - 2015-11-02 15:01:18,188 DEBUG : BROWSER_OUTPUT: __start_report2755__end_report 15:01:18 INFO - 2015-11-02 15:01:18,188 DEBUG : BROWSER_OUTPUT: 15:01:18 INFO - 2015-11-02 15:01:18,195 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505278192__endTimestamp 15:01:19 INFO - 2015-11-02 15:01:19,457 INFO : Browser exited with error code: 0 15:01:19 INFO - 2015-11-02 15:01:19,459 INFO : Running cycle 19/20 for ts_paint test... 15:01:19 INFO - 2015-11-02 15:01:19,459 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:01:22 INFO - 2015-11-02 15:01:22,247 DEBUG : BROWSER_OUTPUT: __start_report2789__end_report 15:01:22 INFO - 2015-11-02 15:01:22,247 DEBUG : BROWSER_OUTPUT: 15:01:22 INFO - 2015-11-02 15:01:22,251 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505282249__endTimestamp 15:01:23 INFO - 2015-11-02 15:01:23,399 INFO : Browser exited with error code: 0 15:01:23 INFO - 2015-11-02 15:01:23,401 INFO : Running cycle 20/20 for ts_paint test... 15:01:23 INFO - 2015-11-02 15:01:23,401 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8G_8HL/profile http://localhost:47433/startup_test/tspaint_test.html 15:01:26 INFO - 2015-11-02 15:01:26,105 DEBUG : BROWSER_OUTPUT: __start_report2698__end_report 15:01:26 INFO - 2015-11-02 15:01:26,105 DEBUG : BROWSER_OUTPUT: 15:01:26 INFO - 2015-11-02 15:01:26,105 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505286104__endTimestamp 15:01:27 INFO - 2015-11-02 15:01:27,239 INFO : Browser exited with error code: 0 15:01:27 INFO - 2015-11-02 15:01:27,259 INFO : Completed test ts_paint (00:01:25) 15:01:27 INFO - 2015-11-02 15:01:27,259 INFO : Starting test tpaint 15:01:27 INFO - 2015-11-02 15:01:27,260 DEBUG : operating with platform_type : linux_ 15:01:27 INFO - 2015-11-02 15:01:27,260 INFO : Initialising browser for tpaint test... 15:01:27 INFO - 2015-11-02 15:01:27,266 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpd5LK8B/profile http://localhost:47433/getInfo.html 15:01:33 INFO - 2015-11-02 15:01:33,039 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 15:01:33 INFO - 2015-11-02 15:01:33,039 DEBUG : BROWSER_OUTPUT: colorDepth:24 15:01:33 INFO - 2015-11-02 15:01:33,039 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 15:01:33 INFO - 2015-11-02 15:01:33,039 DEBUG : BROWSER_OUTPUT: __metrics 15:01:33 INFO - 2015-11-02 15:01:33,208 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 15:01:33 INFO - 2015-11-02 15:01:33,747 DEBUG : BROWSER_OUTPUT: console.error: 15:01:33 INFO - 2015-11-02 15:01:33,763 DEBUG : BROWSER_OUTPUT: Message: Error: Connection closed before committing the transaction. 15:01:33 INFO - 2015-11-02 15:01:33,763 DEBUG : BROWSER_OUTPUT: Stack: 15:01:33 INFO - 2015-11-02 15:01:33,763 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeTransaction/promise resource://gre/modules/Promise-backend.js:934:23 15:01:33 INFO - 2015-11-02 15:01:33,763 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:813:7 15:01:33 INFO - 2015-11-02 15:01:33,763 DEBUG : BROWSER_OUTPUT: Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:11 15:01:33 INFO - 2015-11-02 15:01:33,763 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:776:7 15:01:33 INFO - 2015-11-02 15:01:33,763 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:711:7 15:01:33 INFO - 2015-11-02 15:01:33,763 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:319:13 15:01:33 INFO - 2015-11-02 15:01:33,763 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9 15:01:33 INFO - 2015-11-02 15:01:33,763 DEBUG : BROWSER_OUTPUT: nsAsyncShutdownBarrier.prototype.wait/<@resource://gre/components/nsAsyncShutdown.js:215:7 15:01:33 INFO - 2015-11-02 15:01:33,764 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9 15:01:33 INFO - 2015-11-02 15:01:33,764 DEBUG : BROWSER_OUTPUT: 15:01:34 INFO - 2015-11-02 15:01:34,435 INFO : Browser initialized. 15:01:34 INFO - 2015-11-02 15:01:34,436 INFO : Running cycle 1/1 for tpaint test... 15:01:34 INFO - 2015-11-02 15:01:34,436 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpd5LK8B/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1 15:02:04 INFO - 2015-11-02 15:02:04,095 DEBUG : BROWSER_OUTPUT: __start_report257.28499999999985|264.40499999999975|268.1500000000001|272.619999999999|272.630000000001|273.3000000000011|275.93499999999995|277.1099999999999|279.3850000000002|281.73499999999876|289.2900000000009|289.65999999999985|304.6900000000023|309.3199999999997|317.73999999999796|327.71999999999935|341.0450000000001|354.0499999999993|359.3100000000013|376.130000000001__end_report__startTimestamp1446505324088__endTimestamp 15:02:04 INFO - 2015-11-02 15:02:04,096 DEBUG : BROWSER_OUTPUT: openingTimes=264.40499999999975,268.1500000000001,272.619999999999,272.630000000001,273.3000000000011,275.93499999999995,277.1099999999999,279.3850000000002,281.73499999999876,289.2900000000009,289.65999999999985,304.6900000000023,309.3199999999997,317.73999999999796,327.71999999999935,341.0450000000001,354.0499999999993,359.3100000000013,376.130000000001 15:02:04 INFO - 2015-11-02 15:02:04,096 DEBUG : BROWSER_OUTPUT: avgOpenTime:299.58 15:02:04 INFO - 2015-11-02 15:02:04,096 DEBUG : BROWSER_OUTPUT: minOpenTime:257.28 15:02:04 INFO - 2015-11-02 15:02:04,096 DEBUG : BROWSER_OUTPUT: maxOpenTime:376.13 15:02:04 INFO - 2015-11-02 15:02:04,096 DEBUG : BROWSER_OUTPUT: medOpenTime:285.5124999999998 15:02:04 INFO - 2015-11-02 15:02:04,096 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:285.5124999999998 15:02:05 INFO - 2015-11-02 15:02:05,157 INFO : Browser exited with error code: 0 15:02:05 INFO - 2015-11-02 15:02:05,169 INFO : Completed test tpaint (00:00:37) 15:02:05 INFO - 2015-11-02 15:02:05,169 INFO : Starting test sessionrestore 15:02:05 INFO - 2015-11-02 15:02:05,169 DEBUG : operating with platform_type : linux_ 15:02:05 INFO - 2015-11-02 15:02:05,169 INFO : Initialising browser for sessionrestore test... 15:02:05 INFO - 2015-11-02 15:02:05,178 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/getInfo.html 15:02:16 INFO - 2015-11-02 15:02:16,057 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 15:02:16 INFO - 2015-11-02 15:02:16,057 DEBUG : BROWSER_OUTPUT: colorDepth:24 15:02:16 INFO - 2015-11-02 15:02:16,057 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811 15:02:16 INFO - 2015-11-02 15:02:16,057 DEBUG : BROWSER_OUTPUT: __metrics 15:02:16 INFO - 2015-11-02 15:02:16,254 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 15:02:18 INFO - 2015-11-02 15:02:18,229 INFO : Browser initialized. 15:02:18 INFO - 2015-11-02 15:02:18,230 INFO : Running cycle 1/10 for sessionrestore test... 15:02:18 INFO - 2015-11-02 15:02:18,230 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpFmZwNW/profile/sessionstore.js 15:02:18 INFO - 2015-11-02 15:02:18,232 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpFmZwNW/profile/sessionCheckpoints.json 15:02:18 INFO - 2015-11-02 15:02:18,233 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:02:27 INFO - 2015-11-02 15:02:27,008 DEBUG : BROWSER_OUTPUT: __start_report4929__end_report 15:02:27 INFO - 2015-11-02 15:02:27,008 DEBUG : BROWSER_OUTPUT: 15:02:27 INFO - 2015-11-02 15:02:27,008 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505347002__endTimestamp 15:02:27 INFO - 2015-11-02 15:02:27,008 DEBUG : BROWSER_OUTPUT: 15:02:28 INFO - 2015-11-02 15:02:28,725 INFO : Browser exited with error code: 0 15:02:28 INFO - 2015-11-02 15:02:28,727 INFO : Running cycle 2/10 for sessionrestore test... 15:02:28 INFO - 2015-11-02 15:02:28,727 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpFmZwNW/profile/sessionstore.js 15:02:28 INFO - 2015-11-02 15:02:28,729 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpFmZwNW/profile/sessionCheckpoints.json 15:02:28 INFO - 2015-11-02 15:02:28,730 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:02:36 INFO - 2015-11-02 15:02:36,684 DEBUG : BROWSER_OUTPUT: __start_report4421__end_report 15:02:36 INFO - 2015-11-02 15:02:36,685 DEBUG : BROWSER_OUTPUT: 15:02:36 INFO - 2015-11-02 15:02:36,685 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505356682__endTimestamp 15:02:36 INFO - 2015-11-02 15:02:36,685 DEBUG : BROWSER_OUTPUT: 15:02:38 INFO - 2015-11-02 15:02:38,545 INFO : Browser exited with error code: 0 15:02:38 INFO - 2015-11-02 15:02:38,547 INFO : Running cycle 3/10 for sessionrestore test... 15:02:38 INFO - 2015-11-02 15:02:38,547 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpFmZwNW/profile/sessionstore.js 15:02:38 INFO - 2015-11-02 15:02:38,549 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpFmZwNW/profile/sessionCheckpoints.json 15:02:38 INFO - 2015-11-02 15:02:38,549 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:02:46 INFO - 2015-11-02 15:02:46,424 DEBUG : BROWSER_OUTPUT: __start_report4400__end_report 15:02:46 INFO - 2015-11-02 15:02:46,424 DEBUG : BROWSER_OUTPUT: 15:02:46 INFO - 2015-11-02 15:02:46,424 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505366416__endTimestamp 15:02:46 INFO - 2015-11-02 15:02:46,424 DEBUG : BROWSER_OUTPUT: 15:02:48 INFO - 2015-11-02 15:02:48,265 INFO : Browser exited with error code: 0 15:02:48 INFO - 2015-11-02 15:02:48,267 INFO : Running cycle 4/10 for sessionrestore test... 15:02:48 INFO - 2015-11-02 15:02:48,267 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpFmZwNW/profile/sessionstore.js 15:02:48 INFO - 2015-11-02 15:02:48,269 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpFmZwNW/profile/sessionCheckpoints.json 15:02:48 INFO - 2015-11-02 15:02:48,270 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:02:56 INFO - 2015-11-02 15:02:56,223 DEBUG : BROWSER_OUTPUT: __start_report4415__end_report 15:02:56 INFO - 2015-11-02 15:02:56,223 DEBUG : BROWSER_OUTPUT: 15:02:56 INFO - 2015-11-02 15:02:56,223 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505376216__endTimestamp 15:02:56 INFO - 2015-11-02 15:02:56,223 DEBUG : BROWSER_OUTPUT: 15:02:58 INFO - 2015-11-02 15:02:58,109 INFO : Browser exited with error code: 0 15:02:58 INFO - 2015-11-02 15:02:58,111 INFO : Running cycle 5/10 for sessionrestore test... 15:02:58 INFO - 2015-11-02 15:02:58,111 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpFmZwNW/profile/sessionstore.js 15:02:58 INFO - 2015-11-02 15:02:58,113 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpFmZwNW/profile/sessionCheckpoints.json 15:02:58 INFO - 2015-11-02 15:02:58,114 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:03:05 INFO - 2015-11-02 15:03:05,932 DEBUG : BROWSER_OUTPUT: __start_report4351__end_report 15:03:05 INFO - 2015-11-02 15:03:05,932 DEBUG : BROWSER_OUTPUT: 15:03:05 INFO - 2015-11-02 15:03:05,932 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505385930__endTimestamp 15:03:05 INFO - 2015-11-02 15:03:05,932 DEBUG : BROWSER_OUTPUT: 15:03:07 INFO - 2015-11-02 15:03:07,897 INFO : Browser exited with error code: 0 15:03:07 INFO - 2015-11-02 15:03:07,899 INFO : Running cycle 6/10 for sessionrestore test... 15:03:07 INFO - 2015-11-02 15:03:07,899 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpFmZwNW/profile/sessionstore.js 15:03:07 INFO - 2015-11-02 15:03:07,901 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpFmZwNW/profile/sessionCheckpoints.json 15:03:07 INFO - 2015-11-02 15:03:07,902 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:03:15 INFO - 2015-11-02 15:03:15,791 DEBUG : BROWSER_OUTPUT: __start_report4384__end_report 15:03:15 INFO - 2015-11-02 15:03:15,791 DEBUG : BROWSER_OUTPUT: 15:03:15 INFO - 2015-11-02 15:03:15,791 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505395785__endTimestamp 15:03:15 INFO - 2015-11-02 15:03:15,791 DEBUG : BROWSER_OUTPUT: 15:03:17 INFO - 2015-11-02 15:03:17,741 INFO : Browser exited with error code: 0 15:03:17 INFO - 2015-11-02 15:03:17,743 INFO : Running cycle 7/10 for sessionrestore test... 15:03:17 INFO - 2015-11-02 15:03:17,743 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpFmZwNW/profile/sessionstore.js 15:03:17 INFO - 2015-11-02 15:03:17,745 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpFmZwNW/profile/sessionCheckpoints.json 15:03:17 INFO - 2015-11-02 15:03:17,746 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:03:25 INFO - 2015-11-02 15:03:25,679 DEBUG : BROWSER_OUTPUT: __start_report4392__end_report 15:03:25 INFO - 2015-11-02 15:03:25,679 DEBUG : BROWSER_OUTPUT: 15:03:25 INFO - 2015-11-02 15:03:25,679 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505405674__endTimestamp 15:03:25 INFO - 2015-11-02 15:03:25,679 DEBUG : BROWSER_OUTPUT: 15:03:27 INFO - 2015-11-02 15:03:27,597 INFO : Browser exited with error code: 0 15:03:27 INFO - 2015-11-02 15:03:27,599 INFO : Running cycle 8/10 for sessionrestore test... 15:03:27 INFO - 2015-11-02 15:03:27,599 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpFmZwNW/profile/sessionstore.js 15:03:27 INFO - 2015-11-02 15:03:27,601 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpFmZwNW/profile/sessionCheckpoints.json 15:03:27 INFO - 2015-11-02 15:03:27,602 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:03:35 INFO - 2015-11-02 15:03:35,515 DEBUG : BROWSER_OUTPUT: __start_report4414__end_report 15:03:35 INFO - 2015-11-02 15:03:35,516 DEBUG : BROWSER_OUTPUT: 15:03:35 INFO - 2015-11-02 15:03:35,516 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505415510__endTimestamp 15:03:35 INFO - 2015-11-02 15:03:35,516 DEBUG : BROWSER_OUTPUT: 15:03:37 INFO - 2015-11-02 15:03:37,529 INFO : Browser exited with error code: 0 15:03:37 INFO - 2015-11-02 15:03:37,531 INFO : Running cycle 9/10 for sessionrestore test... 15:03:37 INFO - 2015-11-02 15:03:37,531 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpFmZwNW/profile/sessionstore.js 15:03:37 INFO - 2015-11-02 15:03:37,533 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpFmZwNW/profile/sessionCheckpoints.json 15:03:37 INFO - 2015-11-02 15:03:37,534 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:03:45 INFO - 2015-11-02 15:03:45,412 DEBUG : BROWSER_OUTPUT: __start_report4381__end_report 15:03:45 INFO - 2015-11-02 15:03:45,412 DEBUG : BROWSER_OUTPUT: 15:03:45 INFO - 2015-11-02 15:03:45,412 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505425411__endTimestamp 15:03:45 INFO - 2015-11-02 15:03:45,412 DEBUG : BROWSER_OUTPUT: 15:03:47 INFO - 2015-11-02 15:03:47,389 INFO : Browser exited with error code: 0 15:03:47 INFO - 2015-11-02 15:03:47,391 INFO : Running cycle 10/10 for sessionrestore test... 15:03:47 INFO - 2015-11-02 15:03:47,391 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpFmZwNW/profile/sessionstore.js 15:03:47 INFO - 2015-11-02 15:03:47,393 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpFmZwNW/profile/sessionCheckpoints.json 15:03:47 INFO - 2015-11-02 15:03:47,394 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpFmZwNW/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:03:55 INFO - 2015-11-02 15:03:55,307 DEBUG : BROWSER_OUTPUT: __start_report4382__end_report 15:03:55 INFO - 2015-11-02 15:03:55,308 DEBUG : BROWSER_OUTPUT: 15:03:55 INFO - 2015-11-02 15:03:55,308 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505435300__endTimestamp 15:03:55 INFO - 2015-11-02 15:03:55,308 DEBUG : BROWSER_OUTPUT: 15:03:57 INFO - 2015-11-02 15:03:57,329 INFO : Browser exited with error code: 0 15:03:57 INFO - 2015-11-02 15:03:57,345 INFO : Completed test sessionrestore (00:01:52) 15:03:57 INFO - 2015-11-02 15:03:57,345 INFO : Starting test sessionrestore_no_auto_restore 15:03:57 INFO - 2015-11-02 15:03:57,345 DEBUG : operating with platform_type : linux_ 15:03:57 INFO - 2015-11-02 15:03:57,346 INFO : Initialising browser for sessionrestore_no_auto_restore test... 15:03:57 INFO - 2015-11-02 15:03:57,354 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/getInfo.html 15:04:03 INFO - 2015-11-02 15:04:03,064 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 15:04:03 INFO - 2015-11-02 15:04:03,064 DEBUG : BROWSER_OUTPUT: colorDepth:24 15:04:03 INFO - 2015-11-02 15:04:03,064 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811 15:04:03 INFO - 2015-11-02 15:04:03,064 DEBUG : BROWSER_OUTPUT: __metrics 15:04:03 INFO - 2015-11-02 15:04:03,181 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 15:04:03 INFO - 2015-11-02 15:04:03,620 DEBUG : BROWSER_OUTPUT: JavaScript error: resource://gre/modules/IndexedDBHelper.jsm, line 138: UnknownError: The operation failed for reasons unrelated to the database itself and not covered by any other error code. 15:04:04 INFO - 2015-11-02 15:04:04,359 INFO : Browser initialized. 15:04:04 INFO - 2015-11-02 15:04:04,359 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test... 15:04:04 INFO - 2015-11-02 15:04:04,359 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp4YEYcF/profile/sessionstore.js 15:04:04 INFO - 2015-11-02 15:04:04,362 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp4YEYcF/profile/sessionCheckpoints.json 15:04:04 INFO - 2015-11-02 15:04:04,362 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:04:08 INFO - 2015-11-02 15:04:08,050 DEBUG : BROWSER_OUTPUT: __start_report2267__end_report 15:04:08 INFO - 2015-11-02 15:04:08,050 DEBUG : BROWSER_OUTPUT: 15:04:08 INFO - 2015-11-02 15:04:08,050 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505448044__endTimestamp 15:04:08 INFO - 2015-11-02 15:04:08,050 DEBUG : BROWSER_OUTPUT: 15:04:09 INFO - 2015-11-02 15:04:09,309 INFO : Browser exited with error code: 0 15:04:09 INFO - 2015-11-02 15:04:09,311 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test... 15:04:09 INFO - 2015-11-02 15:04:09,311 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp4YEYcF/profile/sessionstore.js 15:04:09 INFO - 2015-11-02 15:04:09,313 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp4YEYcF/profile/sessionCheckpoints.json 15:04:09 INFO - 2015-11-02 15:04:09,314 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:04:12 INFO - 2015-11-02 15:04:12,322 DEBUG : BROWSER_OUTPUT: __start_report1799__end_report 15:04:12 INFO - 2015-11-02 15:04:12,322 DEBUG : BROWSER_OUTPUT: 15:04:12 INFO - 2015-11-02 15:04:12,322 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505452321__endTimestamp 15:04:12 INFO - 2015-11-02 15:04:12,322 DEBUG : BROWSER_OUTPUT: 15:04:13 INFO - 2015-11-02 15:04:13,517 INFO : Browser exited with error code: 0 15:04:13 INFO - 2015-11-02 15:04:13,519 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test... 15:04:13 INFO - 2015-11-02 15:04:13,519 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp4YEYcF/profile/sessionstore.js 15:04:13 INFO - 2015-11-02 15:04:13,521 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp4YEYcF/profile/sessionCheckpoints.json 15:04:13 INFO - 2015-11-02 15:04:13,522 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:04:16 INFO - 2015-11-02 15:04:16,475 DEBUG : BROWSER_OUTPUT: __start_report1764__end_report 15:04:16 INFO - 2015-11-02 15:04:16,475 DEBUG : BROWSER_OUTPUT: 15:04:16 INFO - 2015-11-02 15:04:16,476 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505456472__endTimestamp 15:04:16 INFO - 2015-11-02 15:04:16,476 DEBUG : BROWSER_OUTPUT: 15:04:17 INFO - 2015-11-02 15:04:17,633 INFO : Browser exited with error code: 0 15:04:17 INFO - 2015-11-02 15:04:17,635 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test... 15:04:17 INFO - 2015-11-02 15:04:17,635 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp4YEYcF/profile/sessionstore.js 15:04:17 INFO - 2015-11-02 15:04:17,637 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp4YEYcF/profile/sessionCheckpoints.json 15:04:17 INFO - 2015-11-02 15:04:17,637 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:04:20 INFO - 2015-11-02 15:04:20,699 DEBUG : BROWSER_OUTPUT: __start_report1806__end_report 15:04:20 INFO - 2015-11-02 15:04:20,699 DEBUG : BROWSER_OUTPUT: 15:04:20 INFO - 2015-11-02 15:04:20,699 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505460697__endTimestamp 15:04:20 INFO - 2015-11-02 15:04:20,699 DEBUG : BROWSER_OUTPUT: 15:04:21 INFO - 2015-11-02 15:04:21,865 INFO : Browser exited with error code: 0 15:04:21 INFO - 2015-11-02 15:04:21,867 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test... 15:04:21 INFO - 2015-11-02 15:04:21,867 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp4YEYcF/profile/sessionstore.js 15:04:21 INFO - 2015-11-02 15:04:21,869 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp4YEYcF/profile/sessionCheckpoints.json 15:04:21 INFO - 2015-11-02 15:04:21,870 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:04:24 INFO - 2015-11-02 15:04:24,852 DEBUG : BROWSER_OUTPUT: __start_report1792__end_report 15:04:24 INFO - 2015-11-02 15:04:24,852 DEBUG : BROWSER_OUTPUT: 15:04:24 INFO - 2015-11-02 15:04:24,852 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505464848__endTimestamp 15:04:24 INFO - 2015-11-02 15:04:24,852 DEBUG : BROWSER_OUTPUT: 15:04:26 INFO - 2015-11-02 15:04:26,173 INFO : Browser exited with error code: 0 15:04:26 INFO - 2015-11-02 15:04:26,175 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test... 15:04:26 INFO - 2015-11-02 15:04:26,175 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp4YEYcF/profile/sessionstore.js 15:04:26 INFO - 2015-11-02 15:04:26,177 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp4YEYcF/profile/sessionCheckpoints.json 15:04:26 INFO - 2015-11-02 15:04:26,178 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:04:29 INFO - 2015-11-02 15:04:29,306 DEBUG : BROWSER_OUTPUT: __start_report1830__end_report 15:04:29 INFO - 2015-11-02 15:04:29,307 DEBUG : BROWSER_OUTPUT: 15:04:29 INFO - 2015-11-02 15:04:29,307 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505469304__endTimestamp 15:04:29 INFO - 2015-11-02 15:04:29,307 DEBUG : BROWSER_OUTPUT: 15:04:30 INFO - 2015-11-02 15:04:30,621 INFO : Browser exited with error code: 0 15:04:30 INFO - 2015-11-02 15:04:30,623 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test... 15:04:30 INFO - 2015-11-02 15:04:30,623 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp4YEYcF/profile/sessionstore.js 15:04:30 INFO - 2015-11-02 15:04:30,625 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp4YEYcF/profile/sessionCheckpoints.json 15:04:30 INFO - 2015-11-02 15:04:30,625 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:04:33 INFO - 2015-11-02 15:04:33,660 DEBUG : BROWSER_OUTPUT: __start_report1812__end_report 15:04:33 INFO - 2015-11-02 15:04:33,660 DEBUG : BROWSER_OUTPUT: 15:04:33 INFO - 2015-11-02 15:04:33,660 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505473657__endTimestamp 15:04:33 INFO - 2015-11-02 15:04:33,660 DEBUG : BROWSER_OUTPUT: 15:04:35 INFO - 2015-11-02 15:04:35,073 INFO : Browser exited with error code: 0 15:04:35 INFO - 2015-11-02 15:04:35,075 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test... 15:04:35 INFO - 2015-11-02 15:04:35,075 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp4YEYcF/profile/sessionstore.js 15:04:35 INFO - 2015-11-02 15:04:35,077 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp4YEYcF/profile/sessionCheckpoints.json 15:04:35 INFO - 2015-11-02 15:04:35,077 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:04:38 INFO - 2015-11-02 15:04:38,139 DEBUG : BROWSER_OUTPUT: __start_report1793__end_report 15:04:38 INFO - 2015-11-02 15:04:38,139 DEBUG : BROWSER_OUTPUT: 15:04:38 INFO - 2015-11-02 15:04:38,139 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505478137__endTimestamp 15:04:38 INFO - 2015-11-02 15:04:38,139 DEBUG : BROWSER_OUTPUT: 15:04:39 INFO - 2015-11-02 15:04:39,437 INFO : Browser exited with error code: 0 15:04:39 INFO - 2015-11-02 15:04:39,439 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test... 15:04:39 INFO - 2015-11-02 15:04:39,439 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp4YEYcF/profile/sessionstore.js 15:04:39 INFO - 2015-11-02 15:04:39,441 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp4YEYcF/profile/sessionCheckpoints.json 15:04:39 INFO - 2015-11-02 15:04:39,442 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:04:42 INFO - 2015-11-02 15:04:42,511 DEBUG : BROWSER_OUTPUT: __start_report1816__end_report 15:04:42 INFO - 2015-11-02 15:04:42,511 DEBUG : BROWSER_OUTPUT: 15:04:42 INFO - 2015-11-02 15:04:42,511 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505482510__endTimestamp 15:04:42 INFO - 2015-11-02 15:04:42,512 DEBUG : BROWSER_OUTPUT: 15:04:43 INFO - 2015-11-02 15:04:43,757 INFO : Browser exited with error code: 0 15:04:43 INFO - 2015-11-02 15:04:43,759 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test... 15:04:43 INFO - 2015-11-02 15:04:43,759 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp4YEYcF/profile/sessionstore.js 15:04:43 INFO - 2015-11-02 15:04:43,761 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp4YEYcF/profile/sessionCheckpoints.json 15:04:43 INFO - 2015-11-02 15:04:43,762 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp4YEYcF/profile http://localhost:47433/startup_test/sessionrestore/index.html 15:04:46 INFO - 2015-11-02 15:04:46,805 DEBUG : BROWSER_OUTPUT: __start_report1786__end_report 15:04:46 INFO - 2015-11-02 15:04:46,806 DEBUG : BROWSER_OUTPUT: 15:04:46 INFO - 2015-11-02 15:04:46,806 DEBUG : BROWSER_OUTPUT: __startTimestamp1446505486802__endTimestamp 15:04:46 INFO - 2015-11-02 15:04:46,806 DEBUG : BROWSER_OUTPUT: 15:04:48 INFO - 2015-11-02 15:04:48,053 INFO : Browser exited with error code: 0 15:04:48 INFO - 2015-11-02 15:04:48,069 INFO : Completed test sessionrestore_no_auto_restore (00:00:50) 15:04:48 INFO - 2015-11-02 15:04:48,516 INFO : Completed test suite (00:06:41) 15:04:48 INFO - 2015-11-02 15:04:48,517 DEBUG : Working with test: a11yr 15:04:48 INFO - 2015-11-02 15:04:48,517 DEBUG : Generating results file: a11yr 15:04:48 INFO - 2015-11-02 15:04:48,517 DEBUG : Working with test: ts_paint 15:04:48 INFO - 2015-11-02 15:04:48,517 DEBUG : Generating results file: ts_paint 15:04:48 INFO - 2015-11-02 15:04:48,518 DEBUG : Working with test: tpaint 15:04:48 INFO - 2015-11-02 15:04:48,518 DEBUG : Generating results file: tpaint 15:04:48 INFO - 2015-11-02 15:04:48,518 DEBUG : Working with test: sessionrestore 15:04:48 INFO - 2015-11-02 15:04:48,518 DEBUG : Generating results file: sessionrestore 15:04:48 INFO - 2015-11-02 15:04:48,519 DEBUG : Working with test: sessionrestore_no_auto_restore 15:04:48 INFO - 2015-11-02 15:04:48,519 DEBUG : Generating results file: sessionrestore_no_auto_restore 15:04:48 INFO - 2015-11-02 15:04:48,519 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 15:04:48 INFO - 2015-11-02 15:04:48,559 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,131,35]] 15:04:48 INFO - 2015-11-02 15:04:48,559 DEBUG : process_Request line: a11yr_paint 692.79 graph.html#tests=[[223,131,35]] 15:04:48 INFO - 2015-11-02 15:04:48,560 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 15:04:48 INFO - 2015-11-02 15:04:48,621 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,131,35]] 15:04:48 INFO - 2015-11-02 15:04:48,621 DEBUG : process_Request line: ts_paint 2779.83 graph.html#tests=[[83,131,35]] 15:04:48 INFO - 2015-11-02 15:04:48,622 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 15:04:48 INFO - 2015-11-02 15:04:48,659 DEBUG : process_Request line: tpaint graph.html#tests=[[82,131,35]] 15:04:48 INFO - 2015-11-02 15:04:48,659 DEBUG : process_Request line: tpaint 304.69 graph.html#tests=[[82,131,35]] 15:04:48 INFO - 2015-11-02 15:04:48,660 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 15:04:48 INFO - 2015-11-02 15:04:48,706 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,131,35]] 15:04:48 INFO - 2015-11-02 15:04:48,707 DEBUG : process_Request line: sessionrestore 4444.13 graph.html#tests=[[313,131,35]] 15:04:48 INFO - 2015-11-02 15:04:48,707 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 15:04:48 INFO - 2015-11-02 15:04:48,751 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,131,35]] 15:04:48 INFO - 2015-11-02 15:04:48,751 DEBUG : process_Request line: sessionrestore_no_auto_restore 1841.72 graph.html#tests=[[315,131,35]] 15:04:48 INFO - 2015-11-02 15:04:48,753 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [1402.0, 1451.0, 1538.0, 1363.0, 1538.0, 1350.0, 1457.0, 1473.0, 1547.0, 1466.0, 1369.0, 1471.0, 1480.0, 1467.0, 1469.0, 1483.0, 1488.0, 1482.0, 1471.0, 1467.0, 1463.0, 1378.0, 1530.0, 1474.0, 1473.0], "tablemutation.html": [335.0, 325.0, 327.0, 326.0, 324.0, 325.0, 327.0, 326.0, 326.0, 336.0, 326.0, 326.0, 327.0, 329.0, 326.0, 328.0, 330.0, 326.0, 325.0, 326.0, 329.0, 326.0, 325.0, 328.0, 325.0]}, "summary": {"suite": 692.7895934647621, "subtests": {"dhtml.html": {"filtered": 1471.0, "value": 1471.0}, "tablemutation.html": {"filtered": 326.0, "value": 326.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-037"}, "testrun": {"date": 1446505087, "suite": "a11yr", "options": {"responsiveness": false, "tpmozafterpaint": true, "tpchrome": true, "tppagecycles": 25, "tpcycles": 1, "tprender": false, "shutdown": false, "cycles": 1, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151102135706", "branch": "Mozilla-Inbound-Non-PGO", "revision": "11dd4cfb65639257a3c3e87886c0b6157be5b876"}}, {"talos_counters": {}, "results": {"ts_paint": [3568.0, 2765.0, 2759.0, 2736.0, 2754.0, 2727.0, 2770.0, 2704.0, 2713.0, 2753.0, 2719.0, 2776.0, 2764.0, 2722.0, 2728.0, 2784.0, 2714.0, 2755.0, 2789.0, 2698.0]}, "summary": {"suite": 2753.0, "subtests": {"ts_paint": {"filtered": 2753.0, "value": 2753.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-037"}, "testrun": {"date": 1446505087, "suite": "ts_paint", "options": {"responsiveness": false, "cycles": 20, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151102135706", "branch": "Mozilla-Inbound-Non-PGO", "revision": "11dd4cfb65639257a3c3e87886c0b6157be5b876"}}, {"talos_counters": {}, "results": {"tpaint": [257.28499999999985, 264.40499999999975, 268.1500000000001, 272.619999999999, 272.630000000001, 273.3000000000011, 275.93499999999995, 277.1099999999999, 279.3850000000002, 281.73499999999876, 289.2900000000009, 289.65999999999985, 304.6900000000023, 309.3199999999997, 317.73999999999796, 327.71999999999935, 341.0450000000001, 354.0499999999993, 359.3100000000013, 376.130000000001]}, "summary": {"suite": 304.6900000000023, "subtests": {"tpaint": {"filtered": 304.6900000000023, "value": 304.6900000000023}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-037"}, "testrun": {"date": 1446505087, "suite": "tpaint", "options": {"responsiveness": false, "cycles": 1, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151102135706", "branch": "Mozilla-Inbound-Non-PGO", "revision": "11dd4cfb65639257a3c3e87886c0b6157be5b876"}}, {"talos_counters": {}, "results": {"sessionrestore": [4929.0, 4421.0, 4400.0, 4415.0, 4351.0, 4384.0, 4392.0, 4414.0, 4381.0, 4382.0]}, "summary": {"suite": 4392.0, "subtests": {"sessionrestore": {"filtered": 4392.0, "value": 4392.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-037"}, "testrun": {"date": 1446505087, "suite": "sessionrestore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151102135706", "branch": "Mozilla-Inbound-Non-PGO", "revision": "11dd4cfb65639257a3c3e87886c0b6157be5b876"}}, {"talos_counters": {}, "results": {"sessionrestore_no_auto_restore": [2267.0, 1799.0, 1764.0, 1806.0, 1792.0, 1830.0, 1812.0, 1793.0, 1816.0, 1786.0]}, "summary": {"suite": 1799.0, "subtests": {"sessionrestore_no_auto_restore": {"filtered": 1799.0, "value": 1799.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-037"}, "testrun": {"date": 1446505087, "suite": "sessionrestore_no_auto_restore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151102135706", "branch": "Mozilla-Inbound-Non-PGO", "revision": "11dd4cfb65639257a3c3e87886c0b6157be5b876"}}] 15:04:48 INFO - RETURN: a11yr_paint: 692.79 15:04:48 INFO - RETURN: ts_paint: 2779.83 15:04:48 INFO - RETURN: tpaint: 304.69 15:04:48 INFO - RETURN: sessionrestore: 4444.13 15:04:48 INFO - RETURN: sessionrestore_no_auto_restore: 1841.72 15:04:48 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,131,35]]", "result": "4444.13"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,131,35]]", "result": "692.79"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,131,35]]", "result": "304.69"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,131,35]]", "result": "2779.83"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,131,35]]", "result": "1841.72"}}} 15:04:48 INFO - Return code: 0 15:04:48 INFO - # TBPL SUCCESS # 15:04:48 INFO - Running post-action listener: _resource_record_post_action 15:04:48 INFO - Running post-run listener: _resource_record_post_run 15:04:49 INFO - Total resource usage - Wall time: 415s; CPU: 13.0%; Read bytes: 4096; Write bytes: 568553472; Read time: 4; Write time: 422044 15:04:49 INFO - install - Wall time: 14s; CPU: 14.0%; Read bytes: 0; Write bytes: 221265920; Read time: 0; Write time: 247544 15:04:49 INFO - run-tests - Wall time: 402s; CPU: 13.0%; Read bytes: 0; Write bytes: 346853376; Read time: 0; Write time: 174472 15:04:49 INFO - Running post-run listener: _upload_blobber_files 15:04:49 INFO - Blob upload gear active. 15:04:49 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ... 15:04:49 INFO - Copying logs to upload dir... 15:04:49 INFO - mkdir: /builds/slave/test/build/upload/logs program finished with exit code 0 elapsedTime=450.810428 ========= master_lag: 0.03 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 7 mins, 30 secs) (at 2015-11-02 15:04:49.822158) ========= ========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-02 15:04:49.826270) ========= bash -c 'for file in `ls -1`; do cat $file; done' in dir /builds/slave/test/properties (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'for file in `ls -1`; do cat $file; done'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test/properties SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False build_url:https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 program finished with exit code 0 elapsedTime=0.009960 build_url: 'https://queue.taskcluster.net/v1/task/xIXWnR5kRPiFjOBJsenD6A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2' ========= master_lag: 0.04 ========= ========= Finished set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-02 15:04:49.880187) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-02 15:04:49.880748) ========= rm -f oauth.txt in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-f', 'oauth.txt'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=6ea65ccfe4e6b94e0d4f826f000001d8-1446504343.358660-593371096 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004641 ========= master_lag: 0.05 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-02 15:04:49.931782) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-02 15:04:49.932116) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-02 15:04:49.932456) ========= ========= Total master_lag: 0.31 =========