builder: mozilla-inbound_ubuntu64_hw_test-other slave: talos-linux64-ix-048 starttime: 1447352668.71 results: success (0) buildid: 20151112100440 builduid: fc42b1225b304fbc87b60387fbfad0da revision: 756632e20aa46ce0b2feebdf6f04e6dacdc09811 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.706713) ========= master: http://buildbot-master104.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.707153) ========= ========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.707459) ========= 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=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False /builds/slave/test program finished with exit code 0 elapsedTime=0.006572 basedir: '/builds/slave/test' ========= master_lag: 0.02 ========= ========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.736342) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.736662) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.777377) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.777648) ========= 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=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004707 ========= master_lag: 0.07 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.847471) ========= ========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.847749) ========= script_repo_url: https://hg.mozilla.org/build/mozharness ========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.848081) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:28.848608) ========= 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=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2015-11-12 10:24:30-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.25, 63.245.215.102 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.25|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12141 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 84.0M=0s 2015-11-12 10:24:30 (84.0 MB/s) - `archiver_client.py' saved [12141/12141] program finished with exit code 0 elapsedTime=0.119738 ========= master_lag: 0.34 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:29.308851) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:29.312372) ========= 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=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.020370 ========= master_lag: 0.05 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:29.383721) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:29.384082) ========= bash -c 'python archiver_client.py mozharness --repo integration/mozilla-inbound --rev 756632e20aa46ce0b2feebdf6f04e6dacdc09811 --destination scripts --debug' in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', u'python archiver_client.py mozharness --repo integration/mozilla-inbound --rev 756632e20aa46ce0b2feebdf6f04e6dacdc09811 --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=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2015-11-12 10:24:30,694 truncating revision to first 12 chars 2015-11-12 10:24:30,694 Setting DEBUG logging. 2015-11-12 10:24:30,694 attempt 1/10 2015-11-12 10:24:30,694 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/mozilla-inbound/756632e20aa4?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2015-11-12 10:24:31,050 unpacking tar archive at: mozilla-inbound-756632e20aa4/testing/mozharness/ program finished with exit code 0 elapsedTime=0.652951 ========= master_lag: 0.03 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:30.069903) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:30.070189) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:30.078069) ========= ========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:30.078335) ========= TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production ========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-12 10:24:30.078686) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 37 secs) (at 2015-11-12 10:24:30.078964) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Inbound-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Inbound-Non-PGO in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'other', '--add-option', '--webServer,localhost', '--branch-name', 'Mozilla-Inbound-Non-PGO', '--system-bits', '64', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Mozilla-Inbound-Non-PGO'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 10:24:31 INFO - MultiFileLogger online at 20151112 10:24:31 in /builds/slave/test 10:24:31 INFO - Run as scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Inbound-Non-PGO --system-bits 64 --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Inbound-Non-PGO 10:24:31 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 10:24:31 INFO - {'append_to_log': False, 10:24:31 INFO - 'base_work_dir': '/builds/slave/test', 10:24:31 INFO - 'blob_upload_branch': 'Mozilla-Inbound-Non-PGO', 10:24:31 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 10:24:31 INFO - 'branch': 'Mozilla-Inbound-Non-PGO', 10:24:31 INFO - 'buildbot_json_path': 'buildprops.json', 10:24:31 INFO - 'config_files': ('talos/linux_config.py',), 10:24:31 INFO - 'default_actions': ('clobber', 10:24:31 INFO - 'read-buildbot-config', 10:24:31 INFO - 'download-and-extract', 10:24:31 INFO - 'populate-webroot', 10:24:31 INFO - 'create-virtualenv', 10:24:31 INFO - 'install', 10:24:31 INFO - 'run-tests'), 10:24:31 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 10:24:31 INFO - 'download_minidump_stackwalk': True, 10:24:31 INFO - 'download_symbols': 'ondemand', 10:24:31 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 10:24:31 INFO - 'tooltool.py': '/tools/tooltool.py', 10:24:31 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 10:24:31 INFO - '/tools/misc-python/virtualenv.py')}, 10:24:31 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 10:24:31 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 10:24:31 INFO - 'installer_path': 'installer.exe', 10:24:31 INFO - 'log_level': 'info', 10:24:31 INFO - 'log_name': 'talos', 10:24:31 INFO - 'log_to_console': True, 10:24:31 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 10:24:31 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 10:24:31 INFO - 'opt_config_files': (), 10:24:31 INFO - 'pip_index': False, 10:24:31 INFO - 'sps_profile': False, 10:24:31 INFO - 'sps_profile_interval': 0, 10:24:31 INFO - 'suite': 'other', 10:24:31 INFO - 'system_bits': '64', 10:24:31 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 10:24:31 INFO - 'title': 'talos-linux64-ix-048', 10:24:31 INFO - 'tooltool_cache': '/builds/tooltool_cache', 10:24:31 INFO - 'use_talos_json': True, 10:24:31 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 10:24:31 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 10:24:31 INFO - 'work_dir': 'build'} 10:24:31 INFO - ##### 10:24:31 INFO - ##### Running clobber step. 10:24:31 INFO - ##### 10:24:31 INFO - Running pre-action listener: _resource_record_pre_action 10:24:31 INFO - Running main action method: clobber 10:24:31 INFO - rmtree: /builds/slave/test/build 10:24:31 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 10:24:31 INFO - Running post-action listener: _resource_record_post_action 10:24:31 INFO - ##### 10:24:31 INFO - ##### Running read-buildbot-config step. 10:24:31 INFO - ##### 10:24:31 INFO - Running pre-action listener: _resource_record_pre_action 10:24:31 INFO - Running main action method: read_buildbot_config 10:24:31 INFO - Using buildbot properties: 10:24:31 INFO - { 10:24:31 INFO - "properties": { 10:24:31 INFO - "buildnumber": 707, 10:24:31 INFO - "product": "firefox", 10:24:31 INFO - "script_repo_revision": "production", 10:24:31 INFO - "builddir": "mozilla-inbound_ubuntu64_hw_test-other", 10:24:31 INFO - "repository": "", 10:24:31 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-inbound talos other", 10:24:31 INFO - "buildid": "20151112100440", 10:24:31 INFO - "slavename": "talos-linux64-ix-048", 10:24:31 INFO - "pgo_build": "False", 10:24:31 INFO - "basedir": "/builds/slave/test", 10:24:31 INFO - "project": "", 10:24:31 INFO - "platform": "ubuntu64_hw", 10:24:31 INFO - "master": "http://buildbot-master104.bb.releng.scl3.mozilla.com:8201/", 10:24:31 INFO - "slavebuilddir": "test", 10:24:31 INFO - "scheduler": "tests-mozilla-inbound-linux64-talos", 10:24:31 INFO - "branch": "mozilla-inbound", 10:24:31 INFO - "repo_path": "integration/mozilla-inbound", 10:24:31 INFO - "stage_platform": "linux64", 10:24:31 INFO - "builduid": "fc42b1225b304fbc87b60387fbfad0da", 10:24:31 INFO - "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811" 10:24:31 INFO - }, 10:24:31 INFO - "sourcestamp": { 10:24:31 INFO - "repository": "", 10:24:31 INFO - "hasPatch": false, 10:24:31 INFO - "project": "", 10:24:31 INFO - "branch": "mozilla-inbound-linux64-talos", 10:24:31 INFO - "changes": [ 10:24:31 INFO - { 10:24:31 INFO - "category": null, 10:24:31 INFO - "files": [ 10:24:31 INFO - { 10:24:31 INFO - "url": null, 10:24:31 INFO - "name": "https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2" 10:24:31 INFO - } 10:24:31 INFO - ], 10:24:31 INFO - "repository": "", 10:24:31 INFO - "rev": "756632e20aa46ce0b2feebdf6f04e6dacdc09811", 10:24:31 INFO - "who": "nfroyd@mozilla.com", 10:24:31 INFO - "when": 1447352650, 10:24:31 INFO - "number": 6654258, 10:24:31 INFO - "comments": "Bug 1221547 - part 2 - copy less data for file transfers over bluetooth; r=btian\n\nWe have a number of places where we create a Bluetooth request with\nallocated memory, then copy that memory into the raw data to be sent\nover the socket. We can do better by transferring ownership to the\nsocket data, rather than copying.", 10:24:31 INFO - "project": "", 10:24:31 INFO - "at": "Thu 12 Nov 2015 10:24:10", 10:24:31 INFO - "branch": "mozilla-inbound-linux64-talos", 10:24:31 INFO - "revlink": "", 10:24:31 INFO - "properties": [ 10:24:31 INFO - [ 10:24:31 INFO - "buildid", 10:24:31 INFO - "20151112100440", 10:24:31 INFO - "Change" 10:24:31 INFO - ], 10:24:31 INFO - [ 10:24:31 INFO - "builduid", 10:24:31 INFO - "fc42b1225b304fbc87b60387fbfad0da", 10:24:31 INFO - "Change" 10:24:31 INFO - ], 10:24:31 INFO - [ 10:24:31 INFO - "pgo_build", 10:24:31 INFO - "False", 10:24:31 INFO - "Change" 10:24:31 INFO - ] 10:24:31 INFO - ], 10:24:31 INFO - "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811" 10:24:31 INFO - } 10:24:31 INFO - ], 10:24:31 INFO - "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811" 10:24:31 INFO - } 10:24:31 INFO - } 10:24:31 INFO - Found installer url https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2. 10:24:31 INFO - Running post-action listener: _resource_record_post_action 10:24:31 INFO - ##### 10:24:31 INFO - ##### Running download-and-extract step. 10:24:31 INFO - ##### 10:24:31 INFO - Running pre-action listener: _resource_record_pre_action 10:24:31 INFO - Running main action method: download_and_extract 10:24:31 INFO - mkdir: /builds/slave/test/build/tests 10:24:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:31 INFO - https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net 10:24:31 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/test_packages.json 10:24:31 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/test_packages.json 10:24:31 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/test_packages.json to /builds/slave/test/build/test_packages.json 10:24:31 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/test_packages.json', 'file_name': '/builds/slave/test/build/test_packages.json'}, attempt #1 10:24:36 INFO - Downloaded 1302 bytes. 10:24:36 INFO - Reading from file /builds/slave/test/build/test_packages.json 10:24:36 INFO - Using the following test package requirements: 10:24:36 INFO - {u'common': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 10:24:36 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.cppunittest.tests.zip'], 10:24:36 INFO - u'jittest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:24:36 INFO - u'jsshell-linux-x86_64.zip'], 10:24:36 INFO - u'mochitest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.mochitest.tests.zip'], 10:24:36 INFO - u'mozbase': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 10:24:36 INFO - u'reftest': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.reftest.tests.zip'], 10:24:36 INFO - u'talos': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'], 10:24:36 INFO - u'web-platform': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.web-platform.tests.zip'], 10:24:36 INFO - u'webapprt': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'], 10:24:36 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 10:24:36 INFO - u'firefox-45.0a1.en-US.linux-x86_64.xpcshell.tests.zip']} 10:24:36 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] for test suite category: common 10:24: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')]} 10:24:36 INFO - https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net 10:24:36 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:24:36 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:24:36 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:24:36 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'}, attempt #1 10:24:37 INFO - Downloaded 21256990 bytes. 10:24:37 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test/build/tests 10:24:37 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:24:37 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760 10:24:38 INFO - Return code: 0 10:24:38 INFO - Downloading packages: [u'firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', u'firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] for test suite category: talos 10:24:38 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:38 INFO - https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip matches https://queue.taskcluster.net 10:24:38 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:24:38 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:24:38 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:24:38 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'}, attempt #1 10:24:40 INFO - Downloaded 21256990 bytes. 10:24:40 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] in /builds/slave/test/build/tests 10:24:40 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip 10:24:40 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.common.tests.zip'] with output_timeout 1760 10:24:41 INFO - Return code: 0 10:24:41 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:41 INFO - https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip matches https://queue.taskcluster.net 10:24:41 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 10:24:41 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 10:24:41 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 10:24:41 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip', 'file_name': u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'}, attempt #1 10:24:42 INFO - Downloaded 11131693 bytes. 10:24:42 INFO - Running command: ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] in /builds/slave/test/build/tests 10:24:42 INFO - Copy/paste: unzip -q -o /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip 10:24:42 INFO - Calling ['unzip', '-q', '-o', u'/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.talos.tests.zip'] with output_timeout 1760 10:24:42 INFO - Return code: 0 10:24:42 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:42 INFO - https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 matches https://queue.taskcluster.net 10:24:42 INFO - URL Candidate: http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 10:24:42 INFO - trying http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 10:24:42 INFO - Downloading http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 to /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 10:24:42 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'http://queue.taskcluster.net.proxxy1.srv.releng.scl3.mozilla.com/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2', 'file_name': '/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2'}, attempt #1 10:24:43 INFO - Downloaded 55657694 bytes. 10:24:43 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 10:24:43 INFO - mkdir: /builds/slave/test/properties 10:24:43 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 10:24:43 INFO - Writing to file /builds/slave/test/properties/build_url 10:24:43 INFO - Contents: 10:24:43 INFO - build_url:https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 10:24:43 INFO - Running post-action listener: _resource_record_post_action 10:24:43 INFO - Running post-action listener: set_extra_try_arguments 10:24:43 INFO - ##### 10:24:43 INFO - ##### Running populate-webroot step. 10:24:43 INFO - ##### 10:24:43 INFO - Running pre-action listener: _resource_record_pre_action 10:24:43 INFO - Running main action method: populate_webroot 10:24:43 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']}, 10:24:43 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']}, 10:24:43 INFO - 'remote-trobocheck2': {'talos_options': ['--fennecIDs', 10:24:43 INFO - '../fennec_ids.txt'], 10:24:43 INFO - 'tests': ['tcheck2']}, 10:24:43 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome', 10:24:43 INFO - '--tppagecycles', 10:24:43 INFO - '7'], 10:24:43 INFO - 'tests': ['tsvgm']}}, 10:24:43 INFO - 'suites': {'chromez': {'tests': ['tresize', 'tcanvasmark']}, 10:24:43 INFO - 'chromez-e10s': {'talos_options': ['--e10s'], 10:24:43 INFO - 'tests': ['tresize', 'tcanvasmark']}, 10:24:43 INFO - 'dromaeojs': {'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 10:24:43 INFO - 'dromaeojs-e10s': {'talos_options': ['--e10s'], 10:24:43 INFO - 'tests': ['dromaeo_css', 'kraken', 'v8_7']}, 10:24:43 INFO - 'g1': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:24:43 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 10:24:43 INFO - 'g1-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:24:43 INFO - 'talos_options': ['--e10s'], 10:24:43 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 10:24:43 INFO - 'g2': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:24:43 INFO - 'tests': ['damp', 'tps']}, 10:24:43 INFO - 'g2-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:24:43 INFO - 'talos_options': ['--e10s'], 10:24:43 INFO - 'tests': ['damp', 'tps']}, 10:24:43 INFO - 'g3': {'tests': ['dromaeo_dom']}, 10:24:43 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 10:24:43 INFO - 'other': {'tests': ['a11yr', 10:24:43 INFO - 'ts_paint', 10:24:43 INFO - 'tpaint', 10:24:43 INFO - 'sessionrestore', 10:24:43 INFO - 'sessionrestore_no_auto_restore']}, 10:24:43 INFO - 'other-e10s': {'talos_options': ['--e10s'], 10:24:43 INFO - 'tests': ['a11yr', 10:24:43 INFO - 'ts_paint', 10:24:43 INFO - 'tpaint', 10:24:43 INFO - 'sessionrestore', 10:24:43 INFO - 'sessionrestore_no_auto_restore']}, 10:24:43 INFO - 'other-e10s_l64': {'talos_options': ['--e10s'], 10:24:43 INFO - 'tests': ['a11yr', 10:24:43 INFO - 'ts_paint', 10:24:43 INFO - 'tpaint', 10:24:43 INFO - 'sessionrestore', 10:24:43 INFO - 'sessionrestore_no_auto_restore']}, 10:24:43 INFO - 'other-e10s_nol64': {'talos_options': ['--e10s'], 10:24:43 INFO - 'tests': ['a11yr', 10:24:43 INFO - 'ts_paint', 10:24:43 INFO - 'tpaint', 10:24:43 INFO - 'sessionrestore', 10:24:43 INFO - 'sessionrestore_no_auto_restore']}, 10:24:43 INFO - 'other_l64': {'tests': ['a11yr', 10:24:43 INFO - 'ts_paint', 10:24:43 INFO - 'tpaint', 10:24:43 INFO - 'sessionrestore', 10:24:43 INFO - 'sessionrestore_no_auto_restore']}, 10:24:43 INFO - 'other_nol64': {'tests': ['a11yr', 10:24:43 INFO - 'ts_paint', 10:24:43 INFO - 'tpaint', 10:24:43 INFO - 'sessionrestore', 10:24:43 INFO - 'sessionrestore_no_auto_restore']}, 10:24:43 INFO - 'svgr': {'tests': ['tsvgx', 10:24:43 INFO - 'tsvgr_opacity', 10:24:43 INFO - 'tart', 10:24:43 INFO - 'tscrollx', 10:24:43 INFO - 'cart']}, 10:24:43 INFO - 'svgr-e10s': {'talos_options': ['--e10s'], 10:24:43 INFO - 'tests': ['tsvgx', 10:24:43 INFO - 'tsvgr_opacity', 10:24:43 INFO - 'tart', 10:24:43 INFO - 'tscrollx', 10:24:43 INFO - 'cart']}, 10:24:43 INFO - 'tp5o': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:24:43 INFO - 'tests': ['tp5o']}, 10:24:43 INFO - 'tp5o-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:24:43 INFO - 'talos_options': ['--e10s'], 10:24:43 INFO - 'tests': ['tp5o']}, 10:24:43 INFO - 'xperf': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:24:43 INFO - 'talos_options': ['--xperf_path', 10:24:43 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 10:24:43 INFO - 'tests': ['tp5n']}, 10:24:43 INFO - 'xperf-e10s': {'pagesets_url': 'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 10:24:43 INFO - 'talos_options': ['--e10s', 10:24:43 INFO - '--xperf_path', 10:24:43 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 10:24:43 INFO - 'tests': ['tp5n']}}, 10:24:43 INFO - 'talos.zip': {'path': '', 10:24:43 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}} 10:24:43 INFO - Running post-action listener: _resource_record_post_action 10:24:43 INFO - ##### 10:24:43 INFO - ##### Running create-virtualenv step. 10:24:43 INFO - ##### 10:24:43 INFO - Running pre-action listener: _resource_record_pre_action 10:24:43 INFO - Running main action method: create_virtualenv 10:24:43 INFO - Creating virtualenv /builds/slave/test/build/venv 10:24:43 INFO - Running command: ['/tools/buildbot/bin/python', '/tools/misc-python/virtualenv.py', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build 10:24:43 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv 10:24:43 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 10:24:43 INFO - Using real prefix '/usr' 10:24:43 INFO - New python executable in /builds/slave/test/build/venv/bin/python 10:24:44 INFO - Installing distribute.............................................................................................................................................................................................done. 10:24:46 INFO - Installing pip.................done. 10:24:46 INFO - Return code: 0 10:24:46 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 10:24:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:46 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:24:46 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:46 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:24:46 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:46 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 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, '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': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 10:24:46 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in /builds/slave/test/build 10:24:46 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5 10:24:46 INFO - Using env: {'DISPLAY': ':0', 10:24:46 INFO - 'HOME': '/home/cltbld', 10:24:46 INFO - 'LANG': 'en_US.UTF-8', 10:24:46 INFO - 'LANGUAGE': 'en_US:en', 10:24:46 INFO - 'LOGNAME': 'cltbld', 10:24:46 INFO - 'MAIL': '/var/mail/cltbld', 10:24:46 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:24:46 INFO - 'MOZ_NO_REMOTE': '1', 10:24:46 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:24:46 INFO - 'NO_EM_RESTART': '1', 10:24:46 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:24:46 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:24:46 INFO - 'PWD': '/builds/slave/test', 10:24:46 INFO - 'SHELL': '/bin/bash', 10:24:46 INFO - 'SHLVL': '1', 10:24:46 INFO - 'TERM': 'linux', 10:24:46 INFO - 'TMOUT': '86400', 10:24:46 INFO - 'USER': 'cltbld', 10:24:46 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 10:24:46 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:24:46 INFO - '_': '/tools/buildbot/bin/python'} 10:24:46 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:24:46 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages/pip-1.5.5-py2.7.egg 10:24:46 INFO - Cleaning up... 10:24:46 INFO - Return code: 0 10:24:46 INFO - Installing psutil>=0.7.1 into virtualenv /builds/slave/test/build/venv 10:24:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:46 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:24:46 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:46 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:24:46 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:46 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 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, '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': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 10:24:46 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=0.7.1'] in /builds/slave/test/build 10:24:46 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=0.7.1 10:24:46 INFO - Using env: {'DISPLAY': ':0', 10:24:46 INFO - 'HOME': '/home/cltbld', 10:24:46 INFO - 'LANG': 'en_US.UTF-8', 10:24:46 INFO - 'LANGUAGE': 'en_US:en', 10:24:46 INFO - 'LOGNAME': 'cltbld', 10:24:46 INFO - 'MAIL': '/var/mail/cltbld', 10:24:46 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:24:46 INFO - 'MOZ_NO_REMOTE': '1', 10:24:46 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:24:46 INFO - 'NO_EM_RESTART': '1', 10:24:46 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:24:46 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:24:46 INFO - 'PWD': '/builds/slave/test', 10:24:46 INFO - 'SHELL': '/bin/bash', 10:24:46 INFO - 'SHLVL': '1', 10:24:46 INFO - 'TERM': 'linux', 10:24:46 INFO - 'TMOUT': '86400', 10:24:46 INFO - 'USER': 'cltbld', 10:24:46 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 10:24:46 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:24:46 INFO - '_': '/tools/buildbot/bin/python'} 10:24:46 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:24:46 INFO - Downloading/unpacking psutil>=0.7.1 10:24:46 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:46 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:46 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:46 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:46 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:46 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:48 INFO - Creating supposed download cache at /builds/slave/test/build/venv/cache 10:24:48 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fpsutil-3.1.1.tar.gz 10:24:48 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 10:24:48 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 10:24:48 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 10:24:48 INFO - Installing collected packages: psutil 10:24:48 INFO - Running setup.py install for psutil 10:24:48 INFO - building 'psutil._psutil_linux' extension 10:24:48 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -DPSUTIL_VERSION=311 -I/usr/include/python2.7 -c psutil/_psutil_linux.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o 10:24:48 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_linux.so 10:24:48 INFO - building 'psutil._psutil_posix' extension 10:24:48 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -I/usr/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o 10:24:48 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_posix.so 10:24:48 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 10:24:48 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 10:24:48 INFO - Successfully installed psutil 10:24:48 INFO - Cleaning up... 10:24:48 INFO - Return code: 0 10:24:48 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv /builds/slave/test/build/venv 10:24:48 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:49 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:24:49 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:49 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:49 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:24:49 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:49 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, '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': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 10:24:49 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.0.0'] in /builds/slave/test/build 10:24:49 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.0.0 10:24:49 INFO - Using env: {'DISPLAY': ':0', 10:24:49 INFO - 'HOME': '/home/cltbld', 10:24:49 INFO - 'LANG': 'en_US.UTF-8', 10:24:49 INFO - 'LANGUAGE': 'en_US:en', 10:24:49 INFO - 'LOGNAME': 'cltbld', 10:24:49 INFO - 'MAIL': '/var/mail/cltbld', 10:24:49 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:24:49 INFO - 'MOZ_NO_REMOTE': '1', 10:24:49 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:24:49 INFO - 'NO_EM_RESTART': '1', 10:24:49 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:24:49 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:24:49 INFO - 'PWD': '/builds/slave/test', 10:24:49 INFO - 'SHELL': '/bin/bash', 10:24:49 INFO - 'SHLVL': '1', 10:24:49 INFO - 'TERM': 'linux', 10:24:49 INFO - 'TMOUT': '86400', 10:24:49 INFO - 'USER': 'cltbld', 10:24:49 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 10:24:49 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:24:49 INFO - '_': '/tools/buildbot/bin/python'} 10:24:49 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:24:49 INFO - Downloading/unpacking mozsystemmonitor==0.0.0 10:24:49 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:49 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:49 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:49 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:49 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:49 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:50 INFO - Downloading mozsystemmonitor-0.0.tar.gz 10:24:50 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fmozsystemmonitor-0.0.tar.gz 10:24:50 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 10:24:50 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.0.0) 10:24:50 INFO - Installing collected packages: mozsystemmonitor 10:24:50 INFO - Running setup.py install for mozsystemmonitor 10:24:51 INFO - Successfully installed mozsystemmonitor 10:24:51 INFO - Cleaning up... 10:24:51 INFO - Return code: 0 10:24:51 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 10:24:51 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:51 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:24:51 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:51 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:51 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:24:51 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:51 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 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, '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': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 10:24:51 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in /builds/slave/test/build 10:24:51 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4 10:24:51 INFO - Using env: {'DISPLAY': ':0', 10:24:51 INFO - 'HOME': '/home/cltbld', 10:24:51 INFO - 'LANG': 'en_US.UTF-8', 10:24:51 INFO - 'LANGUAGE': 'en_US:en', 10:24:51 INFO - 'LOGNAME': 'cltbld', 10:24:51 INFO - 'MAIL': '/var/mail/cltbld', 10:24:51 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:24:51 INFO - 'MOZ_NO_REMOTE': '1', 10:24:51 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:24:51 INFO - 'NO_EM_RESTART': '1', 10:24:51 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:24:51 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:24:51 INFO - 'PWD': '/builds/slave/test', 10:24:51 INFO - 'SHELL': '/bin/bash', 10:24:51 INFO - 'SHLVL': '1', 10:24:51 INFO - 'TERM': 'linux', 10:24:51 INFO - 'TMOUT': '86400', 10:24:51 INFO - 'USER': 'cltbld', 10:24:51 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 10:24:51 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:24:51 INFO - '_': '/tools/buildbot/bin/python'} 10:24:51 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:24:51 INFO - Downloading/unpacking blobuploader==1.2.4 10:24:51 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:51 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:51 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:51 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:51 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:51 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:52 INFO - Downloading blobuploader-1.2.4.tar.gz 10:24:52 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblobuploader-1.2.4.tar.gz 10:24:52 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 10:24:52 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 10:24:52 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:52 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:52 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:52 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:52 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:52 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:53 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Frequests-1.2.3.tar.gz 10:24:53 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 10:24:53 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 10:24:53 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:53 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:53 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:53 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:53 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:53 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:53 INFO - Downloading docopt-0.6.1.tar.gz 10:24:53 INFO - Storing download in cache at ./venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fdocopt-0.6.1.tar.gz 10:24:53 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 10:24:53 INFO - Installing collected packages: blobuploader, requests, docopt 10:24:53 INFO - Running setup.py install for blobuploader 10:24:53 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 10:24:53 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 10:24:53 INFO - Running setup.py install for requests 10:24:54 INFO - Running setup.py install for docopt 10:24:54 INFO - Successfully installed blobuploader requests docopt 10:24:54 INFO - Cleaning up... 10:24:54 INFO - Return code: 0 10:24:54 INFO - Installing None into virtualenv /builds/slave/test/build/venv 10:24:54 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:54 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:24:54 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:54 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:54 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:24:54 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:54 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 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, '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': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 10:24:54 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 10:24:54 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 10:24:54 INFO - Using env: {'DISPLAY': ':0', 10:24:54 INFO - 'HOME': '/home/cltbld', 10:24:54 INFO - 'LANG': 'en_US.UTF-8', 10:24:54 INFO - 'LANGUAGE': 'en_US:en', 10:24:54 INFO - 'LOGNAME': 'cltbld', 10:24:54 INFO - 'MAIL': '/var/mail/cltbld', 10:24:54 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:24:54 INFO - 'MOZ_NO_REMOTE': '1', 10:24:54 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:24:54 INFO - 'NO_EM_RESTART': '1', 10:24:54 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:24:54 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:24:54 INFO - 'PWD': '/builds/slave/test', 10:24:54 INFO - 'SHELL': '/bin/bash', 10:24:54 INFO - 'SHLVL': '1', 10:24:54 INFO - 'TERM': 'linux', 10:24:54 INFO - 'TMOUT': '86400', 10:24:54 INFO - 'USER': 'cltbld', 10:24:54 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 10:24:54 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:24:54 INFO - '_': '/tools/buildbot/bin/python'} 10:24:54 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 10:24:54 INFO - Running setup.py (path:/tmp/pip-VLbhDF-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 10:24:54 INFO - Running setup.py (path:/tmp/pip-kwXeI2-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 10:24:54 INFO - Running setup.py (path:/tmp/pip-_71cVp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 10:24:54 INFO - Running setup.py (path:/tmp/pip-6WskUG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 10:24:54 INFO - Running setup.py (path:/tmp/pip-a3Rcsk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 10:24:54 INFO - Running setup.py (path:/tmp/pip-P3bPTa-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 10:24:54 INFO - Running setup.py (path:/tmp/pip-tWiVJN-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 10:24:54 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 10:24:54 INFO - Running setup.py (path:/tmp/pip-U6hILu-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 10:24:55 INFO - Running setup.py (path:/tmp/pip-ZxJdVD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 10:24:55 INFO - Running setup.py (path:/tmp/pip-vXMJNu-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 10:24:55 INFO - Running setup.py (path:/tmp/pip-EC0kUH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 10:24:55 INFO - Running setup.py (path:/tmp/pip-UiXgz_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 10:24:55 INFO - Running setup.py (path:/tmp/pip-wISMgZ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 10:24:55 INFO - Running setup.py (path:/tmp/pip-5kZYJv-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 10:24:55 INFO - Running setup.py (path:/tmp/pip-uxDiCd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 10:24:55 INFO - Running setup.py (path:/tmp/pip-i7p43c-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 10:24:55 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 10:24:55 INFO - Running setup.py (path:/tmp/pip-bhit39-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 10:24:55 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 10:24:55 INFO - Running setup.py install for manifestparser 10:24:55 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 10:24:55 INFO - Running setup.py install for mozcrash 10:24:55 INFO - Running setup.py install for mozdebug 10:24:55 INFO - Running setup.py install for mozdevice 10:24:56 INFO - Installing sutini script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Installing dm script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Running setup.py install for mozfile 10:24:56 INFO - Running setup.py install for mozhttpd 10:24:56 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Running setup.py install for mozinfo 10:24:56 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Running setup.py install for mozInstall 10:24:56 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Running setup.py install for mozleak 10:24:56 INFO - Running setup.py install for mozlog 10:24:56 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Running setup.py install for moznetwork 10:24:56 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Running setup.py install for mozprocess 10:24:56 INFO - Running setup.py install for mozprofile 10:24:56 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 10:24:56 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 10:24:57 INFO - Running setup.py install for mozrunner 10:24:57 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 10:24:57 INFO - Running setup.py install for mozscreenshot 10:24:57 INFO - Running setup.py install for moztest 10:24:57 INFO - Running setup.py install for mozversion 10:24:57 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 10:24:57 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 10:24:57 INFO - Cleaning up... 10:24:57 INFO - Return code: 0 10:24:57 INFO - Installing None into virtualenv /builds/slave/test/build/venv 10:24:57 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:57 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:24:57 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:57 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:24:57 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:24:57 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:24:57 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 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, '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': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 10:24:57 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 10:24:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 10:24:57 INFO - Using env: {'DISPLAY': ':0', 10:24:57 INFO - 'HOME': '/home/cltbld', 10:24:57 INFO - 'LANG': 'en_US.UTF-8', 10:24:57 INFO - 'LANGUAGE': 'en_US:en', 10:24:57 INFO - 'LOGNAME': 'cltbld', 10:24:57 INFO - 'MAIL': '/var/mail/cltbld', 10:24:57 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:24:57 INFO - 'MOZ_NO_REMOTE': '1', 10:24:57 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:24:57 INFO - 'NO_EM_RESTART': '1', 10:24:57 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:24:57 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:24:57 INFO - 'PWD': '/builds/slave/test', 10:24:57 INFO - 'SHELL': '/bin/bash', 10:24:57 INFO - 'SHLVL': '1', 10:24:57 INFO - 'TERM': 'linux', 10:24:57 INFO - 'TMOUT': '86400', 10:24:57 INFO - 'USER': 'cltbld', 10:24:57 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 10:24:57 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:24:57 INFO - '_': '/tools/buildbot/bin/python'} 10:24:57 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:24:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 10:24:57 INFO - Running setup.py (path:/tmp/pip-eGBJ04-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 10:24:57 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 10:24:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 10:24:57 INFO - Running setup.py (path:/tmp/pip-9ilcfj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 10:24:57 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==0.16 from file:///builds/slave/test/build/tests/mozbase/mozcrash in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 10:24:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 10:24:57 INFO - Running setup.py (path:/tmp/pip-X_XYmp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 10:24:57 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///builds/slave/test/build/tests/mozbase/mozdebug in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 10:24:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 10:24:57 INFO - Running setup.py (path:/tmp/pip-Mbw2nb-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 10:24:57 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.47 from file:///builds/slave/test/build/tests/mozbase/mozdevice in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 10:24:57 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 10:24:57 INFO - Running setup.py (path:/tmp/pip-Mbd13x-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test/build/tests/mozbase/mozfile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 5)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 10:24:58 INFO - Running setup.py (path:/tmp/pip-Z_ow0o-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test/build/tests/mozbase/mozhttpd in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 6)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 10:24:58 INFO - Running setup.py (path:/tmp/pip-JtMuIc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.9 from file:///builds/slave/test/build/tests/mozbase/mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 7)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 10:24:58 INFO - Running setup.py (path:/tmp/pip-OSX7zM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.12 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 10:24:58 INFO - Running setup.py (path:/tmp/pip-_YJInS-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test/build/tests/mozbase/mozleak in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 9)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 10:24:58 INFO - Running setup.py (path:/tmp/pip-svXFzb-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.0 from file:///builds/slave/test/build/tests/mozbase/mozlog in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 10:24:58 INFO - Running setup.py (path:/tmp/pip-9OGMId-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test/build/tests/mozbase/moznetwork in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 11)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 10:24:58 INFO - Running setup.py (path:/tmp/pip-HxFp8u-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.22 from file:///builds/slave/test/build/tests/mozbase/mozprocess in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 12)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 10:24:58 INFO - Running setup.py (path:/tmp/pip-Y9qkD1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.27 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 10:24:58 INFO - Running setup.py (path:/tmp/pip-8d6U3J-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.11 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 10:24:58 INFO - Running setup.py (path:/tmp/pip-tWRg2V-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test/build/tests/mozbase/mozscreenshot in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 15)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 10:24:58 INFO - Running setup.py (path:/tmp/pip-CHHNGr-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.7 from file:///builds/slave/test/build/tests/mozbase/moztest in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 16)) 10:24:58 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 10:24:58 INFO - Running setup.py (path:/tmp/pip-g_bbaO-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///builds/slave/test/build/tests/mozbase/mozversion in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 17)) 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==0.16->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.47->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 10:24:58 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.47->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 10:24:58 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 10:24:58 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:58 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:24:58 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:58 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 10:24:58 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 10:24:58 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 10:25:00 INFO - Downloading blessings-1.5.1.tar.gz 10:25:00 INFO - Storing download in cache at /builds/slave/test/build/venv/cache/http%3A%2F%2Fpypi.pvt.build.mozilla.org%2Fpub%2Fblessings-1.5.1.tar.gz 10:25:00 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 10:25:00 INFO - Installing collected packages: blessings 10:25:00 INFO - Running setup.py install for blessings 10:25:00 INFO - Successfully installed blessings 10:25:00 INFO - Cleaning up... 10:25:00 INFO - Return code: 0 10:25:00 INFO - Done creating virtualenv /builds/slave/test/build/venv. 10:25:00 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 10:25:00 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 10:25:01 INFO - Reading from file tmpfile_stdout 10:25:01 INFO - Current package versions: 10:25:01 INFO - argparse == 1.2.1 10:25:01 INFO - blessings == 1.5.1 10:25:01 INFO - blobuploader == 1.2.4 10:25:01 INFO - docopt == 0.6.1 10:25:01 INFO - manifestparser == 1.1 10:25:01 INFO - mozInstall == 1.12 10:25:01 INFO - mozcrash == 0.16 10:25:01 INFO - mozdebug == 0.1 10:25:01 INFO - mozdevice == 0.47 10:25:01 INFO - mozfile == 1.2 10:25:01 INFO - mozhttpd == 0.7 10:25:01 INFO - mozinfo == 0.9 10:25:01 INFO - mozleak == 0.1 10:25:01 INFO - mozlog == 3.0 10:25:01 INFO - moznetwork == 0.27 10:25:01 INFO - mozprocess == 0.22 10:25:01 INFO - mozprofile == 0.27 10:25:01 INFO - mozrunner == 6.11 10:25:01 INFO - mozscreenshot == 0.1 10:25:01 INFO - mozsystemmonitor == 0.0 10:25:01 INFO - moztest == 0.7 10:25:01 INFO - mozversion == 1.4 10:25:01 INFO - psutil == 3.1.1 10:25:01 INFO - requests == 1.2.3 10:25:01 INFO - wsgiref == 0.1.2 10:25:01 INFO - Installing None into virtualenv /builds/slave/test/build/venv 10:25:01 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:25:01 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 10:25:01 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:25:01 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:25:01 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 10:25:01 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 10:25:01 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 0x7fdd35f06c70>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1ab56c0>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1b669a0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, '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': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 10:25:01 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--download-cache', '/builds/slave/test/build/venv/cache', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/talos 10:25:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --download-cache /builds/slave/test/build/venv/cache --timeout 120 -r /builds/slave/test/build/tests/talos/requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 10:25:01 INFO - Using env: {'DISPLAY': ':0', 10:25:01 INFO - 'HOME': '/home/cltbld', 10:25:01 INFO - 'LANG': 'en_US.UTF-8', 10:25:01 INFO - 'LANGUAGE': 'en_US:en', 10:25:01 INFO - 'LOGNAME': 'cltbld', 10:25:01 INFO - 'MAIL': '/var/mail/cltbld', 10:25:01 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:25:01 INFO - 'MOZ_NO_REMOTE': '1', 10:25:01 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:25:01 INFO - 'NO_EM_RESTART': '1', 10:25:01 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:25:01 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:25:01 INFO - 'PWD': '/builds/slave/test', 10:25:01 INFO - 'SHELL': '/bin/bash', 10:25:01 INFO - 'SHLVL': '1', 10:25:01 INFO - 'TERM': 'linux', 10:25:01 INFO - 'TMOUT': '86400', 10:25:01 INFO - 'USER': 'cltbld', 10:25:01 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 10:25:01 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:25:01 INFO - '_': '/tools/buildbot/bin/python'} 10:25:01 INFO - Ignoring indexes: https://pypi.python.org/simple/ 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2)) 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3)) 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5)) 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6)) 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7)) 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 3)) 10:25:01 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.0->mozcrash>=0.15->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 10:25:01 INFO - Cleaning up... 10:25:01 INFO - Return code: 0 10:25:01 INFO - Running post-action listener: _resource_record_post_action 10:25:01 INFO - Running post-action listener: _start_resource_monitoring 10:25:01 INFO - Starting resource monitoring. 10:25:01 INFO - ##### 10:25:01 INFO - ##### Running install step. 10:25:01 INFO - ##### 10:25:01 INFO - Running pre-action listener: _resource_record_pre_action 10:25:01 INFO - Running main action method: install 10:25:01 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 10:25:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 10:25:01 INFO - Reading from file tmpfile_stdout 10:25:01 INFO - Detecting whether we're running mozinstall >=1.0... 10:25:01 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 10:25:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 10:25:01 INFO - Reading from file tmpfile_stdout 10:25:01 INFO - Output received: 10:25:01 INFO - Usage: mozinstall [options] installer 10:25:01 INFO - Options: 10:25:01 INFO - -h, --help show this help message and exit 10:25:01 INFO - -d DEST, --destination=DEST 10:25:01 INFO - Directory to install application into. [default: 10:25:01 INFO - "/builds/slave/test"] 10:25:01 INFO - --app=APP Application being installed. [default: firefox] 10:25:01 INFO - mkdir: /builds/slave/test/build/application 10:25:01 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2', '--destination', '/builds/slave/test/build/application'] 10:25:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 --destination /builds/slave/test/build/application 10:25:15 INFO - Reading from file tmpfile_stdout 10:25:15 INFO - Output received: 10:25:15 INFO - /builds/slave/test/build/application/firefox/firefox 10:25:15 INFO - Running post-action listener: _resource_record_post_action 10:25:15 INFO - ##### 10:25:15 INFO - ##### Running run-tests step. 10:25:15 INFO - ##### 10:25:15 INFO - Running pre-action listener: _resource_record_pre_action 10:25:15 INFO - Running main action method: run_tests 10:25:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 10:25:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 10:25:15 INFO - Python 2.7.3 10:25:15 INFO - Return code: 0 10:25:15 INFO - grabbing minidump binary from tooltool 10:25:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 10:25:15 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 0x1bf5ac0>, '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 0x1bf69a0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1bf6e50>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 10:25:15 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test/build 10:25:15 INFO - Copy/paste: /tools/tooltool.py --url https://api.pub.build.mozilla.org/tooltool/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest -o -c /builds/tooltool_cache 10:25:15 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 10:25:15 INFO - Return code: 0 10:25:15 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 10:25:15 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 10:25:15 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 10:25:15 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 10:25:15 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 10:25:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Inbound-Non-PGO', '--suite', 'other', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-048', '--webServer', 'localhost'] in /builds/slave/test/build 10:25:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --debug --branchName Mozilla-Inbound-Non-PGO --suite other --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip --title talos-linux64-ix-048 --webServer localhost 10:25:15 INFO - Using env: {'DISPLAY': ':0', 10:25:15 INFO - 'HOME': '/home/cltbld', 10:25:15 INFO - 'LANG': 'en_US.UTF-8', 10:25:15 INFO - 'LANGUAGE': 'en_US:en', 10:25:15 INFO - 'LOGNAME': 'cltbld', 10:25:15 INFO - 'MAIL': '/var/mail/cltbld', 10:25:15 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 10:25:15 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 10:25:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 10:25:15 INFO - 'MOZ_NO_REMOTE': '1', 10:25:15 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 10:25:15 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:25:15 INFO - 'NO_EM_RESTART': '1', 10:25:15 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:25:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:25:15 INFO - 'PWD': '/builds/slave/test', 10:25:15 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 10:25:15 INFO - 'SHELL': '/bin/bash', 10:25:15 INFO - 'SHLVL': '1', 10:25:15 INFO - 'TERM': 'linux', 10:25:15 INFO - 'TMOUT': '86400', 10:25:15 INFO - 'USER': 'cltbld', 10:25:15 INFO - 'XDG_SESSION_COOKIE': 'fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059', 10:25:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 10:25:15 INFO - '_': '/tools/buildbot/bin/python'} 10:25:15 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--debug', '--branchName', 'Mozilla-Inbound-Non-PGO', '--suite', 'other', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-048', '--webServer', 'localhost'] with output_timeout 3600 10:25:16 INFO - mozversion INFO | application_buildid: 20151112100440 10:25:16 INFO - mozversion INFO | application_changeset: 756632e20aa46ce0b2feebdf6f04e6dacdc09811 10:25:16 INFO - mozversion INFO | application_display_name: Nightly 10:25:16 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 10:25:16 INFO - mozversion INFO | application_name: Firefox 10:25:16 INFO - mozversion INFO | application_remotingname: firefox 10:25:16 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/mozilla-inbound 10:25:16 INFO - mozversion INFO | application_vendor: Mozilla 10:25:16 INFO - mozversion INFO | application_version: 45.0a1 10:25:16 INFO - mozversion INFO | platform_buildid: 20151112100440 10:25:16 INFO - mozversion INFO | platform_changeset: 756632e20aa46ce0b2feebdf6f04e6dacdc09811 10:25:16 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/mozilla-inbound 10:25:16 INFO - mozversion INFO | platform_version: 45.0a1 10:25:16 INFO - 2015-11-12 10:25:16,112 DEBUG : using testdate: 1447352716 10:25:16 INFO - 2015-11-12 10:25:16,112 DEBUG : actual date: 1447352716 10:25:16 INFO - 2015-11-12 10:25:16,119 INFO : starting webserver on 'localhost:53596' 10:25:16 INFO - 2015-11-12 10:25:16,120 INFO : Starting test suite talos-linux64-ix-048 10:25:16 INFO - 2015-11-12 10:25:16,120 INFO : Starting test a11yr 10:25:16 INFO - 2015-11-12 10:25:16,120 DEBUG : operating with platform_type : linux_ 10:25:16 INFO - 2015-11-12 10:25:16,121 INFO : Initialising browser for a11yr test... 10:25:16 INFO - 2015-11-12 10:25:16,127 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_5w2w/profile http://localhost:53596/getInfo.html 10:25:22 INFO - 2015-11-12 10:25:22,608 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 10:25:22 INFO - 2015-11-12 10:25:22,608 DEBUG : BROWSER_OUTPUT: colorDepth:24 10:25:22 INFO - 2015-11-12 10:25:22,608 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 10:25:22 INFO - 2015-11-12 10:25:22,608 DEBUG : BROWSER_OUTPUT: __metrics 10:25:22 INFO - 2015-11-12 10:25:22,724 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 10:25:24 INFO - 2015-11-12 10:25:24,048 INFO : Browser initialized. 10:25:24 INFO - 2015-11-12 10:25:24,049 INFO : Running cycle 1/1 for a11yr test... 10:25:24 INFO - 2015-11-12 10:25:24,049 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpH_5w2w/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/a11y/a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25 10:25:35 INFO - 2015-11-12 10:25:35,987 DEBUG : BROWSER_OUTPUT: RSS: Main: 141590528 10:25:35 INFO - 2015-11-12 10:25:35,987 DEBUG : BROWSER_OUTPUT: 10:25:37 INFO - 2015-11-12 10:25:37,412 DEBUG : BROWSER_OUTPUT: 10:25:37 INFO - 2015-11-12 10:25:37,412 DEBUG : BROWSER_OUTPUT: (firefox:29721): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 10:25:37 INFO - 2015-11-12 10:25:37,432 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:25:38 INFO - 2015-11-12 10:25:38,048 DEBUG : BROWSER_OUTPUT: RSS: Main: 178913280 10:25:38 INFO - 2015-11-12 10:25:38,048 DEBUG : BROWSER_OUTPUT: 10:25:39 INFO - 2015-11-12 10:25:39,606 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:25:40 INFO - 2015-11-12 10:25:40,294 DEBUG : BROWSER_OUTPUT: RSS: Main: 183635968 10:25:40 INFO - 2015-11-12 10:25:40,295 DEBUG : BROWSER_OUTPUT: 10:25:41 INFO - 2015-11-12 10:25:41,861 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:25:42 INFO - 2015-11-12 10:25:42,548 DEBUG : BROWSER_OUTPUT: RSS: Main: 180060160 10:25:42 INFO - 2015-11-12 10:25:42,548 DEBUG : BROWSER_OUTPUT: 10:25:44 INFO - 2015-11-12 10:25:44,201 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:25:44 INFO - 2015-11-12 10:25:44,909 DEBUG : BROWSER_OUTPUT: RSS: Main: 182444032 10:25:44 INFO - 2015-11-12 10:25:44,910 DEBUG : BROWSER_OUTPUT: 10:25:46 INFO - 2015-11-12 10:25:46,516 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:25:47 INFO - 2015-11-12 10:25:47,203 DEBUG : BROWSER_OUTPUT: RSS: Main: 179429376 10:25:47 INFO - 2015-11-12 10:25:47,204 DEBUG : BROWSER_OUTPUT: 10:25:48 INFO - 2015-11-12 10:25:48,729 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:25:49 INFO - 2015-11-12 10:25:49,416 DEBUG : BROWSER_OUTPUT: RSS: Main: 180666368 10:25:49 INFO - 2015-11-12 10:25:49,416 DEBUG : BROWSER_OUTPUT: 10:25:50 INFO - 2015-11-12 10:25:50,974 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:25:51 INFO - 2015-11-12 10:25:51,669 DEBUG : BROWSER_OUTPUT: RSS: Main: 180920320 10:25:51 INFO - 2015-11-12 10:25:51,669 DEBUG : BROWSER_OUTPUT: 10:25:53 INFO - 2015-11-12 10:25:53,200 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:25:53 INFO - 2015-11-12 10:25:53,890 DEBUG : BROWSER_OUTPUT: RSS: Main: 182583296 10:25:53 INFO - 2015-11-12 10:25:53,890 DEBUG : BROWSER_OUTPUT: 10:25:55 INFO - 2015-11-12 10:25:55,537 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:25:56 INFO - 2015-11-12 10:25:56,240 DEBUG : BROWSER_OUTPUT: RSS: Main: 182915072 10:25:56 INFO - 2015-11-12 10:25:56,240 DEBUG : BROWSER_OUTPUT: 10:25:57 INFO - 2015-11-12 10:25:57,770 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:25:58 INFO - 2015-11-12 10:25:58,464 DEBUG : BROWSER_OUTPUT: RSS: Main: 182398976 10:25:58 INFO - 2015-11-12 10:25:58,465 DEBUG : BROWSER_OUTPUT: 10:26:00 INFO - 2015-11-12 10:26:00,119 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:00 INFO - 2015-11-12 10:26:00,705 DEBUG : BROWSER_OUTPUT: 10:26:00 INFO - 2015-11-12 10:26:00,705 DEBUG : BROWSER_OUTPUT: (firefox:29721): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 10:26:00 INFO - 2015-11-12 10:26:00,822 DEBUG : BROWSER_OUTPUT: RSS: Main: 184115200 10:26:00 INFO - 2015-11-12 10:26:00,822 DEBUG : BROWSER_OUTPUT: 10:26:02 INFO - 2015-11-12 10:26:02,453 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:03 INFO - 2015-11-12 10:26:03,155 DEBUG : BROWSER_OUTPUT: RSS: Main: 184434688 10:26:03 INFO - 2015-11-12 10:26:03,155 DEBUG : BROWSER_OUTPUT: 10:26:04 INFO - 2015-11-12 10:26:04,612 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:05 INFO - 2015-11-12 10:26:05,314 DEBUG : BROWSER_OUTPUT: RSS: Main: 181751808 10:26:05 INFO - 2015-11-12 10:26:05,314 DEBUG : BROWSER_OUTPUT: 10:26:06 INFO - 2015-11-12 10:26:06,886 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:07 INFO - 2015-11-12 10:26:07,576 DEBUG : BROWSER_OUTPUT: RSS: Main: 183201792 10:26:07 INFO - 2015-11-12 10:26:07,576 DEBUG : BROWSER_OUTPUT: 10:26:09 INFO - 2015-11-12 10:26:09,154 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:09 INFO - 2015-11-12 10:26:09,849 DEBUG : BROWSER_OUTPUT: RSS: Main: 181018624 10:26:09 INFO - 2015-11-12 10:26:09,849 DEBUG : BROWSER_OUTPUT: 10:26:11 INFO - 2015-11-12 10:26:11,407 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:12 INFO - 2015-11-12 10:26:12,098 DEBUG : BROWSER_OUTPUT: RSS: Main: 180850688 10:26:12 INFO - 2015-11-12 10:26:12,098 DEBUG : BROWSER_OUTPUT: 10:26:13 INFO - 2015-11-12 10:26:13,655 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:14 INFO - 2015-11-12 10:26:14,357 DEBUG : BROWSER_OUTPUT: RSS: Main: 181600256 10:26:14 INFO - 2015-11-12 10:26:14,357 DEBUG : BROWSER_OUTPUT: 10:26:15 INFO - 2015-11-12 10:26:15,915 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:16 INFO - 2015-11-12 10:26:16,610 DEBUG : BROWSER_OUTPUT: RSS: Main: 180981760 10:26:16 INFO - 2015-11-12 10:26:16,610 DEBUG : BROWSER_OUTPUT: 10:26:18 INFO - 2015-11-12 10:26:18,156 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:18 INFO - 2015-11-12 10:26:18,850 DEBUG : BROWSER_OUTPUT: RSS: Main: 182296576 10:26:18 INFO - 2015-11-12 10:26:18,850 DEBUG : BROWSER_OUTPUT: 10:26:20 INFO - 2015-11-12 10:26:20,397 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:21 INFO - 2015-11-12 10:26:21,099 DEBUG : BROWSER_OUTPUT: RSS: Main: 182370304 10:26:21 INFO - 2015-11-12 10:26:21,099 DEBUG : BROWSER_OUTPUT: 10:26:22 INFO - 2015-11-12 10:26:22,718 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:23 INFO - 2015-11-12 10:26:23,419 DEBUG : BROWSER_OUTPUT: RSS: Main: 182489088 10:26:23 INFO - 2015-11-12 10:26:23,419 DEBUG : BROWSER_OUTPUT: 10:26:24 INFO - 2015-11-12 10:26:24,985 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:25 INFO - 2015-11-12 10:26:25,667 DEBUG : BROWSER_OUTPUT: 1447352785660 addons.productaddons ERROR Request failed certificate checks: [Exception... "SSL is required and URI scheme is not https." nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)" location: "JS frame :: resource://gre/modules/CertUtils.jsm :: checkCert :: line 145" data: no] 10:26:25 INFO - 2015-11-12 10:26:25,703 DEBUG : BROWSER_OUTPUT: RSS: Main: 189202432 10:26:25 INFO - 2015-11-12 10:26:25,703 DEBUG : BROWSER_OUTPUT: 10:26:27 INFO - 2015-11-12 10:26:27,257 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:27 INFO - 2015-11-12 10:26:27,958 DEBUG : BROWSER_OUTPUT: RSS: Main: 191664128 10:26:27 INFO - 2015-11-12 10:26:27,958 DEBUG : BROWSER_OUTPUT: 10:26:29 INFO - 2015-11-12 10:26:29,524 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:30 INFO - 2015-11-12 10:26:30,226 DEBUG : BROWSER_OUTPUT: RSS: Main: 191782912 10:26:30 INFO - 2015-11-12 10:26:30,226 DEBUG : BROWSER_OUTPUT: 10:26:31 INFO - 2015-11-12 10:26:31,885 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 10:26:32 INFO - 2015-11-12 10:26:32,595 DEBUG : BROWSER_OUTPUT: RSS: Main: 195424256 10:26:32 INFO - 2015-11-12 10:26:32,595 DEBUG : BROWSER_OUTPUT: 10:26:33 INFO - 2015-11-12 10:26:33,839 DEBUG : BROWSER_OUTPUT: 10:26:33 INFO - 2015-11-12 10:26:33,839 DEBUG : BROWSER_OUTPUT: (firefox:29721): GLib-GObject-CRITICAL **: g_type_add_interface_static: assertion `g_type_parent (interface_type) == G_TYPE_INTERFACE' failed 10:26:33 INFO - 2015-11-12 10:26:33,860 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:34 INFO - 2015-11-12 10:26:34,441 DEBUG : BROWSER_OUTPUT: RSS: Main: 190300160 10:26:34 INFO - 2015-11-12 10:26:34,441 DEBUG : BROWSER_OUTPUT: 10:26:35 INFO - 2015-11-12 10:26:35,268 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:35 INFO - 2015-11-12 10:26:35,855 DEBUG : BROWSER_OUTPUT: RSS: Main: 187457536 10:26:35 INFO - 2015-11-12 10:26:35,855 DEBUG : BROWSER_OUTPUT: 10:26:36 INFO - 2015-11-12 10:26:36,737 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:37 INFO - 2015-11-12 10:26:37,326 DEBUG : BROWSER_OUTPUT: RSS: Main: 188792832 10:26:37 INFO - 2015-11-12 10:26:37,326 DEBUG : BROWSER_OUTPUT: 10:26:38 INFO - 2015-11-12 10:26:38,180 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:38 INFO - 2015-11-12 10:26:38,765 DEBUG : BROWSER_OUTPUT: RSS: Main: 180592640 10:26:38 INFO - 2015-11-12 10:26:38,765 DEBUG : BROWSER_OUTPUT: 10:26:39 INFO - 2015-11-12 10:26:39,619 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:40 INFO - 2015-11-12 10:26:40,205 DEBUG : BROWSER_OUTPUT: RSS: Main: 181293056 10:26:40 INFO - 2015-11-12 10:26:40,205 DEBUG : BROWSER_OUTPUT: 10:26:41 INFO - 2015-11-12 10:26:41,067 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:41 INFO - 2015-11-12 10:26:41,653 DEBUG : BROWSER_OUTPUT: RSS: Main: 178884608 10:26:41 INFO - 2015-11-12 10:26:41,653 DEBUG : BROWSER_OUTPUT: 10:26:42 INFO - 2015-11-12 10:26:42,515 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:43 INFO - 2015-11-12 10:26:43,101 DEBUG : BROWSER_OUTPUT: RSS: Main: 180535296 10:26:43 INFO - 2015-11-12 10:26:43,101 DEBUG : BROWSER_OUTPUT: 10:26:43 INFO - 2015-11-12 10:26:43,963 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:44 INFO - 2015-11-12 10:26:44,544 DEBUG : BROWSER_OUTPUT: RSS: Main: 179060736 10:26:44 INFO - 2015-11-12 10:26:44,544 DEBUG : BROWSER_OUTPUT: 10:26:45 INFO - 2015-11-12 10:26:45,411 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:45 INFO - 2015-11-12 10:26:45,997 DEBUG : BROWSER_OUTPUT: RSS: Main: 178196480 10:26:45 INFO - 2015-11-12 10:26:45,997 DEBUG : BROWSER_OUTPUT: 10:26:46 INFO - 2015-11-12 10:26:46,824 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:47 INFO - 2015-11-12 10:26:47,411 DEBUG : BROWSER_OUTPUT: RSS: Main: 180772864 10:26:47 INFO - 2015-11-12 10:26:47,411 DEBUG : BROWSER_OUTPUT: 10:26:48 INFO - 2015-11-12 10:26:48,273 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:48 INFO - 2015-11-12 10:26:48,858 DEBUG : BROWSER_OUTPUT: RSS: Main: 179191808 10:26:48 INFO - 2015-11-12 10:26:48,858 DEBUG : BROWSER_OUTPUT: 10:26:49 INFO - 2015-11-12 10:26:49,740 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:50 INFO - 2015-11-12 10:26:50,322 DEBUG : BROWSER_OUTPUT: RSS: Main: 180776960 10:26:50 INFO - 2015-11-12 10:26:50,322 DEBUG : BROWSER_OUTPUT: 10:26:51 INFO - 2015-11-12 10:26:51,184 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:51 INFO - 2015-11-12 10:26:51,770 DEBUG : BROWSER_OUTPUT: RSS: Main: 178880512 10:26:51 INFO - 2015-11-12 10:26:51,770 DEBUG : BROWSER_OUTPUT: 10:26:52 INFO - 2015-11-12 10:26:52,637 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:53 INFO - 2015-11-12 10:26:53,223 DEBUG : BROWSER_OUTPUT: RSS: Main: 178106368 10:26:53 INFO - 2015-11-12 10:26:53,223 DEBUG : BROWSER_OUTPUT: 10:26:54 INFO - 2015-11-12 10:26:54,105 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:54 INFO - 2015-11-12 10:26:54,706 DEBUG : BROWSER_OUTPUT: RSS: Main: 176394240 10:26:54 INFO - 2015-11-12 10:26:54,706 DEBUG : BROWSER_OUTPUT: 10:26:55 INFO - 2015-11-12 10:26:55,576 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:56 INFO - 2015-11-12 10:26:56,170 DEBUG : BROWSER_OUTPUT: RSS: Main: 179576832 10:26:56 INFO - 2015-11-12 10:26:56,170 DEBUG : BROWSER_OUTPUT: 10:26:57 INFO - 2015-11-12 10:26:57,032 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:57 INFO - 2015-11-12 10:26:57,618 DEBUG : BROWSER_OUTPUT: RSS: Main: 178106368 10:26:57 INFO - 2015-11-12 10:26:57,618 DEBUG : BROWSER_OUTPUT: 10:26:58 INFO - 2015-11-12 10:26:58,480 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:26:59 INFO - 2015-11-12 10:26:59,066 DEBUG : BROWSER_OUTPUT: RSS: Main: 178733056 10:26:59 INFO - 2015-11-12 10:26:59,066 DEBUG : BROWSER_OUTPUT: 10:26:59 INFO - 2015-11-12 10:26:59,948 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:27:00 INFO - 2015-11-12 10:27:00,542 DEBUG : BROWSER_OUTPUT: RSS: Main: 178102272 10:27:00 INFO - 2015-11-12 10:27:00,542 DEBUG : BROWSER_OUTPUT: 10:27:01 INFO - 2015-11-12 10:27:01,429 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:27:02 INFO - 2015-11-12 10:27:02,030 DEBUG : BROWSER_OUTPUT: RSS: Main: 178577408 10:27:02 INFO - 2015-11-12 10:27:02,030 DEBUG : BROWSER_OUTPUT: 10:27:02 INFO - 2015-11-12 10:27:02,913 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:27:03 INFO - 2015-11-12 10:27:03,503 DEBUG : BROWSER_OUTPUT: RSS: Main: 179130368 10:27:03 INFO - 2015-11-12 10:27:03,503 DEBUG : BROWSER_OUTPUT: 10:27:04 INFO - 2015-11-12 10:27:04,364 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:27:04 INFO - 2015-11-12 10:27:04,946 DEBUG : BROWSER_OUTPUT: RSS: Main: 179707904 10:27:04 INFO - 2015-11-12 10:27:04,946 DEBUG : BROWSER_OUTPUT: 10:27:05 INFO - 2015-11-12 10:27:05,775 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:27:06 INFO - 2015-11-12 10:27:06,361 DEBUG : BROWSER_OUTPUT: RSS: Main: 178118656 10:27:06 INFO - 2015-11-12 10:27:06,361 DEBUG : BROWSER_OUTPUT: 10:27:07 INFO - 2015-11-12 10:27:07,228 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:27:07 INFO - 2015-11-12 10:27:07,814 DEBUG : BROWSER_OUTPUT: RSS: Main: 179986432 10:27:07 INFO - 2015-11-12 10:27:07,815 DEBUG : BROWSER_OUTPUT: 10:27:08 INFO - 2015-11-12 10:27:08,696 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///builds/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///builds/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: RSS: Main: 181645312 10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: 10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: __start_tp_report 10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load 10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details 10:27:08 INFO - 2015-11-12 10:27:08,947 DEBUG : BROWSER_OUTPUT: |i|pagename|runs| 10:27:08 INFO - 2015-11-12 10:27:08,948 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1389;1474;1476;1558;1468;1462;1468;1466;1548;1471;1563;1559;1366;1456;1491;1473;1475;1492;1476;1479;1561;1487;1471;1476;1562 10:27:08 INFO - 2015-11-12 10:27:08,948 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;333;324;327;326;327;326;326;325;326;324;327;328;325;325;328;327;327;324;326;326;328;324;325;329;328 10:27:08 INFO - 2015-11-12 10:27:08,948 DEBUG : BROWSER_OUTPUT: __end_tp_report 10:27:08 INFO - 2015-11-12 10:27:08,948 DEBUG : BROWSER_OUTPUT: __start_cc_report 10:27:08 INFO - 2015-11-12 10:27:08,948 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,6831 10:27:08 INFO - 2015-11-12 10:27:08,949 DEBUG : BROWSER_OUTPUT: __end_cc_report 10:27:08 INFO - 2015-11-12 10:27:08,949 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352828944__endTimestamp 10:27:08 INFO - 2015-11-12 10:27:08,949 DEBUG : BROWSER_OUTPUT: 10:27:08 INFO - 2015-11-12 10:27:08,949 DEBUG : BROWSER_OUTPUT: ------- Summary: start ------- 10:27:08 INFO - 2015-11-12 10:27:08,949 DEBUG : BROWSER_OUTPUT: Number of tests: 2 10:27:08 INFO - 2015-11-12 10:27:08,950 DEBUG : BROWSER_OUTPUT: 10:27:08 INFO - 2015-11-12 10:27:08,950 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1486.68 Median:1476.00 stddev:49.71 (3.4%) stddev-sans-first:46.33 10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT: Values: 1389.0 1474.0 1476.0 1558.0 1468.0 1462.0 1468.0 1466.0 1548.0 1471.0 1563.0 1559.0 1366.0 1456.0 1491.0 1473.0 1475.0 1492.0 1476.0 1479.0 1561.0 1487.0 1471.0 1476.0 1562.0 10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT: 10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:326.44 Median:326.00 stddev:1.98 (0.6%) stddev-sans-first:1.46 10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT: Values: 333.0 324.0 327.0 326.0 327.0 326.0 326.0 325.0 326.0 324.0 327.0 328.0 325.0 325.0 328.0 327.0 327.0 324.0 326.0 326.0 328.0 324.0 325.0 329.0 328.0 10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT: -------- Summary: end -------- 10:27:08 INFO - 2015-11-12 10:27:08,951 DEBUG : BROWSER_OUTPUT: 10:27:09 INFO - 2015-11-12 10:27:09,674 INFO : Browser exited with error code: 0 10:27:09 INFO - 2015-11-12 10:27:09,694 INFO : Completed test a11yr (00:01:53) 10:27:09 INFO - 2015-11-12 10:27:09,694 INFO : Starting test ts_paint 10:27:09 INFO - 2015-11-12 10:27:09,694 DEBUG : operating with platform_type : linux_ 10:27:09 INFO - 2015-11-12 10:27:09,694 INFO : Initialising browser for ts_paint test... 10:27:09 INFO - 2015-11-12 10:27:09,700 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/getInfo.html 10:27:13 INFO - 2015-11-12 10:27:13,561 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 10:27:13 INFO - 2015-11-12 10:27:13,561 DEBUG : BROWSER_OUTPUT: colorDepth:24 10:27:13 INFO - 2015-11-12 10:27:13,561 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 10:27:13 INFO - 2015-11-12 10:27:13,561 DEBUG : BROWSER_OUTPUT: __metrics 10:27:13 INFO - 2015-11-12 10:27:13,710 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 10:27:15 INFO - 2015-11-12 10:27:15,019 INFO : Browser initialized. 10:27:15 INFO - 2015-11-12 10:27:15,020 INFO : Running cycle 1/20 for ts_paint test... 10:27:15 INFO - 2015-11-12 10:27:15,020 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:16 INFO - 2015-11-12 10:27:16,660 DEBUG : BROWSER_OUTPUT: __start_report1639__end_report 10:27:16 INFO - 2015-11-12 10:27:16,660 DEBUG : BROWSER_OUTPUT: 10:27:16 INFO - 2015-11-12 10:27:16,676 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352836675__endTimestamp 10:27:17 INFO - 2015-11-12 10:27:17,558 INFO : Browser exited with error code: 0 10:27:17 INFO - 2015-11-12 10:27:17,560 INFO : Running cycle 2/20 for ts_paint test... 10:27:17 INFO - 2015-11-12 10:27:17,560 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:18 INFO - 2015-11-12 10:27:18,690 DEBUG : BROWSER_OUTPUT: __start_report1122__end_report 10:27:18 INFO - 2015-11-12 10:27:18,690 DEBUG : BROWSER_OUTPUT: 10:27:18 INFO - 2015-11-12 10:27:18,694 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352838693__endTimestamp 10:27:19 INFO - 2015-11-12 10:27:19,449 INFO : Browser exited with error code: 0 10:27:19 INFO - 2015-11-12 10:27:19,451 INFO : Running cycle 3/20 for ts_paint test... 10:27:19 INFO - 2015-11-12 10:27:19,451 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:20 INFO - 2015-11-12 10:27:20,642 DEBUG : BROWSER_OUTPUT: __start_report1189__end_report 10:27:20 INFO - 2015-11-12 10:27:20,642 DEBUG : BROWSER_OUTPUT: 10:27:20 INFO - 2015-11-12 10:27:20,646 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352840645__endTimestamp 10:27:21 INFO - 2015-11-12 10:27:21,438 INFO : Browser exited with error code: 0 10:27:21 INFO - 2015-11-12 10:27:21,440 INFO : Running cycle 4/20 for ts_paint test... 10:27:21 INFO - 2015-11-12 10:27:21,440 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:22 INFO - 2015-11-12 10:27:22,560 DEBUG : BROWSER_OUTPUT: __start_report1115__end_report 10:27:22 INFO - 2015-11-12 10:27:22,560 DEBUG : BROWSER_OUTPUT: 10:27:22 INFO - 2015-11-12 10:27:22,596 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352842591__endTimestamp 10:27:23 INFO - 2015-11-12 10:27:23,426 INFO : Browser exited with error code: 0 10:27:23 INFO - 2015-11-12 10:27:23,428 INFO : Running cycle 5/20 for ts_paint test... 10:27:23 INFO - 2015-11-12 10:27:23,428 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:24 INFO - 2015-11-12 10:27:24,576 DEBUG : BROWSER_OUTPUT: __start_report1148__end_report 10:27:24 INFO - 2015-11-12 10:27:24,577 DEBUG : BROWSER_OUTPUT: 10:27:24 INFO - 2015-11-12 10:27:24,584 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352844581__endTimestamp 10:27:25 INFO - 2015-11-12 10:27:25,414 INFO : Browser exited with error code: 0 10:27:25 INFO - 2015-11-12 10:27:25,416 INFO : Running cycle 6/20 for ts_paint test... 10:27:25 INFO - 2015-11-12 10:27:25,416 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:26 INFO - 2015-11-12 10:27:26,529 DEBUG : BROWSER_OUTPUT: __start_report1102__end_report 10:27:26 INFO - 2015-11-12 10:27:26,529 DEBUG : BROWSER_OUTPUT: 10:27:26 INFO - 2015-11-12 10:27:26,544 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352846539__endTimestamp 10:27:27 INFO - 2015-11-12 10:27:27,403 INFO : Browser exited with error code: 0 10:27:27 INFO - 2015-11-12 10:27:27,404 INFO : Running cycle 7/20 for ts_paint test... 10:27:27 INFO - 2015-11-12 10:27:27,405 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:28 INFO - 2015-11-12 10:27:28,559 DEBUG : BROWSER_OUTPUT: __start_report1147__end_report 10:27:28 INFO - 2015-11-12 10:27:28,560 DEBUG : BROWSER_OUTPUT: 10:27:28 INFO - 2015-11-12 10:27:28,575 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352848574__endTimestamp 10:27:29 INFO - 2015-11-12 10:27:29,441 INFO : Browser exited with error code: 0 10:27:29 INFO - 2015-11-12 10:27:29,443 INFO : Running cycle 8/20 for ts_paint test... 10:27:29 INFO - 2015-11-12 10:27:29,443 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:30 INFO - 2015-11-12 10:27:30,599 DEBUG : BROWSER_OUTPUT: __start_report1145__end_report 10:27:30 INFO - 2015-11-12 10:27:30,599 DEBUG : BROWSER_OUTPUT: 10:27:30 INFO - 2015-11-12 10:27:30,627 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352850624__endTimestamp 10:27:31 INFO - 2015-11-12 10:27:31,532 INFO : Browser exited with error code: 0 10:27:31 INFO - 2015-11-12 10:27:31,533 INFO : Running cycle 9/20 for ts_paint test... 10:27:31 INFO - 2015-11-12 10:27:31,534 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:32 INFO - 2015-11-12 10:27:32,680 DEBUG : BROWSER_OUTPUT: __start_report1141__end_report 10:27:32 INFO - 2015-11-12 10:27:32,680 DEBUG : BROWSER_OUTPUT: 10:27:32 INFO - 2015-11-12 10:27:32,687 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352852685__endTimestamp 10:27:33 INFO - 2015-11-12 10:27:33,571 INFO : Browser exited with error code: 0 10:27:33 INFO - 2015-11-12 10:27:33,573 INFO : Running cycle 10/20 for ts_paint test... 10:27:33 INFO - 2015-11-12 10:27:33,573 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:34 INFO - 2015-11-12 10:27:34,710 DEBUG : BROWSER_OUTPUT: __start_report1129__end_report 10:27:34 INFO - 2015-11-12 10:27:34,710 DEBUG : BROWSER_OUTPUT: 10:27:34 INFO - 2015-11-12 10:27:34,725 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352854723__endTimestamp 10:27:35 INFO - 2015-11-12 10:27:35,559 INFO : Browser exited with error code: 0 10:27:35 INFO - 2015-11-12 10:27:35,560 INFO : Running cycle 11/20 for ts_paint test... 10:27:35 INFO - 2015-11-12 10:27:35,561 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:36 INFO - 2015-11-12 10:27:36,717 DEBUG : BROWSER_OUTPUT: __start_report1157__end_report 10:27:36 INFO - 2015-11-12 10:27:36,717 DEBUG : BROWSER_OUTPUT: 10:27:36 INFO - 2015-11-12 10:27:36,725 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352856723__endTimestamp 10:27:37 INFO - 2015-11-12 10:27:37,548 INFO : Browser exited with error code: 0 10:27:37 INFO - 2015-11-12 10:27:37,549 INFO : Running cycle 12/20 for ts_paint test... 10:27:37 INFO - 2015-11-12 10:27:37,550 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:38 INFO - 2015-11-12 10:27:38,723 DEBUG : BROWSER_OUTPUT: __start_report1172__end_report 10:27:38 INFO - 2015-11-12 10:27:38,724 DEBUG : BROWSER_OUTPUT: 10:27:38 INFO - 2015-11-12 10:27:38,731 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352858727__endTimestamp 10:27:39 INFO - 2015-11-12 10:27:39,685 INFO : Browser exited with error code: 0 10:27:39 INFO - 2015-11-12 10:27:39,687 INFO : Running cycle 13/20 for ts_paint test... 10:27:39 INFO - 2015-11-12 10:27:39,687 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:40 INFO - 2015-11-12 10:27:40,823 DEBUG : BROWSER_OUTPUT: __start_report1130__end_report 10:27:40 INFO - 2015-11-12 10:27:40,824 DEBUG : BROWSER_OUTPUT: 10:27:40 INFO - 2015-11-12 10:27:40,839 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352860837__endTimestamp 10:27:41 INFO - 2015-11-12 10:27:41,676 INFO : Browser exited with error code: 0 10:27:41 INFO - 2015-11-12 10:27:41,677 INFO : Running cycle 14/20 for ts_paint test... 10:27:41 INFO - 2015-11-12 10:27:41,677 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:42 INFO - 2015-11-12 10:27:42,832 DEBUG : BROWSER_OUTPUT: __start_report1154__end_report 10:27:42 INFO - 2015-11-12 10:27:42,832 DEBUG : BROWSER_OUTPUT: 10:27:42 INFO - 2015-11-12 10:27:42,848 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352862846__endTimestamp 10:27:43 INFO - 2015-11-12 10:27:43,715 INFO : Browser exited with error code: 0 10:27:43 INFO - 2015-11-12 10:27:43,717 INFO : Running cycle 15/20 for ts_paint test... 10:27:43 INFO - 2015-11-12 10:27:43,717 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:44 INFO - 2015-11-12 10:27:44,866 DEBUG : BROWSER_OUTPUT: __start_report1142__end_report 10:27:44 INFO - 2015-11-12 10:27:44,866 DEBUG : BROWSER_OUTPUT: 10:27:44 INFO - 2015-11-12 10:27:44,881 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352864875__endTimestamp 10:27:45 INFO - 2015-11-12 10:27:45,754 INFO : Browser exited with error code: 0 10:27:45 INFO - 2015-11-12 10:27:45,755 INFO : Running cycle 16/20 for ts_paint test... 10:27:45 INFO - 2015-11-12 10:27:45,755 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:46 INFO - 2015-11-12 10:27:46,876 DEBUG : BROWSER_OUTPUT: __start_report1117__end_report 10:27:46 INFO - 2015-11-12 10:27:46,876 DEBUG : BROWSER_OUTPUT: 10:27:46 INFO - 2015-11-12 10:27:46,884 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352866883__endTimestamp 10:27:47 INFO - 2015-11-12 10:27:47,745 INFO : Browser exited with error code: 0 10:27:47 INFO - 2015-11-12 10:27:47,746 INFO : Running cycle 17/20 for ts_paint test... 10:27:47 INFO - 2015-11-12 10:27:47,746 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:48 INFO - 2015-11-12 10:27:48,877 DEBUG : BROWSER_OUTPUT: __start_report1118__end_report 10:27:48 INFO - 2015-11-12 10:27:48,878 DEBUG : BROWSER_OUTPUT: 10:27:48 INFO - 2015-11-12 10:27:48,879 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352868878__endTimestamp 10:27:49 INFO - 2015-11-12 10:27:49,821 INFO : Browser exited with error code: 0 10:27:49 INFO - 2015-11-12 10:27:49,823 INFO : Running cycle 18/20 for ts_paint test... 10:27:49 INFO - 2015-11-12 10:27:49,823 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:50 INFO - 2015-11-12 10:27:50,945 DEBUG : BROWSER_OUTPUT: __start_report1115__end_report 10:27:50 INFO - 2015-11-12 10:27:50,945 DEBUG : BROWSER_OUTPUT: 10:27:50 INFO - 2015-11-12 10:27:50,961 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352870953__endTimestamp 10:27:51 INFO - 2015-11-12 10:27:51,861 INFO : Browser exited with error code: 0 10:27:51 INFO - 2015-11-12 10:27:51,862 INFO : Running cycle 19/20 for ts_paint test... 10:27:51 INFO - 2015-11-12 10:27:51,862 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:53 INFO - 2015-11-12 10:27:53,013 DEBUG : BROWSER_OUTPUT: __start_report1139__end_report 10:27:53 INFO - 2015-11-12 10:27:53,013 DEBUG : BROWSER_OUTPUT: 10:27:53 INFO - 2015-11-12 10:27:53,028 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352873023__endTimestamp 10:27:53 INFO - 2015-11-12 10:27:53,900 INFO : Browser exited with error code: 0 10:27:53 INFO - 2015-11-12 10:27:53,901 INFO : Running cycle 20/20 for ts_paint test... 10:27:53 INFO - 2015-11-12 10:27:53,902 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp_752hi/profile http://localhost:53596/startup_test/tspaint_test.html 10:27:55 INFO - 2015-11-12 10:27:55,018 DEBUG : BROWSER_OUTPUT: __start_report1118__end_report 10:27:55 INFO - 2015-11-12 10:27:55,018 DEBUG : BROWSER_OUTPUT: 10:27:55 INFO - 2015-11-12 10:27:55,033 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352875028__endTimestamp 10:27:55 INFO - 2015-11-12 10:27:55,940 INFO : Browser exited with error code: 0 10:27:55 INFO - 2015-11-12 10:27:55,960 INFO : Completed test ts_paint (00:00:46) 10:27:55 INFO - 2015-11-12 10:27:55,960 INFO : Starting test tpaint 10:27:55 INFO - 2015-11-12 10:27:55,960 DEBUG : operating with platform_type : linux_ 10:27:55 INFO - 2015-11-12 10:27:55,960 INFO : Initialising browser for tpaint test... 10:27:55 INFO - 2015-11-12 10:27:55,966 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpxX1WRg/profile http://localhost:53596/getInfo.html 10:27:59 INFO - 2015-11-12 10:27:59,835 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 10:27:59 INFO - 2015-11-12 10:27:59,835 DEBUG : BROWSER_OUTPUT: colorDepth:24 10:27:59 INFO - 2015-11-12 10:27:59,835 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1024/697 10:27:59 INFO - 2015-11-12 10:27:59,835 DEBUG : BROWSER_OUTPUT: __metrics 10:27:59 INFO - 2015-11-12 10:27:59,972 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 10:28:01 INFO - 2015-11-12 10:28:01,084 INFO : Browser initialized. 10:28:01 INFO - 2015-11-12 10:28:01,085 INFO : Running cycle 1/1 for tpaint test... 10:28:01 INFO - 2015-11-12 10:28:01,085 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpxX1WRg/profile file:///builds/slave/test/build/tests/talos/talos/startup_test/tpaint.html?auto=1 10:28:27 INFO - 2015-11-12 10:28:27,252 DEBUG : BROWSER_OUTPUT: __start_report206.16499999999996|206.85000000000036|208.0550000000003|209.64000000000306|212.0049999999992|212.10000000000036|212.48500000000058|215.19999999999982|217.8099999999995|220.2449999999999|220.98000000000002|221.54500000000007|222.16999999999825|223.29500000000007|226.3050000000003|231.65999999999985|232.66500000000087|240.3100000000013|245|279.34000000000015__end_report__startTimestamp1447352907245__endTimestamp 10:28:27 INFO - 2015-11-12 10:28:27,252 DEBUG : BROWSER_OUTPUT: openingTimes=206.85000000000036,208.0550000000003,209.64000000000306,212.0049999999992,212.10000000000036,212.48500000000058,215.19999999999982,217.8099999999995,220.2449999999999,220.98000000000002,221.54500000000007,222.16999999999825,223.29500000000007,226.3050000000003,231.65999999999985,232.66500000000087,240.3100000000013,245,279.34000000000015 10:28:27 INFO - 2015-11-12 10:28:27,252 DEBUG : BROWSER_OUTPUT: avgOpenTime:223.19 10:28:27 INFO - 2015-11-12 10:28:27,252 DEBUG : BROWSER_OUTPUT: minOpenTime:206.16 10:28:27 INFO - 2015-11-12 10:28:27,252 DEBUG : BROWSER_OUTPUT: maxOpenTime:279.34 10:28:27 INFO - 2015-11-12 10:28:27,253 DEBUG : BROWSER_OUTPUT: medOpenTime:220.61249999999995 10:28:27 INFO - 2015-11-12 10:28:27,253 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:220.61249999999995 10:28:28 INFO - 2015-11-12 10:28:28,322 INFO : Browser exited with error code: 0 10:28:28 INFO - 2015-11-12 10:28:28,333 INFO : Completed test tpaint (00:00:32) 10:28:28 INFO - 2015-11-12 10:28:28,333 INFO : Starting test sessionrestore 10:28:28 INFO - 2015-11-12 10:28:28,333 DEBUG : operating with platform_type : linux_ 10:28:28 INFO - 2015-11-12 10:28:28,333 INFO : Initialising browser for sessionrestore test... 10:28:28 INFO - 2015-11-12 10:28:28,342 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/getInfo.html 10:28:35 INFO - 2015-11-12 10:28:35,268 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 10:28:35 INFO - 2015-11-12 10:28:35,269 DEBUG : BROWSER_OUTPUT: colorDepth:24 10:28:35 INFO - 2015-11-12 10:28:35,269 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811 10:28:35 INFO - 2015-11-12 10:28:35,269 DEBUG : BROWSER_OUTPUT: __metrics 10:28:35 INFO - 2015-11-12 10:28:35,417 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 10:28:36 INFO - 2015-11-12 10:28:36,272 DEBUG : BROWSER_OUTPUT: JavaScript error: resource://gre/modules/IndexedDBHelper.jsm, line 138: UnknownError: The operation failed for reasons unrelated to the database itself and not covered by any other error code. 10:28:36 INFO - 2015-11-12 10:28:36,348 DEBUG : BROWSER_OUTPUT: console.error: 10:28:36 INFO - 2015-11-12 10:28:36,348 DEBUG : BROWSER_OUTPUT: Message: Error: Connection closed before committing the transaction. 10:28:36 INFO - 2015-11-12 10:28:36,348 DEBUG : BROWSER_OUTPUT: Stack: 10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeTransaction/promise resource://gre/modules/Promise-backend.js:934:23 10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:813:7 10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:11 10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:776:7 10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:711:7 10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:319:13 10:28:36 INFO - 2015-11-12 10:28:36,349 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9 10:28:36 INFO - 2015-11-12 10:28:36,350 DEBUG : BROWSER_OUTPUT: nsAsyncShutdownBarrier.prototype.wait/<@resource://gre/components/nsAsyncShutdown.js:215:7 10:28:36 INFO - 2015-11-12 10:28:36,350 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9 10:28:36 INFO - 2015-11-12 10:28:36,350 DEBUG : BROWSER_OUTPUT: 10:28:37 INFO - 2015-11-12 10:28:37,141 INFO : Browser initialized. 10:28:37 INFO - 2015-11-12 10:28:37,142 INFO : Running cycle 1/10 for sessionrestore test... 10:28:37 INFO - 2015-11-12 10:28:37,142 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js 10:28:37 INFO - 2015-11-12 10:28:37,144 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json 10:28:37 INFO - 2015-11-12 10:28:37,145 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:28:41 INFO - 2015-11-12 10:28:41,948 DEBUG : BROWSER_OUTPUT: __start_report2436__end_report 10:28:41 INFO - 2015-11-12 10:28:41,949 DEBUG : BROWSER_OUTPUT: 10:28:41 INFO - 2015-11-12 10:28:41,949 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352921948__endTimestamp 10:28:41 INFO - 2015-11-12 10:28:41,949 DEBUG : BROWSER_OUTPUT: 10:28:43 INFO - 2015-11-12 10:28:43,545 INFO : Browser exited with error code: 0 10:28:43 INFO - 2015-11-12 10:28:43,547 INFO : Running cycle 2/10 for sessionrestore test... 10:28:43 INFO - 2015-11-12 10:28:43,547 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js 10:28:43 INFO - 2015-11-12 10:28:43,549 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json 10:28:43 INFO - 2015-11-12 10:28:43,550 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:28:47 INFO - 2015-11-12 10:28:47,795 DEBUG : BROWSER_OUTPUT: __start_report2152__end_report 10:28:47 INFO - 2015-11-12 10:28:47,795 DEBUG : BROWSER_OUTPUT: 10:28:47 INFO - 2015-11-12 10:28:47,795 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352927792__endTimestamp 10:28:47 INFO - 2015-11-12 10:28:47,795 DEBUG : BROWSER_OUTPUT: 10:28:49 INFO - 2015-11-12 10:28:49,302 INFO : Browser exited with error code: 0 10:28:49 INFO - 2015-11-12 10:28:49,303 INFO : Running cycle 3/10 for sessionrestore test... 10:28:49 INFO - 2015-11-12 10:28:49,304 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js 10:28:49 INFO - 2015-11-12 10:28:49,305 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json 10:28:49 INFO - 2015-11-12 10:28:49,306 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:28:53 INFO - 2015-11-12 10:28:53,605 DEBUG : BROWSER_OUTPUT: __start_report2228__end_report 10:28:53 INFO - 2015-11-12 10:28:53,605 DEBUG : BROWSER_OUTPUT: 10:28:53 INFO - 2015-11-12 10:28:53,606 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352933604__endTimestamp 10:28:53 INFO - 2015-11-12 10:28:53,606 DEBUG : BROWSER_OUTPUT: 10:28:55 INFO - 2015-11-12 10:28:55,173 INFO : Browser exited with error code: 0 10:28:55 INFO - 2015-11-12 10:28:55,175 INFO : Running cycle 4/10 for sessionrestore test... 10:28:55 INFO - 2015-11-12 10:28:55,175 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js 10:28:55 INFO - 2015-11-12 10:28:55,177 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json 10:28:55 INFO - 2015-11-12 10:28:55,178 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:28:59 INFO - 2015-11-12 10:28:59,495 DEBUG : BROWSER_OUTPUT: __start_report2203__end_report 10:28:59 INFO - 2015-11-12 10:28:59,495 DEBUG : BROWSER_OUTPUT: 10:28:59 INFO - 2015-11-12 10:28:59,495 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352939489__endTimestamp 10:28:59 INFO - 2015-11-12 10:28:59,495 DEBUG : BROWSER_OUTPUT: 10:29:01 INFO - 2015-11-12 10:29:01,234 INFO : Browser exited with error code: 0 10:29:01 INFO - 2015-11-12 10:29:01,235 INFO : Running cycle 5/10 for sessionrestore test... 10:29:01 INFO - 2015-11-12 10:29:01,235 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js 10:29:01 INFO - 2015-11-12 10:29:01,237 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json 10:29:01 INFO - 2015-11-12 10:29:01,238 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:05 INFO - 2015-11-12 10:29:05,591 DEBUG : BROWSER_OUTPUT: __start_report2229__end_report 10:29:05 INFO - 2015-11-12 10:29:05,591 DEBUG : BROWSER_OUTPUT: 10:29:05 INFO - 2015-11-12 10:29:05,591 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352945587__endTimestamp 10:29:05 INFO - 2015-11-12 10:29:05,591 DEBUG : BROWSER_OUTPUT: 10:29:07 INFO - 2015-11-12 10:29:07,365 INFO : Browser exited with error code: 0 10:29:07 INFO - 2015-11-12 10:29:07,367 INFO : Running cycle 6/10 for sessionrestore test... 10:29:07 INFO - 2015-11-12 10:29:07,367 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js 10:29:07 INFO - 2015-11-12 10:29:07,369 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json 10:29:07 INFO - 2015-11-12 10:29:07,370 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:11 INFO - 2015-11-12 10:29:11,655 DEBUG : BROWSER_OUTPUT: __start_report2172__end_report 10:29:11 INFO - 2015-11-12 10:29:11,655 DEBUG : BROWSER_OUTPUT: 10:29:11 INFO - 2015-11-12 10:29:11,655 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352951651__endTimestamp 10:29:11 INFO - 2015-11-12 10:29:11,655 DEBUG : BROWSER_OUTPUT: 10:29:13 INFO - 2015-11-12 10:29:13,421 INFO : Browser exited with error code: 0 10:29:13 INFO - 2015-11-12 10:29:13,423 INFO : Running cycle 7/10 for sessionrestore test... 10:29:13 INFO - 2015-11-12 10:29:13,423 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js 10:29:13 INFO - 2015-11-12 10:29:13,425 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json 10:29:13 INFO - 2015-11-12 10:29:13,426 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:17 INFO - 2015-11-12 10:29:17,730 DEBUG : BROWSER_OUTPUT: __start_report2206__end_report 10:29:17 INFO - 2015-11-12 10:29:17,730 DEBUG : BROWSER_OUTPUT: 10:29:17 INFO - 2015-11-12 10:29:17,730 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352957727__endTimestamp 10:29:17 INFO - 2015-11-12 10:29:17,730 DEBUG : BROWSER_OUTPUT: 10:29:19 INFO - 2015-11-12 10:29:19,497 INFO : Browser exited with error code: 0 10:29:19 INFO - 2015-11-12 10:29:19,499 INFO : Running cycle 8/10 for sessionrestore test... 10:29:19 INFO - 2015-11-12 10:29:19,499 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js 10:29:19 INFO - 2015-11-12 10:29:19,501 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json 10:29:19 INFO - 2015-11-12 10:29:19,502 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:23 INFO - 2015-11-12 10:29:23,768 DEBUG : BROWSER_OUTPUT: __start_report2193__end_report 10:29:23 INFO - 2015-11-12 10:29:23,768 DEBUG : BROWSER_OUTPUT: 10:29:23 INFO - 2015-11-12 10:29:23,768 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352963767__endTimestamp 10:29:23 INFO - 2015-11-12 10:29:23,768 DEBUG : BROWSER_OUTPUT: 10:29:25 INFO - 2015-11-12 10:29:25,454 INFO : Browser exited with error code: 0 10:29:25 INFO - 2015-11-12 10:29:25,455 INFO : Running cycle 9/10 for sessionrestore test... 10:29:25 INFO - 2015-11-12 10:29:25,455 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js 10:29:25 INFO - 2015-11-12 10:29:25,458 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json 10:29:25 INFO - 2015-11-12 10:29:25,458 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:29 INFO - 2015-11-12 10:29:29,753 DEBUG : BROWSER_OUTPUT: __start_report2221__end_report 10:29:29 INFO - 2015-11-12 10:29:29,753 DEBUG : BROWSER_OUTPUT: 10:29:29 INFO - 2015-11-12 10:29:29,753 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352969751__endTimestamp 10:29:29 INFO - 2015-11-12 10:29:29,753 DEBUG : BROWSER_OUTPUT: 10:29:31 INFO - 2015-11-12 10:29:31,477 INFO : Browser exited with error code: 0 10:29:31 INFO - 2015-11-12 10:29:31,479 INFO : Running cycle 10/10 for sessionrestore test... 10:29:31 INFO - 2015-11-12 10:29:31,479 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2w9Cmm/profile/sessionstore.js 10:29:31 INFO - 2015-11-12 10:29:31,481 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2w9Cmm/profile/sessionCheckpoints.json 10:29:31 INFO - 2015-11-12 10:29:31,482 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2w9Cmm/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:35 INFO - 2015-11-12 10:29:35,781 DEBUG : BROWSER_OUTPUT: __start_report2203__end_report 10:29:35 INFO - 2015-11-12 10:29:35,782 DEBUG : BROWSER_OUTPUT: 10:29:35 INFO - 2015-11-12 10:29:35,782 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352975780__endTimestamp 10:29:35 INFO - 2015-11-12 10:29:35,782 DEBUG : BROWSER_OUTPUT: 10:29:37 INFO - 2015-11-12 10:29:37,533 INFO : Browser exited with error code: 0 10:29:37 INFO - 2015-11-12 10:29:37,549 INFO : Completed test sessionrestore (00:01:09) 10:29:37 INFO - 2015-11-12 10:29:37,549 INFO : Starting test sessionrestore_no_auto_restore 10:29:37 INFO - 2015-11-12 10:29:37,549 DEBUG : operating with platform_type : linux_ 10:29:37 INFO - 2015-11-12 10:29:37,550 INFO : Initialising browser for sessionrestore_no_auto_restore test... 10:29:37 INFO - 2015-11-12 10:29:37,558 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/getInfo.html 10:29:41 INFO - 2015-11-12 10:29:41,160 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 10:29:41 INFO - 2015-11-12 10:29:41,161 DEBUG : BROWSER_OUTPUT: colorDepth:24 10:29:41 INFO - 2015-11-12 10:29:41,161 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1151/811 10:29:41 INFO - 2015-11-12 10:29:41,161 DEBUG : BROWSER_OUTPUT: __metrics 10:29:41 INFO - 2015-11-12 10:29:41,298 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 10:29:42 INFO - 2015-11-12 10:29:42,479 INFO : Browser initialized. 10:29:42 INFO - 2015-11-12 10:29:42,479 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test... 10:29:42 INFO - 2015-11-12 10:29:42,479 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js 10:29:42 INFO - 2015-11-12 10:29:42,482 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json 10:29:42 INFO - 2015-11-12 10:29:42,482 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:44 INFO - 2015-11-12 10:29:44,168 DEBUG : BROWSER_OUTPUT: __start_report1077__end_report 10:29:44 INFO - 2015-11-12 10:29:44,169 DEBUG : BROWSER_OUTPUT: 10:29:44 INFO - 2015-11-12 10:29:44,169 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352984167__endTimestamp 10:29:44 INFO - 2015-11-12 10:29:44,169 DEBUG : BROWSER_OUTPUT: 10:29:45 INFO - 2015-11-12 10:29:45,193 INFO : Browser exited with error code: 0 10:29:45 INFO - 2015-11-12 10:29:45,195 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test... 10:29:45 INFO - 2015-11-12 10:29:45,195 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js 10:29:45 INFO - 2015-11-12 10:29:45,197 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json 10:29:45 INFO - 2015-11-12 10:29:45,198 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:46 INFO - 2015-11-12 10:29:46,520 DEBUG : BROWSER_OUTPUT: __start_report814__end_report 10:29:46 INFO - 2015-11-12 10:29:46,520 DEBUG : BROWSER_OUTPUT: 10:29:46 INFO - 2015-11-12 10:29:46,520 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352986517__endTimestamp 10:29:46 INFO - 2015-11-12 10:29:46,520 DEBUG : BROWSER_OUTPUT: 10:29:47 INFO - 2015-11-12 10:29:47,421 INFO : Browser exited with error code: 0 10:29:47 INFO - 2015-11-12 10:29:47,423 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test... 10:29:47 INFO - 2015-11-12 10:29:47,423 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js 10:29:47 INFO - 2015-11-12 10:29:47,425 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json 10:29:47 INFO - 2015-11-12 10:29:47,426 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:48 INFO - 2015-11-12 10:29:48,731 DEBUG : BROWSER_OUTPUT: __start_report822__end_report 10:29:48 INFO - 2015-11-12 10:29:48,731 DEBUG : BROWSER_OUTPUT: 10:29:48 INFO - 2015-11-12 10:29:48,731 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352988727__endTimestamp 10:29:48 INFO - 2015-11-12 10:29:48,731 DEBUG : BROWSER_OUTPUT: 10:29:49 INFO - 2015-11-12 10:29:49,741 INFO : Browser exited with error code: 0 10:29:49 INFO - 2015-11-12 10:29:49,743 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test... 10:29:49 INFO - 2015-11-12 10:29:49,743 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js 10:29:49 INFO - 2015-11-12 10:29:49,745 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json 10:29:49 INFO - 2015-11-12 10:29:49,746 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:51 INFO - 2015-11-12 10:29:51,082 DEBUG : BROWSER_OUTPUT: __start_report839__end_report 10:29:51 INFO - 2015-11-12 10:29:51,082 DEBUG : BROWSER_OUTPUT: 10:29:51 INFO - 2015-11-12 10:29:51,082 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352991081__endTimestamp 10:29:51 INFO - 2015-11-12 10:29:51,082 DEBUG : BROWSER_OUTPUT: 10:29:52 INFO - 2015-11-12 10:29:52,105 INFO : Browser exited with error code: 0 10:29:52 INFO - 2015-11-12 10:29:52,107 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test... 10:29:52 INFO - 2015-11-12 10:29:52,107 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js 10:29:52 INFO - 2015-11-12 10:29:52,109 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json 10:29:52 INFO - 2015-11-12 10:29:52,110 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:53 INFO - 2015-11-12 10:29:53,381 DEBUG : BROWSER_OUTPUT: __start_report802__end_report 10:29:53 INFO - 2015-11-12 10:29:53,381 DEBUG : BROWSER_OUTPUT: 10:29:53 INFO - 2015-11-12 10:29:53,381 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352993379__endTimestamp 10:29:53 INFO - 2015-11-12 10:29:53,381 DEBUG : BROWSER_OUTPUT: 10:29:54 INFO - 2015-11-12 10:29:54,365 INFO : Browser exited with error code: 0 10:29:54 INFO - 2015-11-12 10:29:54,367 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test... 10:29:54 INFO - 2015-11-12 10:29:54,367 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js 10:29:54 INFO - 2015-11-12 10:29:54,369 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json 10:29:54 INFO - 2015-11-12 10:29:54,370 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:55 INFO - 2015-11-12 10:29:55,703 DEBUG : BROWSER_OUTPUT: __start_report798__end_report 10:29:55 INFO - 2015-11-12 10:29:55,703 DEBUG : BROWSER_OUTPUT: 10:29:55 INFO - 2015-11-12 10:29:55,703 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352995695__endTimestamp 10:29:55 INFO - 2015-11-12 10:29:55,703 DEBUG : BROWSER_OUTPUT: 10:29:56 INFO - 2015-11-12 10:29:56,765 INFO : Browser exited with error code: 0 10:29:56 INFO - 2015-11-12 10:29:56,767 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test... 10:29:56 INFO - 2015-11-12 10:29:56,767 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js 10:29:56 INFO - 2015-11-12 10:29:56,769 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json 10:29:56 INFO - 2015-11-12 10:29:56,770 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:29:58 INFO - 2015-11-12 10:29:58,064 DEBUG : BROWSER_OUTPUT: __start_report775__end_report 10:29:58 INFO - 2015-11-12 10:29:58,064 DEBUG : BROWSER_OUTPUT: 10:29:58 INFO - 2015-11-12 10:29:58,064 DEBUG : BROWSER_OUTPUT: __startTimestamp1447352998063__endTimestamp 10:29:58 INFO - 2015-11-12 10:29:58,064 DEBUG : BROWSER_OUTPUT: 10:29:59 INFO - 2015-11-12 10:29:59,121 INFO : Browser exited with error code: 0 10:29:59 INFO - 2015-11-12 10:29:59,123 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test... 10:29:59 INFO - 2015-11-12 10:29:59,123 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js 10:29:59 INFO - 2015-11-12 10:29:59,125 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json 10:29:59 INFO - 2015-11-12 10:29:59,126 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:30:00 INFO - 2015-11-12 10:30:00,401 DEBUG : BROWSER_OUTPUT: __start_report757__end_report 10:30:00 INFO - 2015-11-12 10:30:00,402 DEBUG : BROWSER_OUTPUT: 10:30:00 INFO - 2015-11-12 10:30:00,402 DEBUG : BROWSER_OUTPUT: __startTimestamp1447353000401__endTimestamp 10:30:00 INFO - 2015-11-12 10:30:00,402 DEBUG : BROWSER_OUTPUT: 10:30:01 INFO - 2015-11-12 10:30:01,485 INFO : Browser exited with error code: 0 10:30:01 INFO - 2015-11-12 10:30:01,487 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test... 10:30:01 INFO - 2015-11-12 10:30:01,487 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js 10:30:01 INFO - 2015-11-12 10:30:01,489 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json 10:30:01 INFO - 2015-11-12 10:30:01,490 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:30:02 INFO - 2015-11-12 10:30:02,813 DEBUG : BROWSER_OUTPUT: __start_report831__end_report 10:30:02 INFO - 2015-11-12 10:30:02,814 DEBUG : BROWSER_OUTPUT: 10:30:02 INFO - 2015-11-12 10:30:02,814 DEBUG : BROWSER_OUTPUT: __startTimestamp1447353002811__endTimestamp 10:30:02 INFO - 2015-11-12 10:30:02,814 DEBUG : BROWSER_OUTPUT: 10:30:03 INFO - 2015-11-12 10:30:03,898 INFO : Browser exited with error code: 0 10:30:03 INFO - 2015-11-12 10:30:03,899 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test... 10:30:03 INFO - 2015-11-12 10:30:03,899 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionstore.js on top of /tmp/tmp2VaDX3/profile/sessionstore.js 10:30:03 INFO - 2015-11-12 10:30:03,901 DEBUG : Reinstalling /builds/slave/test/build/tests/talos/talos/startup_test/sessionrestore/profile/sessionCheckpoints.json on top of /tmp/tmp2VaDX3/profile/sessionCheckpoints.json 10:30:03 INFO - 2015-11-12 10:30:03,902 DEBUG : command line: /builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2VaDX3/profile http://localhost:53596/startup_test/sessionrestore/index.html 10:30:05 INFO - 2015-11-12 10:30:05,205 DEBUG : BROWSER_OUTPUT: __start_report776__end_report 10:30:05 INFO - 2015-11-12 10:30:05,205 DEBUG : BROWSER_OUTPUT: 10:30:05 INFO - 2015-11-12 10:30:05,205 DEBUG : BROWSER_OUTPUT: __startTimestamp1447353005203__endTimestamp 10:30:05 INFO - 2015-11-12 10:30:05,205 DEBUG : BROWSER_OUTPUT: 10:30:06 INFO - 2015-11-12 10:30:06,225 INFO : Browser exited with error code: 0 10:30:06 INFO - 2015-11-12 10:30:06,240 INFO : Completed test sessionrestore_no_auto_restore (00:00:28) 10:30:06 INFO - 2015-11-12 10:30:06,549 INFO : Completed test suite (00:04:50) 10:30:06 INFO - 2015-11-12 10:30:06,549 DEBUG : Working with test: a11yr 10:30:06 INFO - 2015-11-12 10:30:06,549 DEBUG : Generating results file: a11yr 10:30:06 INFO - 2015-11-12 10:30:06,550 DEBUG : Working with test: ts_paint 10:30:06 INFO - 2015-11-12 10:30:06,550 DEBUG : Generating results file: ts_paint 10:30:06 INFO - 2015-11-12 10:30:06,550 DEBUG : Working with test: tpaint 10:30:06 INFO - 2015-11-12 10:30:06,551 DEBUG : Generating results file: tpaint 10:30:06 INFO - 2015-11-12 10:30:06,551 DEBUG : Working with test: sessionrestore 10:30:06 INFO - 2015-11-12 10:30:06,551 DEBUG : Generating results file: sessionrestore 10:30:06 INFO - 2015-11-12 10:30:06,551 DEBUG : Working with test: sessionrestore_no_auto_restore 10:30:06 INFO - 2015-11-12 10:30:06,551 DEBUG : Generating results file: sessionrestore_no_auto_restore 10:30:06 INFO - 2015-11-12 10:30:06,552 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 10:30:07 INFO - 2015-11-12 10:30:07,461 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,131,35]] 10:30:07 INFO - 2015-11-12 10:30:07,461 DEBUG : process_Request line: a11yr_paint 693.97 graph.html#tests=[[223,131,35]] 10:30:07 INFO - 2015-11-12 10:30:07,461 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 10:30:07 INFO - 2015-11-12 10:30:07,645 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,131,35]] 10:30:07 INFO - 2015-11-12 10:30:07,645 DEBUG : process_Request line: ts_paint 1157.64 graph.html#tests=[[83,131,35]] 10:30:07 INFO - 2015-11-12 10:30:07,645 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 10:30:07 INFO - 2015-11-12 10:30:07,776 DEBUG : process_Request line: tpaint graph.html#tests=[[82,131,35]] 10:30:07 INFO - 2015-11-12 10:30:07,776 DEBUG : process_Request line: tpaint 222.17 graph.html#tests=[[82,131,35]] 10:30:07 INFO - 2015-11-12 10:30:07,776 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 10:30:07 INFO - 2015-11-12 10:30:07,938 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,131,35]] 10:30:07 INFO - 2015-11-12 10:30:07,939 DEBUG : process_Request line: sessionrestore 2223.12 graph.html#tests=[[313,131,35]] 10:30:07 INFO - 2015-11-12 10:30:07,939 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 10:30:08 INFO - 2015-11-12 10:30:08,081 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,131,35]] 10:30:08 INFO - 2015-11-12 10:30:08,081 DEBUG : process_Request line: sessionrestore_no_auto_restore 825.19 graph.html#tests=[[315,131,35]] 10:30:08 INFO - 2015-11-12 10:30:08,082 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [1389.0, 1474.0, 1476.0, 1558.0, 1468.0, 1462.0, 1468.0, 1466.0, 1548.0, 1471.0, 1563.0, 1559.0, 1366.0, 1456.0, 1491.0, 1473.0, 1475.0, 1492.0, 1476.0, 1479.0, 1561.0, 1487.0, 1471.0, 1476.0, 1562.0], "tablemutation.html": [333.0, 324.0, 327.0, 326.0, 327.0, 326.0, 326.0, 325.0, 326.0, 324.0, 327.0, 328.0, 325.0, 325.0, 328.0, 327.0, 327.0, 324.0, 326.0, 326.0, 328.0, 324.0, 325.0, 329.0, 328.0]}, "summary": {"lowerIsBetter": true, "suite": 693.9669056868825, "subtests": {"dhtml.html": {"lowerIsBetter": true, "filtered": 1476.0, "unit": "ms", "value": 1476.0}, "tablemutation.html": {"lowerIsBetter": true, "filtered": 326.0, "unit": "ms", "value": 326.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-048"}, "testrun": {"date": 1447352716, "suite": "a11yr", "options": {"responsiveness": false, "tpmozafterpaint": true, "tpchrome": true, "tppagecycles": 25, "tpcycles": 1, "tprender": false, "shutdown": false, "cycles": 1, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151112100440", "branch": "Mozilla-Inbound-Non-PGO", "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"}}, {"talos_counters": {}, "results": {"ts_paint": [1639.0, 1122.0, 1189.0, 1115.0, 1148.0, 1102.0, 1147.0, 1145.0, 1141.0, 1129.0, 1157.0, 1172.0, 1130.0, 1154.0, 1142.0, 1117.0, 1118.0, 1115.0, 1139.0, 1118.0]}, "summary": {"suite": 1139.0, "subtests": {"ts_paint": {"filtered": 1139.0, "value": 1139.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-048"}, "testrun": {"date": 1447352716, "suite": "ts_paint", "options": {"responsiveness": false, "cycles": 20, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151112100440", "branch": "Mozilla-Inbound-Non-PGO", "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"}}, {"talos_counters": {}, "results": {"tpaint": [206.16499999999996, 206.85000000000036, 208.0550000000003, 209.64000000000306, 212.0049999999992, 212.10000000000036, 212.48500000000058, 215.19999999999982, 217.8099999999995, 220.2449999999999, 220.98000000000002, 221.54500000000007, 222.16999999999825, 223.29500000000007, 226.3050000000003, 231.65999999999985, 232.66500000000087, 240.3100000000013, 245.0, 279.34000000000015]}, "summary": {"suite": 222.16999999999825, "subtests": {"tpaint": {"filtered": 222.16999999999825, "value": 222.16999999999825}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-048"}, "testrun": {"date": 1447352716, "suite": "tpaint", "options": {"responsiveness": false, "cycles": 1, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151112100440", "branch": "Mozilla-Inbound-Non-PGO", "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"}}, {"talos_counters": {}, "results": {"sessionrestore": [2436.0, 2152.0, 2228.0, 2203.0, 2229.0, 2172.0, 2206.0, 2193.0, 2221.0, 2203.0]}, "summary": {"suite": 2203.0, "subtests": {"sessionrestore": {"filtered": 2203.0, "value": 2203.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-048"}, "testrun": {"date": 1447352716, "suite": "sessionrestore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151112100440", "branch": "Mozilla-Inbound-Non-PGO", "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"}}, {"talos_counters": {}, "results": {"sessionrestore_no_auto_restore": [1077.0, 814.0, 822.0, 839.0, 802.0, 798.0, 775.0, 757.0, 831.0, 776.0]}, "summary": {"suite": 802.0, "subtests": {"sessionrestore_no_auto_restore": {"filtered": 802.0, "value": 802.0}}}, "test_machine": {"platform": "x86_64", "osversion": "Ubuntu 12.04", "os": "linux", "name": "talos-linux64-ix-048"}, "testrun": {"date": 1447352716, "suite": "sessionrestore_no_auto_restore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151112100440", "branch": "Mozilla-Inbound-Non-PGO", "revision": "756632e20aa46ce0b2feebdf6f04e6dacdc09811"}}] 10:30:08 INFO - RETURN: a11yr_paint: 693.97 10:30:08 INFO - RETURN: ts_paint: 1157.64 10:30:08 INFO - RETURN: tpaint: 222.17 10:30:08 INFO - RETURN: sessionrestore: 2223.12 10:30:08 INFO - RETURN: sessionrestore_no_auto_restore: 825.19 10:30:08 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,131,35]]", "result": "2223.12"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,131,35]]", "result": "693.97"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,131,35]]", "result": "222.17"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,131,35]]", "result": "1157.64"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,131,35]]", "result": "825.19"}}} 10:30:08 INFO - Return code: 0 10:30:08 INFO - # TBPL SUCCESS # 10:30:08 INFO - Running post-action listener: _resource_record_post_action 10:30:08 INFO - Running post-run listener: _resource_record_post_run 10:30:09 INFO - Total resource usage - Wall time: 306s; CPU: 13.0%; Read bytes: 4096; Write bytes: 572772352; Read time: 188; Write time: 643520 10:30:09 INFO - install - Wall time: 15s; CPU: 13.0%; Read bytes: 0; Write bytes: 60739584; Read time: 0; Write time: 36948 10:30:09 INFO - run-tests - Wall time: 292s; CPU: 13.0%; Read bytes: 4096; Write bytes: 485376000; Read time: 188; Write time: 554848 10:30:09 INFO - Running post-run listener: _upload_blobber_files 10:30:09 INFO - Blob upload gear active. 10:30:09 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ... 10:30:09 INFO - Copying logs to upload dir... 10:30:09 INFO - mkdir: /builds/slave/test/build/upload/logs program finished with exit code 0 elapsedTime=337.820912 ========= master_lag: 0.02 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 5 mins, 37 secs) (at 2015-11-12 10:30:07.920176) ========= ========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-12 10:30:07.925546) ========= 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=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False build_url:https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/artifacts/public/build/firefox-45.0a1.en-US.linux-x86_64.tar.bz2 program finished with exit code 0 elapsedTime=0.009996 build_url: 'https://queue.taskcluster.net/v1/task/PUyvTLe3SN6UwSQ764OC_A/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-12 10:30:07.976127) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:30:07.976462) ========= 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=fdc9337702648c539b2c5dbe000001aa-1447352228.973177-975042059 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004612 ========= master_lag: 0.05 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-12 10:30:08.026531) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-12 10:30:08.026857) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2015-11-12 10:30:08.027313) ========= ========= Total master_lag: 0.62 =========