builder: fx-team_ubuntu64_hw_test-other-e10s slave: talos-linux64-ix-045 starttime: 1447870777.07 results: success (0) buildid: 20151118091623 builduid: 28474222b74b4731a603f3978a06f218 revision: 1d6ba006a526d17294369eed770a9a0ce2794bde ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.074866) ========= master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.075394) ========= ========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.075678) ========= 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=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False /builds/slave/test program finished with exit code 0 elapsedTime=0.006584 basedir: '/builds/slave/test' ========= master_lag: 0.01 ========= ========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.095322) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.095610) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.103452) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.103766) ========= 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=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004512 ========= master_lag: 0.04 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.152923) ========= ========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.153235) ========= script_repo_url: https://hg.mozilla.org/build/mozharness ========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.153589) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.153856) ========= 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=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2015-11-18 10:19:37-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.102, 63.245.215.25 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.102|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12141 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 5.81M=0.002s 2015-11-18 10:19:37 (5.81 MB/s) - `archiver_client.py' saved [12141/12141] program finished with exit code 0 elapsedTime=0.192586 ========= master_lag: 0.01 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.358612) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.358920) ========= 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=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.014413 ========= master_lag: 0.04 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.408842) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.409200) ========= bash -c 'python archiver_client.py mozharness --repo integration/fx-team --rev 1d6ba006a526d17294369eed770a9a0ce2794bde --destination scripts --debug' in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', u'python archiver_client.py mozharness --repo integration/fx-team --rev 1d6ba006a526d17294369eed770a9a0ce2794bde --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=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2015-11-18 10:19:38,091 truncating revision to first 12 chars 2015-11-18 10:19:38,091 Setting DEBUG logging. 2015-11-18 10:19:38,091 attempt 1/10 2015-11-18 10:19:38,091 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/fx-team/1d6ba006a526?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2015-11-18 10:19:38,330 unpacking tar archive at: fx-team-1d6ba006a526/testing/mozharness/ program finished with exit code 0 elapsedTime=0.527983 ========= master_lag: 0.01 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.950145) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.950498) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.958440) ========= ========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.958749) ========= TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production ========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-18 10:19:37.959198) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 59 secs) (at 2015-11-18 10:19:37.959562) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other-e10s --add-option --webServer,localhost --branch-name Fx-Team-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Fx-Team-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-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Fx-Team-Non-PGO', '--system-bits', '64', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Fx-Team-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=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 10:19:38 INFO - MultiFileLogger online at 20151118 10:19:38 in /builds/slave/test 10:19:38 INFO - Run as scripts/scripts/talos_script.py --suite other-e10s --add-option --webServer,localhost --branch-name Fx-Team-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Fx-Team-Non-PGO 10:19:38 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 10:19:38 INFO - {'append_to_log': False, 10:19:38 INFO - 'base_work_dir': '/builds/slave/test', 10:19:38 INFO - 'blob_upload_branch': 'Fx-Team-Non-PGO', 10:19:38 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 10:19:38 INFO - 'branch': 'Fx-Team-Non-PGO', 10:19:38 INFO - 'buildbot_json_path': 'buildprops.json', 10:19:38 INFO - 'config_files': ('talos/linux_config.py',), 10:19:38 INFO - 'default_actions': ('clobber', 10:19:38 INFO - 'read-buildbot-config', 10:19:38 INFO - 'download-and-extract', 10:19:38 INFO - 'populate-webroot', 10:19:38 INFO - 'create-virtualenv', 10:19:38 INFO - 'install', 10:19:38 INFO - 'run-tests'), 10:19:38 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 10:19:38 INFO - 'download_minidump_stackwalk': True, 10:19:38 INFO - 'download_symbols': 'ondemand', 10:19:38 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 10:19:38 INFO - 'tooltool.py': '/tools/tooltool.py', 10:19:38 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 10:19:38 INFO - '/tools/misc-python/virtualenv.py')}, 10:19:38 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 10:19:38 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 10:19:38 INFO - 'installer_path': 'installer.exe', 10:19:38 INFO - 'log_level': 'info', 10:19:38 INFO - 'log_name': 'talos', 10:19:38 INFO - 'log_to_console': True, 10:19:38 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 10:19:38 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 10:19:38 INFO - 'opt_config_files': (), 10:19:38 INFO - 'pip_index': False, 10:19:38 INFO - 'sps_profile': False, 10:19:38 INFO - 'sps_profile_interval': 0, 10:19:38 INFO - 'suite': 'other-e10s', 10:19:38 INFO - 'system_bits': '64', 10:19:38 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 10:19:38 INFO - 'title': 'talos-linux64-ix-045', 10:19:38 INFO - 'tooltool_cache': '/builds/tooltool_cache', 10:19:38 INFO - 'use_talos_json': True, 10:19:38 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 10:19:38 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 10:19:38 INFO - 'work_dir': 'build'} 10:19:38 INFO - ##### 10:19:38 INFO - ##### Running clobber step. 10:19:38 INFO - ##### 10:19:38 INFO - Running pre-action listener: _resource_record_pre_action 10:19:38 INFO - Running main action method: clobber 10:19:38 INFO - rmtree: /builds/slave/test/build 10:19:38 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 10:19:39 INFO - Running post-action listener: _resource_record_post_action 10:19:39 INFO - ##### 10:19:39 INFO - ##### Running read-buildbot-config step. 10:19:39 INFO - ##### 10:19:39 INFO - Running pre-action listener: _resource_record_pre_action 10:19:39 INFO - Running main action method: read_buildbot_config 10:19:39 INFO - Using buildbot properties: 10:19:39 INFO - { 10:19:39 INFO - "properties": { 10:19:39 INFO - "buildnumber": 485, 10:19:39 INFO - "product": "firefox", 10:19:39 INFO - "script_repo_revision": "production", 10:19:39 INFO - "builddir": "fx-team_ubuntu64_hw_test-other-e10s", 10:19:39 INFO - "repository": "", 10:19:39 INFO - "buildername": "Ubuntu HW 12.04 x64 fx-team talos other-e10s", 10:19:39 INFO - "buildid": "20151118091623", 10:19:39 INFO - "slavename": "talos-linux64-ix-045", 10:19:39 INFO - "pgo_build": "False", 10:19:39 INFO - "basedir": "/builds/slave/test", 10:19:39 INFO - "project": "", 10:19:39 INFO - "platform": "ubuntu64_hw", 10:19:39 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 10:19:39 INFO - "slavebuilddir": "test", 10:19:39 INFO - "scheduler": "tests-fx-team-linux64-talos", 10:19:39 INFO - "branch": "fx-team", 10:19:39 INFO - "repo_path": "integration/fx-team", 10:19:39 INFO - "stage_platform": "linux64", 10:19:39 INFO - "builduid": "28474222b74b4731a603f3978a06f218", 10:19:39 INFO - "revision": "1d6ba006a526d17294369eed770a9a0ce2794bde" 10:19:39 INFO - }, 10:19:39 INFO - "sourcestamp": { 10:19:39 INFO - "repository": "", 10:19:39 INFO - "hasPatch": false, 10:19:39 INFO - "project": "", 10:19:39 INFO - "branch": "fx-team-linux64-talos", 10:19:39 INFO - "changes": [ 10:19:39 INFO - { 10:19:39 INFO - "category": null, 10:19:39 INFO - "files": [ 10:19:39 INFO - { 10:19:39 INFO - "url": null, 10:19:39 INFO - "name": "https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2" 10:19:39 INFO - } 10:19:39 INFO - ], 10:19:39 INFO - "repository": "", 10:19:39 INFO - "rev": "1d6ba006a526d17294369eed770a9a0ce2794bde", 10:19:39 INFO - "who": "dtownsend@mozilla.com", 10:19:39 INFO - "when": 1447867606, 10:19:39 INFO - "number": 6677891, 10:19:39 INFO - "comments": "Bug 1220911: Remove most of the special casing around experiments. r=rhelmer\n\nExperiments should differ from normal add-ons in a few ways:\n\n* They can always be enabled regardless of compatibility info\n* They default to disabled when installed\n* They cannot be checked for updates\n* They only stay enabled for the lifetime of the current process\n* The UI doesn't give users the ability to enable/disable\n\nThis makes a few changes to keep these differences but remove much of the special casing code for experiments.\n\nBeing able to use regardless of compatibility was mostly fixed by bug 1220198 but I've also removed the redundant override in isCompatible.\n\nPreviously the \"enabled until restart\" feature worked with by not updating the DBAddonInternal object and instead using a hack to make the wrapper still seem enabled. This seems likely to break other code that relies on the state of the DBAddonInternal object so instead we update that as normal and simply don't persist the enabled state to disk.\n\nAlso switch the D", 10:19:39 INFO - "project": "", 10:19:39 INFO - "at": "Wed 18 Nov 2015 09:26:46", 10:19:39 INFO - "branch": "fx-team-linux64-talos", 10:19:39 INFO - "revlink": "", 10:19:39 INFO - "properties": [ 10:19:39 INFO - [ 10:19:39 INFO - "buildid", 10:19:39 INFO - "20151118091623", 10:19:39 INFO - "Change" 10:19:39 INFO - ], 10:19:39 INFO - [ 10:19:39 INFO - "builduid", 10:19:39 INFO - "28474222b74b4731a603f3978a06f218", 10:19:39 INFO - "Change" 10:19:39 INFO - ], 10:19:39 INFO - [ 10:19:39 INFO - "pgo_build", 10:19:39 INFO - "False", 10:19:39 INFO - "Change" 10:19:39 INFO - ] 10:19:39 INFO - ], 10:19:39 INFO - "revision": "1d6ba006a526d17294369eed770a9a0ce2794bde" 10:19:39 INFO - } 10:19:39 INFO - ], 10:19:39 INFO - "revision": "1d6ba006a526d17294369eed770a9a0ce2794bde" 10:19:39 INFO - } 10:19:39 INFO - } 10:19:39 INFO - Found installer url https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2. 10:19:39 INFO - Running post-action listener: _resource_record_post_action 10:19:39 INFO - ##### 10:19:39 INFO - ##### Running download-and-extract step. 10:19:39 INFO - ##### 10:19:39 INFO - Running pre-action listener: _resource_record_pre_action 10:19:39 INFO - Running main action method: download_and_extract 10:19:39 INFO - mkdir: /builds/slave/test/build/tests 10:19:39 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')]} 10:19:39 INFO - https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net 10:19:39 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/test_packages.json 10:19:39 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/test_packages.json 10:19:39 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json 10:19:39 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/test_packages.json', 'file_name': '/builds/slave/test/build/test_packages.json'}, attempt #1 10:19:39 INFO - Downloaded 1302 bytes. 10:19:39 INFO - Reading from file /builds/slave/test/build/test_packages.json 10:19:39 INFO - Using the following test package requirements: 10:19:39 INFO - {u'common': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 10:19:39 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.cppunittest.tests.zip'], 10:19:39 INFO - u'jittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:19:39 INFO - u'jsshell-linux-x86_64.zip'], 10:19:39 INFO - u'mochitest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.mochitest.tests.zip'], 10:19:39 INFO - u'mozbase': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 10:19:39 INFO - u'reftest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.reftest.tests.zip'], 10:19:39 INFO - u'talos': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'], 10:19:39 INFO - u'web-platform': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.web-platform.tests.zip'], 10:19:39 INFO - u'webapprt': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 10:19:39 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:19:39 INFO - u'firefox-45.0a1.en-US.linux-x86_64.xpcshell.tests.zip']} 10:19:39 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] for test suite category: common 10:19:39 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')]} 10:19:39 INFO - https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net 10:19:39 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:19:39 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:19:39 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/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 10:19:39 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/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 10:19:41 INFO - Downloaded 21291363 bytes. 10:19:41 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 10:19:41 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:19:41 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 10:19:42 INFO - Return code: 0 10:19:42 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 10:19: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')]} 10:19:42 INFO - https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net 10:19:42 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:19:42 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:19:42 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/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 10:19:42 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/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 10:19:43 INFO - Downloaded 21291363 bytes. 10:19:43 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 10:19:43 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:19:43 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 10:19:44 INFO - Return code: 0 10:19:44 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')]} 10:19:44 INFO - https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip matches https://queue.taskcluster.net 10:19:44 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 10:19:44 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 10:19:44 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/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 10:19:44 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/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 10:19:45 INFO - Downloaded 11130997 bytes. 10:19:45 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 10:19:45 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 10:19:45 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 10:19:45 INFO - Return code: 0 10:19: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')]} 10:19:45 INFO - https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 matches https://queue.taskcluster.net 10:19:45 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 10:19:45 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 10:19:45 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/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 10:19:45 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/oj_sNZtLRR6uEoCsky80IQ/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 10:19:46 INFO - Downloaded 55666594 bytes. 10:19:46 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 10:19:46 INFO - mkdir: /builds/slave/test/properties 10:19:46 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 10:19:46 INFO - Writing to file /builds/slave/test/properties/build_url 10:19:46 INFO - Contents: 10:19:46 INFO - build_url:https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 10:19:46 INFO - Running post-action listener: _resource_record_post_action 10:19:46 INFO - Running post-action listener: set_extra_try_arguments 10:19:46 INFO - ##### 10:19:46 INFO - ##### Running populate-webroot step. 10:19:46 INFO - ##### 10:19:46 INFO - Running pre-action listener: _resource_record_pre_action 10:19:46 INFO - Running main action method: populate_webroot 10:19:46 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']}, 10:19:46 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']}, 10:19:46 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs', 10:19:46 INFO - '../fennec_ids.txt'], 10:19:46 INFO - 'tests': ['tcheck2']}, 10:19:46 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome', 10:19:46 INFO - '--tppagecycles', 10:19:46 INFO - '7'], 10:19:46 INFO - 'tests': ['tsvgm']}}, 10:19:46 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']}, 10:19:46 INFO - 'chromez-e10s': {'talos_options': ['--e10s'], 10:19:46 INFO - 'tests': ['tresize', 'tcanvasmark']}, 10:19:46 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 10:19:46 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'], 10:19:46 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 10:19:46 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:19:46 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 10:19:46 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:19:46 INFO - 'talos_options': ['--e10s'], 10:19:46 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 10:19:46 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:19:46 INFO - 'tests': ['damp', 'tps']}, 10:19:46 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:19:46 INFO - 'talos_options': ['--e10s'], 10:19:46 INFO - 'tests': ['damp', 'tps']}, 10:19:46 INFO - 'g3': {'tests': ['dromaeo_dom']}, 10:19:46 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 10:19:46 INFO - 'other': {'tests': ['a11yr', 10:19:46 INFO - 'ts_paint', 10:19:46 INFO - 'tpaint', 10:19:46 INFO - 'sessionrestore', 10:19:46 INFO - 'sessionrestore_no_auto_restore']}, 10:19:46 INFO - 'other-e10s': {'talos_options': ['--e10s'], 10:19:46 INFO - 'tests': ['a11yr', 10:19:46 INFO - 'ts_paint', 10:19:46 INFO - 'tpaint', 10:19:46 INFO - 'sessionrestore', 10:19:46 INFO - 'sessionrestore_no_auto_restore']}, 10:19:46 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'], 10:19:46 INFO - 'tests': ['a11yr', 10:19:46 INFO - 'ts_paint', 10:19:46 INFO - 'tpaint', 10:19:46 INFO - 'sessionrestore', 10:19:46 INFO - 'sessionrestore_no_auto_restore']}, 10:19:46 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'], 10:19:46 INFO - 'tests': ['a11yr', 10:19:46 INFO - 'ts_paint', 10:19:46 INFO - 'tpaint', 10:19:46 INFO - 'sessionrestore', 10:19:46 INFO - 'sessionrestore_no_auto_restore']}, 10:19:46 INFO - 'other_l64': {'tests': ['a11yr', 10:19:46 INFO - 'ts_paint', 10:19:46 INFO - 'tpaint', 10:19:46 INFO - 'sessionrestore', 10:19:46 INFO - 'sessionrestore_no_auto_restore']}, 10:19:46 INFO - 'other_nol64': {'tests': ['a11yr', 10:19:46 INFO - 'ts_paint', 10:19:46 INFO - 'tpaint', 10:19:46 INFO - 'sessionrestore', 10:19:46 INFO - 'sessionrestore_no_auto_restore']}, 10:19:46 INFO - 'svgr': {'tests': ['tsvgx', 10:19:46 INFO - 'tsvgr_opacity', 10:19:46 INFO - 'tart', 10:19:46 INFO - 'tscrollx', 10:19:46 INFO - 'cart']}, 10:19:46 INFO - 'svgr-e10s': {'talos_options': ['--e10s'], 10:19:46 INFO - 'tests': ['tsvgx', 10:19:46 INFO - 'tsvgr_opacity', 10:19:46 INFO - 'tart', 10:19:46 INFO - 'tscrollx', 10:19:46 INFO - 'cart']}, 10:19:46 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:19:46 INFO - 'tests': ['tp5o']}, 10:19:46 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:19:46 INFO - 'talos_options': ['--e10s'], 10:19:46 INFO - 'tests': ['tp5o']}, 10:19:46 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:19:46 INFO - 'talos_options': ['--xperf_path', 10:19:46 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 10:19:46 INFO - 'tests': ['tp5n']}, 10:19:46 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:19:46 INFO - 'talos_options': ['--e10s', 10:19:46 INFO - '--xperf_path', 10:19:46 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 10:19:46 INFO - 'tests': ['tp5n']}}, 10:19:46 INFO - 'talos.zip': {'path': '', 10:19:46 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}} 10:19:46 INFO - Running post-action listener: _resource_record_post_action 10:19:46 INFO - ##### 10:19:46 INFO - ##### Running create-virtualenv step. 10:19:46 INFO - ##### 10:19:46 INFO - Running pre-action listener: _resource_record_pre_action 10:19:46 INFO - Running main action method: create_virtualenv 10:19:46 INFO - Creating virtualenv /builds/slave/test/build/venv 10:19:46 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 10:19:46 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv 10:19:47 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 10:19:47 INFO - Using real prefix '/usr' 10:19:47 INFO - New python executable in /builds/slave/test/build/venv/bin/python 10:19:47 INFO - Installing distribute.............................................................................................................................................................................................done. 10:19:49 INFO - Installing pip.................done. 10:19:49 INFO - Return code: 0 10:19:49 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 10:19:49 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')]} 10:19:49 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:19:49 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:19:49 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')]} 10:19:49 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:19:49 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:19:49 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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, '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': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', '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 10:19:49 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 10:19:49 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 10:19:49 INFO - Using env: {'DISPLAY': ':0', 10:19:49 INFO - 'HOME': '/home/cltbld', 10:19:49 INFO - 'LANG': 'en_US.UTF-8', 10:19:49 INFO - 'LANGUAGE': 'en_US:en', 10:19:49 INFO - 'LOGNAME': 'cltbld', 10:19:49 INFO - 'MAIL': '/var/mail/cltbld', 10:19:49 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:19:49 INFO - 'MOZ_NO_REMOTE': '1', 10:19:49 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:19:49 INFO - 'NO_EM_RESTART': '1', 10:19:49 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:19:49 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:19:49 INFO - 'PWD': '/builds/slave/test', 10:19:49 INFO - 'SHELL': '/bin/bash', 10:19:49 INFO - 'SHLVL': '1', 10:19:49 INFO - 'TERM': 'linux', 10:19:49 INFO - 'TMOUT': '86400', 10:19:49 INFO - 'USER': 'cltbld', 10:19:49 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 10:19:49 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:19:49 INFO - '_': '/tools/buildbot/bin/python'} 10:19:49 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:19:49 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 10:19:49 INFO - Cleaning up... 10:19:49 INFO - Return code: 0 10:19:49 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv 10:19:49 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')]} 10:19:49 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:19:49 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:19:49 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')]} 10:19:49 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:19:49 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:19:49 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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, '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': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', '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 10:19:49 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 10:19:49 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 10:19:49 INFO - Using env: {'DISPLAY': ':0', 10:19:49 INFO - 'HOME': '/home/cltbld', 10:19:49 INFO - 'LANG': 'en_US.UTF-8', 10:19:49 INFO - 'LANGUAGE': 'en_US:en', 10:19:49 INFO - 'LOGNAME': 'cltbld', 10:19:49 INFO - 'MAIL': '/var/mail/cltbld', 10:19:49 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:19:49 INFO - 'MOZ_NO_REMOTE': '1', 10:19:49 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:19:49 INFO - 'NO_EM_RESTART': '1', 10:19:49 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:19:49 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:19:49 INFO - 'PWD': '/builds/slave/test', 10:19:49 INFO - 'SHELL': '/bin/bash', 10:19:49 INFO - 'SHLVL': '1', 10:19:49 INFO - 'TERM': 'linux', 10:19:49 INFO - 'TMOUT': '86400', 10:19:49 INFO - 'USER': 'cltbld', 10:19:49 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 10:19:49 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:19:49 INFO - '_': '/tools/buildbot/bin/python'} 10:19:49 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:19:49 INFO - Downloading/unpacking psutil>=0.7.1 10:19:49 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 10:19:49 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 10:19:49 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 10:19:49 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 10:19:49 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 10:19:49 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 10:19:51 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache 10:19:51 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz 10:19:51 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 10:19:51 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 10:19:51 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 10:19:51 INFO - Installing collected packages: psutil 10:19:51 INFO - Running setup.py install for psutil 10:19:51 INFO - building 'psutil._psutil_linux' extension 10:19:51 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 10:19:51 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 10:19:52 INFO - building 'psutil._psutil_posix' extension 10:19:52 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 10:19:52 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 10:19:52 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 10:19:52 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 10:19:52 INFO - Successfully installed psutil 10:19:52 INFO - Cleaning up... 10:19:52 INFO - Return code: 0 10:19:52 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv 10:19: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')]} 10:19:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:19:52 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:19: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')]} 10:19:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:19:52 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:19: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', '--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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, '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': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', '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 10:19:52 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 10:19:52 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 10:19:52 INFO - Using env: {'DISPLAY': ':0', 10:19:52 INFO - 'HOME': '/home/cltbld', 10:19:52 INFO - 'LANG': 'en_US.UTF-8', 10:19:52 INFO - 'LANGUAGE': 'en_US:en', 10:19:52 INFO - 'LOGNAME': 'cltbld', 10:19:52 INFO - 'MAIL': '/var/mail/cltbld', 10:19:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:19:52 INFO - 'MOZ_NO_REMOTE': '1', 10:19:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:19:52 INFO - 'NO_EM_RESTART': '1', 10:19:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:19:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:19:52 INFO - 'PWD': '/builds/slave/test', 10:19:52 INFO - 'SHELL': '/bin/bash', 10:19:52 INFO - 'SHLVL': '1', 10:19:52 INFO - 'TERM': 'linux', 10:19:52 INFO - 'TMOUT': '86400', 10:19:52 INFO - 'USER': 'cltbld', 10:19:52 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 10:19:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:19:52 INFO - '_': '/tools/buildbot/bin/python'} 10:19:52 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:19:52 INFO - Downloading/unpacking mozsystemmonitor==0.0.0 10:19:52 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 10:19:52 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 10:19:52 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 10:19:52 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 10:19:52 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 10:19:52 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 10:19:54 INFO - Downloading mozsystemmonitor-0.0.tar.gz 10:19:54 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz 10:19:54 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 10:19:54 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0) 10:19:54 INFO - Installing collected packages: mozsystemmonitor 10:19:54 INFO - Running setup.py install for mozsystemmonitor 10:19:54 INFO - Successfully installed mozsystemmonitor 10:19:54 INFO - Cleaning up... 10:19:54 INFO - Return code: 0 10:19:54 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 10:19:54 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')]} 10:19:54 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:19:54 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:19:54 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')]} 10:19:54 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:19:54 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:19:54 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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, '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': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', '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 10:19:54 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 10:19:54 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 10:19:54 INFO - Using env: {'DISPLAY': ':0', 10:19:54 INFO - 'HOME': '/home/cltbld', 10:19:54 INFO - 'LANG': 'en_US.UTF-8', 10:19:54 INFO - 'LANGUAGE': 'en_US:en', 10:19:54 INFO - 'LOGNAME': 'cltbld', 10:19:54 INFO - 'MAIL': '/var/mail/cltbld', 10:19:54 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:19:54 INFO - 'MOZ_NO_REMOTE': '1', 10:19:54 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:19:54 INFO - 'NO_EM_RESTART': '1', 10:19:54 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:19:54 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:19:54 INFO - 'PWD': '/builds/slave/test', 10:19:54 INFO - 'SHELL': '/bin/bash', 10:19:54 INFO - 'SHLVL': '1', 10:19:54 INFO - 'TERM': 'linux', 10:19:54 INFO - 'TMOUT': '86400', 10:19:54 INFO - 'USER': 'cltbld', 10:19:54 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 10:19:54 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:19:54 INFO - '_': '/tools/buildbot/bin/python'} 10:19:54 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:19:54 INFO - Downloading/unpacking blobuploader==1.2.4 10:19:54 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 10:19:54 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 10:19:54 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 10:19:54 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 10:19:54 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 10:19:54 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 10:19:56 INFO - Downloading blobuploader-1.2.4.tar.gz 10:19:56 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz 10:19:56 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 10:19:56 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 10:19:56 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 10:19:56 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 10:19:56 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 10:19:56 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 10:19:56 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 10:19:56 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 10:19:56 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz 10:19:56 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 10:19:56 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 10:19:56 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 10:19:56 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 10:19:56 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 10:19:56 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 10:19:56 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 10:19:56 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 10:19:56 INFO - Downloading docopt-0.6.1.tar.gz 10:19:56 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz 10:19:56 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 10:19:56 INFO - Installing collected packages: blobuploader, requests, docopt 10:19:56 INFO - Running setup.py install for blobuploader 10:19:57 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 10:19:57 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 10:19:57 INFO - Running setup.py install for requests 10:19:57 INFO - Running setup.py install for docopt 10:19:57 INFO - Successfully installed blobuploader requests docopt 10:19:57 INFO - Cleaning up... 10:19:57 INFO - Return code: 0 10:19:57 INFO - Installing None into virtualenv /builds/slave/test/build/venv 10:19:57 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')]} 10:19:57 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:19:57 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:19:57 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')]} 10:19:57 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:19:57 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:19:57 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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, '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': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', '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 10:19:57 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 10:19:57 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 10:19:57 INFO - Using env: {'DISPLAY': ':0', 10:19:57 INFO - 'HOME': '/home/cltbld', 10:19:57 INFO - 'LANG': 'en_US.UTF-8', 10:19:57 INFO - 'LANGUAGE': 'en_US:en', 10:19:57 INFO - 'LOGNAME': 'cltbld', 10:19:57 INFO - 'MAIL': '/var/mail/cltbld', 10:19:57 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:19:57 INFO - 'MOZ_NO_REMOTE': '1', 10:19:57 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:19:57 INFO - 'NO_EM_RESTART': '1', 10:19:57 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:19:57 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:19:57 INFO - 'PWD': '/builds/slave/test', 10:19:57 INFO - 'SHELL': '/bin/bash', 10:19:57 INFO - 'SHLVL': '1', 10:19:57 INFO - 'TERM': 'linux', 10:19:57 INFO - 'TMOUT': '86400', 10:19:57 INFO - 'USER': 'cltbld', 10:19:57 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 10:19:57 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:19:57 INFO - '_': '/tools/buildbot/bin/python'} 10:19:57 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:19:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 10:19:57 INFO - Running setup.py (path:/tmp/pip-duffhD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 10:19:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 10:19:57 INFO - Running setup.py (path:/tmp/pip-zoIVwU-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 10:19:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 10:19:57 INFO - Running setup.py (path:/tmp/pip-5a6CkH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 10:19:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 10:19:57 INFO - Running setup.py (path:/tmp/pip-ltp60O-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 10:19:58 INFO - Running setup.py (path:/tmp/pip-6og9Yc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 10:19:58 INFO - Running setup.py (path:/tmp/pip-pzT_P0-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 10:19:58 INFO - Running setup.py (path:/tmp/pip-MvRsGI-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 10:19:58 INFO - Running setup.py (path:/tmp/pip-MXP9pP-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 10:19:58 INFO - Running setup.py (path:/tmp/pip-4cCXok-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 10:19:58 INFO - Running setup.py (path:/tmp/pip-9tlR8L-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 10:19:58 INFO - Running setup.py (path:/tmp/pip-XEOXzj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 10:19:58 INFO - Running setup.py (path:/tmp/pip-SQOyIR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 10:19:58 INFO - Running setup.py (path:/tmp/pip-6O7Jwn-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 10:19:58 INFO - Running setup.py (path:/tmp/pip-dsEyVW-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 10:19:58 INFO - Running setup.py (path:/tmp/pip-5tn1DY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 10:19:58 INFO - Running setup.py (path:/tmp/pip-M6FDm_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 10:19:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 10:19:58 INFO - Running setup.py (path:/tmp/pip-pg6eS3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 10:19:58 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 10:19:58 INFO - Running setup.py install for manifestparser 10:19:59 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 10:19:59 INFO - Running setup.py install for mozcrash 10:19:59 INFO - Running setup.py install for mozdebug 10:19:59 INFO - Running setup.py install for mozdevice 10:19:59 INFO - Installing sutini script to /builds/slave/test/build/venv/bin 10:19:59 INFO - Installing dm script to /builds/slave/test/build/venv/bin 10:19:59 INFO - Running setup.py install for mozfile 10:19:59 INFO - Running setup.py install for mozhttpd 10:19:59 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 10:19:59 INFO - Running setup.py install for mozinfo 10:19:59 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 10:19:59 INFO - Running setup.py install for mozInstall 10:19:59 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 10:19:59 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 10:19:59 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 10:19:59 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 10:19:59 INFO - Running setup.py install for mozleak 10:19:59 INFO - Running setup.py install for mozlog 10:19:59 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 10:20:00 INFO - Running setup.py install for moznetwork 10:20:00 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 10:20:00 INFO - Running setup.py install for mozprocess 10:20:00 INFO - Running setup.py install for mozprofile 10:20:00 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 10:20:00 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 10:20:00 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 10:20:00 INFO - Running setup.py install for mozrunner 10:20:00 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 10:20:00 INFO - Running setup.py install for mozscreenshot 10:20:00 INFO - Running setup.py install for moztest 10:20:00 INFO - Running setup.py install for mozversion 10:20:00 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 10:20:00 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 10:20:00 INFO - Cleaning up... 10:20:00 INFO - Return code: 0 10:20:00 INFO - Installing None into virtualenv /builds/slave/test/build/venv 10:20:00 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')]} 10:20:00 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:20:00 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:20:00 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')]} 10:20:00 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:20:00 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:20:00 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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, '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': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', '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 10:20:00 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 10:20:00 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 10:20:00 INFO - Using env: {'DISPLAY': ':0', 10:20:00 INFO - 'HOME': '/home/cltbld', 10:20:00 INFO - 'LANG': 'en_US.UTF-8', 10:20:00 INFO - 'LANGUAGE': 'en_US:en', 10:20:00 INFO - 'LOGNAME': 'cltbld', 10:20:00 INFO - 'MAIL': '/var/mail/cltbld', 10:20:00 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:20:00 INFO - 'MOZ_NO_REMOTE': '1', 10:20:00 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:20:00 INFO - 'NO_EM_RESTART': '1', 10:20:00 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:20:00 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:20:00 INFO - 'PWD': '/builds/slave/test', 10:20:00 INFO - 'SHELL': '/bin/bash', 10:20:00 INFO - 'SHLVL': '1', 10:20:00 INFO - 'TERM': 'linux', 10:20:00 INFO - 'TMOUT': '86400', 10:20:00 INFO - 'USER': 'cltbld', 10:20:00 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 10:20:00 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:20:00 INFO - '_': '/tools/buildbot/bin/python'} 10:20:00 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:20:00 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 10:20:00 INFO - Running setup.py (path:/tmp/pip-c7qutr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 10:20:01 INFO - Running setup.py (path:/tmp/pip-BhrsEy-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 10:20:01 INFO - Running setup.py (path:/tmp/pip-FxzEOY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 10:20:01 INFO - Running setup.py (path:/tmp/pip-3qHW01-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 10:20:01 INFO - Running setup.py (path:/tmp/pip-QeIRIQ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 10:20:01 INFO - Running setup.py (path:/tmp/pip-KCn_JJ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 10:20:01 INFO - Running setup.py (path:/tmp/pip-nIpMOC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 10:20:01 INFO - Running setup.py (path:/tmp/pip-IsOWmd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 10:20:01 INFO - Running setup.py (path:/tmp/pip-SCBwwj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 10:20:01 INFO - Running setup.py (path:/tmp/pip-GW1A0t-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 10:20:01 INFO - Running setup.py (path:/tmp/pip-wga2dh-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 10:20:01 INFO - Running setup.py (path:/tmp/pip-Y0QL7j-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 10:20:01 INFO - Running setup.py (path:/tmp/pip-SDQC51-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 10:20:01 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)) 10:20:01 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 10:20:01 INFO - Running setup.py (path:/tmp/pip-POCZe8-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 10:20:02 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)) 10:20:02 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 10:20:02 INFO - Running setup.py (path:/tmp/pip-LlPyAW-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 10:20:02 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)) 10:20:02 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 10:20:02 INFO - Running setup.py (path:/tmp/pip-G_PqZ4-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 10:20:02 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)) 10:20:02 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 10:20:02 INFO - Running setup.py (path:/tmp/pip-jIm9KN-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 10:20:02 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)) 10:20:02 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)) 10:20:02 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)) 10:20:02 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)) 10:20:02 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)) 10:20:02 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)) 10:20:02 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 10:20:02 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 10:20:02 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 10:20:02 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 10:20:02 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 10:20:02 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 10:20:02 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 10:20:03 INFO - Downloading blessings-1.5.1.tar.gz 10:20:03 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 10:20:03 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 10:20:03 INFO - Installing collected packages: blessings 10:20:03 INFO - Running setup.py install for blessings 10:20:04 INFO - Successfully installed blessings 10:20:04 INFO - Cleaning up... 10:20:04 INFO - Return code: 0 10:20:04 INFO - Done creating virtualenv /builds/slave/test/build/venv. 10:20:04 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 10:20:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 10:20:04 INFO - Reading from file tmpfile_stdout 10:20:04 INFO - Current package versions: 10:20:04 INFO - argparse == 1.2.1 10:20:04 INFO - blessings == 1.5.1 10:20:04 INFO - blobuploader == 1.2.4 10:20:04 INFO - docopt == 0.6.1 10:20:04 INFO - manifestparser == 1.1 10:20:04 INFO - mozInstall == 1.12 10:20:04 INFO - mozcrash == 0.16 10:20:04 INFO - mozdebug == 0.1 10:20:04 INFO - mozdevice == 0.47 10:20:04 INFO - mozfile == 1.2 10:20:04 INFO - mozhttpd == 0.7 10:20:04 INFO - mozinfo == 0.9 10:20:04 INFO - mozleak == 0.1 10:20:04 INFO - mozlog == 3.0 10:20:04 INFO - moznetwork == 0.27 10:20:04 INFO - mozprocess == 0.22 10:20:04 INFO - mozprofile == 0.27 10:20:04 INFO - mozrunner == 6.11 10:20:04 INFO - mozscreenshot == 0.1 10:20:04 INFO - mozsystemmonitor == 0.0 10:20:04 INFO - moztest == 0.7 10:20:04 INFO - mozversion == 1.4 10:20:04 INFO - psutil == 3.1.1 10:20:04 INFO - requests == 1.2.3 10:20:04 INFO - wsgiref == 0.1.2 10:20:04 INFO - Installing None into virtualenv /builds/slave/test/build/venv 10:20:04 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')]} 10:20:04 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:20:04 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:20:04 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')]} 10:20:04 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:20:04 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:20:04 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 0x7fcad9a18c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x21516c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2202900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, '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': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', '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 10:20:04 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 10:20:04 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 10:20:04 INFO - Using env: {'DISPLAY': ':0', 10:20:04 INFO - 'HOME': '/home/cltbld', 10:20:04 INFO - 'LANG': 'en_US.UTF-8', 10:20:04 INFO - 'LANGUAGE': 'en_US:en', 10:20:04 INFO - 'LOGNAME': 'cltbld', 10:20:04 INFO - 'MAIL': '/var/mail/cltbld', 10:20:04 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:20:04 INFO - 'MOZ_NO_REMOTE': '1', 10:20:04 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:20:04 INFO - 'NO_EM_RESTART': '1', 10:20:04 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:20:04 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:20:04 INFO - 'PWD': '/builds/slave/test', 10:20:04 INFO - 'SHELL': '/bin/bash', 10:20:04 INFO - 'SHLVL': '1', 10:20:04 INFO - 'TERM': 'linux', 10:20:04 INFO - 'TMOUT': '86400', 10:20:04 INFO - 'USER': 'cltbld', 10:20:04 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 10:20:04 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:20:04 INFO - '_': '/tools/buildbot/bin/python'} 10:20:04 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:20:04 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)) 10:20:04 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)) 10:20:04 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)) 10:20:04 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)) 10:20:04 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)) 10:20:04 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)) 10:20:04 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)) 10:20:04 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)) 10:20:04 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)) 10:20:04 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)) 10:20:04 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)) 10:20:04 INFO - Cleaning up... 10:20:04 INFO - Return code: 0 10:20:04 INFO - Running post-action listener: _resource_record_post_action 10:20:04 INFO - Running post-action listener: _start_resource_monitoring 10:20:04 INFO - Starting resource monitoring. 10:20:04 INFO - ##### 10:20:04 INFO - ##### Running install step. 10:20:04 INFO - ##### 10:20:04 INFO - Running pre-action listener: _resource_record_pre_action 10:20:04 INFO - Running main action method: install 10:20:04 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 10:20:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 10:20:04 INFO - Reading from file tmpfile_stdout 10:20:04 INFO - Detecting whether we're running mozinstall >=1.0... 10:20:04 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 10:20:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 10:20:04 INFO - Reading from file tmpfile_stdout 10:20:04 INFO - Output received: 10:20:04 INFO - Usage: mozinstall [options] installer 10:20:04 INFO - Options: 10:20:04 INFO - -h, --help show this help message and exit 10:20:04 INFO - -d DEST, --destination=DEST 10:20:04 INFO - Directory to install application into. [default: 10:20:04 INFO - "/builds/slave/test"] 10:20:04 INFO - --app=APP Application being installed. [default: firefox] 10:20:04 INFO - mkdir: /builds/slave/test/build/application 10:20:04 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'] 10:20:04 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 10:20:19 INFO - Reading from file tmpfile_stdout 10:20:19 INFO - Output received: 10:20:19 INFO - /builds/slave/test/build/application/firefox/firefox 10:20:19 INFO - Running post-action listener: _resource_record_post_action 10:20:19 INFO - ##### 10:20:19 INFO - ##### Running run-tests step. 10:20:19 INFO - ##### 10:20:19 INFO - Running pre-action listener: _resource_record_pre_action 10:20:19 INFO - Running main action method: run_tests 10:20:19 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 10:20:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 10:20:19 INFO - Python 2.7.3 10:20:19 INFO - Return code: 0 10:20:19 INFO - grabbing minidump binary from tooltool 10:20: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')]} 10:20:19 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 0x2248b70>, '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 0x2299dc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x229a250>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 10:20:19 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 10:20:19 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 10:20:19 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 10:20:19 INFO - Return code: 0 10:20:19 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 10:20:19 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 10:20:19 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 10:20:19 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 10:20:19 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 10:20:19 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Fx-Team-Non-PGO', '--suite', 'other-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-045', '--webServer', 'localhost'] in /builds/slave/test/build 10:20:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --debug --branchName Fx-Team-Non-PGO --suite other-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip --title talos-linux64-ix-045 --webServer localhost 10:20:19 INFO - Using env: {'DISPLAY': ':0', 10:20:19 INFO - 'HOME': '/home/cltbld', 10:20:19 INFO - 'LANG': 'en_US.UTF-8', 10:20:19 INFO - 'LANGUAGE': 'en_US:en', 10:20:19 INFO - 'LOGNAME': 'cltbld', 10:20:19 INFO - 'MAIL': '/var/mail/cltbld', 10:20:19 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 10:20:19 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 10:20:19 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:20:19 INFO - 'MOZ_NO_REMOTE': '1', 10:20:19 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 10:20:19 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:20:19 INFO - 'NO_EM_RESTART': '1', 10:20:19 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:20:19 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:20:19 INFO - 'PWD': '/builds/slave/test', 10:20:19 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 10:20:19 INFO - 'SHELL': '/bin/bash', 10:20:19 INFO - 'SHLVL': '1', 10:20:19 INFO - 'TERM': 'linux', 10:20:19 INFO - 'TMOUT': '86400', 10:20:19 INFO - 'USER': 'cltbld', 10:20:19 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883', 10:20:19 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:20:19 INFO - '_': '/tools/buildbot/bin/python'} 10:20:19 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Fx-Team-Non-PGO', '--suite', 'other-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-045', '--webServer', 'localhost'] with output_timeout 3600 10:20:19 INFO - mozversion INFO | application_buildid: 20151118091623 10:20:19 INFO - mozversion INFO | application_changeset: 1d6ba006a526d17294369eed770a9a0ce2794bde 10:20:19 INFO - mozversion INFO | application_display_name: Nightly 10:20:19 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 10:20:19 INFO - mozversion INFO | application_name: Firefox 10:20:19 INFO - mozversion INFO | application_remotingname: firefox 10:20:19 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/fx-team 10:20:19 INFO - mozversion INFO | application_vendor: Mozilla 10:20:19 INFO - mozversion INFO | application_version: 45.0a1 10:20:19 INFO - mozversion INFO | platform_buildid: 20151118091623 10:20:19 INFO - mozversion INFO | platform_changeset: 1d6ba006a526d17294369eed770a9a0ce2794bde 10:20:19 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/fx-team 10:20:19 INFO - mozversion INFO | platform_version: 45.0a1 10:20:19 INFO - 2015-11-18 10:20:19,342 DEBUG : using testdate: 1447870819 10:20:19 INFO - 2015-11-18 10:20:19,342 DEBUG : actual date: 1447870819 10:20:19 INFO - 2015-11-18 10:20:19,395 INFO : starting webserver on 'localhost:38426' 10:20:19 INFO - 2015-11-18 10:20:19,396 INFO : Starting test suite talos-linux64-ix-045.e 10:20:19 INFO - 2015-11-18 10:20:19,396 INFO : Starting test a11yr 10:20:19 INFO - 2015-11-18 10:20:19,396 DEBUG : operating with platform_type : linux_ 10:20:19 INFO - 2015-11-18 10:20:19,397 INFO : Initialising browser for a11yr test... 10:20:19 INFO - 2015-11-18 10:20:19,411 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVINgwy/profile http://localhost:38426/getInfo.html 10:20:25 INFO - 2015-11-18 10:20:25,063 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 10:20:25 INFO - 2015-11-18 10:20:25,063 DEBUG : BROWSER_OUTPUT: colorDepth:24 10:20:25 INFO - 2015-11-18 10:20:25,063 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 10:20:25 INFO - 2015-11-18 10:20:25,063 DEBUG : BROWSER_OUTPUT: __metrics 10:20:26 INFO - 2015-11-18 10:20:26,157 INFO : Browser initialized. 10:20:26 INFO - 2015-11-18 10:20:26,158 INFO : Running cycle 1/1 for a11yr test... 10:20:26 INFO - 2015-11-18 10:20:26,158 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVINgwy/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25 10:20:38 INFO - 2015-11-18 10:20:38,100 DEBUG : BROWSER_OUTPUT: RSS: Main: 141447168 10:20:38 INFO - 2015-11-18 10:20:38,100 DEBUG : BROWSER_OUTPUT: 10:20:39 INFO - 2015-11-18 10:20:39,403 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) 10:20:39 INFO - 2015-11-18 10:20:39,540 DEBUG : BROWSER_OUTPUT: 10:20:39 INFO - 2015-11-18 10:20:39,540 DEBUG : BROWSER_OUTPUT: (firefox:17760): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 10:20:39 INFO - 2015-11-18 10:20:39,541 DEBUG : BROWSER_OUTPUT: 10:20:39 INFO - 2015-11-18 10:20:39,541 DEBUG : BROWSER_OUTPUT: (firefox:17760): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 10:20:39 INFO - 2015-11-18 10:20:39,597 DEBUG : BROWSER_OUTPUT: 10:20:39 INFO - 2015-11-18 10:20:39,597 DEBUG : BROWSER_OUTPUT: (firefox:17760): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 10:20:40 INFO - 2015-11-18 10:20:40,037 DEBUG : BROWSER_OUTPUT: RSS: Main: 146771968 10:20:40 INFO - 2015-11-18 10:20:40,037 DEBUG : BROWSER_OUTPUT: 10:20:41 INFO - 2015-11-18 10:20:41,430 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) 10:20:42 INFO - 2015-11-18 10:20:42,132 DEBUG : BROWSER_OUTPUT: RSS: Main: 146055168 10:20:42 INFO - 2015-11-18 10:20:42,132 DEBUG : BROWSER_OUTPUT: 10:20:43 INFO - 2015-11-18 10:20:43,538 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) 10:20:44 INFO - 2015-11-18 10:20:44,229 DEBUG : BROWSER_OUTPUT: RSS: Main: 144490496 10:20:44 INFO - 2015-11-18 10:20:44,229 DEBUG : BROWSER_OUTPUT: 10:20:45 INFO - 2015-11-18 10:20:45,626 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) 10:20:46 INFO - 2015-11-18 10:20:46,396 DEBUG : BROWSER_OUTPUT: RSS: Main: 144896000 10:20:46 INFO - 2015-11-18 10:20:46,396 DEBUG : BROWSER_OUTPUT: 10:20:47 INFO - 2015-11-18 10:20:47,801 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) 10:20:48 INFO - 2015-11-18 10:20:48,515 DEBUG : BROWSER_OUTPUT: RSS: Main: 141832192 10:20:48 INFO - 2015-11-18 10:20:48,515 DEBUG : BROWSER_OUTPUT: 10:20:49 INFO - 2015-11-18 10:20:49,912 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) 10:20:50 INFO - 2015-11-18 10:20:50,614 DEBUG : BROWSER_OUTPUT: RSS: Main: 141914112 10:20:50 INFO - 2015-11-18 10:20:50,614 DEBUG : BROWSER_OUTPUT: 10:20:52 INFO - 2015-11-18 10:20:52,241 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) 10:20:52 INFO - 2015-11-18 10:20:52,947 DEBUG : BROWSER_OUTPUT: RSS: Main: 142258176 10:20:52 INFO - 2015-11-18 10:20:52,948 DEBUG : BROWSER_OUTPUT: 10:20:54 INFO - 2015-11-18 10:20:54,320 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) 10:20:55 INFO - 2015-11-18 10:20:55,031 DEBUG : BROWSER_OUTPUT: RSS: Main: 142127104 10:20:55 INFO - 2015-11-18 10:20:55,032 DEBUG : BROWSER_OUTPUT: 10:20:56 INFO - 2015-11-18 10:20:56,437 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) 10:20:57 INFO - 2015-11-18 10:20:57,192 DEBUG : BROWSER_OUTPUT: RSS: Main: 141893632 10:20:57 INFO - 2015-11-18 10:20:57,192 DEBUG : BROWSER_OUTPUT: 10:20:58 INFO - 2015-11-18 10:20:58,602 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) 10:20:59 INFO - 2015-11-18 10:20:59,304 DEBUG : BROWSER_OUTPUT: RSS: Main: 142069760 10:20:59 INFO - 2015-11-18 10:20:59,304 DEBUG : BROWSER_OUTPUT: 10:21:00 INFO - 2015-11-18 10:21:00,715 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) 10:21:01 INFO - 2015-11-18 10:21:01,424 DEBUG : BROWSER_OUTPUT: RSS: Main: 142389248 10:21:01 INFO - 2015-11-18 10:21:01,425 DEBUG : BROWSER_OUTPUT: 10:21:02 INFO - 2015-11-18 10:21:02,830 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) 10:21:03 INFO - 2015-11-18 10:21:03,537 DEBUG : BROWSER_OUTPUT: RSS: Main: 143298560 10:21:03 INFO - 2015-11-18 10:21:03,537 DEBUG : BROWSER_OUTPUT: 10:21:05 INFO - 2015-11-18 10:21:05,143 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) 10:21:05 INFO - 2015-11-18 10:21:05,853 DEBUG : BROWSER_OUTPUT: RSS: Main: 142671872 10:21:05 INFO - 2015-11-18 10:21:05,854 DEBUG : BROWSER_OUTPUT: 10:21:07 INFO - 2015-11-18 10:21:07,266 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) 10:21:08 INFO - 2015-11-18 10:21:08,039 DEBUG : BROWSER_OUTPUT: RSS: Main: 142528512 10:21:08 INFO - 2015-11-18 10:21:08,040 DEBUG : BROWSER_OUTPUT: 10:21:09 INFO - 2015-11-18 10:21:09,425 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) 10:21:10 INFO - 2015-11-18 10:21:10,132 DEBUG : BROWSER_OUTPUT: RSS: Main: 142446592 10:21:10 INFO - 2015-11-18 10:21:10,133 DEBUG : BROWSER_OUTPUT: 10:21:11 INFO - 2015-11-18 10:21:11,731 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) 10:21:12 INFO - 2015-11-18 10:21:12,440 DEBUG : BROWSER_OUTPUT: RSS: Main: 142184448 10:21:12 INFO - 2015-11-18 10:21:12,441 DEBUG : BROWSER_OUTPUT: 10:21:13 INFO - 2015-11-18 10:21:13,837 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) 10:21:14 INFO - 2015-11-18 10:21:14,544 DEBUG : BROWSER_OUTPUT: RSS: Main: 141963264 10:21:14 INFO - 2015-11-18 10:21:14,545 DEBUG : BROWSER_OUTPUT: 10:21:15 INFO - 2015-11-18 10:21:15,970 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) 10:21:16 INFO - 2015-11-18 10:21:16,731 DEBUG : BROWSER_OUTPUT: RSS: Main: 143949824 10:21:16 INFO - 2015-11-18 10:21:16,732 DEBUG : BROWSER_OUTPUT: 10:21:18 INFO - 2015-11-18 10:21:18,145 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) 10:21:18 INFO - 2015-11-18 10:21:18,848 DEBUG : BROWSER_OUTPUT: RSS: Main: 142241792 10:21:18 INFO - 2015-11-18 10:21:18,848 DEBUG : BROWSER_OUTPUT: 10:21:20 INFO - 2015-11-18 10:21:20,265 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) 10:21:20 INFO - 2015-11-18 10:21:20,966 DEBUG : BROWSER_OUTPUT: RSS: Main: 142389248 10:21:20 INFO - 2015-11-18 10:21:20,966 DEBUG : BROWSER_OUTPUT: 10:21:22 INFO - 2015-11-18 10:21:22,375 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) 10:21:23 INFO - 2015-11-18 10:21:23,077 DEBUG : BROWSER_OUTPUT: RSS: Main: 142417920 10:21:23 INFO - 2015-11-18 10:21:23,078 DEBUG : BROWSER_OUTPUT: 10:21:24 INFO - 2015-11-18 10:21:24,697 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) 10:21:25 INFO - 2015-11-18 10:21:25,403 DEBUG : BROWSER_OUTPUT: RSS: Main: 143220736 10:21:25 INFO - 2015-11-18 10:21:25,403 DEBUG : BROWSER_OUTPUT: 10:21:26 INFO - 2015-11-18 10:21:26,793 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) 10:21:27 INFO - 2015-11-18 10:21:27,503 DEBUG : BROWSER_OUTPUT: RSS: Main: 150614016 10:21:27 INFO - 2015-11-18 10:21:27,503 DEBUG : BROWSER_OUTPUT: 10:21:27 INFO - 2015-11-18 10:21:27,772 DEBUG : BROWSER_OUTPUT: 1447870887770 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] 10:21:28 INFO - 2015-11-18 10:21:28,944 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) 10:21:29 INFO - 2015-11-18 10:21:29,731 DEBUG : BROWSER_OUTPUT: RSS: Main: 156536832 10:21:29 INFO - 2015-11-18 10:21:29,731 DEBUG : BROWSER_OUTPUT: 10:21:31 INFO - 2015-11-18 10:21:31,128 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) 10:21:31 INFO - 2015-11-18 10:21:31,836 DEBUG : BROWSER_OUTPUT: RSS: Main: 156450816 10:21:31 INFO - 2015-11-18 10:21:31,836 DEBUG : BROWSER_OUTPUT: 10:21:31 INFO - 2015-11-18 10:21:31,952 DEBUG : BROWSER_OUTPUT: 10:21:31 INFO - 2015-11-18 10:21:31,952 DEBUG : BROWSER_OUTPUT: (firefox:17760): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 10:21:32 INFO - 2015-11-18 10:21:32,834 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) 10:21:33 INFO - 2015-11-18 10:21:33,423 DEBUG : BROWSER_OUTPUT: RSS: Main: 150986752 10:21:33 INFO - 2015-11-18 10:21:33,423 DEBUG : BROWSER_OUTPUT: 10:21:34 INFO - 2015-11-18 10:21:34,365 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) 10:21:34 INFO - 2015-11-18 10:21:34,967 DEBUG : BROWSER_OUTPUT: RSS: Main: 151580672 10:21:34 INFO - 2015-11-18 10:21:34,968 DEBUG : BROWSER_OUTPUT: 10:21:35 INFO - 2015-11-18 10:21:35,889 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) 10:21:36 INFO - 2015-11-18 10:21:36,496 DEBUG : BROWSER_OUTPUT: RSS: Main: 150511616 10:21:36 INFO - 2015-11-18 10:21:36,496 DEBUG : BROWSER_OUTPUT: 10:21:37 INFO - 2015-11-18 10:21:37,422 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) 10:21:38 INFO - 2015-11-18 10:21:38,028 DEBUG : BROWSER_OUTPUT: RSS: Main: 142790656 10:21:38 INFO - 2015-11-18 10:21:38,028 DEBUG : BROWSER_OUTPUT: 10:21:38 INFO - 2015-11-18 10:21:38,970 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) 10:21:39 INFO - 2015-11-18 10:21:39,576 DEBUG : BROWSER_OUTPUT: RSS: Main: 142901248 10:21:39 INFO - 2015-11-18 10:21:39,576 DEBUG : BROWSER_OUTPUT: 10:21:40 INFO - 2015-11-18 10:21:40,498 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) 10:21:41 INFO - 2015-11-18 10:21:41,102 DEBUG : BROWSER_OUTPUT: RSS: Main: 140406784 10:21:41 INFO - 2015-11-18 10:21:41,103 DEBUG : BROWSER_OUTPUT: 10:21:42 INFO - 2015-11-18 10:21:42,029 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) 10:21:42 INFO - 2015-11-18 10:21:42,630 DEBUG : BROWSER_OUTPUT: RSS: Main: 140062720 10:21:42 INFO - 2015-11-18 10:21:42,630 DEBUG : BROWSER_OUTPUT: 10:21:43 INFO - 2015-11-18 10:21:43,572 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) 10:21:44 INFO - 2015-11-18 10:21:44,174 DEBUG : BROWSER_OUTPUT: RSS: Main: 139816960 10:21:44 INFO - 2015-11-18 10:21:44,174 DEBUG : BROWSER_OUTPUT: 10:21:45 INFO - 2015-11-18 10:21:45,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) 10:21:45 INFO - 2015-11-18 10:21:45,714 DEBUG : BROWSER_OUTPUT: RSS: Main: 139984896 10:21:45 INFO - 2015-11-18 10:21:45,714 DEBUG : BROWSER_OUTPUT: 10:21:46 INFO - 2015-11-18 10:21:46,668 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) 10:21:47 INFO - 2015-11-18 10:21:47,270 DEBUG : BROWSER_OUTPUT: RSS: Main: 140013568 10:21:47 INFO - 2015-11-18 10:21:47,271 DEBUG : BROWSER_OUTPUT: 10:21:48 INFO - 2015-11-18 10:21:48,198 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) 10:21:48 INFO - 2015-11-18 10:21:48,804 DEBUG : BROWSER_OUTPUT: RSS: Main: 141303808 10:21:48 INFO - 2015-11-18 10:21:48,804 DEBUG : BROWSER_OUTPUT: 10:21:49 INFO - 2015-11-18 10:21:49,718 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) 10:21:50 INFO - 2015-11-18 10:21:50,312 DEBUG : BROWSER_OUTPUT: RSS: Main: 139898880 10:21:50 INFO - 2015-11-18 10:21:50,312 DEBUG : BROWSER_OUTPUT: 10:21:51 INFO - 2015-11-18 10:21:51,241 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) 10:21:51 INFO - 2015-11-18 10:21:51,843 DEBUG : BROWSER_OUTPUT: RSS: Main: 140697600 10:21:51 INFO - 2015-11-18 10:21:51,843 DEBUG : BROWSER_OUTPUT: 10:21:52 INFO - 2015-11-18 10:21:52,757 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) 10:21:53 INFO - 2015-11-18 10:21:53,358 DEBUG : BROWSER_OUTPUT: RSS: Main: 141717504 10:21:53 INFO - 2015-11-18 10:21:53,359 DEBUG : BROWSER_OUTPUT: 10:21:54 INFO - 2015-11-18 10:21:54,293 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) 10:21:54 INFO - 2015-11-18 10:21:54,899 DEBUG : BROWSER_OUTPUT: RSS: Main: 141750272 10:21:54 INFO - 2015-11-18 10:21:54,899 DEBUG : BROWSER_OUTPUT: 10:21:55 INFO - 2015-11-18 10:21:55,846 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) 10:21:56 INFO - 2015-11-18 10:21:56,448 DEBUG : BROWSER_OUTPUT: RSS: Main: 141701120 10:21:56 INFO - 2015-11-18 10:21:56,448 DEBUG : BROWSER_OUTPUT: 10:21:57 INFO - 2015-11-18 10:21:57,362 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) 10:21:57 INFO - 2015-11-18 10:21:57,963 DEBUG : BROWSER_OUTPUT: RSS: Main: 141836288 10:21:57 INFO - 2015-11-18 10:21:57,963 DEBUG : BROWSER_OUTPUT: 10:21:58 INFO - 2015-11-18 10:21:58,898 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) 10:21:59 INFO - 2015-11-18 10:21:59,500 DEBUG : BROWSER_OUTPUT: RSS: Main: 142807040 10:21:59 INFO - 2015-11-18 10:21:59,500 DEBUG : BROWSER_OUTPUT: 10:22:00 INFO - 2015-11-18 10:22:00,422 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) 10:22:01 INFO - 2015-11-18 10:22:01,026 DEBUG : BROWSER_OUTPUT: RSS: Main: 140886016 10:22:01 INFO - 2015-11-18 10:22:01,026 DEBUG : BROWSER_OUTPUT: 10:22:01 INFO - 2015-11-18 10:22:01,960 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) 10:22:02 INFO - 2015-11-18 10:22:02,561 DEBUG : BROWSER_OUTPUT: RSS: Main: 141045760 10:22:02 INFO - 2015-11-18 10:22:02,561 DEBUG : BROWSER_OUTPUT: 10:22:03 INFO - 2015-11-18 10:22:03,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) 10:22:04 INFO - 2015-11-18 10:22:04,107 DEBUG : BROWSER_OUTPUT: RSS: Main: 142585856 10:22:04 INFO - 2015-11-18 10:22:04,107 DEBUG : BROWSER_OUTPUT: 10:22:05 INFO - 2015-11-18 10:22:05,042 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) 10:22:05 INFO - 2015-11-18 10:22:05,643 DEBUG : BROWSER_OUTPUT: RSS: Main: 141000704 10:22:05 INFO - 2015-11-18 10:22:05,643 DEBUG : BROWSER_OUTPUT: 10:22:06 INFO - 2015-11-18 10:22:06,557 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) 10:22:07 INFO - 2015-11-18 10:22:07,159 DEBUG : BROWSER_OUTPUT: RSS: Main: 142602240 10:22:07 INFO - 2015-11-18 10:22:07,159 DEBUG : BROWSER_OUTPUT: 10:22:08 INFO - 2015-11-18 10:22:08,081 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) 10:22:08 INFO - 2015-11-18 10:22:08,674 DEBUG : BROWSER_OUTPUT: RSS: Main: 142385152 10:22:08 INFO - 2015-11-18 10:22:08,675 DEBUG : BROWSER_OUTPUT: 10:22:09 INFO - 2015-11-18 10:22:09,609 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) 10:22:09 INFO - 2015-11-18 10:22:09,859 DEBUG : BROWSER_OUTPUT: RSS: Main: 142233600 10:22:09 INFO - 2015-11-18 10:22:09,859 DEBUG : BROWSER_OUTPUT: 10:22:09 INFO - 2015-11-18 10:22:09,860 DEBUG : BROWSER_OUTPUT: __start_tp_report 10:22:09 INFO - 2015-11-18 10:22:09,860 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load 10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details 10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: |i|pagename|runs| 10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1272;1314;1327;1352;1338;1337;1538;1330;1339;1329;1339;1342;1544;1332;1326;1543;1328;1345;1338;1332;1332;1541;1338;1367;1334 10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;402;397;384;383;389;387;380;382;394;410;394;378;390;379;381;382;380;386;384;381;391;390;381;385;389 10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: __end_tp_report 10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: __start_cc_report 10:22:09 INFO - 2015-11-18 10:22:09,861 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,2777 10:22:09 INFO - 2015-11-18 10:22:09,862 DEBUG : BROWSER_OUTPUT: __end_cc_report 10:22:09 INFO - 2015-11-18 10:22:09,862 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870929859__endTimestamp 10:22:09 INFO - 2015-11-18 10:22:09,862 DEBUG : BROWSER_OUTPUT: 10:22:09 INFO - 2015-11-18 10:22:09,863 DEBUG : BROWSER_OUTPUT: ------- Summary: start ------- 10:22:09 INFO - 2015-11-18 10:22:09,863 DEBUG : BROWSER_OUTPUT: Number of tests: 2 10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: 10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1366.28 Median:1338.00 stddev:79.67 (6.0%) stddev-sans-first:78.87 10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: Values: 1272.0 1314.0 1327.0 1352.0 1338.0 1337.0 1538.0 1330.0 1339.0 1329.0 1339.0 1342.0 1544.0 1332.0 1326.0 1543.0 1328.0 1345.0 1338.0 1332.0 1332.0 1541.0 1338.0 1367.0 1334.0 10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: 10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:387.16 Median:385.00 stddev:7.73 (2.0%) stddev-sans-first:7.24 10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: Values: 402.0 397.0 384.0 383.0 389.0 387.0 380.0 382.0 394.0 410.0 394.0 378.0 390.0 379.0 381.0 382.0 380.0 386.0 384.0 381.0 391.0 390.0 381.0 385.0 389.0 10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: -------- Summary: end -------- 10:22:09 INFO - 2015-11-18 10:22:09,864 DEBUG : BROWSER_OUTPUT: 10:22:10 INFO - 2015-11-18 10:22:10,585 INFO : Browser exited with error code: 0 10:22:10 INFO - 2015-11-18 10:22:10,604 INFO : Completed test a11yr (00:01:51) 10:22:10 INFO - 2015-11-18 10:22:10,604 INFO : Starting test ts_paint 10:22:10 INFO - 2015-11-18 10:22:10,604 DEBUG : operating with platform_type : linux_ 10:22:10 INFO - 2015-11-18 10:22:10,604 INFO : Initialising browser for ts_paint test... 10:22:10 INFO - 2015-11-18 10:22:10,610 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/getInfo.html 10:22:15 INFO - 2015-11-18 10:22:15,130 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 10:22:15 INFO - 2015-11-18 10:22:15,130 DEBUG : BROWSER_OUTPUT: colorDepth:24 10:22:15 INFO - 2015-11-18 10:22:15,131 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 10:22:15 INFO - 2015-11-18 10:22:15,131 DEBUG : BROWSER_OUTPUT: __metrics 10:22:16 INFO - 2015-11-18 10:22:16,165 INFO : Browser initialized. 10:22:16 INFO - 2015-11-18 10:22:16,166 INFO : Running cycle 1/20 for ts_paint test... 10:22:16 INFO - 2015-11-18 10:22:16,166 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:18 INFO - 2015-11-18 10:22:18,303 DEBUG : BROWSER_OUTPUT: __start_report458__end_report 10:22:18 INFO - 2015-11-18 10:22:18,303 DEBUG : BROWSER_OUTPUT: 10:22:18 INFO - 2015-11-18 10:22:18,311 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870938309__endTimestamp 10:22:19 INFO - 2015-11-18 10:22:19,293 INFO : Browser exited with error code: 0 10:22:19 INFO - 2015-11-18 10:22:19,295 INFO : Running cycle 2/20 for ts_paint test... 10:22:19 INFO - 2015-11-18 10:22:19,295 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:20 INFO - 2015-11-18 10:22:20,916 DEBUG : BROWSER_OUTPUT: __start_report512__end_report 10:22:20 INFO - 2015-11-18 10:22:20,917 DEBUG : BROWSER_OUTPUT: 10:22:20 INFO - 2015-11-18 10:22:20,932 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870940924__endTimestamp 10:22:21 INFO - 2015-11-18 10:22:21,857 INFO : Browser exited with error code: 0 10:22:21 INFO - 2015-11-18 10:22:21,859 INFO : Running cycle 3/20 for ts_paint test... 10:22:21 INFO - 2015-11-18 10:22:21,859 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:23 INFO - 2015-11-18 10:22:23,513 DEBUG : BROWSER_OUTPUT: __start_report526__end_report 10:22:23 INFO - 2015-11-18 10:22:23,513 DEBUG : BROWSER_OUTPUT: 10:22:23 INFO - 2015-11-18 10:22:23,516 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870943515__endTimestamp 10:22:24 INFO - 2015-11-18 10:22:24,437 INFO : Browser exited with error code: 0 10:22:24 INFO - 2015-11-18 10:22:24,439 INFO : Running cycle 4/20 for ts_paint test... 10:22:24 INFO - 2015-11-18 10:22:24,439 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:26 INFO - 2015-11-18 10:22:26,060 DEBUG : BROWSER_OUTPUT: __start_report532__end_report 10:22:26 INFO - 2015-11-18 10:22:26,060 DEBUG : BROWSER_OUTPUT: 10:22:26 INFO - 2015-11-18 10:22:26,067 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870946064__endTimestamp 10:22:27 INFO - 2015-11-18 10:22:27,053 INFO : Browser exited with error code: 0 10:22:27 INFO - 2015-11-18 10:22:27,055 INFO : Running cycle 5/20 for ts_paint test... 10:22:27 INFO - 2015-11-18 10:22:27,055 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:28 INFO - 2015-11-18 10:22:28,754 DEBUG : BROWSER_OUTPUT: __start_report602__end_report 10:22:28 INFO - 2015-11-18 10:22:28,754 DEBUG : BROWSER_OUTPUT: 10:22:28 INFO - 2015-11-18 10:22:28,770 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870948765__endTimestamp 10:22:29 INFO - 2015-11-18 10:22:29,777 INFO : Browser exited with error code: 0 10:22:29 INFO - 2015-11-18 10:22:29,779 INFO : Running cycle 6/20 for ts_paint test... 10:22:29 INFO - 2015-11-18 10:22:29,779 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:31 INFO - 2015-11-18 10:22:31,395 DEBUG : BROWSER_OUTPUT: __start_report497__end_report 10:22:31 INFO - 2015-11-18 10:22:31,395 DEBUG : BROWSER_OUTPUT: 10:22:31 INFO - 2015-11-18 10:22:31,403 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870951400__endTimestamp 10:22:32 INFO - 2015-11-18 10:22:32,457 INFO : Browser exited with error code: 0 10:22:32 INFO - 2015-11-18 10:22:32,459 INFO : Running cycle 7/20 for ts_paint test... 10:22:32 INFO - 2015-11-18 10:22:32,459 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:34 INFO - 2015-11-18 10:22:34,087 DEBUG : BROWSER_OUTPUT: __start_report509__end_report 10:22:34 INFO - 2015-11-18 10:22:34,087 DEBUG : BROWSER_OUTPUT: 10:22:34 INFO - 2015-11-18 10:22:34,103 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870954095__endTimestamp 10:22:35 INFO - 2015-11-18 10:22:35,173 INFO : Browser exited with error code: 0 10:22:35 INFO - 2015-11-18 10:22:35,175 INFO : Running cycle 8/20 for ts_paint test... 10:22:35 INFO - 2015-11-18 10:22:35,175 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:36 INFO - 2015-11-18 10:22:36,788 DEBUG : BROWSER_OUTPUT: __start_report502__end_report 10:22:36 INFO - 2015-11-18 10:22:36,788 DEBUG : BROWSER_OUTPUT: 10:22:36 INFO - 2015-11-18 10:22:36,789 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870956788__endTimestamp 10:22:37 INFO - 2015-11-18 10:22:37,821 INFO : Browser exited with error code: 0 10:22:37 INFO - 2015-11-18 10:22:37,823 INFO : Running cycle 9/20 for ts_paint test... 10:22:37 INFO - 2015-11-18 10:22:37,823 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:39 INFO - 2015-11-18 10:22:39,477 DEBUG : BROWSER_OUTPUT: __start_report523__end_report 10:22:39 INFO - 2015-11-18 10:22:39,477 DEBUG : BROWSER_OUTPUT: 10:22:39 INFO - 2015-11-18 10:22:39,478 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870959476__endTimestamp 10:22:40 INFO - 2015-11-18 10:22:40,493 INFO : Browser exited with error code: 0 10:22:40 INFO - 2015-11-18 10:22:40,495 INFO : Running cycle 10/20 for ts_paint test... 10:22:40 INFO - 2015-11-18 10:22:40,495 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:42 INFO - 2015-11-18 10:22:42,150 DEBUG : BROWSER_OUTPUT: __start_report538__end_report 10:22:42 INFO - 2015-11-18 10:22:42,150 DEBUG : BROWSER_OUTPUT: 10:22:42 INFO - 2015-11-18 10:22:42,158 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870962156__endTimestamp 10:22:43 INFO - 2015-11-18 10:22:43,225 INFO : Browser exited with error code: 0 10:22:43 INFO - 2015-11-18 10:22:43,227 INFO : Running cycle 11/20 for ts_paint test... 10:22:43 INFO - 2015-11-18 10:22:43,227 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:44 INFO - 2015-11-18 10:22:44,880 DEBUG : BROWSER_OUTPUT: __start_report552__end_report 10:22:44 INFO - 2015-11-18 10:22:44,881 DEBUG : BROWSER_OUTPUT: 10:22:44 INFO - 2015-11-18 10:22:44,884 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870964883__endTimestamp 10:22:45 INFO - 2015-11-18 10:22:45,953 INFO : Browser exited with error code: 0 10:22:45 INFO - 2015-11-18 10:22:45,955 INFO : Running cycle 12/20 for ts_paint test... 10:22:45 INFO - 2015-11-18 10:22:45,955 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:47 INFO - 2015-11-18 10:22:47,636 DEBUG : BROWSER_OUTPUT: __start_report548__end_report 10:22:47 INFO - 2015-11-18 10:22:47,636 DEBUG : BROWSER_OUTPUT: 10:22:47 INFO - 2015-11-18 10:22:47,643 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870967642__endTimestamp 10:22:48 INFO - 2015-11-18 10:22:48,653 INFO : Browser exited with error code: 0 10:22:48 INFO - 2015-11-18 10:22:48,655 INFO : Running cycle 13/20 for ts_paint test... 10:22:48 INFO - 2015-11-18 10:22:48,655 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:50 INFO - 2015-11-18 10:22:50,254 DEBUG : BROWSER_OUTPUT: __start_report496__end_report 10:22:50 INFO - 2015-11-18 10:22:50,254 DEBUG : BROWSER_OUTPUT: 10:22:50 INFO - 2015-11-18 10:22:50,257 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870970255__endTimestamp 10:22:51 INFO - 2015-11-18 10:22:51,329 INFO : Browser exited with error code: 0 10:22:51 INFO - 2015-11-18 10:22:51,331 INFO : Running cycle 14/20 for ts_paint test... 10:22:51 INFO - 2015-11-18 10:22:51,331 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:52 INFO - 2015-11-18 10:22:52,969 DEBUG : BROWSER_OUTPUT: __start_report486__end_report 10:22:52 INFO - 2015-11-18 10:22:52,970 DEBUG : BROWSER_OUTPUT: 10:22:52 INFO - 2015-11-18 10:22:52,977 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870972975__endTimestamp 10:22:54 INFO - 2015-11-18 10:22:54,089 INFO : Browser exited with error code: 0 10:22:54 INFO - 2015-11-18 10:22:54,091 INFO : Running cycle 15/20 for ts_paint test... 10:22:54 INFO - 2015-11-18 10:22:54,091 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:55 INFO - 2015-11-18 10:22:55,747 DEBUG : BROWSER_OUTPUT: __start_report547__end_report 10:22:55 INFO - 2015-11-18 10:22:55,747 DEBUG : BROWSER_OUTPUT: 10:22:55 INFO - 2015-11-18 10:22:55,751 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870975750__endTimestamp 10:22:56 INFO - 2015-11-18 10:22:56,817 INFO : Browser exited with error code: 0 10:22:56 INFO - 2015-11-18 10:22:56,819 INFO : Running cycle 16/20 for ts_paint test... 10:22:56 INFO - 2015-11-18 10:22:56,819 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:22:58 INFO - 2015-11-18 10:22:58,464 DEBUG : BROWSER_OUTPUT: __start_report520__end_report 10:22:58 INFO - 2015-11-18 10:22:58,464 DEBUG : BROWSER_OUTPUT: 10:22:58 INFO - 2015-11-18 10:22:58,472 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870978471__endTimestamp 10:22:59 INFO - 2015-11-18 10:22:59,533 INFO : Browser exited with error code: 0 10:22:59 INFO - 2015-11-18 10:22:59,535 INFO : Running cycle 17/20 for ts_paint test... 10:22:59 INFO - 2015-11-18 10:22:59,535 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:23:01 INFO - 2015-11-18 10:23:01,163 DEBUG : BROWSER_OUTPUT: __start_report510__end_report 10:23:01 INFO - 2015-11-18 10:23:01,163 DEBUG : BROWSER_OUTPUT: 10:23:01 INFO - 2015-11-18 10:23:01,170 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870981166__endTimestamp 10:23:02 INFO - 2015-11-18 10:23:02,373 INFO : Browser exited with error code: 0 10:23:02 INFO - 2015-11-18 10:23:02,375 INFO : Running cycle 18/20 for ts_paint test... 10:23:02 INFO - 2015-11-18 10:23:02,375 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:23:03 INFO - 2015-11-18 10:23:03,991 DEBUG : BROWSER_OUTPUT: __start_report502__end_report 10:23:03 INFO - 2015-11-18 10:23:03,992 DEBUG : BROWSER_OUTPUT: 10:23:03 INFO - 2015-11-18 10:23:03,999 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870983996__endTimestamp 10:23:05 INFO - 2015-11-18 10:23:05,101 INFO : Browser exited with error code: 0 10:23:05 INFO - 2015-11-18 10:23:05,103 INFO : Running cycle 19/20 for ts_paint test... 10:23:05 INFO - 2015-11-18 10:23:05,103 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:23:06 INFO - 2015-11-18 10:23:06,725 DEBUG : BROWSER_OUTPUT: __start_report508__end_report 10:23:06 INFO - 2015-11-18 10:23:06,725 DEBUG : BROWSER_OUTPUT: 10:23:06 INFO - 2015-11-18 10:23:06,741 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870986736__endTimestamp 10:23:07 INFO - 2015-11-18 10:23:07,821 INFO : Browser exited with error code: 0 10:23:07 INFO - 2015-11-18 10:23:07,823 INFO : Running cycle 20/20 for ts_paint test... 10:23:07 INFO - 2015-11-18 10:23:07,823 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpDMulK2/profile http://localhost:38426/startup_test/tspaint_test.html 10:23:09 INFO - 2015-11-18 10:23:09,477 DEBUG : BROWSER_OUTPUT: __start_report546__end_report 10:23:09 INFO - 2015-11-18 10:23:09,477 DEBUG : BROWSER_OUTPUT: 10:23:09 INFO - 2015-11-18 10:23:09,477 DEBUG : BROWSER_OUTPUT: __startTimestamp1447870989474__endTimestamp 10:23:10 INFO - 2015-11-18 10:23:10,525 INFO : Browser exited with error code: 0 10:23:10 INFO - 2015-11-18 10:23:10,544 INFO : Completed test ts_paint (00:00:59) 10:23:10 INFO - 2015-11-18 10:23:10,545 INFO : Starting test tpaint 10:23:10 INFO - 2015-11-18 10:23:10,545 DEBUG : operating with platform_type : linux_ 10:23:10 INFO - 2015-11-18 10:23:10,545 INFO : Initialising browser for tpaint test... 10:23:10 INFO - 2015-11-18 10:23:10,551 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmppTGLfv/profile http://localhost:38426/getInfo.html 10:23:15 INFO - 2015-11-18 10:23:15,133 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 10:23:15 INFO - 2015-11-18 10:23:15,133 DEBUG : BROWSER_OUTPUT: colorDepth:24 10:23:15 INFO - 2015-11-18 10:23:15,133 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 10:23:15 INFO - 2015-11-18 10:23:15,133 DEBUG : BROWSER_OUTPUT: __metrics 10:23:16 INFO - 2015-11-18 10:23:16,269 INFO : Browser initialized. 10:23:16 INFO - 2015-11-18 10:23:16,270 INFO : Running cycle 1/1 for tpaint test... 10:23:16 INFO - 2015-11-18 10:23:16,270 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmppTGLfv/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1 10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: __start_report268.65000000000055|275.880000000001|276.630000000001|281.8899999999999|284.71999999999935|287.2049999999999|289.59000000000015|290.89500000000044|295.3249999999998|304.39999999999964|310.77999999999884|320.22500000000036|323.125|335.59000000000015|335.9200000000019|336.1100000000006|350.27999999999884|355.71500000000015|424.6100000000006|463.8250000000007__end_report__startTimestamp1447871024821__endTimestamp 10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: openingTimes=275.880000000001,276.630000000001,281.8899999999999,284.71999999999935,287.2049999999999,289.59000000000015,290.89500000000044,295.3249999999998,304.39999999999964,310.77999999999884,320.22500000000036,323.125,335.59000000000015,335.9200000000019,336.1100000000006,350.27999999999884,355.71500000000015,424.6100000000006,463.8250000000007 10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: avgOpenTime:320.57 10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: minOpenTime:268.65 10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: maxOpenTime:463.83 10:23:44 INFO - 2015-11-18 10:23:44,822 DEBUG : BROWSER_OUTPUT: medOpenTime:307.58999999999924 10:23:44 INFO - 2015-11-18 10:23:44,823 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:307.58999999999924 10:23:45 INFO - 2015-11-18 10:23:45,961 INFO : Browser exited with error code: 0 10:23:45 INFO - 2015-11-18 10:23:45,978 INFO : Completed test tpaint (00:00:35) 10:23:45 INFO - 2015-11-18 10:23:45,978 INFO : Starting test sessionrestore 10:23:45 INFO - 2015-11-18 10:23:45,978 DEBUG : operating with platform_type : linux_ 10:23:45 INFO - 2015-11-18 10:23:45,979 INFO : Initialising browser for sessionrestore test... 10:23:45 INFO - 2015-11-18 10:23:45,989 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/getInfo.html 10:23:53 INFO - 2015-11-18 10:23:53,694 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 10:23:53 INFO - 2015-11-18 10:23:53,695 DEBUG : BROWSER_OUTPUT: colorDepth:24 10:23:53 INFO - 2015-11-18 10:23:53,695 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811 10:23:53 INFO - 2015-11-18 10:23:53,695 DEBUG : BROWSER_OUTPUT: __metrics 10:23:53 ERROR - 2015-11-18 10:23:53,917 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17087: TypeError: browser.permitUnload is not a function 10:23:54 ERROR - 2015-11-18 10:23:54,456 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17087: TypeError: browser.permitUnload is not a function 10:23:55 INFO - 2015-11-18 10:23:55,433 INFO : Browser initialized. 10:23:55 INFO - 2015-11-18 10:23:55,434 INFO : Running cycle 1/10 for sessionrestore test... 10:23:55 INFO - 2015-11-18 10:23:55,434 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js 10:23:55 INFO - 2015-11-18 10:23:55,437 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json 10:23:55 INFO - 2015-11-18 10:23:55,438 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:24:01 INFO - 2015-11-18 10:24:01,124 DEBUG : BROWSER_OUTPUT: __start_report1495__end_report 10:24:01 INFO - 2015-11-18 10:24:01,124 DEBUG : BROWSER_OUTPUT: 10:24:01 INFO - 2015-11-18 10:24:01,124 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871041118__endTimestamp 10:24:01 INFO - 2015-11-18 10:24:01,124 DEBUG : BROWSER_OUTPUT: 10:24:01 INFO - 2015-11-18 10:24:01,946 DEBUG : BROWSER_OUTPUT: 10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost 10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: 10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: 10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost 10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: 10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: 10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost 10:24:01 INFO - 2015-11-18 10:24:01,948 DEBUG : BROWSER_OUTPUT: 10:24:02 INFO - 2015-11-18 10:24:02,745 INFO : Browser exited with error code: 0 10:24:02 INFO - 2015-11-18 10:24:02,747 INFO : Running cycle 2/10 for sessionrestore test... 10:24:02 INFO - 2015-11-18 10:24:02,748 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js 10:24:02 INFO - 2015-11-18 10:24:02,750 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json 10:24:02 INFO - 2015-11-18 10:24:02,751 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:24:07 INFO - 2015-11-18 10:24:07,992 DEBUG : BROWSER_OUTPUT: __start_report1207__end_report 10:24:07 INFO - 2015-11-18 10:24:07,992 DEBUG : BROWSER_OUTPUT: 10:24:07 INFO - 2015-11-18 10:24:07,992 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871047986__endTimestamp 10:24:07 INFO - 2015-11-18 10:24:07,992 DEBUG : BROWSER_OUTPUT: 10:24:09 INFO - 2015-11-18 10:24:09,513 INFO : Browser exited with error code: 0 10:24:09 INFO - 2015-11-18 10:24:09,515 INFO : Running cycle 3/10 for sessionrestore test... 10:24:09 INFO - 2015-11-18 10:24:09,515 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js 10:24:09 INFO - 2015-11-18 10:24:09,517 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json 10:24:09 INFO - 2015-11-18 10:24:09,518 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:24:14 INFO - 2015-11-18 10:24:14,595 DEBUG : BROWSER_OUTPUT: __start_report1185__end_report 10:24:14 INFO - 2015-11-18 10:24:14,595 DEBUG : BROWSER_OUTPUT: 10:24:14 INFO - 2015-11-18 10:24:14,595 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871054589__endTimestamp 10:24:14 INFO - 2015-11-18 10:24:14,596 DEBUG : BROWSER_OUTPUT: 10:24:16 INFO - 2015-11-18 10:24:16,197 INFO : Browser exited with error code: 0 10:24:16 INFO - 2015-11-18 10:24:16,199 INFO : Running cycle 4/10 for sessionrestore test... 10:24:16 INFO - 2015-11-18 10:24:16,199 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js 10:24:16 INFO - 2015-11-18 10:24:16,201 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json 10:24:16 INFO - 2015-11-18 10:24:16,202 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:24:21 INFO - 2015-11-18 10:24:21,324 DEBUG : BROWSER_OUTPUT: __start_report1189__end_report 10:24:21 INFO - 2015-11-18 10:24:21,324 DEBUG : BROWSER_OUTPUT: 10:24:21 INFO - 2015-11-18 10:24:21,324 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871061323__endTimestamp 10:24:21 INFO - 2015-11-18 10:24:21,324 DEBUG : BROWSER_OUTPUT: 10:24:22 INFO - 2015-11-18 10:24:22,993 INFO : Browser exited with error code: 0 10:24:22 INFO - 2015-11-18 10:24:22,995 INFO : Running cycle 5/10 for sessionrestore test... 10:24:22 INFO - 2015-11-18 10:24:22,995 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js 10:24:22 INFO - 2015-11-18 10:24:22,997 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json 10:24:22 INFO - 2015-11-18 10:24:22,998 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:24:28 INFO - 2015-11-18 10:24:28,321 DEBUG : BROWSER_OUTPUT: __start_report1188__end_report 10:24:28 INFO - 2015-11-18 10:24:28,321 DEBUG : BROWSER_OUTPUT: 10:24:28 INFO - 2015-11-18 10:24:28,321 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871068315__endTimestamp 10:24:28 INFO - 2015-11-18 10:24:28,321 DEBUG : BROWSER_OUTPUT: 10:24:29 INFO - 2015-11-18 10:24:29,204 DEBUG : BROWSER_OUTPUT: [Child 21241] WARNING: pipe error (3): Connection reset by peer: file /builds/slave/fx-team-l64-000000000000000000/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 459 10:24:29 INFO - 2015-11-18 10:24:29,204 DEBUG : BROWSER_OUTPUT: 10:24:29 INFO - 2015-11-18 10:24:29,205 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost 10:24:29 INFO - 2015-11-18 10:24:29,205 DEBUG : BROWSER_OUTPUT: 10:24:29 INFO - 2015-11-18 10:24:29,205 DEBUG : BROWSER_OUTPUT: 10:24:29 INFO - 2015-11-18 10:24:29,205 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost 10:24:29 INFO - 2015-11-18 10:24:29,206 DEBUG : BROWSER_OUTPUT: 10:24:30 INFO - 2015-11-18 10:24:30,037 INFO : Browser exited with error code: 0 10:24:30 INFO - 2015-11-18 10:24:30,039 INFO : Running cycle 6/10 for sessionrestore test... 10:24:30 INFO - 2015-11-18 10:24:30,039 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js 10:24:30 INFO - 2015-11-18 10:24:30,041 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json 10:24:30 INFO - 2015-11-18 10:24:30,042 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:24:35 INFO - 2015-11-18 10:24:35,205 DEBUG : BROWSER_OUTPUT: __start_report1185__end_report 10:24:35 INFO - 2015-11-18 10:24:35,205 DEBUG : BROWSER_OUTPUT: 10:24:35 INFO - 2015-11-18 10:24:35,206 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871075205__endTimestamp 10:24:35 INFO - 2015-11-18 10:24:35,206 DEBUG : BROWSER_OUTPUT: 10:24:36 INFO - 2015-11-18 10:24:36,937 INFO : Browser exited with error code: 0 10:24:36 INFO - 2015-11-18 10:24:36,939 INFO : Running cycle 7/10 for sessionrestore test... 10:24:36 INFO - 2015-11-18 10:24:36,939 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js 10:24:36 INFO - 2015-11-18 10:24:36,941 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json 10:24:36 INFO - 2015-11-18 10:24:36,942 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:24:42 INFO - 2015-11-18 10:24:42,129 DEBUG : BROWSER_OUTPUT: __start_report1206__end_report 10:24:42 INFO - 2015-11-18 10:24:42,129 DEBUG : BROWSER_OUTPUT: 10:24:42 INFO - 2015-11-18 10:24:42,129 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871082127__endTimestamp 10:24:42 INFO - 2015-11-18 10:24:42,129 DEBUG : BROWSER_OUTPUT: 10:24:43 INFO - 2015-11-18 10:24:43,007 DEBUG : BROWSER_OUTPUT: [Child 21480] WARNING: pipe error (3): Connection reset by peer: file /builds/slave/fx-team-l64-000000000000000000/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 459 10:24:43 INFO - 2015-11-18 10:24:43,770 INFO : Browser exited with error code: 0 10:24:43 INFO - 2015-11-18 10:24:43,771 INFO : Running cycle 8/10 for sessionrestore test... 10:24:43 INFO - 2015-11-18 10:24:43,772 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js 10:24:43 INFO - 2015-11-18 10:24:43,774 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json 10:24:43 INFO - 2015-11-18 10:24:43,774 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:24:49 INFO - 2015-11-18 10:24:49,083 DEBUG : BROWSER_OUTPUT: __start_report1212__end_report 10:24:49 INFO - 2015-11-18 10:24:49,084 DEBUG : BROWSER_OUTPUT: 10:24:49 INFO - 2015-11-18 10:24:49,084 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871089083__endTimestamp 10:24:49 INFO - 2015-11-18 10:24:49,084 DEBUG : BROWSER_OUTPUT: 10:24:50 INFO - 2015-11-18 10:24:50,825 INFO : Browser exited with error code: 0 10:24:50 INFO - 2015-11-18 10:24:50,827 INFO : Running cycle 9/10 for sessionrestore test... 10:24:50 INFO - 2015-11-18 10:24:50,827 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js 10:24:50 INFO - 2015-11-18 10:24:50,829 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json 10:24:50 INFO - 2015-11-18 10:24:50,830 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:24:55 INFO - 2015-11-18 10:24:55,916 DEBUG : BROWSER_OUTPUT: __start_report1198__end_report 10:24:55 INFO - 2015-11-18 10:24:55,916 DEBUG : BROWSER_OUTPUT: 10:24:55 INFO - 2015-11-18 10:24:55,916 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871095915__endTimestamp 10:24:55 INFO - 2015-11-18 10:24:55,916 DEBUG : BROWSER_OUTPUT: 10:24:57 INFO - 2015-11-18 10:24:57,597 INFO : Browser exited with error code: 0 10:24:57 INFO - 2015-11-18 10:24:57,599 INFO : Running cycle 10/10 for sessionrestore test... 10:24:57 INFO - 2015-11-18 10:24:57,599 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpH_vwIK/profile/sessionstore.js 10:24:57 INFO - 2015-11-18 10:24:57,601 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpH_vwIK/profile/sessionCheckpoints.json 10:24:57 INFO - 2015-11-18 10:24:57,602 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_vwIK/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:02 INFO - 2015-11-18 10:25:02,666 DEBUG : BROWSER_OUTPUT: __start_report1167__end_report 10:25:02 INFO - 2015-11-18 10:25:02,666 DEBUG : BROWSER_OUTPUT: 10:25:02 INFO - 2015-11-18 10:25:02,666 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871102664__endTimestamp 10:25:02 INFO - 2015-11-18 10:25:02,666 DEBUG : BROWSER_OUTPUT: 10:25:04 INFO - 2015-11-18 10:25:04,433 INFO : Browser exited with error code: 0 10:25:04 INFO - 2015-11-18 10:25:04,450 INFO : Completed test sessionrestore (00:01:18) 10:25:04 INFO - 2015-11-18 10:25:04,450 INFO : Starting test sessionrestore_no_auto_restore 10:25:04 INFO - 2015-11-18 10:25:04,450 DEBUG : operating with platform_type : linux_ 10:25:04 INFO - 2015-11-18 10:25:04,450 INFO : Initialising browser for sessionrestore_no_auto_restore test... 10:25:04 INFO - 2015-11-18 10:25:04,458 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/getInfo.html 10:25:08 INFO - 2015-11-18 10:25:08,723 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 10:25:08 INFO - 2015-11-18 10:25:08,723 DEBUG : BROWSER_OUTPUT: colorDepth:24 10:25:08 INFO - 2015-11-18 10:25:08,723 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811 10:25:08 INFO - 2015-11-18 10:25:08,723 DEBUG : BROWSER_OUTPUT: __metrics 10:25:09 INFO - 2015-11-18 10:25:09,761 INFO : Browser initialized. 10:25:09 INFO - 2015-11-18 10:25:09,762 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test... 10:25:09 INFO - 2015-11-18 10:25:09,762 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js 10:25:09 INFO - 2015-11-18 10:25:09,764 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json 10:25:09 INFO - 2015-11-18 10:25:09,765 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:11 INFO - 2015-11-18 10:25:11,868 DEBUG : BROWSER_OUTPUT: __start_report1094__end_report 10:25:11 INFO - 2015-11-18 10:25:11,868 DEBUG : BROWSER_OUTPUT: 10:25:11 INFO - 2015-11-18 10:25:11,868 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871111867__endTimestamp 10:25:11 INFO - 2015-11-18 10:25:11,868 DEBUG : BROWSER_OUTPUT: 10:25:12 INFO - 2015-11-18 10:25:12,909 INFO : Browser exited with error code: 0 10:25:12 INFO - 2015-11-18 10:25:12,911 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test... 10:25:12 INFO - 2015-11-18 10:25:12,911 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js 10:25:12 INFO - 2015-11-18 10:25:12,913 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json 10:25:12 INFO - 2015-11-18 10:25:12,914 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:14 INFO - 2015-11-18 10:25:14,520 DEBUG : BROWSER_OUTPUT: __start_report780__end_report 10:25:14 INFO - 2015-11-18 10:25:14,520 DEBUG : BROWSER_OUTPUT: 10:25:14 INFO - 2015-11-18 10:25:14,521 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871114519__endTimestamp 10:25:14 INFO - 2015-11-18 10:25:14,521 DEBUG : BROWSER_OUTPUT: 10:25:15 INFO - 2015-11-18 10:25:15,425 INFO : Browser exited with error code: 0 10:25:15 INFO - 2015-11-18 10:25:15,427 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test... 10:25:15 INFO - 2015-11-18 10:25:15,427 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js 10:25:15 INFO - 2015-11-18 10:25:15,429 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json 10:25:15 INFO - 2015-11-18 10:25:15,430 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:17 INFO - 2015-11-18 10:25:17,063 DEBUG : BROWSER_OUTPUT: __start_report795__end_report 10:25:17 INFO - 2015-11-18 10:25:17,063 DEBUG : BROWSER_OUTPUT: 10:25:17 INFO - 2015-11-18 10:25:17,063 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871117062__endTimestamp 10:25:17 INFO - 2015-11-18 10:25:17,063 DEBUG : BROWSER_OUTPUT: 10:25:17 INFO - 2015-11-18 10:25:17,949 INFO : Browser exited with error code: 0 10:25:17 INFO - 2015-11-18 10:25:17,951 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test... 10:25:17 INFO - 2015-11-18 10:25:17,951 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js 10:25:17 INFO - 2015-11-18 10:25:17,953 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json 10:25:17 INFO - 2015-11-18 10:25:17,954 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:19 INFO - 2015-11-18 10:25:19,594 DEBUG : BROWSER_OUTPUT: __start_report775__end_report 10:25:19 INFO - 2015-11-18 10:25:19,595 DEBUG : BROWSER_OUTPUT: 10:25:19 INFO - 2015-11-18 10:25:19,595 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871119593__endTimestamp 10:25:19 INFO - 2015-11-18 10:25:19,595 DEBUG : BROWSER_OUTPUT: 10:25:20 INFO - 2015-11-18 10:25:20,577 INFO : Browser exited with error code: 0 10:25:20 INFO - 2015-11-18 10:25:20,579 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test... 10:25:20 INFO - 2015-11-18 10:25:20,579 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js 10:25:20 INFO - 2015-11-18 10:25:20,581 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json 10:25:20 INFO - 2015-11-18 10:25:20,582 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:22 INFO - 2015-11-18 10:25:22,208 DEBUG : BROWSER_OUTPUT: __start_report771__end_report 10:25:22 INFO - 2015-11-18 10:25:22,208 DEBUG : BROWSER_OUTPUT: 10:25:22 INFO - 2015-11-18 10:25:22,208 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871122206__endTimestamp 10:25:22 INFO - 2015-11-18 10:25:22,208 DEBUG : BROWSER_OUTPUT: 10:25:23 INFO - 2015-11-18 10:25:23,245 INFO : Browser exited with error code: 0 10:25:23 INFO - 2015-11-18 10:25:23,247 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test... 10:25:23 INFO - 2015-11-18 10:25:23,247 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js 10:25:23 INFO - 2015-11-18 10:25:23,249 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json 10:25:23 INFO - 2015-11-18 10:25:23,250 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:24 INFO - 2015-11-18 10:25:24,844 DEBUG : BROWSER_OUTPUT: __start_report750__end_report 10:25:24 INFO - 2015-11-18 10:25:24,844 DEBUG : BROWSER_OUTPUT: 10:25:24 INFO - 2015-11-18 10:25:24,844 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871124838__endTimestamp 10:25:24 INFO - 2015-11-18 10:25:24,844 DEBUG : BROWSER_OUTPUT: 10:25:25 INFO - 2015-11-18 10:25:25,901 INFO : Browser exited with error code: 0 10:25:25 INFO - 2015-11-18 10:25:25,903 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test... 10:25:25 INFO - 2015-11-18 10:25:25,903 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js 10:25:25 INFO - 2015-11-18 10:25:25,905 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json 10:25:25 INFO - 2015-11-18 10:25:25,906 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:27 INFO - 2015-11-18 10:25:27,477 DEBUG : BROWSER_OUTPUT: __start_report761__end_report 10:25:27 INFO - 2015-11-18 10:25:27,477 DEBUG : BROWSER_OUTPUT: 10:25:27 INFO - 2015-11-18 10:25:27,477 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871127469__endTimestamp 10:25:27 INFO - 2015-11-18 10:25:27,478 DEBUG : BROWSER_OUTPUT: 10:25:28 INFO - 2015-11-18 10:25:28,461 INFO : Browser exited with error code: 0 10:25:28 INFO - 2015-11-18 10:25:28,463 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test... 10:25:28 INFO - 2015-11-18 10:25:28,463 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js 10:25:28 INFO - 2015-11-18 10:25:28,465 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json 10:25:28 INFO - 2015-11-18 10:25:28,466 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:30 INFO - 2015-11-18 10:25:30,108 DEBUG : BROWSER_OUTPUT: __start_report778__end_report 10:25:30 INFO - 2015-11-18 10:25:30,109 DEBUG : BROWSER_OUTPUT: 10:25:30 INFO - 2015-11-18 10:25:30,109 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871130108__endTimestamp 10:25:30 INFO - 2015-11-18 10:25:30,109 DEBUG : BROWSER_OUTPUT: 10:25:31 INFO - 2015-11-18 10:25:31,209 INFO : Browser exited with error code: 0 10:25:31 INFO - 2015-11-18 10:25:31,211 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test... 10:25:31 INFO - 2015-11-18 10:25:31,211 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js 10:25:31 INFO - 2015-11-18 10:25:31,213 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json 10:25:31 INFO - 2015-11-18 10:25:31,214 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:32 INFO - 2015-11-18 10:25:32,853 DEBUG : BROWSER_OUTPUT: __start_report782__end_report 10:25:32 INFO - 2015-11-18 10:25:32,853 DEBUG : BROWSER_OUTPUT: 10:25:32 INFO - 2015-11-18 10:25:32,853 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871132851__endTimestamp 10:25:32 INFO - 2015-11-18 10:25:32,854 DEBUG : BROWSER_OUTPUT: 10:25:33 INFO - 2015-11-18 10:25:33,889 INFO : Browser exited with error code: 0 10:25:33 INFO - 2015-11-18 10:25:33,891 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test... 10:25:33 INFO - 2015-11-18 10:25:33,891 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpgOVICc/profile/sessionstore.js 10:25:33 INFO - 2015-11-18 10:25:33,893 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpgOVICc/profile/sessionCheckpoints.json 10:25:33 INFO - 2015-11-18 10:25:33,893 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpgOVICc/profile http://localhost:38426/startup_test/sessionrestore/index.html 10:25:35 INFO - 2015-11-18 10:25:35,480 DEBUG : BROWSER_OUTPUT: __start_report763__end_report 10:25:35 INFO - 2015-11-18 10:25:35,480 DEBUG : BROWSER_OUTPUT: 10:25:35 INFO - 2015-11-18 10:25:35,480 DEBUG : BROWSER_OUTPUT: __startTimestamp1447871135477__endTimestamp 10:25:35 INFO - 2015-11-18 10:25:35,480 DEBUG : BROWSER_OUTPUT: 10:25:36 INFO - 2015-11-18 10:25:36,537 INFO : Browser exited with error code: 0 10:25:36 INFO - 2015-11-18 10:25:36,552 INFO : Completed test sessionrestore_no_auto_restore (00:00:32) 10:25:36 INFO - 2015-11-18 10:25:36,983 INFO : Completed test suite (00:05:17) 10:25:36 INFO - 2015-11-18 10:25:36,983 DEBUG : Working with test: a11yr 10:25:36 INFO - 2015-11-18 10:25:36,984 DEBUG : Generating results file: a11yr 10:25:36 INFO - 2015-11-18 10:25:36,984 DEBUG : Working with test: ts_paint 10:25:36 INFO - 2015-11-18 10:25:36,984 DEBUG : Generating results file: ts_paint 10:25:36 INFO - 2015-11-18 10:25:36,985 DEBUG : Working with test: tpaint 10:25:36 INFO - 2015-11-18 10:25:36,985 DEBUG : Generating results file: tpaint 10:25:36 INFO - 2015-11-18 10:25:36,985 DEBUG : Working with test: sessionrestore 10:25:36 INFO - 2015-11-18 10:25:36,985 DEBUG : Generating results file: sessionrestore 10:25:36 INFO - 2015-11-18 10:25:36,985 DEBUG : Working with test: sessionrestore_no_auto_restore 10:25:36 INFO - 2015-11-18 10:25:36,986 DEBUG : Generating results file: sessionrestore_no_auto_restore 10:25:36 INFO - 2015-11-18 10:25:36,986 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 10:25:37 INFO - 2015-11-18 10:25:37,026 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,132,43]] 10:25:37 INFO - 2015-11-18 10:25:37,026 DEBUG : process_Request line: a11yr_paint 717.46 graph.html#tests=[[223,132,43]] 10:25:37 INFO - 2015-11-18 10:25:37,026 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 10:25:37 INFO - 2015-11-18 10:25:37,084 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,132,43]] 10:25:37 INFO - 2015-11-18 10:25:37,084 DEBUG : process_Request line: ts_paint 519.87 graph.html#tests=[[83,132,43]] 10:25:37 INFO - 2015-11-18 10:25:37,084 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 10:25:37 INFO - 2015-11-18 10:25:37,115 DEBUG : process_Request line: tpaint graph.html#tests=[[82,132,43]] 10:25:37 INFO - 2015-11-18 10:25:37,115 DEBUG : process_Request line: tpaint 323.12 graph.html#tests=[[82,132,43]] 10:25:37 INFO - 2015-11-18 10:25:37,115 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 10:25:37 INFO - 2015-11-18 10:25:37,236 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,132,43]] 10:25:37 INFO - 2015-11-18 10:25:37,236 DEBUG : process_Request line: sessionrestore 1220.16 graph.html#tests=[[313,132,43]] 10:25:37 INFO - 2015-11-18 10:25:37,236 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 10:25:37 INFO - 2015-11-18 10:25:37,346 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,132,43]] 10:25:37 INFO - 2015-11-18 10:25:37,346 DEBUG : process_Request line: sessionrestore_no_auto_restore 800.02 graph.html#tests=[[315,132,43]] 10:25:37 INFO - 2015-11-18 10:25:37,347 INFO : PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"lowerIsBetter": true, "subtests": [{"lowerIsBetter": true, "replicates": [1272.0, 1314.0, 1327.0, 1352.0, 1338.0, 1337.0, 1538.0, 1330.0, 1339.0, 1329.0, 1339.0, 1342.0, 1544.0, 1332.0, 1326.0, 1543.0, 1328.0, 1345.0, 1338.0, 1332.0, 1332.0, 1541.0, 1338.0, 1367.0, 1334.0], "unit": "ms", "name": "dhtml.html", "value": 1338.0}, {"lowerIsBetter": true, "replicates": [402.0, 397.0, 384.0, 383.0, 389.0, 387.0, 380.0, 382.0, 394.0, 410.0, 394.0, 378.0, 390.0, 379.0, 381.0, 382.0, 380.0, 386.0, 384.0, 381.0, 391.0, 390.0, 381.0, 385.0, 389.0], "unit": "ms", "name": "tablemutation.html", "value": 384.5}], "name": "a11yr", "value": 717.4598109845805}, {"subtests": [{"replicates": [458.0, 512.0, 526.0, 532.0, 602.0, 497.0, 509.0, 502.0, 523.0, 538.0, 552.0, 548.0, 496.0, 486.0, 547.0, 520.0, 510.0, 502.0, 508.0, 546.0], "name": "ts_paint", "value": 520.0}], "name": "ts_paint", "value": 520.0}, {"subtests": [{"replicates": [268.65000000000055, 275.880000000001, 276.630000000001, 281.8899999999999, 284.71999999999935, 287.2049999999999, 289.59000000000015, 290.89500000000044, 295.3249999999998, 304.39999999999964, 310.77999999999884, 320.22500000000036, 323.125, 335.59000000000015, 335.9200000000019, 336.1100000000006, 350.27999999999884, 355.71500000000015, 424.6100000000006, 463.8250000000007], "name": "tpaint", "value": 323.125}], "name": "tpaint", "value": 323.125}, {"subtests": [{"replicates": [1495.0, 1207.0, 1185.0, 1189.0, 1188.0, 1185.0, 1206.0, 1212.0, 1198.0, 1167.0], "name": "sessionrestore", "value": 1189.0}], "name": "sessionrestore", "value": 1189.0}, {"subtests": [{"replicates": [1094.0, 780.0, 795.0, 775.0, 771.0, 750.0, 761.0, 778.0, 782.0, 763.0], "name": "sessionrestore_no_auto_restore", "value": 775.0}], "name": "sessionrestore_no_auto_restore", "value": 775.0}]} 10:25:37 INFO - RETURN: a11yr_paint: 717.46 10:25:37 INFO - RETURN: ts_paint: 519.87 10:25:37 INFO - RETURN: tpaint: 323.12 10:25:37 INFO - RETURN: sessionrestore: 1220.16 10:25:37 INFO - RETURN: sessionrestore_no_auto_restore: 800.02 10:25:37 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,132,43]]", "result": "1220.16"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,132,43]]", "result": "717.46"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,132,43]]", "result": "323.12"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,132,43]]", "result": "519.87"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,132,43]]", "result": "800.02"}}} 10:25:37 INFO - Return code: 0 10:25:37 ERROR - # TBPL SUCCESS # 10:25:37 INFO - Running post-action listener: _resource_record_post_action 10:25:37 INFO - Running post-run listener: _resource_record_post_run 10:25:38 INFO - Total resource usage - Wall time: 332s; CPU: 16.0%; Read bytes: 0; Write bytes: 570818560; Read time: 0; Write time: 442308 10:25:38 INFO - install - Wall time: 14s; CPU: 14.0%; Read bytes: 0; Write bytes: 158588928; Read time: 0; Write time: 205824 10:25:38 INFO - run-tests - Wall time: 318s; CPU: 16.0%; Read bytes: 0; Write bytes: 412119040; Read time: 0; Write time: 233796 10:25:38 INFO - Running post-run listener: _upload_blobber_files 10:25:38 INFO - Blob upload gear active. 10:25:38 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ... 10:25:38 INFO - Copying logs to upload dir... 10:25:38 INFO - mkdir: /builds/slave/test/build/upload/logs program finished with exit code 0 elapsedTime=359.828126 ========= master_lag: 0.02 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 59 secs) (at 2015-11-18 10:25:37.812088) ========= ========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-18 10:25:37.815526) ========= 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=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False build_url:https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 program finished with exit code 0 elapsedTime=0.010169 build_url: 'https://queue.taskcluster.net/v1/task/oj_sNZtLRR6uEoCsky80IQ/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-18 10:25:37.866310) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:25:37.866633) ========= 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=61fa6ed41387771909ec0f71000001b3-1447870776.944992-559489883 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004537 ========= master_lag: 0.04 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-18 10:25:37.915872) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-18 10:25:37.916201) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-18 10:25:37.916501) ========= ========= Total master_lag: 0.23 =========