builder: fx-team_ubuntu64_hw_test-other-e10s slave: talos-linux64-ix-045 starttime: 1447940253.13 results: success (0) buildid: 20151119042020 builduid: d1c7e1fcb9d947bead57838aeca77b56 revision: bc29e2e5fac327b36b25e8d38107e09adc0a91b9 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.133603) ========= master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.134080) ========= ========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.134458) ========= 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-1447938538.59755-1196598762 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False /builds/slave/test program finished with exit code 0 elapsedTime=0.006464 basedir: '/builds/slave/test' ========= master_lag: 0.01 ========= ========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.155871) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.156192) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.193254) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.193522) ========= 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-1447938538.59755-1196598762 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004641 ========= master_lag: 0.05 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.246747) ========= ========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.247017) ========= script_repo_url: https://hg.mozilla.org/build/mozharness ========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.247363) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.247882) ========= 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-1447938538.59755-1196598762 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2015-11-19 05:37:33-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.25, 63.245.215.102 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.25|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12141 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 40.3M=0s 2015-11-19 05:37:33 (40.3 MB/s) - `archiver_client.py' saved [12141/12141] program finished with exit code 0 elapsedTime=0.189687 ========= master_lag: 0.01 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.450640) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.450935) ========= 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-1447938538.59755-1196598762 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.014845 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:33.500590) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-11-19 05:37:33.500906) ========= bash -c 'python archiver_client.py mozharness --repo integration/fx-team --rev bc29e2e5fac327b36b25e8d38107e09adc0a91b9 --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 bc29e2e5fac327b36b25e8d38107e09adc0a91b9 --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-1447938538.59755-1196598762 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2015-11-19 05:37:33,764 truncating revision to first 12 chars 2015-11-19 05:37:33,764 Setting DEBUG logging. 2015-11-19 05:37:33,764 attempt 1/10 2015-11-19 05:37:33,764 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/fx-team/bc29e2e5fac3?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2015-11-19 05:37:34,869 unpacking tar archive at: fx-team-bc29e2e5fac3/testing/mozharness/ program finished with exit code 0 elapsedTime=1.389491 ========= master_lag: 0.01 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-11-19 05:37:34.902945) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:34.903260) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:34.911946) ========= ========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:34.912236) ========= TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production ========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-19 05:37:34.912627) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 17 secs) (at 2015-11-19 05:37:34.913192) ========= /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-1447938538.59755-1196598762 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 05:37:35 INFO - MultiFileLogger online at 20151119 05:37:35 in /builds/slave/test 05:37:35 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 05:37:35 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 05:37:35 INFO - {'append_to_log': False, 05:37:35 INFO - 'base_work_dir': '/builds/slave/test', 05:37:35 INFO - 'blob_upload_branch': 'Fx-Team-Non-PGO', 05:37:35 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 05:37:35 INFO - 'branch': 'Fx-Team-Non-PGO', 05:37:35 INFO - 'buildbot_json_path': 'buildprops.json', 05:37:35 INFO - 'config_files': ('talos/linux_config.py',), 05:37:35 INFO - 'default_actions': ('clobber', 05:37:35 INFO - 'read-buildbot-config', 05:37:35 INFO - 'download-and-extract', 05:37:35 INFO - 'populate-webroot', 05:37:35 INFO - 'create-virtualenv', 05:37:35 INFO - 'install', 05:37:35 INFO - 'run-tests'), 05:37:35 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 05:37:35 INFO - 'download_minidump_stackwalk': True, 05:37:35 INFO - 'download_symbols': 'ondemand', 05:37:35 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 05:37:35 INFO - 'tooltool.py': '/tools/tooltool.py', 05:37:35 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 05:37:35 INFO - '/tools/misc-python/virtualenv.py')}, 05:37:35 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 05:37:35 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 05:37:35 INFO - 'installer_path': 'installer.exe', 05:37:35 INFO - 'log_level': 'info', 05:37:35 INFO - 'log_name': 'talos', 05:37:35 INFO - 'log_to_console': True, 05:37:35 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 05:37:35 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 05:37:35 INFO - 'opt_config_files': (), 05:37:35 INFO - 'pip_index': False, 05:37:35 INFO - 'sps_profile': False, 05:37:35 INFO - 'sps_profile_interval': 0, 05:37:35 INFO - 'suite': 'other-e10s', 05:37:35 INFO - 'system_bits': '64', 05:37:35 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 05:37:35 INFO - 'title': 'talos-linux64-ix-045', 05:37:35 INFO - 'tooltool_cache': '/builds/tooltool_cache', 05:37:35 INFO - 'use_talos_json': True, 05:37:35 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 05:37:35 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 05:37:35 INFO - 'work_dir': 'build'} 05:37:35 INFO - ##### 05:37:35 INFO - ##### Running clobber step. 05:37:35 INFO - ##### 05:37:35 INFO - Running pre-action listener: _resource_record_pre_action 05:37:35 INFO - Running main action method: clobber 05:37:35 INFO - rmtree: /builds/slave/test/build 05:37:35 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 05:37:36 INFO - Running post-action listener: _resource_record_post_action 05:37:36 INFO - ##### 05:37:36 INFO - ##### Running read-buildbot-config step. 05:37:36 INFO - ##### 05:37:36 INFO - Running pre-action listener: _resource_record_pre_action 05:37:36 INFO - Running main action method: read_buildbot_config 05:37:36 INFO - Using buildbot properties: 05:37:36 INFO - { 05:37:36 INFO - "properties": { 05:37:36 INFO - "buildnumber": 492, 05:37:36 INFO - "product": "firefox", 05:37:36 INFO - "script_repo_revision": "production", 05:37:36 INFO - "builddir": "fx-team_ubuntu64_hw_test-other-e10s", 05:37:36 INFO - "repository": "", 05:37:36 INFO - "buildername": "Ubuntu HW 12.04 x64 fx-team talos other-e10s", 05:37:36 INFO - "buildid": "20151119042020", 05:37:36 INFO - "slavename": "talos-linux64-ix-045", 05:37:36 INFO - "pgo_build": "False", 05:37:36 INFO - "basedir": "/builds/slave/test", 05:37:36 INFO - "project": "", 05:37:36 INFO - "platform": "ubuntu64_hw", 05:37:36 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 05:37:36 INFO - "slavebuilddir": "test", 05:37:36 INFO - "scheduler": "tests-fx-team-linux64-talos", 05:37:36 INFO - "branch": "fx-team", 05:37:36 INFO - "repo_path": "integration/fx-team", 05:37:36 INFO - "stage_platform": "linux64", 05:37:36 INFO - "builduid": "d1c7e1fcb9d947bead57838aeca77b56", 05:37:36 INFO - "revision": "bc29e2e5fac327b36b25e8d38107e09adc0a91b9" 05:37:36 INFO - }, 05:37:36 INFO - "sourcestamp": { 05:37:36 INFO - "repository": "", 05:37:36 INFO - "hasPatch": false, 05:37:36 INFO - "project": "", 05:37:36 INFO - "branch": "fx-team-linux64-talos", 05:37:36 INFO - "changes": [ 05:37:36 INFO - { 05:37:36 INFO - "category": null, 05:37:36 INFO - "files": [ 05:37:36 INFO - { 05:37:36 INFO - "url": null, 05:37:36 INFO - "name": "https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2" 05:37:36 INFO - } 05:37:36 INFO - ], 05:37:36 INFO - "repository": "", 05:37:36 INFO - "rev": "bc29e2e5fac327b36b25e8d38107e09adc0a91b9", 05:37:36 INFO - "who": "nigelbabu@gmail.com", 05:37:36 INFO - "when": 1447940203, 05:37:36 INFO - "number": 6682439, 05:37:36 INFO - "comments": "Backed out 8 changesets (bug 1171708) for bustage in it's own tests ON A CLOSED TREE\n\nBacked out changeset cae56980cbec (bug 1171708)\nBacked out changeset c60c33f9b573 (bug 1171708)\nBacked out changeset 96830bc690b6 (bug 1171708)\nBacked out changeset e1fcd236bdd3 (bug 1171708)\nBacked out changeset 9a48c1d22248 (bug 1171708)\nBacked out changeset 020345f46fbd (bug 1171708)\nBacked out changeset 6098e098d9eb (bug 1171708)\nBacked out changeset c67eefd6cf4d (bug 1171708)", 05:37:36 INFO - "project": "", 05:37:36 INFO - "at": "Thu 19 Nov 2015 05:36:43", 05:37:36 INFO - "branch": "fx-team-linux64-talos", 05:37:36 INFO - "revlink": "", 05:37:36 INFO - "properties": [ 05:37:36 INFO - [ 05:37:36 INFO - "buildid", 05:37:36 INFO - "20151119042020", 05:37:36 INFO - "Change" 05:37:36 INFO - ], 05:37:36 INFO - [ 05:37:36 INFO - "builduid", 05:37:36 INFO - "d1c7e1fcb9d947bead57838aeca77b56", 05:37:36 INFO - "Change" 05:37:36 INFO - ], 05:37:36 INFO - [ 05:37:36 INFO - "pgo_build", 05:37:36 INFO - "False", 05:37:36 INFO - "Change" 05:37:36 INFO - ] 05:37:36 INFO - ], 05:37:36 INFO - "revision": "bc29e2e5fac327b36b25e8d38107e09adc0a91b9" 05:37:36 INFO - } 05:37:36 INFO - ], 05:37:36 INFO - "revision": "bc29e2e5fac327b36b25e8d38107e09adc0a91b9" 05:37:36 INFO - } 05:37:36 INFO - } 05:37:36 INFO - Found installer url https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2. 05:37:36 INFO - Running post-action listener: _resource_record_post_action 05:37:36 INFO - ##### 05:37:36 INFO - ##### Running download-and-extract step. 05:37:36 INFO - ##### 05:37:36 INFO - Running pre-action listener: _resource_record_pre_action 05:37:36 INFO - Running main action method: download_and_extract 05:37:36 INFO - mkdir: /builds/slave/test/build/tests 05:37:36 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')]} 05:37:36 INFO - https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net 05:37:36 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/test_packages.json 05:37:36 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/test_packages.json 05:37:36 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json 05:37:36 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/test_packages.json', 'file_name': '/builds/slave/test/build/test_packages.json'}, attempt #1 05:37:43 INFO - Downloaded 1302 bytes. 05:37:43 INFO - Reading from file /builds/slave/test/build/test_packages.json 05:37:43 INFO - Using the following test package requirements: 05:37:43 INFO - {u'common': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 05:37:43 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.cppunittest.tests.zip'], 05:37:43 INFO - u'jittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 05:37:43 INFO - u'jsshell-linux-x86_64.zip'], 05:37:43 INFO - u'mochitest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.mochitest.tests.zip'], 05:37:43 INFO - u'mozbase': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 05:37:43 INFO - u'reftest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.reftest.tests.zip'], 05:37:43 INFO - u'talos': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'], 05:37:43 INFO - u'web-platform': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.web-platform.tests.zip'], 05:37:43 INFO - u'webapprt': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 05:37:43 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 05:37:43 INFO - u'firefox-45.0a1.en-US.linux-x86_64.xpcshell.tests.zip']} 05:37:43 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] for test suite category: common 05:37:43 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')]} 05:37:43 INFO - https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net 05:37:43 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 05:37:43 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 05:37:43 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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 05:37:43 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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 05:37:49 INFO - Downloaded 21291001 bytes. 05:37:49 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 05:37:49 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 05:37:49 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 05:37:50 INFO - Return code: 0 05:37:50 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 05:37:50 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')]} 05:37:50 INFO - https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net 05:37:50 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 05:37:50 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 05:37:50 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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 05:37:50 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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 05:37:53 INFO - Downloaded 21291001 bytes. 05:37:53 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 05:37:53 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 05:37:53 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 05:37:54 INFO - Return code: 0 05:37: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')]} 05:37:54 INFO - https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip matches https://queue.taskcluster.net 05:37:54 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 05:37:54 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 05:37:54 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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 05:37:54 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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 05:37:55 INFO - Downloaded 11130997 bytes. 05:37:55 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 05:37:55 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 05:37:55 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 05:37:55 INFO - Return code: 0 05:37:55 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')]} 05:37:55 INFO - https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 matches https://queue.taskcluster.net 05:37:55 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 05:37:55 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 05:37:55 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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 05:37:55 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/hn_i-YmOSISiPFOXjDDJJg/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 05:38:02 INFO - Downloaded 55664259 bytes. 05:38:02 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 05:38:02 INFO - mkdir: /builds/slave/test/properties 05:38:02 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 05:38:02 INFO - Writing to file /builds/slave/test/properties/build_url 05:38:02 INFO - Contents: 05:38:02 INFO - build_url:https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 05:38:02 INFO - Running post-action listener: _resource_record_post_action 05:38:02 INFO - Running post-action listener: set_extra_try_arguments 05:38:02 INFO - ##### 05:38:02 INFO - ##### Running populate-webroot step. 05:38:02 INFO - ##### 05:38:02 INFO - Running pre-action listener: _resource_record_pre_action 05:38:02 INFO - Running main action method: populate_webroot 05:38:02 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']}, 05:38:02 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']}, 05:38:02 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs', 05:38:02 INFO - '../fennec_ids.txt'], 05:38:02 INFO - 'tests': ['tcheck2']}, 05:38:02 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome', 05:38:02 INFO - '--tppagecycles', 05:38:02 INFO - '7'], 05:38:02 INFO - 'tests': ['tsvgm']}}, 05:38:02 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']}, 05:38:02 INFO - 'chromez-e10s': {'talos_options': ['--e10s'], 05:38:02 INFO - 'tests': ['tresize', 'tcanvasmark']}, 05:38:02 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 05:38:02 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'], 05:38:02 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 05:38:02 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 05:38:02 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 05:38:02 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 05:38:02 INFO - 'talos_options': ['--e10s'], 05:38:02 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 05:38:02 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 05:38:02 INFO - 'tests': ['damp', 'tps']}, 05:38:02 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 05:38:02 INFO - 'talos_options': ['--e10s'], 05:38:02 INFO - 'tests': ['damp', 'tps']}, 05:38:02 INFO - 'g3': {'tests': ['dromaeo_dom']}, 05:38:02 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 05:38:02 INFO - 'other': {'tests': ['a11yr', 05:38:02 INFO - 'ts_paint', 05:38:02 INFO - 'tpaint', 05:38:02 INFO - 'sessionrestore', 05:38:02 INFO - 'sessionrestore_no_auto_restore']}, 05:38:02 INFO - 'other-e10s': {'talos_options': ['--e10s'], 05:38:02 INFO - 'tests': ['a11yr', 05:38:02 INFO - 'ts_paint', 05:38:02 INFO - 'tpaint', 05:38:02 INFO - 'sessionrestore', 05:38:02 INFO - 'sessionrestore_no_auto_restore']}, 05:38:02 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'], 05:38:02 INFO - 'tests': ['a11yr', 05:38:02 INFO - 'ts_paint', 05:38:02 INFO - 'tpaint', 05:38:02 INFO - 'sessionrestore', 05:38:02 INFO - 'sessionrestore_no_auto_restore']}, 05:38:02 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'], 05:38:02 INFO - 'tests': ['a11yr', 05:38:02 INFO - 'ts_paint', 05:38:02 INFO - 'tpaint', 05:38:02 INFO - 'sessionrestore', 05:38:02 INFO - 'sessionrestore_no_auto_restore']}, 05:38:02 INFO - 'other_l64': {'tests': ['a11yr', 05:38:02 INFO - 'ts_paint', 05:38:02 INFO - 'tpaint', 05:38:02 INFO - 'sessionrestore', 05:38:02 INFO - 'sessionrestore_no_auto_restore']}, 05:38:02 INFO - 'other_nol64': {'tests': ['a11yr', 05:38:02 INFO - 'ts_paint', 05:38:02 INFO - 'tpaint', 05:38:02 INFO - 'sessionrestore', 05:38:02 INFO - 'sessionrestore_no_auto_restore']}, 05:38:02 INFO - 'svgr': {'tests': ['tsvgx', 05:38:02 INFO - 'tsvgr_opacity', 05:38:02 INFO - 'tart', 05:38:02 INFO - 'tscrollx', 05:38:02 INFO - 'cart']}, 05:38:02 INFO - 'svgr-e10s': {'talos_options': ['--e10s'], 05:38:02 INFO - 'tests': ['tsvgx', 05:38:02 INFO - 'tsvgr_opacity', 05:38:02 INFO - 'tart', 05:38:02 INFO - 'tscrollx', 05:38:02 INFO - 'cart']}, 05:38:02 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 05:38:02 INFO - 'tests': ['tp5o']}, 05:38:02 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 05:38:02 INFO - 'talos_options': ['--e10s'], 05:38:02 INFO - 'tests': ['tp5o']}, 05:38:02 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 05:38:02 INFO - 'talos_options': ['--xperf_path', 05:38:02 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 05:38:02 INFO - 'tests': ['tp5n']}, 05:38:02 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 05:38:02 INFO - 'talos_options': ['--e10s', 05:38:02 INFO - '--xperf_path', 05:38:02 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 05:38:02 INFO - 'tests': ['tp5n']}}, 05:38:02 INFO - 'talos.zip': {'path': '', 05:38:02 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}} 05:38:02 INFO - Running post-action listener: _resource_record_post_action 05:38:02 INFO - ##### 05:38:02 INFO - ##### Running create-virtualenv step. 05:38:02 INFO - ##### 05:38:02 INFO - Running pre-action listener: _resource_record_pre_action 05:38:02 INFO - Running main action method: create_virtualenv 05:38:02 INFO - Creating virtualenv /builds/slave/test/build/venv 05:38:02 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 05:38:02 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv 05:38:02 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 05:38:02 INFO - Using real prefix '/usr' 05:38:02 INFO - New python executable in /builds/slave/test/build/venv/bin/python 05:38:02 INFO - Installing distribute.............................................................................................................................................................................................done. 05:38:04 INFO - Installing pip.................done. 05:38:04 INFO - Return code: 0 05:38:04 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 05:38: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')]} 05:38:04 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:38:04 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38: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')]} 05:38:04 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:38:04 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38: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', '--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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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-1447938538.59755-1196598762', '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 05:38:04 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 05:38:04 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 05:38:04 INFO - Using env: {'DISPLAY': ':0', 05:38:04 INFO - 'HOME': '/home/cltbld', 05:38:04 INFO - 'LANG': 'en_US.UTF-8', 05:38:04 INFO - 'LANGUAGE': 'en_US:en', 05:38:04 INFO - 'LOGNAME': 'cltbld', 05:38:04 INFO - 'MAIL': '/var/mail/cltbld', 05:38:04 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:38:04 INFO - 'MOZ_NO_REMOTE': '1', 05:38:04 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:38:04 INFO - 'NO_EM_RESTART': '1', 05:38:04 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:38:04 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:38:04 INFO - 'PWD': '/builds/slave/test', 05:38:04 INFO - 'SHELL': '/bin/bash', 05:38:04 INFO - 'SHLVL': '1', 05:38:04 INFO - 'TERM': 'linux', 05:38:04 INFO - 'TMOUT': '86400', 05:38:04 INFO - 'USER': 'cltbld', 05:38:04 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', 05:38:04 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:38:04 INFO - '_': '/tools/buildbot/bin/python'} 05:38:05 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:38:05 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 05:38:05 INFO - Cleaning up... 05:38:05 INFO - Return code: 0 05:38:05 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv 05:38:05 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')]} 05:38:05 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:38:05 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:05 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')]} 05:38:05 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:38:05 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:05 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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-1447938538.59755-1196598762', '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 05:38:05 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 05:38:05 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 05:38:05 INFO - Using env: {'DISPLAY': ':0', 05:38:05 INFO - 'HOME': '/home/cltbld', 05:38:05 INFO - 'LANG': 'en_US.UTF-8', 05:38:05 INFO - 'LANGUAGE': 'en_US:en', 05:38:05 INFO - 'LOGNAME': 'cltbld', 05:38:05 INFO - 'MAIL': '/var/mail/cltbld', 05:38:05 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:38:05 INFO - 'MOZ_NO_REMOTE': '1', 05:38:05 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:38:05 INFO - 'NO_EM_RESTART': '1', 05:38:05 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:38:05 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:38:05 INFO - 'PWD': '/builds/slave/test', 05:38:05 INFO - 'SHELL': '/bin/bash', 05:38:05 INFO - 'SHLVL': '1', 05:38:05 INFO - 'TERM': 'linux', 05:38:05 INFO - 'TMOUT': '86400', 05:38:05 INFO - 'USER': 'cltbld', 05:38:05 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', 05:38:05 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:38:05 INFO - '_': '/tools/buildbot/bin/python'} 05:38:05 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:38:05 INFO - Downloading/unpacking psutil>=0.7.1 05:38:05 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 05:38:05 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 05:38:05 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 05:38:05 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 05:38:05 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 05:38:05 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 05:38:06 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache 05:38:06 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz 05:38:06 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 05:38:07 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 05:38:07 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 05:38:07 INFO - Installing collected packages: psutil 05:38:07 INFO - Running setup.py install for psutil 05:38:07 INFO - building 'psutil._psutil_linux' extension 05:38:07 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 05:38:07 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 05:38:07 INFO - building 'psutil._psutil_posix' extension 05:38:07 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 05:38:07 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 05:38:07 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 05:38:07 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 05:38:07 INFO - Successfully installed psutil 05:38:07 INFO - Cleaning up... 05:38:07 INFO - Return code: 0 05:38:07 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv 05:38:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 05:38:07 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:38:07 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 05:38:07 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:38:07 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:07 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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-1447938538.59755-1196598762', '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 05:38:07 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 05:38:07 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 05:38:07 INFO - Using env: {'DISPLAY': ':0', 05:38:07 INFO - 'HOME': '/home/cltbld', 05:38:07 INFO - 'LANG': 'en_US.UTF-8', 05:38:07 INFO - 'LANGUAGE': 'en_US:en', 05:38:07 INFO - 'LOGNAME': 'cltbld', 05:38:07 INFO - 'MAIL': '/var/mail/cltbld', 05:38:07 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:38:07 INFO - 'MOZ_NO_REMOTE': '1', 05:38:07 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:38:07 INFO - 'NO_EM_RESTART': '1', 05:38:07 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:38:07 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:38:07 INFO - 'PWD': '/builds/slave/test', 05:38:07 INFO - 'SHELL': '/bin/bash', 05:38:07 INFO - 'SHLVL': '1', 05:38:07 INFO - 'TERM': 'linux', 05:38:07 INFO - 'TMOUT': '86400', 05:38:07 INFO - 'USER': 'cltbld', 05:38:07 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', 05:38:07 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:38:07 INFO - '_': '/tools/buildbot/bin/python'} 05:38:07 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:38:07 INFO - Downloading/unpacking mozsystemmonitor==0.0.0 05:38:07 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 05:38:07 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 05:38:07 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 05:38:07 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 05:38:07 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 05:38:07 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 05:38:09 INFO - Downloading mozsystemmonitor-0.0.tar.gz 05:38:09 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz 05:38:09 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 05:38:09 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0) 05:38:09 INFO - Installing collected packages: mozsystemmonitor 05:38:09 INFO - Running setup.py install for mozsystemmonitor 05:38:09 INFO - Successfully installed mozsystemmonitor 05:38:09 INFO - Cleaning up... 05:38:09 INFO - Return code: 0 05:38:09 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 05:38:09 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')]} 05:38:09 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:38:09 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:09 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')]} 05:38:09 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:38:09 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:09 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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-1447938538.59755-1196598762', '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 05:38:09 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 05:38:09 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 05:38:09 INFO - Using env: {'DISPLAY': ':0', 05:38:09 INFO - 'HOME': '/home/cltbld', 05:38:09 INFO - 'LANG': 'en_US.UTF-8', 05:38:09 INFO - 'LANGUAGE': 'en_US:en', 05:38:09 INFO - 'LOGNAME': 'cltbld', 05:38:09 INFO - 'MAIL': '/var/mail/cltbld', 05:38:09 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:38:09 INFO - 'MOZ_NO_REMOTE': '1', 05:38:09 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:38:09 INFO - 'NO_EM_RESTART': '1', 05:38:09 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:38:09 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:38:09 INFO - 'PWD': '/builds/slave/test', 05:38:09 INFO - 'SHELL': '/bin/bash', 05:38:09 INFO - 'SHLVL': '1', 05:38:09 INFO - 'TERM': 'linux', 05:38:09 INFO - 'TMOUT': '86400', 05:38:09 INFO - 'USER': 'cltbld', 05:38:09 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', 05:38:09 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:38:09 INFO - '_': '/tools/buildbot/bin/python'} 05:38:09 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:38:09 INFO - Downloading/unpacking blobuploader==1.2.4 05:38:09 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 05:38:09 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 05:38:09 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 05:38:09 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 05:38:09 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 05:38:09 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 05:38:11 INFO - Downloading blobuploader-1.2.4.tar.gz 05:38:11 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz 05:38:11 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 05:38:11 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 05:38:11 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 05:38:11 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 05:38:11 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 05:38:11 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 05:38:11 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 05:38:11 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 05:38:11 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz 05:38:11 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 05:38:11 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 05:38:11 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 05:38:11 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 05:38:11 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 05:38:11 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 05:38:11 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 05:38:11 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 05:38:12 INFO - Downloading docopt-0.6.1.tar.gz 05:38:12 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz 05:38:12 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 05:38:12 INFO - Installing collected packages: blobuploader, requests, docopt 05:38:12 INFO - Running setup.py install for blobuploader 05:38:12 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 05:38:12 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 05:38:12 INFO - Running setup.py install for requests 05:38:12 INFO - Running setup.py install for docopt 05:38:12 INFO - Successfully installed blobuploader requests docopt 05:38:12 INFO - Cleaning up... 05:38:12 INFO - Return code: 0 05:38:12 INFO - Installing None into virtualenv /builds/slave/test/build/venv 05:38:12 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')]} 05:38:12 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:38:12 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:12 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')]} 05:38:12 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:38:12 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:12 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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-1447938538.59755-1196598762', '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 05:38:12 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 05:38:12 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 05:38:12 INFO - Using env: {'DISPLAY': ':0', 05:38:12 INFO - 'HOME': '/home/cltbld', 05:38:12 INFO - 'LANG': 'en_US.UTF-8', 05:38:12 INFO - 'LANGUAGE': 'en_US:en', 05:38:12 INFO - 'LOGNAME': 'cltbld', 05:38:12 INFO - 'MAIL': '/var/mail/cltbld', 05:38:12 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:38:12 INFO - 'MOZ_NO_REMOTE': '1', 05:38:12 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:38:12 INFO - 'NO_EM_RESTART': '1', 05:38:12 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:38:12 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:38:12 INFO - 'PWD': '/builds/slave/test', 05:38:12 INFO - 'SHELL': '/bin/bash', 05:38:12 INFO - 'SHLVL': '1', 05:38:12 INFO - 'TERM': 'linux', 05:38:12 INFO - 'TMOUT': '86400', 05:38:12 INFO - 'USER': 'cltbld', 05:38:12 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', 05:38:12 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:38:12 INFO - '_': '/tools/buildbot/bin/python'} 05:38:12 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:38:12 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 05:38:12 INFO - Running setup.py (path:/tmp/pip-3GADbD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 05:38:13 INFO - Running setup.py (path:/tmp/pip-uS1GeD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 05:38:13 INFO - Running setup.py (path:/tmp/pip-VkXuuM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 05:38:13 INFO - Running setup.py (path:/tmp/pip-kxnANZ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 05:38:13 INFO - Running setup.py (path:/tmp/pip-UpfFtk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 05:38:13 INFO - Running setup.py (path:/tmp/pip-mfYHye-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 05:38:13 INFO - Running setup.py (path:/tmp/pip-flJk_7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 05:38:13 INFO - Running setup.py (path:/tmp/pip-fOJvJt-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 05:38:13 INFO - Running setup.py (path:/tmp/pip-e_ZMFB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 05:38:13 INFO - Running setup.py (path:/tmp/pip-FsadUM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 05:38:13 INFO - Running setup.py (path:/tmp/pip-mCDMA3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 05:38:13 INFO - Running setup.py (path:/tmp/pip-GHVHLo-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 05:38:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 05:38:13 INFO - Running setup.py (path:/tmp/pip-AFKWmr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 05:38:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 05:38:14 INFO - Running setup.py (path:/tmp/pip-QJ4kdz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 05:38:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 05:38:14 INFO - Running setup.py (path:/tmp/pip-H1MC_1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 05:38:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 05:38:14 INFO - Running setup.py (path:/tmp/pip-_lqtQB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 05:38:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 05:38:14 INFO - Running setup.py (path:/tmp/pip-l2gC4D-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 05:38:14 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 05:38:14 INFO - Running setup.py install for manifestparser 05:38:14 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 05:38:14 INFO - Running setup.py install for mozcrash 05:38:14 INFO - Running setup.py install for mozdebug 05:38:14 INFO - Running setup.py install for mozdevice 05:38:14 INFO - Installing sutini script to /builds/slave/test/build/venv/bin 05:38:14 INFO - Installing dm script to /builds/slave/test/build/venv/bin 05:38:14 INFO - Running setup.py install for mozfile 05:38:14 INFO - Running setup.py install for mozhttpd 05:38:14 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 05:38:14 INFO - Running setup.py install for mozinfo 05:38:15 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Running setup.py install for mozInstall 05:38:15 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Running setup.py install for mozleak 05:38:15 INFO - Running setup.py install for mozlog 05:38:15 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Running setup.py install for moznetwork 05:38:15 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Running setup.py install for mozprocess 05:38:15 INFO - Running setup.py install for mozprofile 05:38:15 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Running setup.py install for mozrunner 05:38:15 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 05:38:15 INFO - Running setup.py install for mozscreenshot 05:38:15 INFO - Running setup.py install for moztest 05:38:15 INFO - Running setup.py install for mozversion 05:38:16 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 05:38:16 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 05:38:16 INFO - Cleaning up... 05:38:16 INFO - Return code: 0 05:38:16 INFO - Installing None into virtualenv /builds/slave/test/build/venv 05:38:16 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')]} 05:38:16 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:38:16 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:16 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')]} 05:38:16 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:38:16 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:16 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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-1447938538.59755-1196598762', '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 05:38:16 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 05:38:16 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 05:38:16 INFO - Using env: {'DISPLAY': ':0', 05:38:16 INFO - 'HOME': '/home/cltbld', 05:38:16 INFO - 'LANG': 'en_US.UTF-8', 05:38:16 INFO - 'LANGUAGE': 'en_US:en', 05:38:16 INFO - 'LOGNAME': 'cltbld', 05:38:16 INFO - 'MAIL': '/var/mail/cltbld', 05:38:16 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:38:16 INFO - 'MOZ_NO_REMOTE': '1', 05:38:16 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:38:16 INFO - 'NO_EM_RESTART': '1', 05:38:16 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:38:16 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:38:16 INFO - 'PWD': '/builds/slave/test', 05:38:16 INFO - 'SHELL': '/bin/bash', 05:38:16 INFO - 'SHLVL': '1', 05:38:16 INFO - 'TERM': 'linux', 05:38:16 INFO - 'TMOUT': '86400', 05:38:16 INFO - 'USER': 'cltbld', 05:38:16 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', 05:38:16 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:38:16 INFO - '_': '/tools/buildbot/bin/python'} 05:38:16 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 05:38:16 INFO - Running setup.py (path:/tmp/pip-2KvrK6-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 05:38:16 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)) 05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 05:38:16 INFO - Running setup.py (path:/tmp/pip-XKFC67-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 05:38:16 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)) 05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 05:38:16 INFO - Running setup.py (path:/tmp/pip-jHEq39-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 05:38:16 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)) 05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 05:38:16 INFO - Running setup.py (path:/tmp/pip-HsYUTH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 05:38:16 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)) 05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 05:38:16 INFO - Running setup.py (path:/tmp/pip-KLBP7a-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 05:38:16 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)) 05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 05:38:16 INFO - Running setup.py (path:/tmp/pip-13kTNl-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 05:38:16 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)) 05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 05:38:16 INFO - Running setup.py (path:/tmp/pip-TzVxlU-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 05:38:16 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)) 05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 05:38:16 INFO - Running setup.py (path:/tmp/pip-uN7aKG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 05:38:16 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)) 05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 05:38:16 INFO - Running setup.py (path:/tmp/pip-QIiyI_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 05:38:16 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)) 05:38:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 05:38:16 INFO - Running setup.py (path:/tmp/pip-le1kJ0-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 05:38:17 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)) 05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 05:38:17 INFO - Running setup.py (path:/tmp/pip-i2j2gM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 05:38:17 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)) 05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 05:38:17 INFO - Running setup.py (path:/tmp/pip-ly_s4f-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 05:38:17 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)) 05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 05:38:17 INFO - Running setup.py (path:/tmp/pip-UB8Qnq-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 05:38:17 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)) 05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 05:38:17 INFO - Running setup.py (path:/tmp/pip-tiuBwx-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 05:38:17 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)) 05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 05:38:17 INFO - Running setup.py (path:/tmp/pip-xRn1Sr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 05:38:17 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)) 05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 05:38:17 INFO - Running setup.py (path:/tmp/pip-e4PS4s-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 05:38:17 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)) 05:38:17 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 05:38:17 INFO - Running setup.py (path:/tmp/pip-ux332L-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 05:38:17 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)) 05:38:17 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)) 05:38:17 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)) 05:38:17 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)) 05:38:17 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)) 05:38:17 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)) 05:38:17 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 05:38:17 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 05:38:17 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 05:38:17 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 05:38:17 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 05:38:17 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 05:38:17 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 05:38:19 INFO - Downloading blessings-1.5.1.tar.gz 05:38:19 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 05:38:19 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 05:38:19 INFO - Installing collected packages: blessings 05:38:19 INFO - Running setup.py install for blessings 05:38:19 INFO - Successfully installed blessings 05:38:19 INFO - Cleaning up... 05:38:19 INFO - Return code: 0 05:38:19 INFO - Done creating virtualenv /builds/slave/test/build/venv. 05:38:19 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 05:38:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 05:38:19 INFO - Reading from file tmpfile_stdout 05:38:19 INFO - Current package versions: 05:38:19 INFO - argparse == 1.2.1 05:38:19 INFO - blessings == 1.5.1 05:38:19 INFO - blobuploader == 1.2.4 05:38:19 INFO - docopt == 0.6.1 05:38:19 INFO - manifestparser == 1.1 05:38:19 INFO - mozInstall == 1.12 05:38:19 INFO - mozcrash == 0.16 05:38:19 INFO - mozdebug == 0.1 05:38:19 INFO - mozdevice == 0.47 05:38:19 INFO - mozfile == 1.2 05:38:19 INFO - mozhttpd == 0.7 05:38:19 INFO - mozinfo == 0.9 05:38:19 INFO - mozleak == 0.1 05:38:19 INFO - mozlog == 3.0 05:38:19 INFO - moznetwork == 0.27 05:38:19 INFO - mozprocess == 0.22 05:38:19 INFO - mozprofile == 0.27 05:38:19 INFO - mozrunner == 6.11 05:38:19 INFO - mozscreenshot == 0.1 05:38:19 INFO - mozsystemmonitor == 0.0 05:38:19 INFO - moztest == 0.7 05:38:19 INFO - mozversion == 1.4 05:38:19 INFO - psutil == 3.1.1 05:38:19 INFO - requests == 1.2.3 05:38:19 INFO - wsgiref == 0.1.2 05:38:19 INFO - Installing None into virtualenv /builds/slave/test/build/venv 05:38: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')]} 05:38:19 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:38:19 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38: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')]} 05:38:19 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:38:19 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 05:38:19 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 0x7f165f797c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x25726c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2623900>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, '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-1447938538.59755-1196598762', '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 05:38:19 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 05:38:19 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 05:38:19 INFO - Using env: {'DISPLAY': ':0', 05:38:19 INFO - 'HOME': '/home/cltbld', 05:38:19 INFO - 'LANG': 'en_US.UTF-8', 05:38:19 INFO - 'LANGUAGE': 'en_US:en', 05:38:19 INFO - 'LOGNAME': 'cltbld', 05:38:19 INFO - 'MAIL': '/var/mail/cltbld', 05:38:19 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:38:19 INFO - 'MOZ_NO_REMOTE': '1', 05:38:19 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:38:19 INFO - 'NO_EM_RESTART': '1', 05:38:19 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:38:19 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:38:19 INFO - 'PWD': '/builds/slave/test', 05:38:19 INFO - 'SHELL': '/bin/bash', 05:38:19 INFO - 'SHLVL': '1', 05:38:19 INFO - 'TERM': 'linux', 05:38:19 INFO - 'TMOUT': '86400', 05:38:19 INFO - 'USER': 'cltbld', 05:38:19 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', 05:38:19 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:38:19 INFO - '_': '/tools/buildbot/bin/python'} 05:38:19 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:38:19 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)) 05:38:19 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)) 05:38:19 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)) 05:38:19 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)) 05:38:19 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)) 05:38:19 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)) 05:38:19 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)) 05:38:19 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)) 05:38:19 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)) 05:38:19 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)) 05:38:19 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)) 05:38:19 INFO - Cleaning up... 05:38:19 INFO - Return code: 0 05:38:19 INFO - Running post-action listener: _resource_record_post_action 05:38:19 INFO - Running post-action listener: _start_resource_monitoring 05:38:19 INFO - Starting resource monitoring. 05:38:19 INFO - ##### 05:38:19 INFO - ##### Running install step. 05:38:19 INFO - ##### 05:38:19 INFO - Running pre-action listener: _resource_record_pre_action 05:38:19 INFO - Running main action method: install 05:38:19 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 05:38:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 05:38:20 INFO - Reading from file tmpfile_stdout 05:38:20 INFO - Detecting whether we're running mozinstall >=1.0... 05:38:20 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 05:38:20 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 05:38:20 INFO - Reading from file tmpfile_stdout 05:38:20 INFO - Output received: 05:38:20 INFO - Usage: mozinstall [options] installer 05:38:20 INFO - Options: 05:38:20 INFO - -h, --help show this help message and exit 05:38:20 INFO - -d DEST, --destination=DEST 05:38:20 INFO - Directory to install application into. [default: 05:38:20 INFO - "/builds/slave/test"] 05:38:20 INFO - --app=APP Application being installed. [default: firefox] 05:38:20 INFO - mkdir: /builds/slave/test/build/application 05:38:20 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'] 05:38:20 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 05:38:34 INFO - Reading from file tmpfile_stdout 05:38:34 INFO - Output received: 05:38:34 INFO - /builds/slave/test/build/application/firefox/firefox 05:38:34 INFO - Running post-action listener: _resource_record_post_action 05:38:34 INFO - ##### 05:38:34 INFO - ##### Running run-tests step. 05:38:34 INFO - ##### 05:38:34 INFO - Running pre-action listener: _resource_record_pre_action 05:38:34 INFO - Running main action method: run_tests 05:38:34 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 05:38:34 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 05:38:34 INFO - Python 2.7.3 05:38:34 INFO - Return code: 0 05:38:34 INFO - grabbing minidump binary from tooltool 05:38:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 05:38:34 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 0x2669b70>, '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 0x26badc0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x26bb250>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 05:38:34 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 05:38:34 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 05:38:34 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 05:38:34 INFO - Return code: 0 05:38:34 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 05:38:34 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 05:38:34 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 05:38:34 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 05:38:34 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 05:38:34 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/hn_i-YmOSISiPFOXjDDJJg/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 05:38:34 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/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip --title talos-linux64-ix-045 --webServer localhost 05:38:34 INFO - Using env: {'DISPLAY': ':0', 05:38:34 INFO - 'HOME': '/home/cltbld', 05:38:34 INFO - 'LANG': 'en_US.UTF-8', 05:38:34 INFO - 'LANGUAGE': 'en_US:en', 05:38:34 INFO - 'LOGNAME': 'cltbld', 05:38:34 INFO - 'MAIL': '/var/mail/cltbld', 05:38:34 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 05:38:34 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 05:38:34 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:38:34 INFO - 'MOZ_NO_REMOTE': '1', 05:38:34 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 05:38:34 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:38:34 INFO - 'NO_EM_RESTART': '1', 05:38:34 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:38:34 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:38:34 INFO - 'PWD': '/builds/slave/test', 05:38:34 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 05:38:34 INFO - 'SHELL': '/bin/bash', 05:38:34 INFO - 'SHLVL': '1', 05:38:34 INFO - 'TERM': 'linux', 05:38:34 INFO - 'TMOUT': '86400', 05:38:34 INFO - 'USER': 'cltbld', 05:38:34 INFO - 'XDG_SESSION_COOKIE': '61fa6ed41387771909ec0f71000001b3-1447938538.59755-1196598762', 05:38:34 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:38:34 INFO - '_': '/tools/buildbot/bin/python'} 05:38:34 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/hn_i-YmOSISiPFOXjDDJJg/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 05:38:34 INFO - mozversion INFO | application_buildid: 20151119042020 05:38:34 INFO - mozversion INFO | application_changeset: bc29e2e5fac327b36b25e8d38107e09adc0a91b9 05:38:34 INFO - mozversion INFO | application_display_name: Nightly 05:38:34 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 05:38:34 INFO - mozversion INFO | application_name: Firefox 05:38:34 INFO - mozversion INFO | application_remotingname: firefox 05:38:34 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/fx-team 05:38:34 INFO - mozversion INFO | application_vendor: Mozilla 05:38:34 INFO - mozversion INFO | application_version: 45.0a1 05:38:34 INFO - mozversion INFO | platform_buildid: 20151119042020 05:38:34 INFO - mozversion INFO | platform_changeset: bc29e2e5fac327b36b25e8d38107e09adc0a91b9 05:38:34 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/fx-team 05:38:34 INFO - mozversion INFO | platform_version: 45.0a1 05:38:34 INFO - 2015-11-19 05:38:34,523 DEBUG : using testdate: 1447940314 05:38:34 INFO - 2015-11-19 05:38:34,523 DEBUG : actual date: 1447940314 05:38:34 INFO - 2015-11-19 05:38:34,531 INFO : starting webserver on 'localhost:59992' 05:38:34 INFO - 2015-11-19 05:38:34,532 INFO : Starting test suite talos-linux64-ix-045.e 05:38:34 INFO - 2015-11-19 05:38:34,532 INFO : Starting test a11yr 05:38:34 INFO - 2015-11-19 05:38:34,532 DEBUG : operating with platform_type : linux_ 05:38:34 INFO - 2015-11-19 05:38:34,533 INFO : Initialising browser for a11yr test... 05:38:34 INFO - 2015-11-19 05:38:34,545 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_gMzSk/profile http://localhost:59992/getInfo.html 05:38:39 INFO - 2015-11-19 05:38:39,206 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 05:38:39 INFO - 2015-11-19 05:38:39,207 DEBUG : BROWSER_OUTPUT: colorDepth:24 05:38:39 INFO - 2015-11-19 05:38:39,207 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 05:38:39 INFO - 2015-11-19 05:38:39,207 DEBUG : BROWSER_OUTPUT: __metrics 05:38:40 INFO - 2015-11-19 05:38:40,325 INFO : Browser initialized. 05:38:40 INFO - 2015-11-19 05:38:40,326 INFO : Running cycle 1/1 for a11yr test... 05:38:40 INFO - 2015-11-19 05:38:40,326 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_gMzSk/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25 05:38:52 INFO - 2015-11-19 05:38:52,344 DEBUG : BROWSER_OUTPUT: RSS: Main: 141918208 05:38:52 INFO - 2015-11-19 05:38:52,345 DEBUG : BROWSER_OUTPUT: 05:38:53 INFO - 2015-11-19 05:38:53,633 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) 05:38:53 INFO - 2015-11-19 05:38:53,770 DEBUG : BROWSER_OUTPUT: 05:38:53 INFO - 2015-11-19 05:38:53,770 DEBUG : BROWSER_OUTPUT: (firefox:4447): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 05:38:53 INFO - 2015-11-19 05:38:53,770 DEBUG : BROWSER_OUTPUT: 05:38:53 INFO - 2015-11-19 05:38:53,770 DEBUG : BROWSER_OUTPUT: (firefox:4447): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 05:38:53 INFO - 2015-11-19 05:38:53,826 DEBUG : BROWSER_OUTPUT: 05:38:53 INFO - 2015-11-19 05:38:53,826 DEBUG : BROWSER_OUTPUT: (firefox:4447): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 05:38:54 INFO - 2015-11-19 05:38:54,267 DEBUG : BROWSER_OUTPUT: RSS: Main: 147214336 05:38:54 INFO - 2015-11-19 05:38:54,267 DEBUG : BROWSER_OUTPUT: 05:38:55 INFO - 2015-11-19 05:38:55,659 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) 05:38:56 INFO - 2015-11-19 05:38:56,361 DEBUG : BROWSER_OUTPUT: RSS: Main: 146321408 05:38:56 INFO - 2015-11-19 05:38:56,361 DEBUG : BROWSER_OUTPUT: 05:38:57 INFO - 2015-11-19 05:38:57,746 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) 05:38:58 INFO - 2015-11-19 05:38:58,447 DEBUG : BROWSER_OUTPUT: RSS: Main: 146010112 05:38:58 INFO - 2015-11-19 05:38:58,447 DEBUG : BROWSER_OUTPUT: 05:38:59 INFO - 2015-11-19 05:38:59,873 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) 05:39:00 INFO - 2015-11-19 05:39:00,626 DEBUG : BROWSER_OUTPUT: RSS: Main: 145678336 05:39:00 INFO - 2015-11-19 05:39:00,626 DEBUG : BROWSER_OUTPUT: 05:39:02 INFO - 2015-11-19 05:39:02,012 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) 05:39:02 INFO - 2015-11-19 05:39:02,774 DEBUG : BROWSER_OUTPUT: RSS: Main: 142524416 05:39:02 INFO - 2015-11-19 05:39:02,774 DEBUG : BROWSER_OUTPUT: 05:39:04 INFO - 2015-11-19 05:39:04,150 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) 05:39:04 INFO - 2015-11-19 05:39:04,852 DEBUG : BROWSER_OUTPUT: RSS: Main: 143552512 05:39:04 INFO - 2015-11-19 05:39:04,853 DEBUG : BROWSER_OUTPUT: 05:39:06 INFO - 2015-11-19 05:39:06,270 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) 05:39:07 INFO - 2015-11-19 05:39:07,024 DEBUG : BROWSER_OUTPUT: RSS: Main: 142475264 05:39:07 INFO - 2015-11-19 05:39:07,024 DEBUG : BROWSER_OUTPUT: 05:39:08 INFO - 2015-11-19 05:39:08,436 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) 05:39:09 INFO - 2015-11-19 05:39:09,138 DEBUG : BROWSER_OUTPUT: RSS: Main: 143634432 05:39:09 INFO - 2015-11-19 05:39:09,138 DEBUG : BROWSER_OUTPUT: 05:39:10 INFO - 2015-11-19 05:39:10,717 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) 05:39:11 INFO - 2015-11-19 05:39:11,423 DEBUG : BROWSER_OUTPUT: RSS: Main: 143343616 05:39:11 INFO - 2015-11-19 05:39:11,424 DEBUG : BROWSER_OUTPUT: 05:39:13 INFO - 2015-11-19 05:39:13,001 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) 05:39:13 INFO - 2015-11-19 05:39:13,704 DEBUG : BROWSER_OUTPUT: RSS: Main: 143278080 05:39:13 INFO - 2015-11-19 05:39:13,704 DEBUG : BROWSER_OUTPUT: 05:39:15 INFO - 2015-11-19 05:39:15,073 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) 05:39:15 INFO - 2015-11-19 05:39:15,780 DEBUG : BROWSER_OUTPUT: RSS: Main: 143466496 05:39:15 INFO - 2015-11-19 05:39:15,780 DEBUG : BROWSER_OUTPUT: 05:39:17 INFO - 2015-11-19 05:39:17,176 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) 05:39:17 INFO - 2015-11-19 05:39:17,883 DEBUG : BROWSER_OUTPUT: RSS: Main: 143765504 05:39:17 INFO - 2015-11-19 05:39:17,883 DEBUG : BROWSER_OUTPUT: 05:39:19 INFO - 2015-11-19 05:39:19,482 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) 05:39:20 INFO - 2015-11-19 05:39:20,184 DEBUG : BROWSER_OUTPUT: RSS: Main: 143319040 05:39:20 INFO - 2015-11-19 05:39:20,184 DEBUG : BROWSER_OUTPUT: 05:39:21 INFO - 2015-11-19 05:39:21,595 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) 05:39:22 INFO - 2015-11-19 05:39:22,362 DEBUG : BROWSER_OUTPUT: RSS: Main: 143818752 05:39:22 INFO - 2015-11-19 05:39:22,362 DEBUG : BROWSER_OUTPUT: 05:39:23 INFO - 2015-11-19 05:39:23,977 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) 05:39:24 INFO - 2015-11-19 05:39:24,684 DEBUG : BROWSER_OUTPUT: RSS: Main: 143175680 05:39:24 INFO - 2015-11-19 05:39:24,684 DEBUG : BROWSER_OUTPUT: 05:39:26 INFO - 2015-11-19 05:39:26,061 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) 05:39:26 INFO - 2015-11-19 05:39:26,763 DEBUG : BROWSER_OUTPUT: RSS: Main: 143273984 05:39:26 INFO - 2015-11-19 05:39:26,763 DEBUG : BROWSER_OUTPUT: 05:39:28 INFO - 2015-11-19 05:39:28,156 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) 05:39:28 INFO - 2015-11-19 05:39:28,863 DEBUG : BROWSER_OUTPUT: RSS: Main: 143183872 05:39:28 INFO - 2015-11-19 05:39:28,863 DEBUG : BROWSER_OUTPUT: 05:39:30 INFO - 2015-11-19 05:39:30,268 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) 05:39:30 INFO - 2015-11-19 05:39:30,962 DEBUG : BROWSER_OUTPUT: RSS: Main: 141996032 05:39:30 INFO - 2015-11-19 05:39:30,962 DEBUG : BROWSER_OUTPUT: 05:39:32 INFO - 2015-11-19 05:39:32,392 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) 05:39:33 INFO - 2015-11-19 05:39:33,094 DEBUG : BROWSER_OUTPUT: RSS: Main: 142860288 05:39:33 INFO - 2015-11-19 05:39:33,094 DEBUG : BROWSER_OUTPUT: 05:39:34 INFO - 2015-11-19 05:39:34,483 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) 05:39:35 INFO - 2015-11-19 05:39:35,191 DEBUG : BROWSER_OUTPUT: RSS: Main: 142868480 05:39:35 INFO - 2015-11-19 05:39:35,191 DEBUG : BROWSER_OUTPUT: 05:39:36 INFO - 2015-11-19 05:39:36,575 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) 05:39:37 INFO - 2015-11-19 05:39:37,277 DEBUG : BROWSER_OUTPUT: RSS: Main: 143155200 05:39:37 INFO - 2015-11-19 05:39:37,277 DEBUG : BROWSER_OUTPUT: 05:39:38 INFO - 2015-11-19 05:39:38,682 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 05:39:39 INFO - 2015-11-19 05:39:39,397 DEBUG : BROWSER_OUTPUT: RSS: Main: 143560704 05:39:39 INFO - 2015-11-19 05:39:39,397 DEBUG : BROWSER_OUTPUT: 05:39:40 INFO - 2015-11-19 05:39:40,802 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) 05:39:41 INFO - 2015-11-19 05:39:41,511 DEBUG : BROWSER_OUTPUT: RSS: Main: 150597632 05:39:41 INFO - 2015-11-19 05:39:41,511 DEBUG : BROWSER_OUTPUT: 05:39:41 INFO - 2015-11-19 05:39:41,990 DEBUG : BROWSER_OUTPUT: 1447940381983 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] 05:39:42 INFO - 2015-11-19 05:39:42,937 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) 05:39:43 INFO - 2015-11-19 05:39:43,658 DEBUG : BROWSER_OUTPUT: RSS: Main: 158507008 05:39:43 INFO - 2015-11-19 05:39:43,659 DEBUG : BROWSER_OUTPUT: 05:39:45 INFO - 2015-11-19 05:39:45,043 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) 05:39:45 INFO - 2015-11-19 05:39:45,757 DEBUG : BROWSER_OUTPUT: RSS: Main: 157929472 05:39:45 INFO - 2015-11-19 05:39:45,757 DEBUG : BROWSER_OUTPUT: 05:39:46 INFO - 2015-11-19 05:39:46,140 DEBUG : BROWSER_OUTPUT: 05:39:46 INFO - 2015-11-19 05:39:46,140 DEBUG : BROWSER_OUTPUT: (firefox:4447): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 05:39:46 INFO - 2015-11-19 05:39:46,719 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) 05:39:47 INFO - 2015-11-19 05:39:47,309 DEBUG : BROWSER_OUTPUT: RSS: Main: 152285184 05:39:47 INFO - 2015-11-19 05:39:47,309 DEBUG : BROWSER_OUTPUT: 05:39:48 INFO - 2015-11-19 05:39:48,243 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) 05:39:48 INFO - 2015-11-19 05:39:48,845 DEBUG : BROWSER_OUTPUT: RSS: Main: 152743936 05:39:48 INFO - 2015-11-19 05:39:48,845 DEBUG : BROWSER_OUTPUT: 05:39:49 INFO - 2015-11-19 05:39:49,766 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) 05:39:50 INFO - 2015-11-19 05:39:50,367 DEBUG : BROWSER_OUTPUT: RSS: Main: 151793664 05:39:50 INFO - 2015-11-19 05:39:50,367 DEBUG : BROWSER_OUTPUT: 05:39:51 INFO - 2015-11-19 05:39:51,322 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) 05:39:51 INFO - 2015-11-19 05:39:51,928 DEBUG : BROWSER_OUTPUT: RSS: Main: 150601728 05:39:51 INFO - 2015-11-19 05:39:51,928 DEBUG : BROWSER_OUTPUT: 05:39:52 INFO - 2015-11-19 05:39:52,891 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) 05:39:53 INFO - 2015-11-19 05:39:53,484 DEBUG : BROWSER_OUTPUT: RSS: Main: 144220160 05:39:53 INFO - 2015-11-19 05:39:53,484 DEBUG : BROWSER_OUTPUT: 05:39:54 INFO - 2015-11-19 05:39:54,431 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) 05:39:55 INFO - 2015-11-19 05:39:55,032 DEBUG : BROWSER_OUTPUT: RSS: Main: 143130624 05:39:55 INFO - 2015-11-19 05:39:55,032 DEBUG : BROWSER_OUTPUT: 05:39:55 INFO - 2015-11-19 05:39:55,946 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) 05:39:56 INFO - 2015-11-19 05:39:56,548 DEBUG : BROWSER_OUTPUT: RSS: Main: 141570048 05:39:56 INFO - 2015-11-19 05:39:56,548 DEBUG : BROWSER_OUTPUT: 05:39:57 INFO - 2015-11-19 05:39:57,494 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) 05:39:58 INFO - 2015-11-19 05:39:58,095 DEBUG : BROWSER_OUTPUT: RSS: Main: 141824000 05:39:58 INFO - 2015-11-19 05:39:58,095 DEBUG : BROWSER_OUTPUT: 05:39:59 INFO - 2015-11-19 05:39:59,005 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) 05:39:59 INFO - 2015-11-19 05:39:59,607 DEBUG : BROWSER_OUTPUT: RSS: Main: 141479936 05:39:59 INFO - 2015-11-19 05:39:59,607 DEBUG : BROWSER_OUTPUT: 05:40:00 INFO - 2015-11-19 05:40:00,549 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) 05:40:01 INFO - 2015-11-19 05:40:01,155 DEBUG : BROWSER_OUTPUT: RSS: Main: 141811712 05:40:01 INFO - 2015-11-19 05:40:01,155 DEBUG : BROWSER_OUTPUT: 05:40:02 INFO - 2015-11-19 05:40:02,089 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) 05:40:02 INFO - 2015-11-19 05:40:02,691 DEBUG : BROWSER_OUTPUT: RSS: Main: 141414400 05:40:02 INFO - 2015-11-19 05:40:02,691 DEBUG : BROWSER_OUTPUT: 05:40:03 INFO - 2015-11-19 05:40:03,634 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) 05:40:04 INFO - 2015-11-19 05:40:04,240 DEBUG : BROWSER_OUTPUT: RSS: Main: 141668352 05:40:04 INFO - 2015-11-19 05:40:04,240 DEBUG : BROWSER_OUTPUT: 05:40:05 INFO - 2015-11-19 05:40:05,174 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) 05:40:05 INFO - 2015-11-19 05:40:05,775 DEBUG : BROWSER_OUTPUT: RSS: Main: 141602816 05:40:05 INFO - 2015-11-19 05:40:05,776 DEBUG : BROWSER_OUTPUT: 05:40:06 INFO - 2015-11-19 05:40:06,682 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) 05:40:07 INFO - 2015-11-19 05:40:07,285 DEBUG : BROWSER_OUTPUT: RSS: Main: 141770752 05:40:07 INFO - 2015-11-19 05:40:07,286 DEBUG : BROWSER_OUTPUT: 05:40:08 INFO - 2015-11-19 05:40:08,208 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) 05:40:08 INFO - 2015-11-19 05:40:08,810 DEBUG : BROWSER_OUTPUT: RSS: Main: 141742080 05:40:08 INFO - 2015-11-19 05:40:08,810 DEBUG : BROWSER_OUTPUT: 05:40:09 INFO - 2015-11-19 05:40:09,764 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) 05:40:10 INFO - 2015-11-19 05:40:10,370 DEBUG : BROWSER_OUTPUT: RSS: Main: 141688832 05:40:10 INFO - 2015-11-19 05:40:10,370 DEBUG : BROWSER_OUTPUT: 05:40:11 INFO - 2015-11-19 05:40:11,297 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) 05:40:11 INFO - 2015-11-19 05:40:11,898 DEBUG : BROWSER_OUTPUT: RSS: Main: 141647872 05:40:11 INFO - 2015-11-19 05:40:11,898 DEBUG : BROWSER_OUTPUT: 05:40:12 INFO - 2015-11-19 05:40:12,840 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) 05:40:13 INFO - 2015-11-19 05:40:13,442 DEBUG : BROWSER_OUTPUT: RSS: Main: 142970880 05:40:13 INFO - 2015-11-19 05:40:13,442 DEBUG : BROWSER_OUTPUT: 05:40:14 INFO - 2015-11-19 05:40:14,405 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) 05:40:15 INFO - 2015-11-19 05:40:15,011 DEBUG : BROWSER_OUTPUT: RSS: Main: 141160448 05:40:15 INFO - 2015-11-19 05:40:15,011 DEBUG : BROWSER_OUTPUT: 05:40:15 INFO - 2015-11-19 05:40:15,933 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) 05:40:16 INFO - 2015-11-19 05:40:16,534 DEBUG : BROWSER_OUTPUT: RSS: Main: 142901248 05:40:16 INFO - 2015-11-19 05:40:16,534 DEBUG : BROWSER_OUTPUT: 05:40:17 INFO - 2015-11-19 05:40:17,456 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) 05:40:18 INFO - 2015-11-19 05:40:18,057 DEBUG : BROWSER_OUTPUT: RSS: Main: 141115392 05:40:18 INFO - 2015-11-19 05:40:18,057 DEBUG : BROWSER_OUTPUT: 05:40:18 INFO - 2015-11-19 05:40:18,979 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) 05:40:19 INFO - 2015-11-19 05:40:19,572 DEBUG : BROWSER_OUTPUT: RSS: Main: 142802944 05:40:19 INFO - 2015-11-19 05:40:19,573 DEBUG : BROWSER_OUTPUT: 05:40:20 INFO - 2015-11-19 05:40:20,493 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) 05:40:21 INFO - 2015-11-19 05:40:21,094 DEBUG : BROWSER_OUTPUT: RSS: Main: 143052800 05:40:21 INFO - 2015-11-19 05:40:21,095 DEBUG : BROWSER_OUTPUT: 05:40:22 INFO - 2015-11-19 05:40:22,029 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) 05:40:22 INFO - 2015-11-19 05:40:22,630 DEBUG : BROWSER_OUTPUT: RSS: Main: 142974976 05:40:22 INFO - 2015-11-19 05:40:22,631 DEBUG : BROWSER_OUTPUT: 05:40:23 INFO - 2015-11-19 05:40:23,557 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) 05:40:23 INFO - 2015-11-19 05:40:23,807 DEBUG : BROWSER_OUTPUT: RSS: Main: 142757888 05:40:23 INFO - 2015-11-19 05:40:23,808 DEBUG : BROWSER_OUTPUT: 05:40:23 INFO - 2015-11-19 05:40:23,808 DEBUG : BROWSER_OUTPUT: __start_tp_report 05:40:23 INFO - 2015-11-19 05:40:23,808 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load 05:40:23 INFO - 2015-11-19 05:40:23,808 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details 05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: |i|pagename|runs| 05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1261;1299;1307;1341;1328;1323;1344;1330;1524;1525;1315;1325;1526;1334;1527;1322;1316;1313;1348;1324;1331;1329;1333;1339;1320 05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;380;381;377;383;390;388;378;390;378;392;387;385;399;377;388;393;393;387;402;384;380;379;387;397;386 05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: __end_tp_report 05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: __start_cc_report 05:40:23 INFO - 2015-11-19 05:40:23,809 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,2755 05:40:23 INFO - 2015-11-19 05:40:23,810 DEBUG : BROWSER_OUTPUT: __end_cc_report 05:40:23 INFO - 2015-11-19 05:40:23,811 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940423807__endTimestamp 05:40:23 INFO - 2015-11-19 05:40:23,811 DEBUG : BROWSER_OUTPUT: 05:40:23 INFO - 2015-11-19 05:40:23,811 DEBUG : BROWSER_OUTPUT: ------- Summary: start ------- 05:40:23 INFO - 2015-11-19 05:40:23,811 DEBUG : BROWSER_OUTPUT: Number of tests: 2 05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: 05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1355.36 Median:1329.00 stddev:77.67 (5.8%) stddev-sans-first:76.76 05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: Values: 1261.0 1299.0 1307.0 1341.0 1328.0 1323.0 1344.0 1330.0 1524.0 1525.0 1315.0 1325.0 1526.0 1334.0 1527.0 1322.0 1316.0 1313.0 1348.0 1324.0 1331.0 1329.0 1333.0 1339.0 1320.0 05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: 05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:386.44 Median:387.00 stddev:6.98 (1.8%) stddev-sans-first:6.99 05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: Values: 380.0 381.0 377.0 383.0 390.0 388.0 378.0 390.0 378.0 392.0 387.0 385.0 399.0 377.0 388.0 393.0 393.0 387.0 402.0 384.0 380.0 379.0 387.0 397.0 386.0 05:40:23 INFO - 2015-11-19 05:40:23,812 DEBUG : BROWSER_OUTPUT: -------- Summary: end -------- 05:40:23 INFO - 2015-11-19 05:40:23,813 DEBUG : BROWSER_OUTPUT: 05:40:24 INFO - 2015-11-19 05:40:24,537 INFO : Browser exited with error code: 0 05:40:24 INFO - 2015-11-19 05:40:24,551 INFO : Completed test a11yr (00:01:50) 05:40:24 INFO - 2015-11-19 05:40:24,551 INFO : Starting test ts_paint 05:40:24 INFO - 2015-11-19 05:40:24,551 DEBUG : operating with platform_type : linux_ 05:40:24 INFO - 2015-11-19 05:40:24,551 INFO : Initialising browser for ts_paint test... 05:40:24 INFO - 2015-11-19 05:40:24,557 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/getInfo.html 05:40:29 INFO - 2015-11-19 05:40:29,054 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 05:40:29 INFO - 2015-11-19 05:40:29,055 DEBUG : BROWSER_OUTPUT: colorDepth:24 05:40:29 INFO - 2015-11-19 05:40:29,055 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 05:40:29 INFO - 2015-11-19 05:40:29,055 DEBUG : BROWSER_OUTPUT: __metrics 05:40:30 INFO - 2015-11-19 05:40:30,189 INFO : Browser initialized. 05:40:30 INFO - 2015-11-19 05:40:30,190 INFO : Running cycle 1/20 for ts_paint test... 05:40:30 INFO - 2015-11-19 05:40:30,190 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:32 INFO - 2015-11-19 05:40:32,309 DEBUG : BROWSER_OUTPUT: __start_report480__end_report 05:40:32 INFO - 2015-11-19 05:40:32,309 DEBUG : BROWSER_OUTPUT: 05:40:32 INFO - 2015-11-19 05:40:32,317 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940432313__endTimestamp 05:40:33 INFO - 2015-11-19 05:40:33,273 INFO : Browser exited with error code: 0 05:40:33 INFO - 2015-11-19 05:40:33,275 INFO : Running cycle 2/20 for ts_paint test... 05:40:33 INFO - 2015-11-19 05:40:33,275 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:34 INFO - 2015-11-19 05:40:34,921 DEBUG : BROWSER_OUTPUT: __start_report571__end_report 05:40:34 INFO - 2015-11-19 05:40:34,921 DEBUG : BROWSER_OUTPUT: 05:40:34 INFO - 2015-11-19 05:40:34,937 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940434931__endTimestamp 05:40:35 INFO - 2015-11-19 05:40:35,877 INFO : Browser exited with error code: 0 05:40:35 INFO - 2015-11-19 05:40:35,879 INFO : Running cycle 3/20 for ts_paint test... 05:40:35 INFO - 2015-11-19 05:40:35,879 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:37 INFO - 2015-11-19 05:40:37,525 DEBUG : BROWSER_OUTPUT: __start_report511__end_report 05:40:37 INFO - 2015-11-19 05:40:37,525 DEBUG : BROWSER_OUTPUT: 05:40:37 INFO - 2015-11-19 05:40:37,529 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940437528__endTimestamp 05:40:38 INFO - 2015-11-19 05:40:38,478 INFO : Browser exited with error code: 0 05:40:38 INFO - 2015-11-19 05:40:38,480 INFO : Running cycle 4/20 for ts_paint test... 05:40:38 INFO - 2015-11-19 05:40:38,480 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:40 INFO - 2015-11-19 05:40:40,133 DEBUG : BROWSER_OUTPUT: __start_report523__end_report 05:40:40 INFO - 2015-11-19 05:40:40,133 DEBUG : BROWSER_OUTPUT: 05:40:40 INFO - 2015-11-19 05:40:40,141 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940440137__endTimestamp 05:40:41 INFO - 2015-11-19 05:40:41,153 INFO : Browser exited with error code: 0 05:40:41 INFO - 2015-11-19 05:40:41,155 INFO : Running cycle 5/20 for ts_paint test... 05:40:41 INFO - 2015-11-19 05:40:41,155 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:42 INFO - 2015-11-19 05:40:42,788 DEBUG : BROWSER_OUTPUT: __start_report519__end_report 05:40:42 INFO - 2015-11-19 05:40:42,788 DEBUG : BROWSER_OUTPUT: 05:40:42 INFO - 2015-11-19 05:40:42,804 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940442798__endTimestamp 05:40:43 INFO - 2015-11-19 05:40:43,837 INFO : Browser exited with error code: 0 05:40:43 INFO - 2015-11-19 05:40:43,839 INFO : Running cycle 6/20 for ts_paint test... 05:40:43 INFO - 2015-11-19 05:40:43,839 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:45 INFO - 2015-11-19 05:40:45,461 DEBUG : BROWSER_OUTPUT: __start_report520__end_report 05:40:45 INFO - 2015-11-19 05:40:45,462 DEBUG : BROWSER_OUTPUT: 05:40:45 INFO - 2015-11-19 05:40:45,478 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940445471__endTimestamp 05:40:46 INFO - 2015-11-19 05:40:46,525 INFO : Browser exited with error code: 0 05:40:46 INFO - 2015-11-19 05:40:46,527 INFO : Running cycle 7/20 for ts_paint test... 05:40:46 INFO - 2015-11-19 05:40:46,527 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:48 INFO - 2015-11-19 05:40:48,167 DEBUG : BROWSER_OUTPUT: __start_report523__end_report 05:40:48 INFO - 2015-11-19 05:40:48,167 DEBUG : BROWSER_OUTPUT: 05:40:48 INFO - 2015-11-19 05:40:48,169 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940448168__endTimestamp 05:40:49 INFO - 2015-11-19 05:40:49,237 INFO : Browser exited with error code: 0 05:40:49 INFO - 2015-11-19 05:40:49,239 INFO : Running cycle 8/20 for ts_paint test... 05:40:49 INFO - 2015-11-19 05:40:49,239 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:50 INFO - 2015-11-19 05:40:50,914 DEBUG : BROWSER_OUTPUT: __start_report554__end_report 05:40:50 INFO - 2015-11-19 05:40:50,914 DEBUG : BROWSER_OUTPUT: 05:40:50 INFO - 2015-11-19 05:40:50,930 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940450922__endTimestamp 05:40:51 INFO - 2015-11-19 05:40:51,981 INFO : Browser exited with error code: 0 05:40:51 INFO - 2015-11-19 05:40:51,983 INFO : Running cycle 9/20 for ts_paint test... 05:40:51 INFO - 2015-11-19 05:40:51,983 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:53 INFO - 2015-11-19 05:40:53,569 DEBUG : BROWSER_OUTPUT: __start_report504__end_report 05:40:53 INFO - 2015-11-19 05:40:53,570 DEBUG : BROWSER_OUTPUT: 05:40:53 INFO - 2015-11-19 05:40:53,585 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940453581__endTimestamp 05:40:54 INFO - 2015-11-19 05:40:54,641 INFO : Browser exited with error code: 0 05:40:54 INFO - 2015-11-19 05:40:54,643 INFO : Running cycle 10/20 for ts_paint test... 05:40:54 INFO - 2015-11-19 05:40:54,643 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:56 INFO - 2015-11-19 05:40:56,358 DEBUG : BROWSER_OUTPUT: __start_report618__end_report 05:40:56 INFO - 2015-11-19 05:40:56,358 DEBUG : BROWSER_OUTPUT: 05:40:56 INFO - 2015-11-19 05:40:56,366 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940456362__endTimestamp 05:40:57 INFO - 2015-11-19 05:40:57,397 INFO : Browser exited with error code: 0 05:40:57 INFO - 2015-11-19 05:40:57,399 INFO : Running cycle 11/20 for ts_paint test... 05:40:57 INFO - 2015-11-19 05:40:57,399 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:40:59 INFO - 2015-11-19 05:40:59,025 DEBUG : BROWSER_OUTPUT: __start_report520__end_report 05:40:59 INFO - 2015-11-19 05:40:59,025 DEBUG : BROWSER_OUTPUT: 05:40:59 INFO - 2015-11-19 05:40:59,041 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940459033__endTimestamp 05:41:00 INFO - 2015-11-19 05:41:00,057 INFO : Browser exited with error code: 0 05:41:00 INFO - 2015-11-19 05:41:00,059 INFO : Running cycle 12/20 for ts_paint test... 05:41:00 INFO - 2015-11-19 05:41:00,059 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:41:01 INFO - 2015-11-19 05:41:01,701 DEBUG : BROWSER_OUTPUT: __start_report554__end_report 05:41:01 INFO - 2015-11-19 05:41:01,701 DEBUG : BROWSER_OUTPUT: 05:41:01 INFO - 2015-11-19 05:41:01,717 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940461712__endTimestamp 05:41:02 INFO - 2015-11-19 05:41:02,805 INFO : Browser exited with error code: 0 05:41:02 INFO - 2015-11-19 05:41:02,807 INFO : Running cycle 13/20 for ts_paint test... 05:41:02 INFO - 2015-11-19 05:41:02,807 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:41:04 INFO - 2015-11-19 05:41:04,467 DEBUG : BROWSER_OUTPUT: __start_report549__end_report 05:41:04 INFO - 2015-11-19 05:41:04,467 DEBUG : BROWSER_OUTPUT: 05:41:04 INFO - 2015-11-19 05:41:04,483 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940464476__endTimestamp 05:41:05 INFO - 2015-11-19 05:41:05,605 INFO : Browser exited with error code: 0 05:41:05 INFO - 2015-11-19 05:41:05,607 INFO : Running cycle 14/20 for ts_paint test... 05:41:05 INFO - 2015-11-19 05:41:05,607 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:41:07 INFO - 2015-11-19 05:41:07,224 DEBUG : BROWSER_OUTPUT: __start_report517__end_report 05:41:07 INFO - 2015-11-19 05:41:07,225 DEBUG : BROWSER_OUTPUT: 05:41:07 INFO - 2015-11-19 05:41:07,232 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940467230__endTimestamp 05:41:08 INFO - 2015-11-19 05:41:08,329 INFO : Browser exited with error code: 0 05:41:08 INFO - 2015-11-19 05:41:08,331 INFO : Running cycle 15/20 for ts_paint test... 05:41:08 INFO - 2015-11-19 05:41:08,331 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:41:09 INFO - 2015-11-19 05:41:09,970 DEBUG : BROWSER_OUTPUT: __start_report541__end_report 05:41:09 INFO - 2015-11-19 05:41:09,970 DEBUG : BROWSER_OUTPUT: 05:41:09 INFO - 2015-11-19 05:41:09,978 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940469977__endTimestamp 05:41:11 INFO - 2015-11-19 05:41:11,021 INFO : Browser exited with error code: 0 05:41:11 INFO - 2015-11-19 05:41:11,023 INFO : Running cycle 16/20 for ts_paint test... 05:41:11 INFO - 2015-11-19 05:41:11,023 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:41:12 INFO - 2015-11-19 05:41:12,656 DEBUG : BROWSER_OUTPUT: __start_report503__end_report 05:41:12 INFO - 2015-11-19 05:41:12,656 DEBUG : BROWSER_OUTPUT: 05:41:12 INFO - 2015-11-19 05:41:12,663 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940472663__endTimestamp 05:41:13 INFO - 2015-11-19 05:41:13,749 INFO : Browser exited with error code: 0 05:41:13 INFO - 2015-11-19 05:41:13,751 INFO : Running cycle 17/20 for ts_paint test... 05:41:13 INFO - 2015-11-19 05:41:13,751 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:41:15 INFO - 2015-11-19 05:41:15,390 DEBUG : BROWSER_OUTPUT: __start_report534__end_report 05:41:15 INFO - 2015-11-19 05:41:15,390 DEBUG : BROWSER_OUTPUT: 05:41:15 INFO - 2015-11-19 05:41:15,406 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940475399__endTimestamp 05:41:16 INFO - 2015-11-19 05:41:16,481 INFO : Browser exited with error code: 0 05:41:16 INFO - 2015-11-19 05:41:16,483 INFO : Running cycle 18/20 for ts_paint test... 05:41:16 INFO - 2015-11-19 05:41:16,483 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:41:18 INFO - 2015-11-19 05:41:18,161 DEBUG : BROWSER_OUTPUT: __start_report562__end_report 05:41:18 INFO - 2015-11-19 05:41:18,161 DEBUG : BROWSER_OUTPUT: 05:41:18 INFO - 2015-11-19 05:41:18,177 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940478170__endTimestamp 05:41:19 INFO - 2015-11-19 05:41:19,261 INFO : Browser exited with error code: 0 05:41:19 INFO - 2015-11-19 05:41:19,263 INFO : Running cycle 19/20 for ts_paint test... 05:41:19 INFO - 2015-11-19 05:41:19,263 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:41:20 INFO - 2015-11-19 05:41:20,928 DEBUG : BROWSER_OUTPUT: __start_report513__end_report 05:41:20 INFO - 2015-11-19 05:41:20,928 DEBUG : BROWSER_OUTPUT: 05:41:20 INFO - 2015-11-19 05:41:20,944 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940480936__endTimestamp 05:41:22 INFO - 2015-11-19 05:41:22,025 INFO : Browser exited with error code: 0 05:41:22 INFO - 2015-11-19 05:41:22,027 INFO : Running cycle 20/20 for ts_paint test... 05:41:22 INFO - 2015-11-19 05:41:22,027 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpEtccsd/profile http://localhost:59992/startup_test/tspaint_test.html 05:41:23 INFO - 2015-11-19 05:41:23,708 DEBUG : BROWSER_OUTPUT: __start_report556__end_report 05:41:23 INFO - 2015-11-19 05:41:23,708 DEBUG : BROWSER_OUTPUT: 05:41:23 INFO - 2015-11-19 05:41:23,724 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940483718__endTimestamp 05:41:24 INFO - 2015-11-19 05:41:24,849 INFO : Browser exited with error code: 0 05:41:24 INFO - 2015-11-19 05:41:24,871 INFO : Completed test ts_paint (00:01:00) 05:41:24 INFO - 2015-11-19 05:41:24,871 INFO : Starting test tpaint 05:41:24 INFO - 2015-11-19 05:41:24,871 DEBUG : operating with platform_type : linux_ 05:41:24 INFO - 2015-11-19 05:41:24,871 INFO : Initialising browser for tpaint test... 05:41:24 INFO - 2015-11-19 05:41:24,877 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmphqxOng/profile http://localhost:59992/getInfo.html 05:41:29 INFO - 2015-11-19 05:41:29,389 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 05:41:29 INFO - 2015-11-19 05:41:29,390 DEBUG : BROWSER_OUTPUT: colorDepth:24 05:41:29 INFO - 2015-11-19 05:41:29,390 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 05:41:29 INFO - 2015-11-19 05:41:29,390 DEBUG : BROWSER_OUTPUT: __metrics 05:41:30 INFO - 2015-11-19 05:41:30,521 INFO : Browser initialized. 05:41:30 INFO - 2015-11-19 05:41:30,522 INFO : Running cycle 1/1 for tpaint test... 05:41:30 INFO - 2015-11-19 05:41:30,522 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmphqxOng/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1 05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: __start_report267.27999999999975|272.0699999999997|272.5|272.65999999999985|279.4549999999999|280.28999999999905|285.1350000000002|287.0499999999993|288.84000000000003|289.22999999999956|306.2099999999991|307.1399999999994|323.1449999999968|327.04499999999825|329.1749999999993|335.7399999999998|343.2099999999991|349.0699999999997|385.6850000000013|412.65499999999884__end_report__startTimestamp1447940518800__endTimestamp 05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: openingTimes=272.0699999999997,272.5,272.65999999999985,279.4549999999999,280.28999999999905,285.1350000000002,287.0499999999993,288.84000000000003,289.22999999999956,306.2099999999991,307.1399999999994,323.1449999999968,327.04499999999825,329.1749999999993,335.7399999999998,343.2099999999991,349.0699999999997,385.6850000000013,412.65499999999884 05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: avgOpenTime:310.68 05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: minOpenTime:267.28 05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: maxOpenTime:412.65 05:41:58 INFO - 2015-11-19 05:41:58,803 DEBUG : BROWSER_OUTPUT: medOpenTime:297.71999999999935 05:41:58 INFO - 2015-11-19 05:41:58,804 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:297.71999999999935 05:41:59 INFO - 2015-11-19 05:41:59,793 INFO : Browser exited with error code: 0 05:41:59 INFO - 2015-11-19 05:41:59,805 INFO : Completed test tpaint (00:00:34) 05:41:59 INFO - 2015-11-19 05:41:59,805 INFO : Starting test sessionrestore 05:41:59 INFO - 2015-11-19 05:41:59,805 DEBUG : operating with platform_type : linux_ 05:41:59 INFO - 2015-11-19 05:41:59,805 INFO : Initialising browser for sessionrestore test... 05:41:59 INFO - 2015-11-19 05:41:59,814 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/getInfo.html 05:42:07 INFO - 2015-11-19 05:42:07,761 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 05:42:07 INFO - 2015-11-19 05:42:07,761 DEBUG : BROWSER_OUTPUT: colorDepth:24 05:42:07 INFO - 2015-11-19 05:42:07,761 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811 05:42:07 INFO - 2015-11-19 05:42:07,761 DEBUG : BROWSER_OUTPUT: __metrics 05:42:08 ERROR - 2015-11-19 05:42:08,099 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17087: TypeError: browser.permitUnload is not a function 05:42:08 ERROR - 2015-11-19 05:42:08,578 DEBUG : BROWSER_OUTPUT: JavaScript error: chrome://browser/content/browser.js, line 17087: TypeError: browser.permitUnload is not a function 05:42:09 INFO - 2015-11-19 05:42:09,513 INFO : Browser initialized. 05:42:09 INFO - 2015-11-19 05:42:09,514 INFO : Running cycle 1/10 for sessionrestore test... 05:42:09 INFO - 2015-11-19 05:42:09,514 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js 05:42:09 INFO - 2015-11-19 05:42:09,516 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json 05:42:09 INFO - 2015-11-19 05:42:09,517 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:42:15 INFO - 2015-11-19 05:42:15,242 DEBUG : BROWSER_OUTPUT: __start_report1523__end_report 05:42:15 INFO - 2015-11-19 05:42:15,242 DEBUG : BROWSER_OUTPUT: 05:42:15 INFO - 2015-11-19 05:42:15,243 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940535238__endTimestamp 05:42:15 INFO - 2015-11-19 05:42:15,243 DEBUG : BROWSER_OUTPUT: 05:42:16 INFO - 2015-11-19 05:42:16,853 INFO : Browser exited with error code: 0 05:42:16 INFO - 2015-11-19 05:42:16,855 INFO : Running cycle 2/10 for sessionrestore test... 05:42:16 INFO - 2015-11-19 05:42:16,855 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js 05:42:16 INFO - 2015-11-19 05:42:16,857 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json 05:42:16 INFO - 2015-11-19 05:42:16,858 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:42:22 INFO - 2015-11-19 05:42:22,024 DEBUG : BROWSER_OUTPUT: __start_report1187__end_report 05:42:22 INFO - 2015-11-19 05:42:22,025 DEBUG : BROWSER_OUTPUT: 05:42:22 INFO - 2015-11-19 05:42:22,025 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940542021__endTimestamp 05:42:22 INFO - 2015-11-19 05:42:22,025 DEBUG : BROWSER_OUTPUT: 05:42:23 INFO - 2015-11-19 05:42:23,577 INFO : Browser exited with error code: 0 05:42:23 INFO - 2015-11-19 05:42:23,579 INFO : Running cycle 3/10 for sessionrestore test... 05:42:23 INFO - 2015-11-19 05:42:23,579 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js 05:42:23 INFO - 2015-11-19 05:42:23,581 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json 05:42:23 INFO - 2015-11-19 05:42:23,582 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:42:28 INFO - 2015-11-19 05:42:28,761 DEBUG : BROWSER_OUTPUT: __start_report1181__end_report 05:42:28 INFO - 2015-11-19 05:42:28,762 DEBUG : BROWSER_OUTPUT: 05:42:28 INFO - 2015-11-19 05:42:28,762 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940548758__endTimestamp 05:42:28 INFO - 2015-11-19 05:42:28,762 DEBUG : BROWSER_OUTPUT: 05:42:30 INFO - 2015-11-19 05:42:30,349 INFO : Browser exited with error code: 0 05:42:30 INFO - 2015-11-19 05:42:30,351 INFO : Running cycle 4/10 for sessionrestore test... 05:42:30 INFO - 2015-11-19 05:42:30,351 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js 05:42:30 INFO - 2015-11-19 05:42:30,353 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json 05:42:30 INFO - 2015-11-19 05:42:30,354 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:42:35 INFO - 2015-11-19 05:42:35,542 DEBUG : BROWSER_OUTPUT: __start_report1178__end_report 05:42:35 INFO - 2015-11-19 05:42:35,543 DEBUG : BROWSER_OUTPUT: 05:42:35 INFO - 2015-11-19 05:42:35,543 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940555540__endTimestamp 05:42:35 INFO - 2015-11-19 05:42:35,543 DEBUG : BROWSER_OUTPUT: 05:42:37 INFO - 2015-11-19 05:42:37,297 INFO : Browser exited with error code: 0 05:42:37 INFO - 2015-11-19 05:42:37,299 INFO : Running cycle 5/10 for sessionrestore test... 05:42:37 INFO - 2015-11-19 05:42:37,299 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js 05:42:37 INFO - 2015-11-19 05:42:37,301 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json 05:42:37 INFO - 2015-11-19 05:42:37,302 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:42:42 INFO - 2015-11-19 05:42:42,424 DEBUG : BROWSER_OUTPUT: __start_report1185__end_report 05:42:42 INFO - 2015-11-19 05:42:42,424 DEBUG : BROWSER_OUTPUT: 05:42:42 INFO - 2015-11-19 05:42:42,425 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940562422__endTimestamp 05:42:42 INFO - 2015-11-19 05:42:42,425 DEBUG : BROWSER_OUTPUT: 05:42:44 INFO - 2015-11-19 05:42:44,173 INFO : Browser exited with error code: 0 05:42:44 INFO - 2015-11-19 05:42:44,175 INFO : Running cycle 6/10 for sessionrestore test... 05:42:44 INFO - 2015-11-19 05:42:44,175 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js 05:42:44 INFO - 2015-11-19 05:42:44,177 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json 05:42:44 INFO - 2015-11-19 05:42:44,178 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:42:49 INFO - 2015-11-19 05:42:49,348 DEBUG : BROWSER_OUTPUT: __start_report1178__end_report 05:42:49 INFO - 2015-11-19 05:42:49,348 DEBUG : BROWSER_OUTPUT: 05:42:49 INFO - 2015-11-19 05:42:49,348 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940569345__endTimestamp 05:42:49 INFO - 2015-11-19 05:42:49,348 DEBUG : BROWSER_OUTPUT: 05:42:50 INFO - 2015-11-19 05:42:50,185 DEBUG : BROWSER_OUTPUT: [Child 8049] 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 05:42:50 INFO - 2015-11-19 05:42:50,185 DEBUG : BROWSER_OUTPUT: 05:42:50 INFO - 2015-11-19 05:42:50,185 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost 05:42:50 INFO - 2015-11-19 05:42:50,185 DEBUG : BROWSER_OUTPUT: 05:42:50 INFO - 2015-11-19 05:42:50,186 DEBUG : BROWSER_OUTPUT: 05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost 05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: 05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: 05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost 05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: 05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: 05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost 05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: 05:42:50 INFO - 2015-11-19 05:42:50,187 DEBUG : BROWSER_OUTPUT: 05:42:50 INFO - 2015-11-19 05:42:50,188 DEBUG : BROWSER_OUTPUT: ###!!! [Child][MessageChannel] Error: (msgtype=0x280043,name=PBrowser::Msg___delete__) Channel closing: too late to send/recv, messages will be lost 05:42:50 INFO - 2015-11-19 05:42:50,188 DEBUG : BROWSER_OUTPUT: 05:42:51 INFO - 2015-11-19 05:42:51,033 INFO : Browser exited with error code: 0 05:42:51 INFO - 2015-11-19 05:42:51,035 INFO : Running cycle 7/10 for sessionrestore test... 05:42:51 INFO - 2015-11-19 05:42:51,035 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js 05:42:51 INFO - 2015-11-19 05:42:51,037 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json 05:42:51 INFO - 2015-11-19 05:42:51,038 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:42:56 INFO - 2015-11-19 05:42:56,189 DEBUG : BROWSER_OUTPUT: __start_report1194__end_report 05:42:56 INFO - 2015-11-19 05:42:56,189 DEBUG : BROWSER_OUTPUT: 05:42:56 INFO - 2015-11-19 05:42:56,189 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940576187__endTimestamp 05:42:56 INFO - 2015-11-19 05:42:56,189 DEBUG : BROWSER_OUTPUT: 05:42:57 INFO - 2015-11-19 05:42:57,869 INFO : Browser exited with error code: 0 05:42:57 INFO - 2015-11-19 05:42:57,871 INFO : Running cycle 8/10 for sessionrestore test... 05:42:57 INFO - 2015-11-19 05:42:57,871 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js 05:42:57 INFO - 2015-11-19 05:42:57,873 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json 05:42:57 INFO - 2015-11-19 05:42:57,874 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:03 INFO - 2015-11-19 05:43:03,118 DEBUG : BROWSER_OUTPUT: __start_report1193__end_report 05:43:03 INFO - 2015-11-19 05:43:03,118 DEBUG : BROWSER_OUTPUT: 05:43:03 INFO - 2015-11-19 05:43:03,118 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940583114__endTimestamp 05:43:03 INFO - 2015-11-19 05:43:03,118 DEBUG : BROWSER_OUTPUT: 05:43:04 INFO - 2015-11-19 05:43:04,813 INFO : Browser exited with error code: 0 05:43:04 INFO - 2015-11-19 05:43:04,815 INFO : Running cycle 9/10 for sessionrestore test... 05:43:04 INFO - 2015-11-19 05:43:04,815 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js 05:43:04 INFO - 2015-11-19 05:43:04,817 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json 05:43:04 INFO - 2015-11-19 05:43:04,818 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:10 INFO - 2015-11-19 05:43:10,123 DEBUG : BROWSER_OUTPUT: __start_report1183__end_report 05:43:10 INFO - 2015-11-19 05:43:10,123 DEBUG : BROWSER_OUTPUT: 05:43:10 INFO - 2015-11-19 05:43:10,123 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940590121__endTimestamp 05:43:10 INFO - 2015-11-19 05:43:10,123 DEBUG : BROWSER_OUTPUT: 05:43:11 INFO - 2015-11-19 05:43:11,021 DEBUG : BROWSER_OUTPUT: [Child 8403] 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 05:43:11 INFO - 2015-11-19 05:43:11,893 INFO : Browser exited with error code: 0 05:43:11 INFO - 2015-11-19 05:43:11,895 INFO : Running cycle 10/10 for sessionrestore test... 05:43:11 INFO - 2015-11-19 05:43:11,895 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmpVSLCRI/profile/sessionstore.js 05:43:11 INFO - 2015-11-19 05:43:11,897 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmpVSLCRI/profile/sessionCheckpoints.json 05:43:11 INFO - 2015-11-19 05:43:11,898 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpVSLCRI/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:17 INFO - 2015-11-19 05:43:17,048 DEBUG : BROWSER_OUTPUT: __start_report1178__end_report 05:43:17 INFO - 2015-11-19 05:43:17,048 DEBUG : BROWSER_OUTPUT: 05:43:17 INFO - 2015-11-19 05:43:17,048 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940597046__endTimestamp 05:43:17 INFO - 2015-11-19 05:43:17,048 DEBUG : BROWSER_OUTPUT: 05:43:18 INFO - 2015-11-19 05:43:18,745 INFO : Browser exited with error code: 0 05:43:18 INFO - 2015-11-19 05:43:18,764 INFO : Completed test sessionrestore (00:01:18) 05:43:18 INFO - 2015-11-19 05:43:18,764 INFO : Starting test sessionrestore_no_auto_restore 05:43:18 INFO - 2015-11-19 05:43:18,764 DEBUG : operating with platform_type : linux_ 05:43:18 INFO - 2015-11-19 05:43:18,764 INFO : Initialising browser for sessionrestore_no_auto_restore test... 05:43:18 INFO - 2015-11-19 05:43:18,773 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/getInfo.html 05:43:23 INFO - 2015-11-19 05:43:23,042 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 05:43:23 INFO - 2015-11-19 05:43:23,042 DEBUG : BROWSER_OUTPUT: colorDepth:24 05:43:23 INFO - 2015-11-19 05:43:23,042 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811 05:43:23 INFO - 2015-11-19 05:43:23,042 DEBUG : BROWSER_OUTPUT: __metrics 05:43:24 INFO - 2015-11-19 05:43:24,137 INFO : Browser initialized. 05:43:24 INFO - 2015-11-19 05:43:24,138 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test... 05:43:24 INFO - 2015-11-19 05:43:24,138 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js 05:43:24 INFO - 2015-11-19 05:43:24,140 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json 05:43:24 INFO - 2015-11-19 05:43:24,141 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:26 INFO - 2015-11-19 05:43:26,237 DEBUG : BROWSER_OUTPUT: __start_report1113__end_report 05:43:26 INFO - 2015-11-19 05:43:26,238 DEBUG : BROWSER_OUTPUT: 05:43:26 INFO - 2015-11-19 05:43:26,238 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940606230__endTimestamp 05:43:26 INFO - 2015-11-19 05:43:26,238 DEBUG : BROWSER_OUTPUT: 05:43:27 INFO - 2015-11-19 05:43:27,217 INFO : Browser exited with error code: 0 05:43:27 INFO - 2015-11-19 05:43:27,219 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test... 05:43:27 INFO - 2015-11-19 05:43:27,219 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js 05:43:27 INFO - 2015-11-19 05:43:27,221 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json 05:43:27 INFO - 2015-11-19 05:43:27,222 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:28 INFO - 2015-11-19 05:43:28,834 DEBUG : BROWSER_OUTPUT: __start_report745__end_report 05:43:28 INFO - 2015-11-19 05:43:28,834 DEBUG : BROWSER_OUTPUT: 05:43:28 INFO - 2015-11-19 05:43:28,834 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940608827__endTimestamp 05:43:28 INFO - 2015-11-19 05:43:28,834 DEBUG : BROWSER_OUTPUT: 05:43:29 INFO - 2015-11-19 05:43:29,797 INFO : Browser exited with error code: 0 05:43:29 INFO - 2015-11-19 05:43:29,799 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test... 05:43:29 INFO - 2015-11-19 05:43:29,799 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js 05:43:29 INFO - 2015-11-19 05:43:29,801 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json 05:43:29 INFO - 2015-11-19 05:43:29,801 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:31 INFO - 2015-11-19 05:43:31,415 DEBUG : BROWSER_OUTPUT: __start_report784__end_report 05:43:31 INFO - 2015-11-19 05:43:31,415 DEBUG : BROWSER_OUTPUT: 05:43:31 INFO - 2015-11-19 05:43:31,415 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940611412__endTimestamp 05:43:31 INFO - 2015-11-19 05:43:31,415 DEBUG : BROWSER_OUTPUT: 05:43:32 INFO - 2015-11-19 05:43:32,393 INFO : Browser exited with error code: 0 05:43:32 INFO - 2015-11-19 05:43:32,395 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test... 05:43:32 INFO - 2015-11-19 05:43:32,395 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js 05:43:32 INFO - 2015-11-19 05:43:32,397 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json 05:43:32 INFO - 2015-11-19 05:43:32,397 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:34 INFO - 2015-11-19 05:43:34,031 DEBUG : BROWSER_OUTPUT: __start_report771__end_report 05:43:34 INFO - 2015-11-19 05:43:34,032 DEBUG : BROWSER_OUTPUT: 05:43:34 INFO - 2015-11-19 05:43:34,032 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940614030__endTimestamp 05:43:34 INFO - 2015-11-19 05:43:34,032 DEBUG : BROWSER_OUTPUT: 05:43:35 INFO - 2015-11-19 05:43:35,089 INFO : Browser exited with error code: 0 05:43:35 INFO - 2015-11-19 05:43:35,091 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test... 05:43:35 INFO - 2015-11-19 05:43:35,091 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js 05:43:35 INFO - 2015-11-19 05:43:35,093 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json 05:43:35 INFO - 2015-11-19 05:43:35,093 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:36 INFO - 2015-11-19 05:43:36,698 DEBUG : BROWSER_OUTPUT: __start_report766__end_report 05:43:36 INFO - 2015-11-19 05:43:36,698 DEBUG : BROWSER_OUTPUT: 05:43:36 INFO - 2015-11-19 05:43:36,699 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940616696__endTimestamp 05:43:36 INFO - 2015-11-19 05:43:36,699 DEBUG : BROWSER_OUTPUT: 05:43:37 INFO - 2015-11-19 05:43:37,713 INFO : Browser exited with error code: 0 05:43:37 INFO - 2015-11-19 05:43:37,715 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test... 05:43:37 INFO - 2015-11-19 05:43:37,715 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js 05:43:37 INFO - 2015-11-19 05:43:37,717 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json 05:43:37 INFO - 2015-11-19 05:43:37,717 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:39 INFO - 2015-11-19 05:43:39,312 DEBUG : BROWSER_OUTPUT: __start_report772__end_report 05:43:39 INFO - 2015-11-19 05:43:39,312 DEBUG : BROWSER_OUTPUT: 05:43:39 INFO - 2015-11-19 05:43:39,312 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940619311__endTimestamp 05:43:39 INFO - 2015-11-19 05:43:39,313 DEBUG : BROWSER_OUTPUT: 05:43:40 INFO - 2015-11-19 05:43:40,417 INFO : Browser exited with error code: 0 05:43:40 INFO - 2015-11-19 05:43:40,419 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test... 05:43:40 INFO - 2015-11-19 05:43:40,419 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js 05:43:40 INFO - 2015-11-19 05:43:40,421 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json 05:43:40 INFO - 2015-11-19 05:43:40,421 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:42 INFO - 2015-11-19 05:43:42,040 DEBUG : BROWSER_OUTPUT: __start_report769__end_report 05:43:42 INFO - 2015-11-19 05:43:42,040 DEBUG : BROWSER_OUTPUT: 05:43:42 INFO - 2015-11-19 05:43:42,040 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940622035__endTimestamp 05:43:42 INFO - 2015-11-19 05:43:42,040 DEBUG : BROWSER_OUTPUT: 05:43:43 INFO - 2015-11-19 05:43:43,161 INFO : Browser exited with error code: 0 05:43:43 INFO - 2015-11-19 05:43:43,163 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test... 05:43:43 INFO - 2015-11-19 05:43:43,163 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js 05:43:43 INFO - 2015-11-19 05:43:43,165 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json 05:43:43 INFO - 2015-11-19 05:43:43,166 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:44 INFO - 2015-11-19 05:43:44,785 DEBUG : BROWSER_OUTPUT: __start_report800__end_report 05:43:44 INFO - 2015-11-19 05:43:44,786 DEBUG : BROWSER_OUTPUT: 05:43:44 INFO - 2015-11-19 05:43:44,786 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940624785__endTimestamp 05:43:44 INFO - 2015-11-19 05:43:44,786 DEBUG : BROWSER_OUTPUT: 05:43:45 INFO - 2015-11-19 05:43:45,845 INFO : Browser exited with error code: 0 05:43:45 INFO - 2015-11-19 05:43:45,847 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test... 05:43:45 INFO - 2015-11-19 05:43:45,847 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js 05:43:45 INFO - 2015-11-19 05:43:45,849 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json 05:43:45 INFO - 2015-11-19 05:43:45,850 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:47 INFO - 2015-11-19 05:43:47,424 DEBUG : BROWSER_OUTPUT: __start_report749__end_report 05:43:47 INFO - 2015-11-19 05:43:47,424 DEBUG : BROWSER_OUTPUT: 05:43:47 INFO - 2015-11-19 05:43:47,424 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940627421__endTimestamp 05:43:47 INFO - 2015-11-19 05:43:47,424 DEBUG : BROWSER_OUTPUT: 05:43:48 INFO - 2015-11-19 05:43:48,545 INFO : Browser exited with error code: 0 05:43:48 INFO - 2015-11-19 05:43:48,547 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test... 05:43:48 INFO - 2015-11-19 05:43:48,547 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp5hQUy8/profile/sessionstore.js 05:43:48 INFO - 2015-11-19 05:43:48,549 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp5hQUy8/profile/sessionCheckpoints.json 05:43:48 INFO - 2015-11-19 05:43:48,550 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5hQUy8/profile http://localhost:59992/startup_test/sessionrestore/index.html 05:43:50 INFO - 2015-11-19 05:43:50,197 DEBUG : BROWSER_OUTPUT: __start_report754__end_report 05:43:50 INFO - 2015-11-19 05:43:50,197 DEBUG : BROWSER_OUTPUT: 05:43:50 INFO - 2015-11-19 05:43:50,197 DEBUG : BROWSER_OUTPUT: __startTimestamp1447940630194__endTimestamp 05:43:50 INFO - 2015-11-19 05:43:50,197 DEBUG : BROWSER_OUTPUT: 05:43:51 INFO - 2015-11-19 05:43:51,273 INFO : Browser exited with error code: 0 05:43:51 INFO - 2015-11-19 05:43:51,294 INFO : Completed test sessionrestore_no_auto_restore (00:00:32) 05:43:51 INFO - 2015-11-19 05:43:51,610 INFO : Completed test suite (00:05:17) 05:43:51 INFO - 2015-11-19 05:43:51,610 DEBUG : Working with test: a11yr 05:43:51 INFO - 2015-11-19 05:43:51,610 DEBUG : Generating results file: a11yr 05:43:51 INFO - 2015-11-19 05:43:51,610 DEBUG : Working with test: ts_paint 05:43:51 INFO - 2015-11-19 05:43:51,610 DEBUG : Generating results file: ts_paint 05:43:51 INFO - 2015-11-19 05:43:51,611 DEBUG : Working with test: tpaint 05:43:51 INFO - 2015-11-19 05:43:51,612 DEBUG : Generating results file: tpaint 05:43:51 INFO - 2015-11-19 05:43:51,612 DEBUG : Working with test: sessionrestore 05:43:51 INFO - 2015-11-19 05:43:51,612 DEBUG : Generating results file: sessionrestore 05:43:51 INFO - 2015-11-19 05:43:51,612 DEBUG : Working with test: sessionrestore_no_auto_restore 05:43:51 INFO - 2015-11-19 05:43:51,613 DEBUG : Generating results file: sessionrestore_no_auto_restore 05:43:51 INFO - 2015-11-19 05:43:51,613 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 05:43:51 INFO - 2015-11-19 05:43:51,656 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,132,43]] 05:43:51 INFO - 2015-11-19 05:43:51,656 DEBUG : process_Request line: a11yr_paint 717.49 graph.html#tests=[[223,132,43]] 05:43:51 INFO - 2015-11-19 05:43:51,656 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 05:43:51 INFO - 2015-11-19 05:43:51,715 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,132,43]] 05:43:51 INFO - 2015-11-19 05:43:51,715 DEBUG : process_Request line: ts_paint 532.80 graph.html#tests=[[83,132,43]] 05:43:51 INFO - 2015-11-19 05:43:51,716 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 05:43:51 INFO - 2015-11-19 05:43:51,744 DEBUG : process_Request line: tpaint graph.html#tests=[[82,132,43]] 05:43:51 INFO - 2015-11-19 05:43:51,744 DEBUG : process_Request line: tpaint 323.14 graph.html#tests=[[82,132,43]] 05:43:51 INFO - 2015-11-19 05:43:51,744 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 05:43:51 INFO - 2015-11-19 05:43:51,785 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,132,43]] 05:43:51 INFO - 2015-11-19 05:43:51,785 DEBUG : process_Request line: sessionrestore 1214.28 graph.html#tests=[[313,132,43]] 05:43:51 INFO - 2015-11-19 05:43:51,785 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 05:43:51 INFO - 2015-11-19 05:43:51,830 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,132,43]] 05:43:51 INFO - 2015-11-19 05:43:51,830 DEBUG : process_Request line: sessionrestore_no_auto_restore 796.67 graph.html#tests=[[315,132,43]] 05:43:51 INFO - 2015-11-19 05:43:51,831 INFO : PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"lowerIsBetter": true, "subtests": [{"lowerIsBetter": true, "replicates": [1261.0, 1299.0, 1307.0, 1341.0, 1328.0, 1323.0, 1344.0, 1330.0, 1524.0, 1525.0, 1315.0, 1325.0, 1526.0, 1334.0, 1527.0, 1322.0, 1316.0, 1313.0, 1348.0, 1324.0, 1331.0, 1329.0, 1333.0, 1339.0, 1320.0], "unit": "ms", "name": "dhtml.html", "value": 1329.5}, {"lowerIsBetter": true, "replicates": [380.0, 381.0, 377.0, 383.0, 390.0, 388.0, 378.0, 390.0, 378.0, 392.0, 387.0, 385.0, 399.0, 377.0, 388.0, 393.0, 393.0, 387.0, 402.0, 384.0, 380.0, 379.0, 387.0, 397.0, 386.0], "unit": "ms", "name": "tablemutation.html", "value": 387.0}], "name": "a11yr", "value": 717.4942588497139}, {"subtests": [{"replicates": [480.0, 571.0, 511.0, 523.0, 519.0, 520.0, 523.0, 554.0, 504.0, 618.0, 520.0, 554.0, 549.0, 517.0, 541.0, 503.0, 534.0, 562.0, 513.0, 556.0], "name": "ts_paint", "value": 523.0}], "name": "ts_paint", "value": 523.0}, {"subtests": [{"replicates": [267.27999999999975, 272.0699999999997, 272.5, 272.65999999999985, 279.4549999999999, 280.28999999999905, 285.1350000000002, 287.0499999999993, 288.84000000000003, 289.22999999999956, 306.2099999999991, 307.1399999999994, 323.1449999999968, 327.04499999999825, 329.1749999999993, 335.7399999999998, 343.2099999999991, 349.0699999999997, 385.6850000000013, 412.65499999999884], "name": "tpaint", "value": 323.1449999999968}], "name": "tpaint", "value": 323.1449999999968}, {"subtests": [{"replicates": [1523.0, 1187.0, 1181.0, 1178.0, 1185.0, 1178.0, 1194.0, 1193.0, 1183.0, 1178.0], "name": "sessionrestore", "value": 1183.0}], "name": "sessionrestore", "value": 1183.0}, {"subtests": [{"replicates": [1113.0, 745.0, 784.0, 771.0, 766.0, 772.0, 769.0, 800.0, 749.0, 754.0], "name": "sessionrestore_no_auto_restore", "value": 769.0}], "name": "sessionrestore_no_auto_restore", "value": 769.0}]} 05:43:51 INFO - RETURN: a11yr_paint: 717.49 05:43:51 INFO - RETURN: ts_paint: 532.80 05:43:51 INFO - RETURN: tpaint: 323.14 05:43:51 INFO - RETURN: sessionrestore: 1214.28 05:43:51 INFO - RETURN: sessionrestore_no_auto_restore: 796.67 05:43:51 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,132,43]]", "result": "1214.28"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,132,43]]", "result": "717.49"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,132,43]]", "result": "323.14"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,132,43]]", "result": "532.80"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,132,43]]", "result": "796.67"}}} 05:43:51 INFO - Return code: 0 05:43:51 ERROR - # TBPL SUCCESS # 05:43:51 INFO - Running post-action listener: _resource_record_post_action 05:43:51 INFO - Running post-run listener: _resource_record_post_run 05:43:52 INFO - Total resource usage - Wall time: 331s; CPU: 16.0%; Read bytes: 28672; Write bytes: 568246272; Read time: 176; Write time: 380392 05:43:52 INFO - install - Wall time: 14s; CPU: 13.0%; Read bytes: 4096; Write bytes: 159371264; Read time: 68; Write time: 153444 05:43:52 INFO - run-tests - Wall time: 318s; CPU: 16.0%; Read bytes: 20480; Write bytes: 340631552; Read time: 24; Write time: 169560 05:43:52 INFO - Running post-run listener: _upload_blobber_files 05:43:52 INFO - Blob upload gear active. 05:43:52 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ... 05:43:52 INFO - Copying logs to upload dir... 05:43:52 INFO - mkdir: /builds/slave/test/build/upload/logs program finished with exit code 0 elapsedTime=377.785737 ========= master_lag: 0.02 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 6 mins, 17 secs) (at 2015-11-19 05:43:52.720985) ========= ========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-19 05:43:52.724443) ========= 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-1447938538.59755-1196598762 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False build_url:https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 program finished with exit code 0 elapsedTime=0.010179 build_url: 'https://queue.taskcluster.net/v1/task/hn_i-YmOSISiPFOXjDDJJg/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-19 05:43:52.774849) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:43:52.775177) ========= 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-1447938538.59755-1196598762 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004549 ========= master_lag: 0.05 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-19 05:43:52.825292) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-19 05:43:52.825590) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-19 05:43:52.825871) ========= ========= Total master_lag: 0.23 =========