builder: mozilla-inbound_win7-ix_test-other slave: t-w732-ix-084 starttime: 1447110283.98 results: success (0) buildid: 20151109133533 builduid: 89002388416e4d0ab3298b5bbf2504e1 revision: 09cd7947ffd969860d6de0effc9402e9f99f1d21 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:43.985289) ========= master: http://buildbot-master119.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:43.985801) ========= ========= Started set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:43.986164) ========= 'cd' in dir C:\slave\test\. (timeout 1200 secs) watching logfiles {} argv: ['cd'] environment: ALLUSERSPROFILE=C:\ProgramData APPDATA=C:\Users\cltbld\AppData\Roaming COMMONPROGRAMFILES=C:\Program Files\Common Files COMPUTERNAME=T-W732-IX-084 COMSPEC=C:\windows\system32\cmd.exe CYGWINBASE=C:\cygwin DCLOCATION=SCL3 DNSSUFFIX=wintest.releng.scl3.mozilla.com FP_NO_HOST_CHECK=NO HOMEDRIVE=C: HOMEPATH=\Users\cltbld KTS_HOME=C:\Program Files\KTS KTS_VERSION=1.19c LOCALAPPDATA=C:\Users\cltbld\AppData\Local LOGONSERVER=\\T-W732-IX-084 MONDIR=C:\Monitor_config\ MOZBUILDDIR=C:\mozilla-build\ MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 NUMBER_OF_PROCESSORS=8 OS=Windows_NT OURDRIVE=C: PATH=C:\Python24;C:\Python24\Scripts;C:\cygwin\bin;C:\WINDOWS\System32;C:\program files\gnuwin32\bin;C:\WINDOWS;C:\mozilla-build\msys\bin;C:\mozilla-build\python27;C:\mozilla-build\python27\Scripts;C:\mozilla-build\info-zip;C:\mozilla-build\wget;C:\Program Files (x86)\GnuWin32\bin; PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC PROCESSOR_ARCHITECTURE=x86 PROCESSOR_IDENTIFIER=x86 Family 6 Model 30 Stepping 5, GenuineIntel PROCESSOR_LEVEL=6 PROCESSOR_REVISION=1e05 PROGRAMDATA=C:\ProgramData PROGRAMFILES=C:\Program Files PROMPT=$P$G PSMODULEPATH=C:\windows\system32\WindowsPowerShell\v1.0\Modules\ PUBLIC=C:\Users\Public PWD=C:\slave\test RUNLOGFILE=C:\slave\\runslave.log SLAVEDIR=C:\slave\ SYSTEMDRIVE=C: SYSTEMROOT=C:\windows TEMP=C:\Users\cltbld\AppData\Local\Temp TEST1=testie TMP=C:\Users\cltbld\AppData\Local\Temp USERDOMAIN=T-W732-IX-084 USERNAME=cltbld USERPROFILE=C:\Users\cltbld WINDIR=C:\windows WINDOWS_TRACING_FLAGS=3 WINDOWS_TRACING_LOGFILE=C:\BVTBin\Tests\installpackage\csilogfile.log XPCOM_DEBUG_BREAK=warn using PTY: False C:\slave\test program finished with exit code 0 elapsedTime=0.570000 basedir: 'C:\\slave\\test' ========= master_lag: 0.05 ========= ========= Finished set props: basedir (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:44.608897) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:44.609222) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:44.759266) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:44.759671) ========= 'rm' '-rf' 'properties' in dir C:\slave\test\. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'properties'] environment: ALLUSERSPROFILE=C:\ProgramData APPDATA=C:\Users\cltbld\AppData\Roaming COMMONPROGRAMFILES=C:\Program Files\Common Files COMPUTERNAME=T-W732-IX-084 COMSPEC=C:\windows\system32\cmd.exe CYGWINBASE=C:\cygwin DCLOCATION=SCL3 DNSSUFFIX=wintest.releng.scl3.mozilla.com FP_NO_HOST_CHECK=NO HOMEDRIVE=C: HOMEPATH=\Users\cltbld KTS_HOME=C:\Program Files\KTS KTS_VERSION=1.19c LOCALAPPDATA=C:\Users\cltbld\AppData\Local LOGONSERVER=\\T-W732-IX-084 MONDIR=C:\Monitor_config\ MOZBUILDDIR=C:\mozilla-build\ MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 NUMBER_OF_PROCESSORS=8 OS=Windows_NT OURDRIVE=C: PATH=C:\Python24;C:\Python24\Scripts;C:\cygwin\bin;C:\WINDOWS\System32;C:\program files\gnuwin32\bin;C:\WINDOWS;C:\mozilla-build\msys\bin;C:\mozilla-build\python27;C:\mozilla-build\python27\Scripts;C:\mozilla-build\info-zip;C:\mozilla-build\wget;C:\Program Files (x86)\GnuWin32\bin; PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC PROCESSOR_ARCHITECTURE=x86 PROCESSOR_IDENTIFIER=x86 Family 6 Model 30 Stepping 5, GenuineIntel PROCESSOR_LEVEL=6 PROCESSOR_REVISION=1e05 PROGRAMDATA=C:\ProgramData PROGRAMFILES=C:\Program Files PROMPT=$P$G PSMODULEPATH=C:\windows\system32\WindowsPowerShell\v1.0\Modules\ PUBLIC=C:\Users\Public PWD=C:\slave\test RUNLOGFILE=C:\slave\\runslave.log SLAVEDIR=C:\slave\ SYSTEMDRIVE=C: SYSTEMROOT=C:\windows TEMP=C:\Users\cltbld\AppData\Local\Temp TEST1=testie TMP=C:\Users\cltbld\AppData\Local\Temp USERDOMAIN=T-W732-IX-084 USERNAME=cltbld USERPROFILE=C:\Users\cltbld WINDIR=C:\windows WINDOWS_TRACING_FLAGS=3 WINDOWS_TRACING_LOGFILE=C:\BVTBin\Tests\installpackage\csilogfile.log XPCOM_DEBUG_BREAK=warn using PTY: False program finished with exit code 0 elapsedTime=0.601000 ========= master_lag: 0.02 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:45.376510) ========= ========= Started set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:45.376826) ========= script_repo_url: https://hg.mozilla.org/build/mozharness ========= Finished set props: script_repo_url (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:45.377243) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:45.377512) ========= '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 C:\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: ALLUSERSPROFILE=C:\ProgramData APPDATA=C:\Users\cltbld\AppData\Roaming COMMONPROGRAMFILES=C:\Program Files\Common Files COMPUTERNAME=T-W732-IX-084 COMSPEC=C:\windows\system32\cmd.exe CYGWINBASE=C:\cygwin DCLOCATION=SCL3 DNSSUFFIX=wintest.releng.scl3.mozilla.com FP_NO_HOST_CHECK=NO HOMEDRIVE=C: HOMEPATH=\Users\cltbld KTS_HOME=C:\Program Files\KTS KTS_VERSION=1.19c LOCALAPPDATA=C:\Users\cltbld\AppData\Local LOGONSERVER=\\T-W732-IX-084 MONDIR=C:\Monitor_config\ MOZBUILDDIR=C:\mozilla-build\ MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 NUMBER_OF_PROCESSORS=8 OS=Windows_NT OURDRIVE=C: PATH=C:\Python24;C:\Python24\Scripts;C:\cygwin\bin;C:\WINDOWS\System32;C:\program files\gnuwin32\bin;C:\WINDOWS;C:\mozilla-build\msys\bin;C:\mozilla-build\python27;C:\mozilla-build\python27\Scripts;C:\mozilla-build\info-zip;C:\mozilla-build\wget;C:\Program Files (x86)\GnuWin32\bin; PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC PROCESSOR_ARCHITECTURE=x86 PROCESSOR_IDENTIFIER=x86 Family 6 Model 30 Stepping 5, GenuineIntel PROCESSOR_LEVEL=6 PROCESSOR_REVISION=1e05 PROGRAMDATA=C:\ProgramData PROGRAMFILES=C:\Program Files PROMPT=$P$G PSMODULEPATH=C:\windows\system32\WindowsPowerShell\v1.0\Modules\ PUBLIC=C:\Users\Public PWD=C:\slave\test RUNLOGFILE=C:\slave\\runslave.log SLAVEDIR=C:\slave\ SYSTEMDRIVE=C: SYSTEMROOT=C:\windows TEMP=C:\Users\cltbld\AppData\Local\Temp TEST1=testie TMP=C:\Users\cltbld\AppData\Local\Temp USERDOMAIN=T-W732-IX-084 USERNAME=cltbld USERPROFILE=C:\Users\cltbld WINDIR=C:\windows WINDOWS_TRACING_FLAGS=3 WINDOWS_TRACING_LOGFILE=C:\BVTBin\Tests\installpackage\csilogfile.log XPCOM_DEBUG_BREAK=warn using PTY: False --15:04:45-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py => `archiver_client.py' Resolving hg.mozilla.org... 63.245.215.102, 63.245.215.25 Connecting to hg.mozilla.org|63.245.215.102|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12,141 (12K) [text/x-python] 0K .......... . 100% 27.12 MB/s 15:04:46 (27.12 MB/s) - `archiver_client.py' saved [12141/12141] program finished with exit code 0 elapsedTime=0.739000 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2015-11-09 15:04:46.131820) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 13 secs) (at 2015-11-09 15:04:46.132168) ========= 'rm' '-rf' 'scripts' in dir C:\slave\test\. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'scripts'] environment: ALLUSERSPROFILE=C:\ProgramData APPDATA=C:\Users\cltbld\AppData\Roaming COMMONPROGRAMFILES=C:\Program Files\Common Files COMPUTERNAME=T-W732-IX-084 COMSPEC=C:\windows\system32\cmd.exe CYGWINBASE=C:\cygwin DCLOCATION=SCL3 DNSSUFFIX=wintest.releng.scl3.mozilla.com FP_NO_HOST_CHECK=NO HOMEDRIVE=C: HOMEPATH=\Users\cltbld KTS_HOME=C:\Program Files\KTS KTS_VERSION=1.19c LOCALAPPDATA=C:\Users\cltbld\AppData\Local LOGONSERVER=\\T-W732-IX-084 MONDIR=C:\Monitor_config\ MOZBUILDDIR=C:\mozilla-build\ MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 NUMBER_OF_PROCESSORS=8 OS=Windows_NT OURDRIVE=C: PATH=C:\Python24;C:\Python24\Scripts;C:\cygwin\bin;C:\WINDOWS\System32;C:\program files\gnuwin32\bin;C:\WINDOWS;C:\mozilla-build\msys\bin;C:\mozilla-build\python27;C:\mozilla-build\python27\Scripts;C:\mozilla-build\info-zip;C:\mozilla-build\wget;C:\Program Files (x86)\GnuWin32\bin; PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC PROCESSOR_ARCHITECTURE=x86 PROCESSOR_IDENTIFIER=x86 Family 6 Model 30 Stepping 5, GenuineIntel PROCESSOR_LEVEL=6 PROCESSOR_REVISION=1e05 PROGRAMDATA=C:\ProgramData PROGRAMFILES=C:\Program Files PROMPT=$P$G PSMODULEPATH=C:\windows\system32\WindowsPowerShell\v1.0\Modules\ PUBLIC=C:\Users\Public PWD=C:\slave\test RUNLOGFILE=C:\slave\\runslave.log SLAVEDIR=C:\slave\ SYSTEMDRIVE=C: SYSTEMROOT=C:\windows TEMP=C:\Users\cltbld\AppData\Local\Temp TEST1=testie TMP=C:\Users\cltbld\AppData\Local\Temp USERDOMAIN=T-W732-IX-084 USERNAME=cltbld USERPROFILE=C:\Users\cltbld WINDIR=C:\windows WINDOWS_TRACING_FLAGS=3 WINDOWS_TRACING_LOGFILE=C:\BVTBin\Tests\installpackage\csilogfile.log XPCOM_DEBUG_BREAK=warn using PTY: False program finished with exit code 0 elapsedTime=13.701000 ========= master_lag: 0.02 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 13 secs) (at 2015-11-09 15:04:59.848200) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-11-09 15:04:59.848599) ========= 'bash' '-c' u'python archiver_client.py mozharness --repo integration/mozilla-inbound --rev 09cd7947ffd969860d6de0effc9402e9f99f1d21 --destination scripts --debug' in dir C:\slave\test\. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', u'python archiver_client.py mozharness --repo integration/mozilla-inbound --rev 09cd7947ffd969860d6de0effc9402e9f99f1d21 --destination scripts --debug'] environment: ALLUSERSPROFILE=C:\ProgramData APPDATA=C:\Users\cltbld\AppData\Roaming COMMONPROGRAMFILES=C:\Program Files\Common Files COMPUTERNAME=T-W732-IX-084 COMSPEC=C:\windows\system32\cmd.exe CYGWINBASE=C:\cygwin DCLOCATION=SCL3 DNSSUFFIX=wintest.releng.scl3.mozilla.com FP_NO_HOST_CHECK=NO HOMEDRIVE=C: HOMEPATH=\Users\cltbld KTS_HOME=C:\Program Files\KTS KTS_VERSION=1.19c LOCALAPPDATA=C:\Users\cltbld\AppData\Local LOGONSERVER=\\T-W732-IX-084 MONDIR=C:\Monitor_config\ MOZBUILDDIR=C:\mozilla-build\ MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 NUMBER_OF_PROCESSORS=8 OS=Windows_NT OURDRIVE=C: PATH=C:\Python24;C:\Python24\Scripts;C:\cygwin\bin;C:\WINDOWS\System32;C:\program files\gnuwin32\bin;C:\WINDOWS;C:\mozilla-build\msys\bin;C:\mozilla-build\python27;C:\mozilla-build\python27\Scripts;C:\mozilla-build\info-zip;C:\mozilla-build\wget;C:\Program Files (x86)\GnuWin32\bin; PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC PROCESSOR_ARCHITECTURE=x86 PROCESSOR_IDENTIFIER=x86 Family 6 Model 30 Stepping 5, GenuineIntel PROCESSOR_LEVEL=6 PROCESSOR_REVISION=1e05 PROGRAMDATA=C:\ProgramData PROGRAMFILES=C:\Program Files PROMPT=$P$G PSMODULEPATH=C:\windows\system32\WindowsPowerShell\v1.0\Modules\ PUBLIC=C:\Users\Public PWD=C:\slave\test RUNLOGFILE=C:\slave\\runslave.log SLAVEDIR=C:\slave\ SYSTEMDRIVE=C: SYSTEMROOT=C:\windows TEMP=C:\Users\cltbld\AppData\Local\Temp TEST1=testie TMP=C:\Users\cltbld\AppData\Local\Temp USERDOMAIN=T-W732-IX-084 USERNAME=cltbld USERPROFILE=C:\Users\cltbld WINDIR=C:\windows WINDOWS_TRACING_FLAGS=3 WINDOWS_TRACING_LOGFILE=C:\BVTBin\Tests\installpackage\csilogfile.log XPCOM_DEBUG_BREAK=warn using PTY: False 2015-11-09 15:05:00,253 truncating revision to first 12 chars 2015-11-09 15:05:00,253 Setting DEBUG logging. 2015-11-09 15:05:00,253 attempt 1/10 2015-11-09 15:05:00,253 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/integration/mozilla-inbound/09cd7947ffd9?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2015-11-09 15:05:00,713 unpacking tar archive at: mozilla-inbound-09cd7947ffd9/testing/mozharness/ program finished with exit code 0 elapsedTime=1.274000 ========= master_lag: 0.04 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2015-11-09 15:05:01.161158) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-09 15:05:01.161491) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2015-11-09 15:05:01.176255) ========= ========= Started tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-09 15:05:01.176636) ========= TinderboxPrint: script_revlink: https://hg.mozilla.org/build/mozharness/rev/production ========= Finished tinderboxprint_script_revlink (results: 0, elapsed: 0 secs) (at 2015-11-09 15:05:01.177098) ========= ========= Started 'c:/mozilla-build/python27/python -u ...' (results: 0, elapsed: 8 mins, 41 secs) (at 2015-11-09 15:05:01.177413) ========= 'c:/mozilla-build/python27/python' '-u' 'scripts/scripts/talos_script.py' '--suite' 'other' '--add-option' '--webServer,localhost' '--branch-name' 'Mozilla-Inbound-Non-PGO' '--system-bits' '32' '--cfg' 'talos/windows_config.py' '--download-symbols' 'ondemand' '--use-talos-json' '--blob-upload-branch' 'Mozilla-Inbound-Non-PGO' in dir C:\slave\test\. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['c:/mozilla-build/python27/python', '-u', 'scripts/scripts/talos_script.py', '--suite', 'other', '--add-option', '--webServer,localhost', '--branch-name', 'Mozilla-Inbound-Non-PGO', '--system-bits', '32', '--cfg', 'talos/windows_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Mozilla-Inbound-Non-PGO'] environment: ALLUSERSPROFILE=C:\ProgramData APPDATA=C:\Users\cltbld\AppData\Roaming COMMONPROGRAMFILES=C:\Program Files\Common Files COMPUTERNAME=T-W732-IX-084 COMSPEC=C:\windows\system32\cmd.exe CYGWINBASE=C:\cygwin DCLOCATION=SCL3 DNSSUFFIX=wintest.releng.scl3.mozilla.com FP_NO_HOST_CHECK=NO HOMEDRIVE=C: HOMEPATH=\Users\cltbld KTS_HOME=C:\Program Files\KTS KTS_VERSION=1.19c LOCALAPPDATA=C:\Users\cltbld\AppData\Local LOGONSERVER=\\T-W732-IX-084 MONDIR=C:\Monitor_config\ MOZBUILDDIR=C:\mozilla-build\ MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 NUMBER_OF_PROCESSORS=8 OS=Windows_NT OURDRIVE=C: PATH=C:\Python24;C:\Python24\Scripts;C:\cygwin\bin;C:\WINDOWS\System32;C:\program files\gnuwin32\bin;C:\WINDOWS;C:\mozilla-build\msys\bin;C:\mozilla-build\python27;C:\mozilla-build\python27\Scripts;C:\mozilla-build\info-zip;C:\mozilla-build\wget;C:\Program Files (x86)\GnuWin32\bin; PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC PROCESSOR_ARCHITECTURE=x86 PROCESSOR_IDENTIFIER=x86 Family 6 Model 30 Stepping 5, GenuineIntel PROCESSOR_LEVEL=6 PROCESSOR_REVISION=1e05 PROGRAMDATA=C:\ProgramData PROGRAMFILES=C:\Program Files PROMPT=$P$G PROPERTIES_FILE=C:\slave\test/buildprops.json PSMODULEPATH=C:\windows\system32\WindowsPowerShell\v1.0\Modules\ PUBLIC=C:\Users\Public PWD=C:\slave\test RUNLOGFILE=C:\slave\\runslave.log SLAVEDIR=C:\slave\ SYSTEMDRIVE=C: SYSTEMROOT=C:\windows TEMP=C:\Users\cltbld\AppData\Local\Temp TEST1=testie TMP=C:\Users\cltbld\AppData\Local\Temp USERDOMAIN=T-W732-IX-084 USERNAME=cltbld USERPROFILE=C:\Users\cltbld WINDIR=C:\windows WINDOWS_TRACING_FLAGS=3 WINDOWS_TRACING_LOGFILE=C:\BVTBin\Tests\installpackage\csilogfile.log XPCOM_DEBUG_BREAK=warn using PTY: False 15:05:01 INFO - MultiFileLogger online at 20151109 15:05:01 in C:\slave\test 15:05:01 INFO - Run as scripts/scripts/talos_script.py --suite other --add-option --webServer,localhost --branch-name Mozilla-Inbound-Non-PGO --system-bits 32 --cfg talos/windows_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Mozilla-Inbound-Non-PGO 15:05:01 INFO - Dumping config to C:\slave\test\logs\localconfig.json. 15:05:01 INFO - {'append_to_log': False, 15:05:01 INFO - 'base_work_dir': 'C:\\slave\\test', 15:05:01 INFO - 'blob_upload_branch': 'Mozilla-Inbound-Non-PGO', 15:05:01 INFO - 'blob_uploader_auth_file': 'C:\\slave\\test\\oauth.txt', 15:05:01 INFO - 'branch': 'Mozilla-Inbound-Non-PGO', 15:05:01 INFO - 'buildbot_json_path': 'buildprops.json', 15:05:01 INFO - 'config_files': ('talos/windows_config.py',), 15:05:01 INFO - 'default_actions': ('clobber', 15:05:01 INFO - 'read-buildbot-config', 15:05:01 INFO - 'download-and-extract', 15:05:01 INFO - 'populate-webroot', 15:05:01 INFO - 'create-virtualenv', 15:05:01 INFO - 'install', 15:05:01 INFO - 'run-tests'), 15:05:01 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 15:05:01 INFO - 'download_minidump_stackwalk': True, 15:05:01 INFO - 'download_symbols': 'ondemand', 15:05:01 INFO - 'exes': {'easy_install': ('C:\\slave\\test\\build/venv/scripts/python', 15:05:01 INFO - 'C:\\slave\\test\\build/venv/scripts/easy_install-2.7-script.py'), 15:05:01 INFO - 'hg': 'c:/mozilla-build/hg/hg', 15:05:01 INFO - 'mozinstall': ('C:\\slave\\test\\build/venv/scripts/python', 15:05:01 INFO - 'C:\\slave\\test\\build/venv/scripts/mozinstall-script.py'), 15:05:01 INFO - 'python': 'c:/mozilla-build/python27/python.exe', 15:05:01 INFO - 'tooltool.py': ('c:/mozilla-build/python27/python.exe', 15:05:01 INFO - 'C:/mozilla-build/tooltool.py'), 15:05:01 INFO - 'virtualenv': ('c:/mozilla-build/python27/python.exe', 15:05:01 INFO - 'c:/mozilla-build/buildbotve/virtualenv.py')}, 15:05:01 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 15:05:01 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 15:05:01 INFO - 'installer_path': 'installer.exe', 15:05:01 INFO - 'log_level': 'info', 15:05:01 INFO - 'log_name': 'talos', 15:05:01 INFO - 'log_to_console': True, 15:05:01 INFO - 'metro_harness_path_frmt': '%(metro_base_path)s/metro/metrotestharness.exe', 15:05:01 INFO - 'minidump_stackwalk_path': 'win32-minidump_stackwalk.exe', 15:05:01 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/win32/releng.manifest', 15:05:01 INFO - 'opt_config_files': (), 15:05:01 INFO - 'pip_index': False, 15:05:01 INFO - 'sps_profile': False, 15:05:01 INFO - 'sps_profile_interval': 0, 15:05:01 INFO - 'suite': 'other', 15:05:01 INFO - 'system_bits': '32', 15:05:01 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 15:05:01 INFO - 'title': 'T-W732-IX-084', 15:05:01 INFO - 'use_talos_json': True, 15:05:01 INFO - 'virtualenv_modules': ('pywin32', 'talos', 'mozinstall'), 15:05:01 INFO - 'virtualenv_path': 'C:\\slave\\test\\build/venv', 15:05:01 INFO - 'virtualenv_python_dll': 'c:/mozilla-build/python27/python27.dll', 15:05:01 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 15:05:01 INFO - 'work_dir': 'build'} 15:05:01 INFO - ##### 15:05:01 INFO - ##### Running clobber step. 15:05:01 INFO - ##### 15:05:01 INFO - Running pre-action listener: _resource_record_pre_action 15:05:01 INFO - Running main action method: clobber 15:05:01 INFO - rmtree: C:\slave\test\build 15:05:01 INFO - Using _rmtree_windows ... 15:05:01 INFO - retry: Calling _rmtree_windows with args: ('C:\\slave\\test\\build',), kwargs: {}, attempt #1 15:06:17 INFO - Running post-action listener: _resource_record_post_action 15:06:17 INFO - ##### 15:06:17 INFO - ##### Running read-buildbot-config step. 15:06:17 INFO - ##### 15:06:17 INFO - Running pre-action listener: _resource_record_pre_action 15:06:17 INFO - Running main action method: read_buildbot_config 15:06:17 INFO - Using buildbot properties: 15:06:17 INFO - { 15:06:17 INFO - "properties": { 15:06:17 INFO - "buildnumber": 453, 15:06:17 INFO - "product": "firefox", 15:06:17 INFO - "script_repo_revision": "production", 15:06:17 INFO - "builddir": "mozilla-inbound_win7-ix_test-other", 15:06:17 INFO - "repository": "", 15:06:17 INFO - "buildername": "Windows 7 32-bit mozilla-inbound talos other", 15:06:17 INFO - "buildid": "20151109133533", 15:06:17 INFO - "slavename": "t-w732-ix-084", 15:06:17 INFO - "pgo_build": "False", 15:06:17 INFO - "basedir": "C:\\slave\\test", 15:06:17 INFO - "project": "", 15:06:17 INFO - "platform": "win7-ix", 15:06:17 INFO - "master": "http://buildbot-master119.bb.releng.scl3.mozilla.com:8201/", 15:06:17 INFO - "slavebuilddir": "test", 15:06:17 INFO - "scheduler": "tests-mozilla-inbound-win32-talos", 15:06:17 INFO - "branch": "mozilla-inbound", 15:06:17 INFO - "repo_path": "integration/mozilla-inbound", 15:06:17 INFO - "stage_platform": "win32", 15:06:17 INFO - "builduid": "89002388416e4d0ab3298b5bbf2504e1", 15:06:17 INFO - "revision": "09cd7947ffd969860d6de0effc9402e9f99f1d21" 15:06:17 INFO - }, 15:06:17 INFO - "sourcestamp": { 15:06:17 INFO - "repository": "", 15:06:17 INFO - "hasPatch": false, 15:06:17 INFO - "project": "", 15:06:17 INFO - "branch": "mozilla-inbound-win32-talos", 15:06:17 INFO - "changes": [ 15:06:17 INFO - { 15:06:17 INFO - "category": null, 15:06:17 INFO - "files": [ 15:06:17 INFO - { 15:06:17 INFO - "url": null, 15:06:17 INFO - "name": "https://queue.taskcluster.net/v1/task/4RVE6LQWSTSJqaFMil4cng/artifacts/public/build/firefox-45.0a1.en-US.win32.zip" 15:06:17 INFO - } 15:06:17 INFO - ], 15:06:17 INFO - "repository": "", 15:06:17 INFO - "rev": "6c6d04b021ddfdfe1ce35f5b6939ef80deda3f3f", 15:06:17 INFO - "who": "rgiles@mozilla.com", 15:06:17 INFO - "when": 1447110153, 15:06:17 INFO - "number": 6639448, 15:06:17 INFO - "comments": "Bug 1222145 - Bump maximum video size to 8k. r=jya\n\nYouTube and WebVR have been experimenting with 8k video for\nimmersive applications, where you need more than 4k resolution\neven on a mid-resolution display because you're not looking\nat the whole scene simultaneously.\n\nWe were rejecting video frames larger than 4000x3000,\nor 16k in any one dimension, to limit resource exhaustion\nattacks. Bump this to accept 8k video now that there's\na demand for it.", 15:06:17 INFO - "project": "", 15:06:17 INFO - "at": "Mon 09 Nov 2015 15:02:33", 15:06:17 INFO - "branch": "mozilla-inbound-win32-talos", 15:06:17 INFO - "revlink": "", 15:06:17 INFO - "properties": [ 15:06:17 INFO - [ 15:06:17 INFO - "buildid", 15:06:17 INFO - "20151109132133", 15:06:17 INFO - "Change" 15:06:17 INFO - ], 15:06:17 INFO - [ 15:06:17 INFO - "builduid", 15:06:17 INFO - "60bca578163d4d938e68697233565017", 15:06:17 INFO - "Change" 15:06:17 INFO - ], 15:06:17 INFO - [ 15:06:17 INFO - "pgo_build", 15:06:17 INFO - "False", 15:06:17 INFO - "Change" 15:06:17 INFO - ] 15:06:17 INFO - ], 15:06:17 INFO - "revision": "6c6d04b021ddfdfe1ce35f5b6939ef80deda3f3f" 15:06:17 INFO - }, 15:06:17 INFO - { 15:06:17 INFO - "category": null, 15:06:17 INFO - "files": [ 15:06:17 INFO - { 15:06:17 INFO - "url": null, 15:06:17 INFO - "name": "https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.zip" 15:06:17 INFO - } 15:06:17 INFO - ], 15:06:17 INFO - "repository": "", 15:06:17 INFO - "rev": "09cd7947ffd969860d6de0effc9402e9f99f1d21", 15:06:17 INFO - "who": "jmuizelaar@mozilla.com", 15:06:17 INFO - "when": 1447110242, 15:06:17 INFO - "number": 6639456, 15:06:17 INFO - "comments": "Bug 1222496. Avoid having ANGLE default to D3D11.\n\nThis fixes a regression where we would not be able to ask\nANGLE not to use D3D11.\n", 15:06:17 INFO - "project": "", 15:06:17 INFO - "at": "Mon 09 Nov 2015 15:04:02", 15:06:17 INFO - "branch": "mozilla-inbound-win32-talos", 15:06:17 INFO - "revlink": "", 15:06:17 INFO - "properties": [ 15:06:17 INFO - [ 15:06:17 INFO - "buildid", 15:06:17 INFO - "20151109133533", 15:06:17 INFO - "Change" 15:06:17 INFO - ], 15:06:17 INFO - [ 15:06:17 INFO - "builduid", 15:06:17 INFO - "89002388416e4d0ab3298b5bbf2504e1", 15:06:17 INFO - "Change" 15:06:17 INFO - ], 15:06:17 INFO - [ 15:06:17 INFO - "pgo_build", 15:06:17 INFO - "False", 15:06:17 INFO - "Change" 15:06:17 INFO - ] 15:06:17 INFO - ], 15:06:17 INFO - "revision": "09cd7947ffd969860d6de0effc9402e9f99f1d21" 15:06:17 INFO - } 15:06:17 INFO - ], 15:06:17 INFO - "revision": "09cd7947ffd969860d6de0effc9402e9f99f1d21" 15:06:17 INFO - } 15:06:17 INFO - } 15:06:17 INFO - Found installer url https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.zip. 15:06:17 INFO - Running post-action listener: _resource_record_post_action 15:06:17 INFO - ##### 15:06:17 INFO - ##### Running download-and-extract step. 15:06:17 INFO - ##### 15:06:17 INFO - Running pre-action listener: _resource_record_pre_action 15:06:17 INFO - Running main action method: download_and_extract 15:06:17 INFO - mkdir: C:\slave\test\build\tests 15:06:17 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')]} 15:06:17 INFO - https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/test_packages.json matches https://queue.taskcluster.net 15:06:17 INFO - trying https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/test_packages.json 15:06:17 INFO - Downloading https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/test_packages.json to C:\slave\test\build\test_packages.json 15:06:17 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/test_packages.json', 'file_name': 'C:\\slave\\test\\build\\test_packages.json'}, attempt #1 15:06:19 INFO - Downloaded 1221 bytes. 15:06:19 INFO - Reading from file C:\slave\test\build\test_packages.json 15:06:19 INFO - Using the following test package requirements: 15:06:19 INFO - {u'common': [u'firefox-45.0a1.en-US.win32.common.tests.zip'], 15:06:19 INFO - u'cppunittest': [u'firefox-45.0a1.en-US.win32.common.tests.zip', 15:06:19 INFO - u'firefox-45.0a1.en-US.win32.cppunittest.tests.zip'], 15:06:19 INFO - u'jittest': [u'firefox-45.0a1.en-US.win32.common.tests.zip', 15:06:19 INFO - u'jsshell-win32.zip'], 15:06:19 INFO - u'mochitest': [u'firefox-45.0a1.en-US.win32.common.tests.zip', 15:06:19 INFO - u'firefox-45.0a1.en-US.win32.mochitest.tests.zip'], 15:06:19 INFO - u'mozbase': [u'firefox-45.0a1.en-US.win32.common.tests.zip'], 15:06:19 INFO - u'reftest': [u'firefox-45.0a1.en-US.win32.common.tests.zip', 15:06:19 INFO - u'firefox-45.0a1.en-US.win32.reftest.tests.zip'], 15:06:19 INFO - u'talos': [u'firefox-45.0a1.en-US.win32.common.tests.zip', 15:06:19 INFO - u'firefox-45.0a1.en-US.win32.talos.tests.zip'], 15:06:19 INFO - u'web-platform': [u'firefox-45.0a1.en-US.win32.common.tests.zip', 15:06:19 INFO - u'firefox-45.0a1.en-US.win32.web-platform.tests.zip'], 15:06:19 INFO - u'webapprt': [u'firefox-45.0a1.en-US.win32.common.tests.zip'], 15:06:19 INFO - u'xpcshell': [u'firefox-45.0a1.en-US.win32.common.tests.zip', 15:06:19 INFO - u'firefox-45.0a1.en-US.win32.xpcshell.tests.zip']} 15:06:19 INFO - Downloading packages: [u'firefox-45.0a1.en-US.win32.common.tests.zip'] for test suite category: common 15:06:19 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:06:19 INFO - https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.common.tests.zip matches https://queue.taskcluster.net 15:06:19 INFO - trying https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.common.tests.zip 15:06:19 INFO - Downloading https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.common.tests.zip to C:\slave\test\build\firefox-45.0a1.en-US.win32.common.tests.zip 15:06:19 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.common.tests.zip', 'file_name': u'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.common.tests.zip'}, attempt #1 15:06:20 INFO - Downloaded 17994385 bytes. 15:06:20 INFO - Running command: ['unzip', '-q', '-o', u'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.common.tests.zip'] in C:\slave\test\build\tests 15:06:20 INFO - Copy/paste: unzip -q -o C:\slave\test\build\firefox-45.0a1.en-US.win32.common.tests.zip 15:06:20 INFO - Calling ['unzip', '-q', '-o', u'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.common.tests.zip'] with output_timeout 1760 15:06:54 INFO - Return code: 0 15:06:54 INFO - Downloading packages: [u'firefox-45.0a1.en-US.win32.common.tests.zip', u'firefox-45.0a1.en-US.win32.talos.tests.zip'] for test suite category: talos 15:06: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')]} 15:06:54 INFO - https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.common.tests.zip matches https://queue.taskcluster.net 15:06:54 INFO - trying https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.common.tests.zip 15:06:54 INFO - Downloading https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.common.tests.zip to C:\slave\test\build\firefox-45.0a1.en-US.win32.common.tests.zip 15:06:54 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.common.tests.zip', 'file_name': u'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.common.tests.zip'}, attempt #1 15:07:10 INFO - Downloaded 17994385 bytes. 15:07:10 INFO - Running command: ['unzip', '-q', '-o', u'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.common.tests.zip'] in C:\slave\test\build\tests 15:07:10 INFO - Copy/paste: unzip -q -o C:\slave\test\build\firefox-45.0a1.en-US.win32.common.tests.zip 15:07:10 INFO - Calling ['unzip', '-q', '-o', u'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.common.tests.zip'] with output_timeout 1760 15:07:36 INFO - Return code: 0 15:07: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')]} 15:07:36 INFO - https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.talos.tests.zip matches https://queue.taskcluster.net 15:07:36 INFO - trying https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.talos.tests.zip 15:07:36 INFO - Downloading https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.talos.tests.zip to C:\slave\test\build\firefox-45.0a1.en-US.win32.talos.tests.zip 15:07:36 INFO - retry: Calling _download_file with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.talos.tests.zip', 'file_name': u'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.talos.tests.zip'}, attempt #1 15:07:39 INFO - Downloaded 11131618 bytes. 15:07:39 INFO - Running command: ['unzip', '-q', '-o', u'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.talos.tests.zip'] in C:\slave\test\build\tests 15:07:39 INFO - Copy/paste: unzip -q -o C:\slave\test\build\firefox-45.0a1.en-US.win32.talos.tests.zip 15:07:39 INFO - Calling ['unzip', '-q', '-o', u'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.talos.tests.zip'] with output_timeout 1760 15:07:43 INFO - Return code: 0 15:07:43 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:07:43 INFO - https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.zip matches https://queue.taskcluster.net 15:07:43 INFO - trying https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.zip 15:07:43 INFO - Downloading https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.zip to C:\slave\test\build\firefox-45.0a1.en-US.win32.zip 15:07:43 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.zip', 'file_name': 'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.zip'}, attempt #1 15:07:50 INFO - Downloaded 51607195 bytes. 15:07:50 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.zip 15:07:50 INFO - mkdir: C:\slave\test\properties 15:07:50 INFO - Writing buildbot properties ['build_url'] to C:\slave\test\properties\build_url 15:07:50 INFO - Writing to file C:\slave\test\properties\build_url 15:07:50 INFO - Contents: 15:07:50 INFO - build_url:https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.zip 15:07:50 INFO - Running post-action listener: _resource_record_post_action 15:07:50 INFO - Running post-action listener: set_extra_try_arguments 15:07:50 INFO - ##### 15:07:50 INFO - ##### Running populate-webroot step. 15:07:50 INFO - ##### 15:07:50 INFO - Running pre-action listener: _resource_record_pre_action 15:07:50 INFO - Running main action method: populate_webroot 15:07:50 INFO - Guessing talos json url... 15:07:50 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:07:50 INFO - https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.txt matches https://queue.taskcluster.net 15:07:50 INFO - trying https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.txt 15:07:50 INFO - Downloading https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.txt to C:\slave\test\build\firefox-45.0a1.en-US.win32.txt 15:07:50 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.txt', 'file_name': 'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.txt'}, attempt #1 15:07:51 INFO - Downloaded 111 bytes. 15:07:51 INFO - Reading from file C:\slave\test\build\firefox-45.0a1.en-US.win32.txt 15:07:51 INFO - Contents: 15:07:51 INFO - 20151109133533 15:07:51 INFO - https://hg.mozilla.org/integration/mozilla-inbound/rev/09cd7947ffd969860d6de0effc9402e9f99f1d21 15:07: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')]} 15:07:51 INFO - trying https://hg.mozilla.org/integration/mozilla-inbound/raw-file/09cd7947ff/testing/talos/talos.json 15:07:51 INFO - Downloading https://hg.mozilla.org/integration/mozilla-inbound/raw-file/09cd7947ff/testing/talos/talos.json to C:\slave\test\build\talos.json 15:07:51 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://hg.mozilla.org/integration/mozilla-inbound/raw-file/09cd7947ff/testing/talos/talos.json', 'file_name': 'C:\\slave\\test\\build\\talos.json'}, attempt #1 15:07:52 INFO - Downloaded 4206 bytes. 15:07:52 INFO - {u'extra_options': {u'android': [u'--apkPath=%(apk_path)s']}, 15:07:52 INFO - u'mobile-suites': {u'remote-tp4m_nochrome': {u'tests': [u'tp4m']}, 15:07:52 INFO - u'remote-trobocheck2': {u'talos_options': [u'--fennecIDs', 15:07:52 INFO - u'../fennec_ids.txt'], 15:07:52 INFO - u'tests': [u'tcheck2']}, 15:07:52 INFO - u'remote-tsvgx': {u'talos_options': [u'--noChrome', 15:07:52 INFO - u'--tppagecycles', 15:07:52 INFO - u'7'], 15:07:52 INFO - u'tests': [u'tsvgm']}}, 15:07:52 INFO - u'suites': {u'chromez': {u'tests': [u'tresize', u'tcanvasmark']}, 15:07:52 INFO - u'chromez-e10s': {u'talos_options': [u'--e10s'], 15:07:52 INFO - u'tests': [u'tresize', u'tcanvasmark']}, 15:07:52 INFO - u'dromaeojs': {u'tests': [u'dromaeo_css', u'kraken', u'v8_7']}, 15:07:52 INFO - u'dromaeojs-e10s': {u'talos_options': [u'--e10s'], 15:07:52 INFO - u'tests': [u'dromaeo_css', 15:07:52 INFO - u'kraken', 15:07:52 INFO - u'v8_7']}, 15:07:52 INFO - u'g1': {u'pagesets_url': u'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 15:07:52 INFO - u'tests': [u'tp5o_scroll', u'glterrain']}, 15:07:52 INFO - u'g1-e10s': {u'pagesets_url': u'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 15:07:52 INFO - u'talos_options': [u'--e10s'], 15:07:52 INFO - u'tests': [u'tp5o_scroll', u'glterrain']}, 15:07:52 INFO - u'g2': {u'pagesets_url': u'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 15:07:52 INFO - u'tests': [u'damp', u'tps']}, 15:07:52 INFO - u'g2-e10s': {u'pagesets_url': u'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 15:07:52 INFO - u'talos_options': [u'--e10s'], 15:07:52 INFO - u'tests': [u'damp', u'tps']}, 15:07:52 INFO - u'g3': {u'tests': [u'dromaeo_dom']}, 15:07:52 INFO - u'g3-e10s': {u'tests': [u'dromaeo_dom']}, 15:07:52 INFO - u'other': {u'tests': [u'a11yr', 15:07:52 INFO - u'ts_paint', 15:07:52 INFO - u'tpaint', 15:07:52 INFO - u'sessionrestore', 15:07:52 INFO - u'sessionrestore_no_auto_restore']}, 15:07:52 INFO - u'other-e10s': {u'talos_options': [u'--e10s'], 15:07:52 INFO - u'tests': [u'a11yr', 15:07:52 INFO - u'ts_paint', 15:07:52 INFO - u'tpaint', 15:07:52 INFO - u'sessionrestore', 15:07:52 INFO - u'sessionrestore_no_auto_restore']}, 15:07:52 INFO - u'other-e10s_l64': {u'talos_options': [u'--e10s'], 15:07:52 INFO - u'tests': [u'a11yr', 15:07:52 INFO - u'ts_paint', 15:07:52 INFO - u'tpaint', 15:07:52 INFO - u'sessionrestore', 15:07:52 INFO - u'sessionrestore_no_auto_restore']}, 15:07:52 INFO - u'other-e10s_nol64': {u'talos_options': [u'--e10s'], 15:07:52 INFO - u'tests': [u'a11yr', 15:07:52 INFO - u'ts_paint', 15:07:52 INFO - u'tpaint', 15:07:52 INFO - u'sessionrestore', 15:07:52 INFO - u'sessionrestore_no_auto_restore']}, 15:07:52 INFO - u'other_l64': {u'tests': [u'a11yr', 15:07:52 INFO - u'ts_paint', 15:07:52 INFO - u'tpaint', 15:07:52 INFO - u'sessionrestore', 15:07:52 INFO - u'sessionrestore_no_auto_restore']}, 15:07:52 INFO - u'other_nol64': {u'tests': [u'a11yr', 15:07:52 INFO - u'ts_paint', 15:07:52 INFO - u'tpaint', 15:07:52 INFO - u'sessionrestore', 15:07:52 INFO - u'sessionrestore_no_auto_restore']}, 15:07:52 INFO - u'svgr': {u'tests': [u'tsvgx', 15:07:52 INFO - u'tsvgr_opacity', 15:07:52 INFO - u'tart', 15:07:52 INFO - u'tscrollx', 15:07:52 INFO - u'cart']}, 15:07:52 INFO - u'svgr-e10s': {u'talos_options': [u'--e10s'], 15:07:52 INFO - u'tests': [u'tsvgx', 15:07:52 INFO - u'tsvgr_opacity', 15:07:52 INFO - u'tart', 15:07:52 INFO - u'tscrollx', 15:07:52 INFO - u'cart']}, 15:07:52 INFO - u'tp5o': {u'pagesets_url': u'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 15:07:52 INFO - u'tests': [u'tp5o']}, 15:07:52 INFO - u'tp5o-e10s': {u'pagesets_url': u'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 15:07:52 INFO - u'talos_options': [u'--e10s'], 15:07:52 INFO - u'tests': [u'tp5o']}, 15:07:52 INFO - u'xperf': {u'pagesets_url': u'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 15:07:52 INFO - u'talos_options': [u'--xperf_path', 15:07:52 INFO - u'"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 15:07:52 INFO - u'tests': [u'tp5n']}, 15:07:52 INFO - u'xperf-e10s': {u'pagesets_url': u'http://talos-bundles.pvt.build.mozilla.org/zips/tp5n.zip', 15:07:52 INFO - u'talos_options': [u'--e10s', 15:07:52 INFO - u'--xperf_path', 15:07:52 INFO - u'"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 15:07:52 INFO - u'tests': [u'tp5n']}}, 15:07:52 INFO - u'talos.zip': {u'path': u'', 15:07:52 INFO - u'url': u'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}} 15:07:52 INFO - Running post-action listener: _resource_record_post_action 15:07:52 INFO - ##### 15:07:52 INFO - ##### Running create-virtualenv step. 15:07:52 INFO - ##### 15:07:52 INFO - Running pre-action listener: _resource_record_pre_action 15:07:52 INFO - Running main action method: create_virtualenv 15:07:52 INFO - Creating virtualenv C:\slave\test\build/venv 15:07:52 INFO - mkdir: C:\slave\test\build\venv\Scripts 15:07:52 INFO - Copying c:/mozilla-build/python27/python27.dll to C:\slave\test\build\venv\Scripts\python27.dll 15:07:52 WARNING - Can't copy c:/mozilla-build/python27/python27.dll to C:\slave\test\build\venv\Scripts\python27.dll: [Errno 2] No such file or directory: 'c:/mozilla-build/python27/python27.dll'! 15:07:52 INFO - Running command: ['c:/mozilla-build/python27/python.exe', 'c:/mozilla-build/buildbotve/virtualenv.py', '--no-site-packages', '--distribute', 'C:\\slave\\test\\build/venv'] in C:\slave\test\build 15:07:52 INFO - Copy/paste: c:/mozilla-build/python27/python.exe c:/mozilla-build/buildbotve/virtualenv.py --no-site-packages --distribute C:\slave\test\build/venv 15:07:55 INFO - New python executable in C:\slave\test\build/venv\Scripts\python.exe 15:07:59 INFO - Installing distribute......................................................................................................................................................................................done. 15:08:01 INFO - Return code: 0 15:08:01 INFO - Installing pip>=1.5 into virtualenv C:\slave\test\build/venv 15:08: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')]} 15:08:01 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:08: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')]} 15:08:01 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:08:01 INFO - retry: Calling run_command with args: [['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '--no-index', '--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 0x018F9B10>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x018BDEA8>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x017CB660>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x01298B48>, '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 0x012BA700>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x01984660>, 'level': 'critical'}], 'cwd': 'C:\\slave\\test\\build', 'env': {'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'TEST1': 'testie', 'COMPUTERNAME': 'T-W732-IX-084', 'USERDOMAIN': 'T-W732-IX-084', 'KTS_VERSION': '1.19c', 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 'PROGRAMFILES': 'C:\\Program Files', 'PROCESSOR_REVISION': '1e05', 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 'SYSTEMROOT': 'C:\\windows', 'NO_EM_RESTART': '1', 'OURDRIVE': 'C:', 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 'XPCOM_DEBUG_BREAK': 'warn', 'MONDIR': 'C:\\Monitor_config\\', 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 'PROCESSOR_ARCHITECTURE': 'x86', 'ALLUSERSPROFILE': 'C:\\ProgramData', 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 'HOMEPATH': '\\Users\\cltbld', 'MOZBUILDDIR': 'C:\\mozilla-build\\', 'USERNAME': 'cltbld', 'LOGONSERVER': '\\\\T-W732-IX-084', 'MOZ_NO_REMOTE': '1', 'WINDOWS_TRACING_FLAGS': '3', 'CYGWINBASE': 'C:\\cygwin', 'PROGRAMDATA': 'C:\\ProgramData', 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 'PROMPT': '$P$G', 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 'FP_NO_HOST_CHECK': 'NO', 'DCLOCATION': 'SCL3', 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 'HOMEDRIVE': 'C:', 'SYSTEMDRIVE': 'C:', 'SLAVEDIR': 'C:\\slave\\', 'NUMBER_OF_PROCESSORS': '8', 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 'PWD': 'C:\\slave\\test', 'PROCESSOR_LEVEL': '6', 'KTS_HOME': 'C:\\Program Files\\KTS', 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'USERPROFILE': 'C:\\Users\\cltbld', 'OS': 'Windows_NT', 'PUBLIC': 'C:\\Users\\Public', 'WINDIR': 'C:\\windows'}}, attempt #1 15:08:01 INFO - Running command: ['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in C:\slave\test\build 15:08:01 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\pip install --download-cache C:\slave\test\build/venv\cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5 15:08:01 INFO - Using env: {'ALLUSERSPROFILE': 'C:\\ProgramData', 15:08:01 INFO - 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 15:08:01 INFO - 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 15:08:01 INFO - 'COMPUTERNAME': 'T-W732-IX-084', 15:08:01 INFO - 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 15:08:01 INFO - 'CYGWINBASE': 'C:\\cygwin', 15:08:01 INFO - 'DCLOCATION': 'SCL3', 15:08:01 INFO - 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 15:08:01 INFO - 'FP_NO_HOST_CHECK': 'NO', 15:08:01 INFO - 'HOMEDRIVE': 'C:', 15:08:01 INFO - 'HOMEPATH': '\\Users\\cltbld', 15:08:01 INFO - 'KTS_HOME': 'C:\\Program Files\\KTS', 15:08:01 INFO - 'KTS_VERSION': '1.19c', 15:08:01 INFO - 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 15:08:01 INFO - 'LOGONSERVER': '\\\\T-W732-IX-084', 15:08:01 INFO - 'MONDIR': 'C:\\Monitor_config\\', 15:08:01 INFO - 'MOZBUILDDIR': 'C:\\mozilla-build\\', 15:08:01 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:08:01 INFO - 'MOZ_NO_REMOTE': '1', 15:08:01 INFO - 'NO_EM_RESTART': '1', 15:08:01 INFO - 'NUMBER_OF_PROCESSORS': '8', 15:08:01 INFO - 'OS': 'Windows_NT', 15:08:01 INFO - 'OURDRIVE': 'C:', 15:08:01 INFO - 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 15:08:01 INFO - 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 15:08:01 INFO - 'PROCESSOR_ARCHITECTURE': 'x86', 15:08:01 INFO - 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 15:08:01 INFO - 'PROCESSOR_LEVEL': '6', 15:08:01 INFO - 'PROCESSOR_REVISION': '1e05', 15:08:01 INFO - 'PROGRAMDATA': 'C:\\ProgramData', 15:08:01 INFO - 'PROGRAMFILES': 'C:\\Program Files', 15:08:01 INFO - 'PROMPT': '$P$G', 15:08:01 INFO - 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 15:08:01 INFO - 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 15:08:01 INFO - 'PUBLIC': 'C:\\Users\\Public', 15:08:01 INFO - 'PWD': 'C:\\slave\\test', 15:08:01 INFO - 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 15:08:01 INFO - 'SLAVEDIR': 'C:\\slave\\', 15:08:01 INFO - 'SYSTEMDRIVE': 'C:', 15:08:01 INFO - 'SYSTEMROOT': 'C:\\windows', 15:08:01 INFO - 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:01 INFO - 'TEST1': 'testie', 15:08:01 INFO - 'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:01 INFO - 'USERDOMAIN': 'T-W732-IX-084', 15:08:01 INFO - 'USERNAME': 'cltbld', 15:08:01 INFO - 'USERPROFILE': 'C:\\Users\\cltbld', 15:08:01 INFO - 'WINDIR': 'C:\\windows', 15:08:01 INFO - 'WINDOWS_TRACING_FLAGS': '3', 15:08:01 INFO - 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 15:08:01 INFO - 'XPCOM_DEBUG_BREAK': 'warn'} 15:08:02 INFO - Ignoring indexes: http://pypi.python.org/simple/ 15:08:02 INFO - Downloading/unpacking pip>=1.5 15:08:02 INFO - Creating supposed download cache at C:\slave\test\build/venv\cache 15:08:06 INFO - Storing download in cache at c:\slave\test\build\venv\cache\http%3a%2f%2fpypi.pvt.build.mozilla.org%2fpub%2fpip-1.5.5.tar.gz 15:08:06 INFO - Running setup.py egg_info for package pip 15:08:06 INFO - warning: no files found matching 'pip\cacert.pem' 15:08:06 INFO - warning: no files found matching '*.html' under directory 'docs' 15:08:06 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs\_build' 15:08:06 INFO - no previously-included directories found matching 'docs\_build\_sources' 15:08:06 INFO - Installing collected packages: pip 15:08:06 INFO - Found existing installation: pip 0.8.2 15:08:06 INFO - Uninstalling pip: 15:08:06 INFO - Successfully uninstalled pip 15:08:06 INFO - Running setup.py install for pip 15:08:06 INFO - warning: no files found matching 'pip\cacert.pem' 15:08:06 INFO - warning: no files found matching '*.html' under directory 'docs' 15:08:06 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs\_build' 15:08:06 INFO - no previously-included directories found matching 'docs\_build\_sources' 15:08:06 INFO - Installing pip-script.py script to C:\slave\test\build\venv\Scripts 15:08:06 INFO - Installing pip.exe script to C:\slave\test\build\venv\Scripts 15:08:06 INFO - Installing pip2.7-script.py script to C:\slave\test\build\venv\Scripts 15:08:06 INFO - Installing pip2.7.exe script to C:\slave\test\build\venv\Scripts 15:08:06 INFO - Installing pip2-script.py script to C:\slave\test\build\venv\Scripts 15:08:06 INFO - Installing pip2.exe script to C:\slave\test\build\venv\Scripts 15:08:06 INFO - Successfully installed pip 15:08:06 INFO - Cleaning up... 15:08:06 INFO - Return code: 0 15:08:06 INFO - Installing psutil>=0.7.1 into virtualenv C:\slave\test\build/venv 15:08:06 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')]} 15:08:06 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:08:06 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')]} 15:08:06 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:08:06 INFO - retry: Calling run_command with args: [['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '--no-index', '--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 0x018F9B10>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x018BDEA8>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x017CB660>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x01298B48>, '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 0x012BA700>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x01984660>, 'level': 'critical'}], 'cwd': 'C:\\slave\\test\\build', 'env': {'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'TEST1': 'testie', 'COMPUTERNAME': 'T-W732-IX-084', 'USERDOMAIN': 'T-W732-IX-084', 'KTS_VERSION': '1.19c', 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 'PROGRAMFILES': 'C:\\Program Files', 'PROCESSOR_REVISION': '1e05', 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 'SYSTEMROOT': 'C:\\windows', 'NO_EM_RESTART': '1', 'OURDRIVE': 'C:', 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 'XPCOM_DEBUG_BREAK': 'warn', 'MONDIR': 'C:\\Monitor_config\\', 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 'PROCESSOR_ARCHITECTURE': 'x86', 'ALLUSERSPROFILE': 'C:\\ProgramData', 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 'HOMEPATH': '\\Users\\cltbld', 'MOZBUILDDIR': 'C:\\mozilla-build\\', 'USERNAME': 'cltbld', 'LOGONSERVER': '\\\\T-W732-IX-084', 'MOZ_NO_REMOTE': '1', 'WINDOWS_TRACING_FLAGS': '3', 'CYGWINBASE': 'C:\\cygwin', 'PROGRAMDATA': 'C:\\ProgramData', 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 'PROMPT': '$P$G', 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 'FP_NO_HOST_CHECK': 'NO', 'DCLOCATION': 'SCL3', 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 'HOMEDRIVE': 'C:', 'SYSTEMDRIVE': 'C:', 'SLAVEDIR': 'C:\\slave\\', 'NUMBER_OF_PROCESSORS': '8', 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 'PWD': 'C:\\slave\\test', 'PROCESSOR_LEVEL': '6', 'KTS_HOME': 'C:\\Program Files\\KTS', 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'USERPROFILE': 'C:\\Users\\cltbld', 'OS': 'Windows_NT', 'PUBLIC': 'C:\\Users\\Public', 'WINDIR': 'C:\\windows'}}, attempt #1 15:08:06 INFO - Running command: ['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=0.7.1'] in C:\slave\test\build 15:08:06 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\pip install --download-cache C:\slave\test\build/venv\cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=0.7.1 15:08:06 INFO - Using env: {'ALLUSERSPROFILE': 'C:\\ProgramData', 15:08:06 INFO - 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 15:08:06 INFO - 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 15:08:06 INFO - 'COMPUTERNAME': 'T-W732-IX-084', 15:08:06 INFO - 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 15:08:06 INFO - 'CYGWINBASE': 'C:\\cygwin', 15:08:06 INFO - 'DCLOCATION': 'SCL3', 15:08:06 INFO - 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 15:08:06 INFO - 'FP_NO_HOST_CHECK': 'NO', 15:08:06 INFO - 'HOMEDRIVE': 'C:', 15:08:06 INFO - 'HOMEPATH': '\\Users\\cltbld', 15:08:06 INFO - 'KTS_HOME': 'C:\\Program Files\\KTS', 15:08:06 INFO - 'KTS_VERSION': '1.19c', 15:08:06 INFO - 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 15:08:06 INFO - 'LOGONSERVER': '\\\\T-W732-IX-084', 15:08:06 INFO - 'MONDIR': 'C:\\Monitor_config\\', 15:08:06 INFO - 'MOZBUILDDIR': 'C:\\mozilla-build\\', 15:08:06 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:08:06 INFO - 'MOZ_NO_REMOTE': '1', 15:08:06 INFO - 'NO_EM_RESTART': '1', 15:08:06 INFO - 'NUMBER_OF_PROCESSORS': '8', 15:08:06 INFO - 'OS': 'Windows_NT', 15:08:06 INFO - 'OURDRIVE': 'C:', 15:08:06 INFO - 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 15:08:06 INFO - 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 15:08:06 INFO - 'PROCESSOR_ARCHITECTURE': 'x86', 15:08:06 INFO - 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 15:08:06 INFO - 'PROCESSOR_LEVEL': '6', 15:08:06 INFO - 'PROCESSOR_REVISION': '1e05', 15:08:06 INFO - 'PROGRAMDATA': 'C:\\ProgramData', 15:08:06 INFO - 'PROGRAMFILES': 'C:\\Program Files', 15:08:06 INFO - 'PROMPT': '$P$G', 15:08:06 INFO - 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 15:08:06 INFO - 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 15:08:06 INFO - 'PUBLIC': 'C:\\Users\\Public', 15:08:06 INFO - 'PWD': 'C:\\slave\\test', 15:08:06 INFO - 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 15:08:06 INFO - 'SLAVEDIR': 'C:\\slave\\', 15:08:06 INFO - 'SYSTEMDRIVE': 'C:', 15:08:06 INFO - 'SYSTEMROOT': 'C:\\windows', 15:08:06 INFO - 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:06 INFO - 'TEST1': 'testie', 15:08:06 INFO - 'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:06 INFO - 'USERDOMAIN': 'T-W732-IX-084', 15:08:06 INFO - 'USERNAME': 'cltbld', 15:08:06 INFO - 'USERPROFILE': 'C:\\Users\\cltbld', 15:08:06 INFO - 'WINDIR': 'C:\\windows', 15:08:06 INFO - 'WINDOWS_TRACING_FLAGS': '3', 15:08:06 INFO - 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 15:08:06 INFO - 'XPCOM_DEBUG_BREAK': 'warn'} 15:08:08 INFO - Ignoring indexes: https://pypi.python.org/simple/ 15:08:08 INFO - Downloading/unpacking psutil>=0.7.1 15:08:08 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 15:08:08 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 15:08:09 INFO - Storing download in cache at c:\slave\test\build\venv\cache\http%3a%2f%2fpypi.pvt.build.mozilla.org%2fpub%2fpsutil-3.1.1-cp27-none-win32.whl 15:08:09 INFO - Installing collected packages: psutil 15:08:09 INFO - Successfully installed psutil 15:08:09 INFO - Cleaning up... 15:08:09 INFO - Return code: 0 15:08:09 INFO - Installing mozsystemmonitor==0.0.0 into virtualenv C:\slave\test\build/venv 15:08:09 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:08:09 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:08:09 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:08:09 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:08:09 INFO - retry: Calling run_command with args: [['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '--no-index', '--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 0x018F9B10>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x018BDEA8>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x017CB660>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x01298B48>, '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 0x012BA700>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x01984660>, 'level': 'critical'}], 'cwd': 'C:\\slave\\test\\build', 'env': {'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'TEST1': 'testie', 'COMPUTERNAME': 'T-W732-IX-084', 'USERDOMAIN': 'T-W732-IX-084', 'KTS_VERSION': '1.19c', 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 'PROGRAMFILES': 'C:\\Program Files', 'PROCESSOR_REVISION': '1e05', 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 'SYSTEMROOT': 'C:\\windows', 'NO_EM_RESTART': '1', 'OURDRIVE': 'C:', 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 'XPCOM_DEBUG_BREAK': 'warn', 'MONDIR': 'C:\\Monitor_config\\', 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 'PROCESSOR_ARCHITECTURE': 'x86', 'ALLUSERSPROFILE': 'C:\\ProgramData', 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 'HOMEPATH': '\\Users\\cltbld', 'MOZBUILDDIR': 'C:\\mozilla-build\\', 'USERNAME': 'cltbld', 'LOGONSERVER': '\\\\T-W732-IX-084', 'MOZ_NO_REMOTE': '1', 'WINDOWS_TRACING_FLAGS': '3', 'CYGWINBASE': 'C:\\cygwin', 'PROGRAMDATA': 'C:\\ProgramData', 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 'PROMPT': '$P$G', 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 'FP_NO_HOST_CHECK': 'NO', 'DCLOCATION': 'SCL3', 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 'HOMEDRIVE': 'C:', 'SYSTEMDRIVE': 'C:', 'SLAVEDIR': 'C:\\slave\\', 'NUMBER_OF_PROCESSORS': '8', 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 'PWD': 'C:\\slave\\test', 'PROCESSOR_LEVEL': '6', 'KTS_HOME': 'C:\\Program Files\\KTS', 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'USERPROFILE': 'C:\\Users\\cltbld', 'OS': 'Windows_NT', 'PUBLIC': 'C:\\Users\\Public', 'WINDIR': 'C:\\windows'}}, attempt #1 15:08:09 INFO - Running command: ['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.0.0'] in C:\slave\test\build 15:08:09 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\pip install --download-cache C:\slave\test\build/venv\cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.0.0 15:08:09 INFO - Using env: {'ALLUSERSPROFILE': 'C:\\ProgramData', 15:08:09 INFO - 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 15:08:09 INFO - 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 15:08:09 INFO - 'COMPUTERNAME': 'T-W732-IX-084', 15:08:09 INFO - 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 15:08:09 INFO - 'CYGWINBASE': 'C:\\cygwin', 15:08:09 INFO - 'DCLOCATION': 'SCL3', 15:08:09 INFO - 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 15:08:09 INFO - 'FP_NO_HOST_CHECK': 'NO', 15:08:09 INFO - 'HOMEDRIVE': 'C:', 15:08:09 INFO - 'HOMEPATH': '\\Users\\cltbld', 15:08:09 INFO - 'KTS_HOME': 'C:\\Program Files\\KTS', 15:08:09 INFO - 'KTS_VERSION': '1.19c', 15:08:09 INFO - 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 15:08:09 INFO - 'LOGONSERVER': '\\\\T-W732-IX-084', 15:08:09 INFO - 'MONDIR': 'C:\\Monitor_config\\', 15:08:09 INFO - 'MOZBUILDDIR': 'C:\\mozilla-build\\', 15:08:09 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:08:09 INFO - 'MOZ_NO_REMOTE': '1', 15:08:09 INFO - 'NO_EM_RESTART': '1', 15:08:09 INFO - 'NUMBER_OF_PROCESSORS': '8', 15:08:09 INFO - 'OS': 'Windows_NT', 15:08:09 INFO - 'OURDRIVE': 'C:', 15:08:09 INFO - 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 15:08:09 INFO - 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 15:08:09 INFO - 'PROCESSOR_ARCHITECTURE': 'x86', 15:08:09 INFO - 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 15:08:09 INFO - 'PROCESSOR_LEVEL': '6', 15:08:09 INFO - 'PROCESSOR_REVISION': '1e05', 15:08:09 INFO - 'PROGRAMDATA': 'C:\\ProgramData', 15:08:09 INFO - 'PROGRAMFILES': 'C:\\Program Files', 15:08:09 INFO - 'PROMPT': '$P$G', 15:08:09 INFO - 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 15:08:09 INFO - 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 15:08:09 INFO - 'PUBLIC': 'C:\\Users\\Public', 15:08:09 INFO - 'PWD': 'C:\\slave\\test', 15:08:09 INFO - 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 15:08:09 INFO - 'SLAVEDIR': 'C:\\slave\\', 15:08:09 INFO - 'SYSTEMDRIVE': 'C:', 15:08:09 INFO - 'SYSTEMROOT': 'C:\\windows', 15:08:09 INFO - 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:09 INFO - 'TEST1': 'testie', 15:08:09 INFO - 'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:09 INFO - 'USERDOMAIN': 'T-W732-IX-084', 15:08:09 INFO - 'USERNAME': 'cltbld', 15:08:09 INFO - 'USERPROFILE': 'C:\\Users\\cltbld', 15:08:09 INFO - 'WINDIR': 'C:\\windows', 15:08:09 INFO - 'WINDOWS_TRACING_FLAGS': '3', 15:08:09 INFO - 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 15:08:09 INFO - 'XPCOM_DEBUG_BREAK': 'warn'} 15:08:10 INFO - Ignoring indexes: https://pypi.python.org/simple/ 15:08:10 INFO - Downloading/unpacking mozsystemmonitor==0.0.0 15:08:10 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 15:08:10 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 15:08:11 INFO - Downloading mozsystemmonitor-0.0.tar.gz 15:08:11 INFO - Storing download in cache at c:\slave\test\build\venv\cache\http%3a%2f%2fpypi.pvt.build.mozilla.org%2fpub%2fmozsystemmonitor-0.0.tar.gz 15:08:11 INFO - Running setup.py (path:C:\slave\test\build\venv\build\mozsystemmonitor\setup.py) egg_info for package mozsystemmonitor 15:08:11 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=0.7.1 in c:\slave\test\build\venv\lib\site-packages (from mozsystemmonitor==0.0.0) 15:08:11 INFO - Installing collected packages: mozsystemmonitor 15:08:11 INFO - Running setup.py install for mozsystemmonitor 15:08:11 INFO - Successfully installed mozsystemmonitor 15:08:11 INFO - Cleaning up... 15:08:11 INFO - Return code: 0 15:08:11 INFO - Installing blobuploader==1.2.4 into virtualenv C:\slave\test\build/venv 15:08:11 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')]} 15:08:11 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:08:11 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')]} 15:08:11 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:08:11 INFO - retry: Calling run_command with args: [['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '--no-index', '--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 0x018F9B10>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x018BDEA8>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x017CB660>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x01298B48>, '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 0x012BA700>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x01984660>, 'level': 'critical'}], 'cwd': 'C:\\slave\\test\\build', 'env': {'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'TEST1': 'testie', 'COMPUTERNAME': 'T-W732-IX-084', 'USERDOMAIN': 'T-W732-IX-084', 'KTS_VERSION': '1.19c', 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 'PROGRAMFILES': 'C:\\Program Files', 'PROCESSOR_REVISION': '1e05', 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 'SYSTEMROOT': 'C:\\windows', 'NO_EM_RESTART': '1', 'OURDRIVE': 'C:', 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 'XPCOM_DEBUG_BREAK': 'warn', 'MONDIR': 'C:\\Monitor_config\\', 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 'PROCESSOR_ARCHITECTURE': 'x86', 'ALLUSERSPROFILE': 'C:\\ProgramData', 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 'HOMEPATH': '\\Users\\cltbld', 'MOZBUILDDIR': 'C:\\mozilla-build\\', 'USERNAME': 'cltbld', 'LOGONSERVER': '\\\\T-W732-IX-084', 'MOZ_NO_REMOTE': '1', 'WINDOWS_TRACING_FLAGS': '3', 'CYGWINBASE': 'C:\\cygwin', 'PROGRAMDATA': 'C:\\ProgramData', 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 'PROMPT': '$P$G', 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 'FP_NO_HOST_CHECK': 'NO', 'DCLOCATION': 'SCL3', 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 'HOMEDRIVE': 'C:', 'SYSTEMDRIVE': 'C:', 'SLAVEDIR': 'C:\\slave\\', 'NUMBER_OF_PROCESSORS': '8', 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 'PWD': 'C:\\slave\\test', 'PROCESSOR_LEVEL': '6', 'KTS_HOME': 'C:\\Program Files\\KTS', 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'USERPROFILE': 'C:\\Users\\cltbld', 'OS': 'Windows_NT', 'PUBLIC': 'C:\\Users\\Public', 'WINDIR': 'C:\\windows'}}, attempt #1 15:08:11 INFO - Running command: ['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in C:\slave\test\build 15:08:11 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\pip install --download-cache C:\slave\test\build/venv\cache --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4 15:08:11 INFO - Using env: {'ALLUSERSPROFILE': 'C:\\ProgramData', 15:08:11 INFO - 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 15:08:11 INFO - 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 15:08:11 INFO - 'COMPUTERNAME': 'T-W732-IX-084', 15:08:11 INFO - 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 15:08:11 INFO - 'CYGWINBASE': 'C:\\cygwin', 15:08:11 INFO - 'DCLOCATION': 'SCL3', 15:08:11 INFO - 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 15:08:11 INFO - 'FP_NO_HOST_CHECK': 'NO', 15:08:11 INFO - 'HOMEDRIVE': 'C:', 15:08:11 INFO - 'HOMEPATH': '\\Users\\cltbld', 15:08:11 INFO - 'KTS_HOME': 'C:\\Program Files\\KTS', 15:08:11 INFO - 'KTS_VERSION': '1.19c', 15:08:11 INFO - 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 15:08:11 INFO - 'LOGONSERVER': '\\\\T-W732-IX-084', 15:08:11 INFO - 'MONDIR': 'C:\\Monitor_config\\', 15:08:11 INFO - 'MOZBUILDDIR': 'C:\\mozilla-build\\', 15:08:11 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:08:11 INFO - 'MOZ_NO_REMOTE': '1', 15:08:11 INFO - 'NO_EM_RESTART': '1', 15:08:11 INFO - 'NUMBER_OF_PROCESSORS': '8', 15:08:11 INFO - 'OS': 'Windows_NT', 15:08:11 INFO - 'OURDRIVE': 'C:', 15:08:11 INFO - 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 15:08:11 INFO - 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 15:08:11 INFO - 'PROCESSOR_ARCHITECTURE': 'x86', 15:08:11 INFO - 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 15:08:11 INFO - 'PROCESSOR_LEVEL': '6', 15:08:11 INFO - 'PROCESSOR_REVISION': '1e05', 15:08:11 INFO - 'PROGRAMDATA': 'C:\\ProgramData', 15:08:11 INFO - 'PROGRAMFILES': 'C:\\Program Files', 15:08:11 INFO - 'PROMPT': '$P$G', 15:08:11 INFO - 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 15:08:11 INFO - 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 15:08:11 INFO - 'PUBLIC': 'C:\\Users\\Public', 15:08:11 INFO - 'PWD': 'C:\\slave\\test', 15:08:11 INFO - 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 15:08:11 INFO - 'SLAVEDIR': 'C:\\slave\\', 15:08:11 INFO - 'SYSTEMDRIVE': 'C:', 15:08:11 INFO - 'SYSTEMROOT': 'C:\\windows', 15:08:11 INFO - 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:11 INFO - 'TEST1': 'testie', 15:08:11 INFO - 'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:11 INFO - 'USERDOMAIN': 'T-W732-IX-084', 15:08:11 INFO - 'USERNAME': 'cltbld', 15:08:11 INFO - 'USERPROFILE': 'C:\\Users\\cltbld', 15:08:11 INFO - 'WINDIR': 'C:\\windows', 15:08:11 INFO - 'WINDOWS_TRACING_FLAGS': '3', 15:08:11 INFO - 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 15:08:11 INFO - 'XPCOM_DEBUG_BREAK': 'warn'} 15:08:11 INFO - Ignoring indexes: https://pypi.python.org/simple/ 15:08:11 INFO - Downloading/unpacking blobuploader==1.2.4 15:08:11 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 15:08:11 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 15:08:12 INFO - Downloading blobuploader-1.2.4.tar.gz 15:08:13 INFO - Storing download in cache at c:\slave\test\build\venv\cache\http%3a%2f%2fpypi.pvt.build.mozilla.org%2fpub%2fblobuploader-1.2.4.tar.gz 15:08:13 INFO - Running setup.py (path:C:\slave\test\build\venv\build\blobuploader\setup.py) egg_info for package blobuploader 15:08:13 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 15:08:13 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 15:08:13 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 15:08:13 INFO - Storing download in cache at c:\slave\test\build\venv\cache\http%3a%2f%2fpypi.pvt.build.mozilla.org%2fpub%2frequests-1.2.3.tar.gz 15:08:13 INFO - Running setup.py (path:C:\slave\test\build\venv\build\requests\setup.py) egg_info for package requests 15:08:13 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 15:08:13 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 15:08:13 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 15:08:14 INFO - Downloading docopt-0.6.1.tar.gz 15:08:14 INFO - Storing download in cache at c:\slave\test\build\venv\cache\http%3a%2f%2fpypi.pvt.build.mozilla.org%2fpub%2fdocopt-0.6.1.tar.gz 15:08:14 INFO - Running setup.py (path:C:\slave\test\build\venv\build\docopt\setup.py) egg_info for package docopt 15:08:14 INFO - Installing collected packages: blobuploader, requests, docopt 15:08:14 INFO - Running setup.py install for blobuploader 15:08:14 INFO - Running setup.py install for requests 15:08:15 INFO - Running setup.py install for docopt 15:08:15 INFO - Successfully installed blobuploader requests docopt 15:08:15 INFO - Cleaning up... 15:08:16 INFO - Return code: 0 15:08:16 INFO - Installing None into virtualenv C:\slave\test\build/venv 15:08:16 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:08:16 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:08:16 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:08:16 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:08:16 INFO - retry: Calling run_command with args: [['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--no-deps', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '-r', 'C:\\slave\\test\\build\\tests\\config\\mozbase_requirements.txt', '--no-index', '--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 0x018F9B10>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x018BDEA8>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x017CB660>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x01298B48>, '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 0x012BA700>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x01984660>, 'level': 'critical'}], 'cwd': 'C:\\slave\\test\\build\\tests\\config', 'env': {'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'TEST1': 'testie', 'COMPUTERNAME': 'T-W732-IX-084', 'USERDOMAIN': 'T-W732-IX-084', 'KTS_VERSION': '1.19c', 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 'PROGRAMFILES': 'C:\\Program Files', 'PROCESSOR_REVISION': '1e05', 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 'SYSTEMROOT': 'C:\\windows', 'NO_EM_RESTART': '1', 'OURDRIVE': 'C:', 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 'XPCOM_DEBUG_BREAK': 'warn', 'MONDIR': 'C:\\Monitor_config\\', 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 'PROCESSOR_ARCHITECTURE': 'x86', 'ALLUSERSPROFILE': 'C:\\ProgramData', 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 'HOMEPATH': '\\Users\\cltbld', 'MOZBUILDDIR': 'C:\\mozilla-build\\', 'USERNAME': 'cltbld', 'LOGONSERVER': '\\\\T-W732-IX-084', 'MOZ_NO_REMOTE': '1', 'WINDOWS_TRACING_FLAGS': '3', 'CYGWINBASE': 'C:\\cygwin', 'PROGRAMDATA': 'C:\\ProgramData', 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 'PROMPT': '$P$G', 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 'FP_NO_HOST_CHECK': 'NO', 'DCLOCATION': 'SCL3', 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 'HOMEDRIVE': 'C:', 'SYSTEMDRIVE': 'C:', 'SLAVEDIR': 'C:\\slave\\', 'NUMBER_OF_PROCESSORS': '8', 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 'PWD': 'C:\\slave\\test', 'PROCESSOR_LEVEL': '6', 'KTS_HOME': 'C:\\Program Files\\KTS', 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'USERPROFILE': 'C:\\Users\\cltbld', 'OS': 'Windows_NT', 'PUBLIC': 'C:\\Users\\Public', 'WINDIR': 'C:\\windows'}}, attempt #1 15:08:16 INFO - Running command: ['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--no-deps', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '-r', 'C:\\slave\\test\\build\\tests\\config\\mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in C:\slave\test\build\tests\config 15:08:16 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\pip install --no-deps --download-cache C:\slave\test\build/venv\cache --timeout 120 -r C:\slave\test\build\tests\config\mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 15:08:16 INFO - Using env: {'ALLUSERSPROFILE': 'C:\\ProgramData', 15:08:16 INFO - 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 15:08:16 INFO - 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 15:08:16 INFO - 'COMPUTERNAME': 'T-W732-IX-084', 15:08:16 INFO - 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 15:08:16 INFO - 'CYGWINBASE': 'C:\\cygwin', 15:08:16 INFO - 'DCLOCATION': 'SCL3', 15:08:16 INFO - 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 15:08:16 INFO - 'FP_NO_HOST_CHECK': 'NO', 15:08:16 INFO - 'HOMEDRIVE': 'C:', 15:08:16 INFO - 'HOMEPATH': '\\Users\\cltbld', 15:08:16 INFO - 'KTS_HOME': 'C:\\Program Files\\KTS', 15:08:16 INFO - 'KTS_VERSION': '1.19c', 15:08:16 INFO - 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 15:08:16 INFO - 'LOGONSERVER': '\\\\T-W732-IX-084', 15:08:16 INFO - 'MONDIR': 'C:\\Monitor_config\\', 15:08:16 INFO - 'MOZBUILDDIR': 'C:\\mozilla-build\\', 15:08:16 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:08:16 INFO - 'MOZ_NO_REMOTE': '1', 15:08:16 INFO - 'NO_EM_RESTART': '1', 15:08:16 INFO - 'NUMBER_OF_PROCESSORS': '8', 15:08:16 INFO - 'OS': 'Windows_NT', 15:08:16 INFO - 'OURDRIVE': 'C:', 15:08:16 INFO - 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 15:08:16 INFO - 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 15:08:16 INFO - 'PROCESSOR_ARCHITECTURE': 'x86', 15:08:16 INFO - 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 15:08:16 INFO - 'PROCESSOR_LEVEL': '6', 15:08:16 INFO - 'PROCESSOR_REVISION': '1e05', 15:08:16 INFO - 'PROGRAMDATA': 'C:\\ProgramData', 15:08:16 INFO - 'PROGRAMFILES': 'C:\\Program Files', 15:08:16 INFO - 'PROMPT': '$P$G', 15:08:16 INFO - 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 15:08:16 INFO - 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 15:08:16 INFO - 'PUBLIC': 'C:\\Users\\Public', 15:08:16 INFO - 'PWD': 'C:\\slave\\test', 15:08:16 INFO - 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 15:08:16 INFO - 'SLAVEDIR': 'C:\\slave\\', 15:08:16 INFO - 'SYSTEMDRIVE': 'C:', 15:08:16 INFO - 'SYSTEMROOT': 'C:\\windows', 15:08:16 INFO - 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:16 INFO - 'TEST1': 'testie', 15:08:16 INFO - 'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:16 INFO - 'USERDOMAIN': 'T-W732-IX-084', 15:08:16 INFO - 'USERNAME': 'cltbld', 15:08:16 INFO - 'USERPROFILE': 'C:\\Users\\cltbld', 15:08:16 INFO - 'WINDIR': 'C:\\windows', 15:08:16 INFO - 'WINDOWS_TRACING_FLAGS': '3', 15:08:16 INFO - 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 15:08:16 INFO - 'XPCOM_DEBUG_BREAK': 'warn'} 15:08:17 INFO - Ignoring indexes: https://pypi.python.org/simple/ 15:08:17 INFO - Unpacking c:\slave\test\build\tests\mozbase\manifestparser 15:08:17 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-rwrcta-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/manifestparser 15:08:17 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozcrash 15:08:17 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-2waaof-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozcrash 15:08:17 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozdebug 15:08:17 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-qjprh6-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozdebug 15:08:17 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozdevice 15:08:17 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-pwcqmk-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozdevice 15:08:17 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozfile 15:08:17 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-7f3y7f-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozfile 15:08:17 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozhttpd 15:08:17 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-90zho6-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozhttpd 15:08:17 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozinfo 15:08:17 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-ad4vfa-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozinfo 15:08:18 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozinstall 15:08:18 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-p8qqwj-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozinstall 15:08:18 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozleak 15:08:18 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-vxorep-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozleak 15:08:18 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozlog 15:08:18 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-8s9nlk-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozlog 15:08:18 INFO - Unpacking c:\slave\test\build\tests\mozbase\moznetwork 15:08:18 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-vlojwa-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/moznetwork 15:08:18 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozprocess 15:08:18 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-7ggvav-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozprocess 15:08:18 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozprofile 15:08:18 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-rknav9-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozprofile 15:08:19 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozrunner 15:08:19 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-pm0pw6-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozrunner 15:08:19 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozscreenshot 15:08:19 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-nkg6ew-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozscreenshot 15:08:20 INFO - Unpacking c:\slave\test\build\tests\mozbase\moztest 15:08:20 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-gzud3j-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/moztest 15:08:20 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozversion 15:08:20 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-tuwrln-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozversion 15:08:20 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 15:08:20 INFO - Running setup.py install for manifestparser 15:08:20 INFO - Installing manifestparser-script.py script to C:\slave\test\build\venv\Scripts 15:08:20 INFO - Installing manifestparser.exe script to C:\slave\test\build\venv\Scripts 15:08:21 INFO - Running setup.py install for mozcrash 15:08:21 INFO - Running setup.py install for mozdebug 15:08:21 INFO - Running setup.py install for mozdevice 15:08:21 INFO - Installing sutini-script.py script to C:\slave\test\build\venv\Scripts 15:08:21 INFO - Installing sutini.exe script to C:\slave\test\build\venv\Scripts 15:08:21 INFO - Installing dm-script.py script to C:\slave\test\build\venv\Scripts 15:08:21 INFO - Installing dm.exe script to C:\slave\test\build\venv\Scripts 15:08:22 INFO - Running setup.py install for mozfile 15:08:22 INFO - Running setup.py install for mozhttpd 15:08:22 INFO - Installing mozhttpd-script.py script to C:\slave\test\build\venv\Scripts 15:08:22 INFO - Installing mozhttpd.exe script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Running setup.py install for mozinfo 15:08:23 INFO - Installing mozinfo-script.py script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Installing mozinfo.exe script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Running setup.py install for mozInstall 15:08:23 INFO - Installing moz_remove_from_system-script.py script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Installing moz_remove_from_system.exe script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Installing mozuninstall-script.py script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Installing mozuninstall.exe script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Installing mozinstall-script.py script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Installing mozinstall.exe script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Installing moz_add_to_system-script.py script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Installing moz_add_to_system.exe script to C:\slave\test\build\venv\Scripts 15:08:23 INFO - Running setup.py install for mozleak 15:08:24 INFO - Running setup.py install for mozlog 15:08:24 INFO - Installing structlog-script.py script to C:\slave\test\build\venv\Scripts 15:08:24 INFO - Installing structlog.exe script to C:\slave\test\build\venv\Scripts 15:08:25 INFO - Running setup.py install for moznetwork 15:08:25 INFO - Installing moznetwork-script.py script to C:\slave\test\build\venv\Scripts 15:08:25 INFO - Installing moznetwork.exe script to C:\slave\test\build\venv\Scripts 15:08:25 INFO - Running setup.py install for mozprocess 15:08:26 INFO - Running setup.py install for mozprofile 15:08:26 INFO - Installing mozprofile-script.py script to C:\slave\test\build\venv\Scripts 15:08:26 INFO - Installing mozprofile.exe script to C:\slave\test\build\venv\Scripts 15:08:26 INFO - Installing diff-profiles-script.py script to C:\slave\test\build\venv\Scripts 15:08:26 INFO - Installing diff-profiles.exe script to C:\slave\test\build\venv\Scripts 15:08:26 INFO - Installing view-profile-script.py script to C:\slave\test\build\venv\Scripts 15:08:26 INFO - Installing view-profile.exe script to C:\slave\test\build\venv\Scripts 15:08:26 INFO - Running setup.py install for mozrunner 15:08:27 INFO - Installing mozrunner-script.py script to C:\slave\test\build\venv\Scripts 15:08:27 INFO - Installing mozrunner.exe script to C:\slave\test\build\venv\Scripts 15:08:27 INFO - Running setup.py install for mozscreenshot 15:08:27 INFO - Running setup.py install for moztest 15:08:28 INFO - Running setup.py install for mozversion 15:08:28 INFO - Installing mozversion-script.py script to C:\slave\test\build\venv\Scripts 15:08:28 INFO - Installing mozversion.exe script to C:\slave\test\build\venv\Scripts 15:08:28 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 15:08:28 INFO - Cleaning up... 15:08:28 INFO - Return code: 0 15:08:28 INFO - Installing None into virtualenv C:\slave\test\build/venv 15:08:28 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:08:28 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:08:28 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:08:28 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:08:28 INFO - retry: Calling run_command with args: [['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '-r', 'C:\\slave\\test\\build\\tests\\config\\mozbase_requirements.txt', '--no-index', '--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 0x018F9B10>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x018BDEA8>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x017CB660>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x01298B48>, '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 0x012BA700>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x01984660>, 'level': 'critical'}], 'cwd': 'C:\\slave\\test\\build\\tests\\config', 'env': {'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'TEST1': 'testie', 'COMPUTERNAME': 'T-W732-IX-084', 'USERDOMAIN': 'T-W732-IX-084', 'KTS_VERSION': '1.19c', 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 'PROGRAMFILES': 'C:\\Program Files', 'PROCESSOR_REVISION': '1e05', 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 'SYSTEMROOT': 'C:\\windows', 'NO_EM_RESTART': '1', 'OURDRIVE': 'C:', 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 'XPCOM_DEBUG_BREAK': 'warn', 'MONDIR': 'C:\\Monitor_config\\', 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 'PROCESSOR_ARCHITECTURE': 'x86', 'ALLUSERSPROFILE': 'C:\\ProgramData', 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 'HOMEPATH': '\\Users\\cltbld', 'MOZBUILDDIR': 'C:\\mozilla-build\\', 'USERNAME': 'cltbld', 'LOGONSERVER': '\\\\T-W732-IX-084', 'MOZ_NO_REMOTE': '1', 'WINDOWS_TRACING_FLAGS': '3', 'CYGWINBASE': 'C:\\cygwin', 'PROGRAMDATA': 'C:\\ProgramData', 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 'PROMPT': '$P$G', 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 'FP_NO_HOST_CHECK': 'NO', 'DCLOCATION': 'SCL3', 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 'HOMEDRIVE': 'C:', 'SYSTEMDRIVE': 'C:', 'SLAVEDIR': 'C:\\slave\\', 'NUMBER_OF_PROCESSORS': '8', 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 'PWD': 'C:\\slave\\test', 'PROCESSOR_LEVEL': '6', 'KTS_HOME': 'C:\\Program Files\\KTS', 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'USERPROFILE': 'C:\\Users\\cltbld', 'OS': 'Windows_NT', 'PUBLIC': 'C:\\Users\\Public', 'WINDIR': 'C:\\windows'}}, attempt #1 15:08:28 INFO - Running command: ['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '-r', 'C:\\slave\\test\\build\\tests\\config\\mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in C:\slave\test\build\tests\config 15:08:28 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\pip install --download-cache C:\slave\test\build/venv\cache --timeout 120 -r C:\slave\test\build\tests\config\mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 15:08:28 INFO - Using env: {'ALLUSERSPROFILE': 'C:\\ProgramData', 15:08:28 INFO - 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 15:08:28 INFO - 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 15:08:28 INFO - 'COMPUTERNAME': 'T-W732-IX-084', 15:08:28 INFO - 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 15:08:28 INFO - 'CYGWINBASE': 'C:\\cygwin', 15:08:28 INFO - 'DCLOCATION': 'SCL3', 15:08:28 INFO - 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 15:08:28 INFO - 'FP_NO_HOST_CHECK': 'NO', 15:08:28 INFO - 'HOMEDRIVE': 'C:', 15:08:28 INFO - 'HOMEPATH': '\\Users\\cltbld', 15:08:28 INFO - 'KTS_HOME': 'C:\\Program Files\\KTS', 15:08:28 INFO - 'KTS_VERSION': '1.19c', 15:08:28 INFO - 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 15:08:28 INFO - 'LOGONSERVER': '\\\\T-W732-IX-084', 15:08:28 INFO - 'MONDIR': 'C:\\Monitor_config\\', 15:08:28 INFO - 'MOZBUILDDIR': 'C:\\mozilla-build\\', 15:08:28 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:08:28 INFO - 'MOZ_NO_REMOTE': '1', 15:08:28 INFO - 'NO_EM_RESTART': '1', 15:08:28 INFO - 'NUMBER_OF_PROCESSORS': '8', 15:08:28 INFO - 'OS': 'Windows_NT', 15:08:28 INFO - 'OURDRIVE': 'C:', 15:08:28 INFO - 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 15:08:28 INFO - 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 15:08:28 INFO - 'PROCESSOR_ARCHITECTURE': 'x86', 15:08:28 INFO - 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 15:08:28 INFO - 'PROCESSOR_LEVEL': '6', 15:08:28 INFO - 'PROCESSOR_REVISION': '1e05', 15:08:28 INFO - 'PROGRAMDATA': 'C:\\ProgramData', 15:08:28 INFO - 'PROGRAMFILES': 'C:\\Program Files', 15:08:28 INFO - 'PROMPT': '$P$G', 15:08:28 INFO - 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 15:08:28 INFO - 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 15:08:28 INFO - 'PUBLIC': 'C:\\Users\\Public', 15:08:28 INFO - 'PWD': 'C:\\slave\\test', 15:08:28 INFO - 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 15:08:28 INFO - 'SLAVEDIR': 'C:\\slave\\', 15:08:28 INFO - 'SYSTEMDRIVE': 'C:', 15:08:28 INFO - 'SYSTEMROOT': 'C:\\windows', 15:08:28 INFO - 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:28 INFO - 'TEST1': 'testie', 15:08:28 INFO - 'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:28 INFO - 'USERDOMAIN': 'T-W732-IX-084', 15:08:28 INFO - 'USERNAME': 'cltbld', 15:08:28 INFO - 'USERPROFILE': 'C:\\Users\\cltbld', 15:08:28 INFO - 'WINDIR': 'C:\\windows', 15:08:28 INFO - 'WINDOWS_TRACING_FLAGS': '3', 15:08:28 INFO - 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 15:08:28 INFO - 'XPCOM_DEBUG_BREAK': 'warn'} 15:08:29 INFO - Ignoring indexes: https://pypi.python.org/simple/ 15:08:29 INFO - Unpacking c:\slave\test\build\tests\mozbase\manifestparser 15:08:29 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-uhkcyd-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/manifestparser 15:08:29 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///C:/slave/test/build/tests/mozbase/manifestparser in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 1)) 15:08:29 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozcrash 15:08:29 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-jx3ykm-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozcrash 15:08:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==0.16 from file:///C:/slave/test/build/tests/mozbase/mozcrash in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 2)) 15:08:29 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozdebug 15:08:29 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-wd9_ns-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozdebug 15:08:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///C:/slave/test/build/tests/mozbase/mozdebug in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 3)) 15:08:29 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozdevice 15:08:29 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-okt_oi-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozdevice 15:08:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.47 from file:///C:/slave/test/build/tests/mozbase/mozdevice in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 4)) 15:08:29 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozfile 15:08:29 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-zh9p9s-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozfile 15:08:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///C:/slave/test/build/tests/mozbase/mozfile in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 5)) 15:08:29 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozhttpd 15:08:29 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-qtsgfx-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozhttpd 15:08:30 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///C:/slave/test/build/tests/mozbase/mozhttpd in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 6)) 15:08:30 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozinfo 15:08:30 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-rkfj46-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozinfo 15:08:30 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.9 from file:///C:/slave/test/build/tests/mozbase/mozinfo in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 7)) 15:08:30 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozinstall 15:08:30 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-ana5i5-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozinstall 15:08:30 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.12 from file:///C:/slave/test/build/tests/mozbase/mozinstall in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 8)) 15:08:30 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozleak 15:08:30 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-izzidw-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozleak 15:08:30 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///C:/slave/test/build/tests/mozbase/mozleak in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 9)) 15:08:30 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozlog 15:08:30 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-6zcq57-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozlog 15:08:30 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.0 from file:///C:/slave/test/build/tests/mozbase/mozlog in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 10)) 15:08:30 INFO - Unpacking c:\slave\test\build\tests\mozbase\moznetwork 15:08:30 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-2cxsfd-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/moznetwork 15:08:31 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///C:/slave/test/build/tests/mozbase/moznetwork in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 11)) 15:08:31 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozprocess 15:08:31 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-xkvoeq-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozprocess 15:08:31 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.22 from file:///C:/slave/test/build/tests/mozbase/mozprocess in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 12)) 15:08:31 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozprofile 15:08:31 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-ngig4_-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozprofile 15:08:31 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.27 from file:///C:/slave/test/build/tests/mozbase/mozprofile in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 13)) 15:08:31 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozrunner 15:08:31 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-t810bj-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozrunner 15:08:31 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.11 from file:///C:/slave/test/build/tests/mozbase/mozrunner in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 14)) 15:08:31 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozscreenshot 15:08:31 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-evq3et-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozscreenshot 15:08:31 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///C:/slave/test/build/tests/mozbase/mozscreenshot in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 15)) 15:08:31 INFO - Unpacking c:\slave\test\build\tests\mozbase\moztest 15:08:31 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-j8p9sg-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/moztest 15:08:31 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.7 from file:///C:/slave/test/build/tests/mozbase/moztest in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 16)) 15:08:31 INFO - Unpacking c:\slave\test\build\tests\mozbase\mozversion 15:08:31 INFO - Running setup.py (path:c:\users\cltbld\appdata\local\temp\pip-pchgyu-build\setup.py) egg_info for package from file:///C:/slave/test/build/tests/mozbase/mozversion 15:08:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///C:/slave/test/build/tests/mozbase/mozversion in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 17)) 15:08:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in c:\slave\test\build\venv\lib\site-packages (from mozcrash==0.16->-r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 2)) 15:08:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in c:\slave\test\build\venv\lib\site-packages (from mozcrash==0.16->-r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 2)) 15:08:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in c:\slave\test\build\venv\lib\site-packages (from mozdebug==0.1->-r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 3)) 15:08:32 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in c:\slave\test\build\venv\lib\site-packages (from mozdevice==0.47->-r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 4)) 15:08:32 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in c:\slave\test\build\venv\lib\site-packages (from mozdevice==0.47->-r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 4)) 15:08:32 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.0->-r C:\slave\test\build\tests\config\mozbase_requirements.txt (line 10)) 15:08:32 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 15:08:32 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 15:08:33 INFO - Downloading blessings-1.5.1.tar.gz 15:08:33 INFO - Storing download in cache at c:\slave\test\build\venv\cache\http%3a%2f%2fpypi.pvt.build.mozilla.org%2fpub%2fblessings-1.5.1.tar.gz 15:08:33 INFO - Running setup.py (path:C:\slave\test\build\venv\build\blessings\setup.py) egg_info for package blessings 15:08:33 INFO - Installing collected packages: blessings 15:08:33 INFO - Running setup.py install for blessings 15:08:33 INFO - Successfully installed blessings 15:08:33 INFO - Cleaning up... 15:08:36 INFO - Return code: 0 15:08:36 INFO - Done creating virtualenv C:\slave\test\build/venv. 15:08:36 INFO - Getting output from command: ['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'freeze'] 15:08:36 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\pip freeze 15:08:37 INFO - Reading from file tmpfile_stdout 15:08:37 INFO - Using _rmtree_windows ... 15:08:37 INFO - Using _rmtree_windows ... 15:08:37 INFO - Current package versions: 15:08:37 INFO - blessings == 1.5.1 15:08:37 INFO - blobuploader == 1.2.4 15:08:37 INFO - docopt == 0.6.1 15:08:37 INFO - manifestparser == 1.1 15:08:37 INFO - mozInstall == 1.12 15:08:37 INFO - mozcrash == 0.16 15:08:37 INFO - mozdebug == 0.1 15:08:37 INFO - mozdevice == 0.47 15:08:37 INFO - mozfile == 1.2 15:08:37 INFO - mozhttpd == 0.7 15:08:37 INFO - mozinfo == 0.9 15:08:37 INFO - mozleak == 0.1 15:08:37 INFO - mozlog == 3.0 15:08:37 INFO - moznetwork == 0.27 15:08:37 INFO - mozprocess == 0.22 15:08:37 INFO - mozprofile == 0.27 15:08:37 INFO - mozrunner == 6.11 15:08:37 INFO - mozscreenshot == 0.1 15:08:37 INFO - mozsystemmonitor == 0.0 15:08:37 INFO - moztest == 0.7 15:08:37 INFO - mozversion == 1.4 15:08:37 INFO - psutil == 3.1.1 15:08:37 INFO - requests == 1.2.3 15:08:37 INFO - Installing None into virtualenv C:\slave\test\build/venv 15:08:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:08:37 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 15:08:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:08:37 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 15:08:37 INFO - retry: Calling run_command with args: [['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '-r', 'C:\\slave\\test\\build\\tests\\talos\\requirements.txt', '--no-index', '--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 0x018F9B10>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x018BDEA8>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x017CB660>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x01298B48>, '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 0x012BA700>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x01984660>, 'level': 'critical'}], 'cwd': 'C:\\slave\\test\\build\\tests\\talos', 'env': {'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'TEST1': 'testie', 'COMPUTERNAME': 'T-W732-IX-084', 'USERDOMAIN': 'T-W732-IX-084', 'KTS_VERSION': '1.19c', 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 'PROGRAMFILES': 'C:\\Program Files', 'PROCESSOR_REVISION': '1e05', 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 'SYSTEMROOT': 'C:\\windows', 'NO_EM_RESTART': '1', 'OURDRIVE': 'C:', 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 'XPCOM_DEBUG_BREAK': 'warn', 'MONDIR': 'C:\\Monitor_config\\', 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 'PROCESSOR_ARCHITECTURE': 'x86', 'ALLUSERSPROFILE': 'C:\\ProgramData', 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 'HOMEPATH': '\\Users\\cltbld', 'MOZBUILDDIR': 'C:\\mozilla-build\\', 'USERNAME': 'cltbld', 'LOGONSERVER': '\\\\T-W732-IX-084', 'MOZ_NO_REMOTE': '1', 'WINDOWS_TRACING_FLAGS': '3', 'CYGWINBASE': 'C:\\cygwin', 'PROGRAMDATA': 'C:\\ProgramData', 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 'PROMPT': '$P$G', 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 'FP_NO_HOST_CHECK': 'NO', 'DCLOCATION': 'SCL3', 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 'HOMEDRIVE': 'C:', 'SYSTEMDRIVE': 'C:', 'SLAVEDIR': 'C:\\slave\\', 'NUMBER_OF_PROCESSORS': '8', 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 'PWD': 'C:\\slave\\test', 'PROCESSOR_LEVEL': '6', 'KTS_HOME': 'C:\\Program Files\\KTS', 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'USERPROFILE': 'C:\\Users\\cltbld', 'OS': 'Windows_NT', 'PUBLIC': 'C:\\Users\\Public', 'WINDIR': 'C:\\windows'}}, attempt #1 15:08:37 INFO - Running command: ['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'install', '--download-cache', 'C:\\slave\\test\\build/venv\\cache', '--timeout', '120', '-r', 'C:\\slave\\test\\build\\tests\\talos\\requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in C:\slave\test\build\tests\talos 15:08:37 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\pip install --download-cache C:\slave\test\build/venv\cache --timeout 120 -r C:\slave\test\build\tests\talos\requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 15:08:37 INFO - Using env: {'ALLUSERSPROFILE': 'C:\\ProgramData', 15:08:37 INFO - 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 15:08:37 INFO - 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 15:08:37 INFO - 'COMPUTERNAME': 'T-W732-IX-084', 15:08:37 INFO - 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 15:08:37 INFO - 'CYGWINBASE': 'C:\\cygwin', 15:08:37 INFO - 'DCLOCATION': 'SCL3', 15:08:37 INFO - 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 15:08:37 INFO - 'FP_NO_HOST_CHECK': 'NO', 15:08:37 INFO - 'HOMEDRIVE': 'C:', 15:08:37 INFO - 'HOMEPATH': '\\Users\\cltbld', 15:08:37 INFO - 'KTS_HOME': 'C:\\Program Files\\KTS', 15:08:37 INFO - 'KTS_VERSION': '1.19c', 15:08:37 INFO - 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 15:08:37 INFO - 'LOGONSERVER': '\\\\T-W732-IX-084', 15:08:37 INFO - 'MONDIR': 'C:\\Monitor_config\\', 15:08:37 INFO - 'MOZBUILDDIR': 'C:\\mozilla-build\\', 15:08:37 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:08:37 INFO - 'MOZ_NO_REMOTE': '1', 15:08:37 INFO - 'NO_EM_RESTART': '1', 15:08:37 INFO - 'NUMBER_OF_PROCESSORS': '8', 15:08:37 INFO - 'OS': 'Windows_NT', 15:08:37 INFO - 'OURDRIVE': 'C:', 15:08:37 INFO - 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 15:08:37 INFO - 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 15:08:37 INFO - 'PROCESSOR_ARCHITECTURE': 'x86', 15:08:37 INFO - 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 15:08:37 INFO - 'PROCESSOR_LEVEL': '6', 15:08:37 INFO - 'PROCESSOR_REVISION': '1e05', 15:08:37 INFO - 'PROGRAMDATA': 'C:\\ProgramData', 15:08:37 INFO - 'PROGRAMFILES': 'C:\\Program Files', 15:08:37 INFO - 'PROMPT': '$P$G', 15:08:37 INFO - 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 15:08:37 INFO - 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 15:08:37 INFO - 'PUBLIC': 'C:\\Users\\Public', 15:08:37 INFO - 'PWD': 'C:\\slave\\test', 15:08:37 INFO - 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 15:08:37 INFO - 'SLAVEDIR': 'C:\\slave\\', 15:08:37 INFO - 'SYSTEMDRIVE': 'C:', 15:08:37 INFO - 'SYSTEMROOT': 'C:\\windows', 15:08:37 INFO - 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:37 INFO - 'TEST1': 'testie', 15:08:37 INFO - 'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:37 INFO - 'USERDOMAIN': 'T-W732-IX-084', 15:08:37 INFO - 'USERNAME': 'cltbld', 15:08:37 INFO - 'USERPROFILE': 'C:\\Users\\cltbld', 15:08:37 INFO - 'WINDIR': 'C:\\windows', 15:08:37 INFO - 'WINDOWS_TRACING_FLAGS': '3', 15:08:37 INFO - 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 15:08:37 INFO - 'XPCOM_DEBUG_BREAK': 'warn'} 15:08:37 INFO - Ignoring indexes: https://pypi.python.org/simple/ 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\talos\requirements.txt (line 1)) 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\talos\requirements.txt (line 2)) 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\talos\requirements.txt (line 3)) 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\talos\requirements.txt (line 4)) 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\talos\requirements.txt (line 5)) 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\talos\requirements.txt (line 6)) 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\talos\requirements.txt (line 7)) 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in c:\slave\test\build\venv\lib\site-packages (from -r C:\slave\test\build\tests\talos\requirements.txt (line 8)) 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in c:\slave\test\build\venv\lib\site-packages (from mozcrash>=0.15->-r C:\slave\test\build\tests\talos\requirements.txt (line 1)) 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in c:\slave\test\build\venv\lib\site-packages (from mozhttpd>=0.7->-r C:\slave\test\build\tests\talos\requirements.txt (line 3)) 15:08:37 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in c:\slave\test\build\venv\lib\site-packages (from mozlog>=3.0->mozcrash>=0.15->-r C:\slave\test\build\tests\talos\requirements.txt (line 1)) 15:08:37 INFO - Cleaning up... 15:08:37 INFO - Return code: 0 15:08:37 INFO - Running post-action listener: _resource_record_post_action 15:08:37 INFO - Running post-action listener: _start_resource_monitoring 15:08:37 INFO - Starting resource monitoring. 15:08:37 INFO - ##### 15:08:37 INFO - ##### Running install step. 15:08:37 INFO - ##### 15:08:37 INFO - Running pre-action listener: _resource_record_pre_action 15:08:37 INFO - Running main action method: install 15:08:37 INFO - Getting output from command: ['C:\\slave\\test\\build\\venv\\Scripts\\pip', 'freeze'] 15:08:37 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\pip freeze 15:08:38 INFO - Reading from file tmpfile_stdout 15:08:38 INFO - Using _rmtree_windows ... 15:08:38 INFO - Using _rmtree_windows ... 15:08:38 INFO - Detecting whether we're running mozinstall >=1.0... 15:08:38 INFO - Getting output from command: ['C:\\slave\\test\\build/venv/scripts/python', 'C:\\slave\\test\\build/venv/scripts/mozinstall-script.py', '-h'] 15:08:38 INFO - Copy/paste: C:\slave\test\build/venv/scripts/python C:\slave\test\build/venv/scripts/mozinstall-script.py -h 15:08:38 INFO - Reading from file tmpfile_stdout 15:08:38 INFO - Output received: 15:08:38 INFO - Usage: mozinstall-script.py [options] installer 15:08:38 INFO - Options: 15:08:38 INFO - -h, --help show this help message and exit 15:08:38 INFO - -d DEST, --destination=DEST 15:08:38 INFO - Directory to install application into. [default: 15:08:38 INFO - "C:\slave\test"] 15:08:38 INFO - --app=APP Application being installed. [default: firefox] 15:08:38 INFO - Using _rmtree_windows ... 15:08:38 INFO - Using _rmtree_windows ... 15:08:38 INFO - mkdir: C:\slave\test\build\application 15:08:38 INFO - Getting output from command: ['C:\\slave\\test\\build/venv/scripts/python', 'C:\\slave\\test\\build/venv/scripts/mozinstall-script.py', 'C:\\slave\\test\\build\\firefox-45.0a1.en-US.win32.zip', '--destination', 'C:\\slave\\test\\build\\application'] 15:08:38 INFO - Copy/paste: C:\slave\test\build/venv/scripts/python C:\slave\test\build/venv/scripts/mozinstall-script.py C:\slave\test\build\firefox-45.0a1.en-US.win32.zip --destination C:\slave\test\build\application 15:08:39 INFO - Reading from file tmpfile_stdout 15:08:39 INFO - Output received: 15:08:39 INFO - C:\slave\test\build\application\firefox\firefox.exe 15:08:39 INFO - Using _rmtree_windows ... 15:08:39 INFO - Using _rmtree_windows ... 15:08:39 INFO - Running post-action listener: _resource_record_post_action 15:08:39 INFO - ##### 15:08:39 INFO - ##### Running run-tests step. 15:08:39 INFO - ##### 15:08:39 INFO - Running pre-action listener: _resource_record_pre_action 15:08:39 INFO - Running main action method: run_tests 15:08:39 INFO - Running command: ['C:\\slave\\test\\build\\venv\\Scripts\\python', '--version'] 15:08:39 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\python --version 15:08:39 INFO - Python 2.7.3 15:08:39 INFO - Return code: 0 15:08:39 INFO - grabbing minidump binary from tooltool 15:08:39 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pvtbuilds.pvt.build.mozilla.org', 'pvtbuilds.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org'), ('https://queue.taskcluster.net', 'queue.taskcluster.net')]} 15:08:39 INFO - retry: Calling run_command with args: (['c:/mozilla-build/python27/python.exe', 'C:/mozilla-build/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', 'c:\\builds\\relengapi.tok', 'fetch', '-m', 'C:\\slave\\test\\build\\tests\\config/tooltool-manifests/win32/releng.manifest', '-o'],), kwargs: {'error_list': [{'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x01298B48>, '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 0x012BA700>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x01984660>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': 'C:\\slave\\test\\build', 'privileged': False}, attempt #1 15:08:39 INFO - Running command: ['c:/mozilla-build/python27/python.exe', 'C:/mozilla-build/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', 'c:\\builds\\relengapi.tok', 'fetch', '-m', 'C:\\slave\\test\\build\\tests\\config/tooltool-manifests/win32/releng.manifest', '-o'] in C:\slave\test\build 15:08:39 INFO - Copy/paste: c:/mozilla-build/python27/python.exe C:/mozilla-build/tooltool.py --url https://api.pub.build.mozilla.org/tooltool/ --authentication-file c:\builds\relengapi.tok fetch -m C:\slave\test\build\tests\config/tooltool-manifests/win32/releng.manifest -o 15:08:39 INFO - INFO - Attempting to fetch from 'https://api.pub.build.mozilla.org/tooltool/'... 15:08:40 INFO - INFO - File win32-minidump_stackwalk.exe fetched from https://api.pub.build.mozilla.org/tooltool/ as C:\slave\test\build\tmpy_i0ne 15:08:40 INFO - INFO - File integrity verified, renaming tmpy_i0ne to win32-minidump_stackwalk.exe 15:08:40 INFO - Return code: 0 15:08:40 INFO - Chmoding C:\slave\test\build\win32-minidump_stackwalk.exe to 0755 15:08:40 INFO - mkdir: C:\slave\test\build\blobber_upload_dir 15:08:40 INFO - ENV: MOZ_UPLOAD_DIR is now C:\slave\test\build\blobber_upload_dir 15:08:40 INFO - ENV: MINIDUMP_STACKWALK is now C:\slave\test\build\win32-minidump_stackwalk.exe 15:08:40 INFO - ENV: MINIDUMP_SAVE_PATH is now C:\slave\test\build\blobber_upload_dir 15:08:40 INFO - Running command: ['C:\\slave\\test\\build\\venv\\Scripts\\python', 'C:\\slave\\test\\build\\tests\\talos\\talos\\run_tests.py', '--debug', '--branchName', 'Mozilla-Inbound-Non-PGO', '--suite', 'other', '--executablePath', 'C:\\slave\\test\\build\\application\\firefox\\firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.crashreporter-symbols.zip', '--title', 'T-W732-IX-084', '--webServer', 'localhost'] in C:\slave\test\build 15:08:40 INFO - Copy/paste: C:\slave\test\build\venv\Scripts\python C:\slave\test\build\tests\talos\talos\run_tests.py --debug --branchName Mozilla-Inbound-Non-PGO --suite other --executablePath C:\slave\test\build\application\firefox\firefox --symbolsPath https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.crashreporter-symbols.zip --title T-W732-IX-084 --webServer localhost 15:08:40 INFO - Using env: {'ALLUSERSPROFILE': 'C:\\ProgramData', 15:08:40 INFO - 'APPDATA': 'C:\\Users\\cltbld\\AppData\\Roaming', 15:08:40 INFO - 'COMMONPROGRAMFILES': 'C:\\Program Files\\Common Files', 15:08:40 INFO - 'COMPUTERNAME': 'T-W732-IX-084', 15:08:40 INFO - 'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 15:08:40 INFO - 'CYGWINBASE': 'C:\\cygwin', 15:08:40 INFO - 'DCLOCATION': 'SCL3', 15:08:40 INFO - 'DNSSUFFIX': 'wintest.releng.scl3.mozilla.com', 15:08:40 INFO - 'FP_NO_HOST_CHECK': 'NO', 15:08:40 INFO - 'HOMEDRIVE': 'C:', 15:08:40 INFO - 'HOMEPATH': '\\Users\\cltbld', 15:08:40 INFO - 'KTS_HOME': 'C:\\Program Files\\KTS', 15:08:40 INFO - 'KTS_VERSION': '1.19c', 15:08:40 INFO - 'LOCALAPPDATA': 'C:\\Users\\cltbld\\AppData\\Local', 15:08:40 INFO - 'LOGONSERVER': '\\\\T-W732-IX-084', 15:08:40 INFO - 'MINIDUMP_SAVE_PATH': 'C:\\slave\\test\\build\\blobber_upload_dir', 15:08:40 INFO - 'MINIDUMP_STACKWALK': 'C:\\slave\\test\\build\\win32-minidump_stackwalk.exe', 15:08:40 INFO - 'MONDIR': 'C:\\Monitor_config\\', 15:08:40 INFO - 'MOZBUILDDIR': 'C:\\mozilla-build\\', 15:08:40 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 15:08:40 INFO - 'MOZ_NO_REMOTE': '1', 15:08:40 INFO - 'MOZ_UPLOAD_DIR': 'C:\\slave\\test\\build\\blobber_upload_dir', 15:08:40 INFO - 'NO_EM_RESTART': '1', 15:08:40 INFO - 'NUMBER_OF_PROCESSORS': '8', 15:08:40 INFO - 'OS': 'Windows_NT', 15:08:40 INFO - 'OURDRIVE': 'C:', 15:08:40 INFO - 'PATH': 'C:\\Python24;C:\\Python24\\Scripts;C:\\cygwin\\bin;C:\\WINDOWS\\System32;C:\\program files\\gnuwin32\\bin;C:\\WINDOWS;C:\\mozilla-build\\msys\\bin;C:\\mozilla-build\\python27;C:\\mozilla-build\\python27\\Scripts;C:\\mozilla-build\\info-zip;C:\\mozilla-build\\wget;C:\\Program Files (x86)\\GnuWin32\\bin;', 15:08:40 INFO - 'PATHEXT': '.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC', 15:08:40 INFO - 'PROCESSOR_ARCHITECTURE': 'x86', 15:08:40 INFO - 'PROCESSOR_IDENTIFIER': 'x86 Family 6 Model 30 Stepping 5, GenuineIntel', 15:08:40 INFO - 'PROCESSOR_LEVEL': '6', 15:08:40 INFO - 'PROCESSOR_REVISION': '1e05', 15:08:40 INFO - 'PROGRAMDATA': 'C:\\ProgramData', 15:08:40 INFO - 'PROGRAMFILES': 'C:\\Program Files', 15:08:40 INFO - 'PROMPT': '$P$G', 15:08:41 INFO - 'PROPERTIES_FILE': 'C:\\slave\\test/buildprops.json', 15:08:41 INFO - 'PSMODULEPATH': 'C:\\windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\', 15:08:41 INFO - 'PUBLIC': 'C:\\Users\\Public', 15:08:41 INFO - 'PWD': 'C:\\slave\\test', 15:08:41 INFO - 'PYTHONPATH': 'C:\\slave\\test\\build\\tests\\talos', 15:08:41 INFO - 'RUNLOGFILE': 'C:\\slave\\\\runslave.log', 15:08:41 INFO - 'SLAVEDIR': 'C:\\slave\\', 15:08:41 INFO - 'SYSTEMDRIVE': 'C:', 15:08:41 INFO - 'SYSTEMROOT': 'C:\\windows', 15:08:41 INFO - 'TEMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:41 INFO - 'TEST1': 'testie', 15:08:41 INFO - 'TMP': 'C:\\Users\\cltbld\\AppData\\Local\\Temp', 15:08:41 INFO - 'USERDOMAIN': 'T-W732-IX-084', 15:08:41 INFO - 'USERNAME': 'cltbld', 15:08:41 INFO - 'USERPROFILE': 'C:\\Users\\cltbld', 15:08:41 INFO - 'WINDIR': 'C:\\windows', 15:08:41 INFO - 'WINDOWS_TRACING_FLAGS': '3', 15:08:41 INFO - 'WINDOWS_TRACING_LOGFILE': 'C:\\BVTBin\\Tests\\installpackage\\csilogfile.log', 15:08:41 INFO - 'XPCOM_DEBUG_BREAK': 'warn'} 15:08:41 INFO - Calling ['C:\\slave\\test\\build\\venv\\Scripts\\python', 'C:\\slave\\test\\build\\tests\\talos\\talos\\run_tests.py', '--debug', '--branchName', 'Mozilla-Inbound-Non-PGO', '--suite', 'other', '--executablePath', 'C:\\slave\\test\\build\\application\\firefox\\firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.crashreporter-symbols.zip', '--title', 'T-W732-IX-084', '--webServer', 'localhost'] with output_timeout 3600 15:08:42 INFO - mozversion INFO | application_buildid: 20151109133533 15:08:42 INFO - mozversion INFO | application_changeset: 09cd7947ffd969860d6de0effc9402e9f99f1d21 15:08:42 INFO - mozversion INFO | application_display_name: Nightly 15:08:42 INFO - mozversion INFO | application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 15:08:42 INFO - mozversion INFO | application_name: Firefox 15:08:42 INFO - mozversion INFO | application_remotingname: firefox 15:08:42 INFO - mozversion INFO | application_repository: https://hg.mozilla.org/integration/mozilla-inbound 15:08:42 INFO - mozversion INFO | application_vendor: Mozilla 15:08:42 INFO - mozversion INFO | application_version: 45.0a1 15:08:42 INFO - mozversion INFO | platform_buildid: 20151109133533 15:08:42 INFO - mozversion INFO | platform_changeset: 09cd7947ffd969860d6de0effc9402e9f99f1d21 15:08:42 INFO - mozversion INFO | platform_repository: https://hg.mozilla.org/integration/mozilla-inbound 15:08:42 INFO - mozversion INFO | platform_version: 45.0a1 15:08:42 INFO - 2015-11-09 15:08:42,181 DEBUG : using testdate: 1447110522 15:08:42 INFO - 2015-11-09 15:08:42,181 DEBUG : actual date: 1447110522 15:08:42 INFO - 2015-11-09 15:08:42,191 INFO : starting webserver on 'localhost:49660' 15:08:42 INFO - 2015-11-09 15:08:42,194 INFO : Starting test suite T-W732-IX-084 15:08:42 INFO - 2015-11-09 15:08:42,194 INFO : Starting test a11yr 15:08:42 INFO - 2015-11-09 15:08:42,194 DEBUG : operating with platform_type : w7_ 15:08:42 INFO - 2015-11-09 15:08:42,194 INFO : Initialising browser for a11yr test... 15:08:42 INFO - 2015-11-09 15:08:42,328 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpojjoj5\profile http://localhost:49660/getInfo.html 15:08:52 INFO - 2015-11-09 15:08:52,989 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 15:08:52 INFO - 2015-11-09 15:08:52,989 DEBUG : BROWSER_OUTPUT: colorDepth:24 15:08:52 INFO - 2015-11-09 15:08:52,989 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1010/674 15:08:52 INFO - 2015-11-09 15:08:52,989 DEBUG : BROWSER_OUTPUT: __metrics 15:08:53 INFO - 2015-11-09 15:08:53,055 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 15:08:54 INFO - 2015-11-09 15:08:54,111 DEBUG : BROWSER_OUTPUT: JavaScript error: resource://gre/modules/IndexedDBHelper.jsm, line 138: UnknownError: The operation failed for reasons unrelated to the database itself and not covered by any other error code. 15:08:55 INFO - 2015-11-09 15:08:55,177 INFO : Browser initialized. 15:08:55 INFO - 2015-11-09 15:08:55,177 INFO : Running cycle 1/1 for a11yr test... 15:08:55 INFO - 2015-11-09 15:08:55,177 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpojjoj5\profile -tp file:\C:\slave\test\build\tests\talos\talos\tests\a11y\a11y.manifest.develop -tpchrome -tpmozafterpaint -tpnoisy -tpcycles 1 -tppagecycles 25 15:08:55 INFO - 2015-11-09 15:08:55,841 DEBUG : BROWSER_OUTPUT: [GFX1-]: Invalid size in UpdateRenderTarget Size(116,0) 15:09:06 INFO - 2015-11-09 15:09:06,759 DEBUG : BROWSER_OUTPUT: RSS: Main: 140079104 15:09:06 INFO - 2015-11-09 15:09:06,759 DEBUG : BROWSER_OUTPUT: 15:09:08 INFO - 2015-11-09 15:09:08,474 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:09 INFO - 2015-11-09 15:09:09,075 DEBUG : BROWSER_OUTPUT: RSS: Main: 170078208 15:09:09 INFO - 2015-11-09 15:09:09,075 DEBUG : BROWSER_OUTPUT: 15:09:10 INFO - 2015-11-09 15:09:10,831 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:11 INFO - 2015-11-09 15:09:11,492 DEBUG : BROWSER_OUTPUT: RSS: Main: 172105728 15:09:11 INFO - 2015-11-09 15:09:11,492 DEBUG : BROWSER_OUTPUT: 15:09:13 INFO - 2015-11-09 15:09:13,046 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:13 INFO - 2015-11-09 15:09:13,707 DEBUG : BROWSER_OUTPUT: RSS: Main: 167849984 15:09:13 INFO - 2015-11-09 15:09:13,707 DEBUG : BROWSER_OUTPUT: 15:09:15 INFO - 2015-11-09 15:09:15,282 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:15 INFO - 2015-11-09 15:09:15,944 DEBUG : BROWSER_OUTPUT: RSS: Main: 166367232 15:09:15 INFO - 2015-11-09 15:09:15,944 DEBUG : BROWSER_OUTPUT: 15:09:17 INFO - 2015-11-09 15:09:17,619 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:18 INFO - 2015-11-09 15:09:18,282 DEBUG : BROWSER_OUTPUT: RSS: Main: 160931840 15:09:18 INFO - 2015-11-09 15:09:18,282 DEBUG : BROWSER_OUTPUT: 15:09:20 INFO - 2015-11-09 15:09:20,109 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:20 INFO - 2015-11-09 15:09:20,773 DEBUG : BROWSER_OUTPUT: RSS: Main: 162377728 15:09:20 INFO - 2015-11-09 15:09:20,773 DEBUG : BROWSER_OUTPUT: 15:09:22 INFO - 2015-11-09 15:09:22,493 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:23 INFO - 2015-11-09 15:09:23,155 DEBUG : BROWSER_OUTPUT: RSS: Main: 160407552 15:09:23 INFO - 2015-11-09 15:09:23,155 DEBUG : BROWSER_OUTPUT: 15:09:24 INFO - 2015-11-09 15:09:24,835 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:25 INFO - 2015-11-09 15:09:25,496 DEBUG : BROWSER_OUTPUT: RSS: Main: 160309248 15:09:25 INFO - 2015-11-09 15:09:25,496 DEBUG : BROWSER_OUTPUT: 15:09:27 INFO - 2015-11-09 15:09:27,190 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:27 INFO - 2015-11-09 15:09:27,851 DEBUG : BROWSER_OUTPUT: RSS: Main: 159608832 15:09:27 INFO - 2015-11-09 15:09:27,851 DEBUG : BROWSER_OUTPUT: 15:09:29 INFO - 2015-11-09 15:09:29,529 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:30 INFO - 2015-11-09 15:09:30,204 DEBUG : BROWSER_OUTPUT: RSS: Main: 161193984 15:09:30 INFO - 2015-11-09 15:09:30,204 DEBUG : BROWSER_OUTPUT: 15:09:31 INFO - 2015-11-09 15:09:31,884 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:32 INFO - 2015-11-09 15:09:32,542 DEBUG : BROWSER_OUTPUT: RSS: Main: 159465472 15:09:32 INFO - 2015-11-09 15:09:32,542 DEBUG : BROWSER_OUTPUT: 15:09:34 INFO - 2015-11-09 15:09:34,237 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:34 INFO - 2015-11-09 15:09:34,898 DEBUG : BROWSER_OUTPUT: RSS: Main: 161804288 15:09:34 INFO - 2015-11-09 15:09:34,898 DEBUG : BROWSER_OUTPUT: 15:09:36 INFO - 2015-11-09 15:09:36,686 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:37 INFO - 2015-11-09 15:09:37,348 DEBUG : BROWSER_OUTPUT: RSS: Main: 159969280 15:09:37 INFO - 2015-11-09 15:09:37,348 DEBUG : BROWSER_OUTPUT: 15:09:39 INFO - 2015-11-09 15:09:39,075 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:39 INFO - 2015-11-09 15:09:39,739 DEBUG : BROWSER_OUTPUT: RSS: Main: 159801344 15:09:39 INFO - 2015-11-09 15:09:39,739 DEBUG : BROWSER_OUTPUT: 15:09:41 INFO - 2015-11-09 15:09:41,325 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:42 INFO - 2015-11-09 15:09:42,000 DEBUG : BROWSER_OUTPUT: RSS: Main: 159887360 15:09:42 INFO - 2015-11-09 15:09:42,000 DEBUG : BROWSER_OUTPUT: 15:09:43 INFO - 2015-11-09 15:09:43,676 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:44 INFO - 2015-11-09 15:09:44,351 DEBUG : BROWSER_OUTPUT: RSS: Main: 160108544 15:09:44 INFO - 2015-11-09 15:09:44,351 DEBUG : BROWSER_OUTPUT: 15:09:46 INFO - 2015-11-09 15:09:46,065 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:46 INFO - 2015-11-09 15:09:46,726 DEBUG : BROWSER_OUTPUT: RSS: Main: 160661504 15:09:46 INFO - 2015-11-09 15:09:46,726 DEBUG : BROWSER_OUTPUT: 15:09:48 INFO - 2015-11-09 15:09:48,345 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:49 INFO - 2015-11-09 15:09:49,019 DEBUG : BROWSER_OUTPUT: RSS: Main: 161513472 15:09:49 INFO - 2015-11-09 15:09:49,019 DEBUG : BROWSER_OUTPUT: 15:09:50 INFO - 2015-11-09 15:09:50,663 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:51 INFO - 2015-11-09 15:09:51,322 DEBUG : BROWSER_OUTPUT: RSS: Main: 160235520 15:09:51 INFO - 2015-11-09 15:09:51,322 DEBUG : BROWSER_OUTPUT: 15:09:53 INFO - 2015-11-09 15:09:53,101 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:53 INFO - 2015-11-09 15:09:53,769 DEBUG : BROWSER_OUTPUT: RSS: Main: 161976320 15:09:53 INFO - 2015-11-09 15:09:53,769 DEBUG : BROWSER_OUTPUT: 15:09:55 INFO - 2015-11-09 15:09:55,529 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:56 INFO - 2015-11-09 15:09:56,207 DEBUG : BROWSER_OUTPUT: RSS: Main: 165359616 15:09:56 INFO - 2015-11-09 15:09:56,207 DEBUG : BROWSER_OUTPUT: 15:09:57 INFO - 2015-11-09 15:09:57,914 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:09:57 INFO - 2015-11-09 15:09:57,915 DEBUG : BROWSER_OUTPUT: 1447110597921 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] 15:09:58 INFO - 2015-11-09 15:09:58,591 DEBUG : BROWSER_OUTPUT: RSS: Main: 169086976 15:09:58 INFO - 2015-11-09 15:09:58,591 DEBUG : BROWSER_OUTPUT: 15:10:00 INFO - 2015-11-09 15:10:00,378 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:10:01 INFO - 2015-11-09 15:10:01,058 DEBUG : BROWSER_OUTPUT: RSS: Main: 167866368 15:10:01 INFO - 2015-11-09 15:10:01,058 DEBUG : BROWSER_OUTPUT: 15:10:02 INFO - 2015-11-09 15:10:02,825 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:10:03 INFO - 2015-11-09 15:10:03,503 DEBUG : BROWSER_OUTPUT: RSS: Main: 167690240 15:10:03 INFO - 2015-11-09 15:10:03,503 DEBUG : BROWSER_OUTPUT: 15:10:05 INFO - 2015-11-09 15:10:05,051 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html) 15:10:05 INFO - 2015-11-09 15:10:05,730 DEBUG : BROWSER_OUTPUT: RSS: Main: 167260160 15:10:05 INFO - 2015-11-09 15:10:05,730 DEBUG : BROWSER_OUTPUT: 15:10:06 INFO - 2015-11-09 15:10:06,684 DEBUG : BROWSER_OUTPUT: Cycle 1(1): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:07 INFO - 2015-11-09 15:10:07,259 DEBUG : BROWSER_OUTPUT: RSS: Main: 163213312 15:10:07 INFO - 2015-11-09 15:10:07,259 DEBUG : BROWSER_OUTPUT: 15:10:08 INFO - 2015-11-09 15:10:08,161 DEBUG : BROWSER_OUTPUT: Cycle 1(2): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:08 INFO - 2015-11-09 15:10:08,740 DEBUG : BROWSER_OUTPUT: RSS: Main: 158380032 15:10:08 INFO - 2015-11-09 15:10:08,740 DEBUG : BROWSER_OUTPUT: 15:10:09 INFO - 2015-11-09 15:10:09,641 DEBUG : BROWSER_OUTPUT: Cycle 1(3): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:10 INFO - 2015-11-09 15:10:10,220 DEBUG : BROWSER_OUTPUT: RSS: Main: 157560832 15:10:10 INFO - 2015-11-09 15:10:10,220 DEBUG : BROWSER_OUTPUT: 15:10:11 INFO - 2015-11-09 15:10:11,121 DEBUG : BROWSER_OUTPUT: Cycle 1(4): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:11 INFO - 2015-11-09 15:10:11,700 DEBUG : BROWSER_OUTPUT: RSS: Main: 159703040 15:10:11 INFO - 2015-11-09 15:10:11,700 DEBUG : BROWSER_OUTPUT: 15:10:12 INFO - 2015-11-09 15:10:12,595 DEBUG : BROWSER_OUTPUT: Cycle 1(5): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:13 INFO - 2015-11-09 15:10:13,174 DEBUG : BROWSER_OUTPUT: RSS: Main: 158167040 15:10:13 INFO - 2015-11-09 15:10:13,174 DEBUG : BROWSER_OUTPUT: 15:10:14 INFO - 2015-11-09 15:10:14,082 DEBUG : BROWSER_OUTPUT: Cycle 1(6): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:14 INFO - 2015-11-09 15:10:14,661 DEBUG : BROWSER_OUTPUT: RSS: Main: 158195712 15:10:14 INFO - 2015-11-09 15:10:14,661 DEBUG : BROWSER_OUTPUT: 15:10:15 INFO - 2015-11-09 15:10:15,559 DEBUG : BROWSER_OUTPUT: Cycle 1(7): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:16 INFO - 2015-11-09 15:10:16,141 DEBUG : BROWSER_OUTPUT: RSS: Main: 157675520 15:10:16 INFO - 2015-11-09 15:10:16,141 DEBUG : BROWSER_OUTPUT: 15:10:17 INFO - 2015-11-09 15:10:17,039 DEBUG : BROWSER_OUTPUT: Cycle 1(8): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:17 INFO - 2015-11-09 15:10:17,618 DEBUG : BROWSER_OUTPUT: RSS: Main: 159297536 15:10:17 INFO - 2015-11-09 15:10:17,618 DEBUG : BROWSER_OUTPUT: 15:10:18 INFO - 2015-11-09 15:10:18,506 DEBUG : BROWSER_OUTPUT: Cycle 1(9): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:19 INFO - 2015-11-09 15:10:19,085 DEBUG : BROWSER_OUTPUT: RSS: Main: 157126656 15:10:19 INFO - 2015-11-09 15:10:19,085 DEBUG : BROWSER_OUTPUT: 15:10:20 INFO - 2015-11-09 15:10:20,000 DEBUG : BROWSER_OUTPUT: Cycle 1(10): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:20 INFO - 2015-11-09 15:10:20,578 DEBUG : BROWSER_OUTPUT: RSS: Main: 157708288 15:10:20 INFO - 2015-11-09 15:10:20,578 DEBUG : BROWSER_OUTPUT: 15:10:21 INFO - 2015-11-09 15:10:21,493 DEBUG : BROWSER_OUTPUT: Cycle 1(11): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:22 INFO - 2015-11-09 15:10:22,069 DEBUG : BROWSER_OUTPUT: RSS: Main: 159006720 15:10:22 INFO - 2015-11-09 15:10:22,069 DEBUG : BROWSER_OUTPUT: 15:10:22 INFO - 2015-11-09 15:10:22,967 DEBUG : BROWSER_OUTPUT: Cycle 1(12): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:23 INFO - 2015-11-09 15:10:23,548 DEBUG : BROWSER_OUTPUT: RSS: Main: 157949952 15:10:23 INFO - 2015-11-09 15:10:23,548 DEBUG : BROWSER_OUTPUT: 15:10:24 INFO - 2015-11-09 15:10:24,447 DEBUG : BROWSER_OUTPUT: Cycle 1(13): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:25 INFO - 2015-11-09 15:10:25,026 DEBUG : BROWSER_OUTPUT: RSS: Main: 157011968 15:10:25 INFO - 2015-11-09 15:10:25,026 DEBUG : BROWSER_OUTPUT: 15:10:25 INFO - 2015-11-09 15:10:25,924 DEBUG : BROWSER_OUTPUT: Cycle 1(14): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:26 INFO - 2015-11-09 15:10:26,507 DEBUG : BROWSER_OUTPUT: RSS: Main: 159023104 15:10:26 INFO - 2015-11-09 15:10:26,507 DEBUG : BROWSER_OUTPUT: 15:10:27 INFO - 2015-11-09 15:10:27,434 DEBUG : BROWSER_OUTPUT: Cycle 1(15): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:28 INFO - 2015-11-09 15:10:28,013 DEBUG : BROWSER_OUTPUT: RSS: Main: 157388800 15:10:28 INFO - 2015-11-09 15:10:28,013 DEBUG : BROWSER_OUTPUT: 15:10:28 INFO - 2015-11-09 15:10:28,921 DEBUG : BROWSER_OUTPUT: Cycle 1(16): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:29 INFO - 2015-11-09 15:10:29,500 DEBUG : BROWSER_OUTPUT: RSS: Main: 159219712 15:10:29 INFO - 2015-11-09 15:10:29,500 DEBUG : BROWSER_OUTPUT: 15:10:30 INFO - 2015-11-09 15:10:30,414 DEBUG : BROWSER_OUTPUT: Cycle 1(17): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:31 INFO - 2015-11-09 15:10:30,997 DEBUG : BROWSER_OUTPUT: RSS: Main: 156938240 15:10:31 INFO - 2015-11-09 15:10:30,997 DEBUG : BROWSER_OUTPUT: 15:10:31 INFO - 2015-11-09 15:10:31,924 DEBUG : BROWSER_OUTPUT: Cycle 1(18): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:32 INFO - 2015-11-09 15:10:32,507 DEBUG : BROWSER_OUTPUT: RSS: Main: 155762688 15:10:32 INFO - 2015-11-09 15:10:32,507 DEBUG : BROWSER_OUTPUT: 15:10:33 INFO - 2015-11-09 15:10:33,427 DEBUG : BROWSER_OUTPUT: Cycle 1(19): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:34 INFO - 2015-11-09 15:10:34,009 DEBUG : BROWSER_OUTPUT: RSS: Main: 157503488 15:10:34 INFO - 2015-11-09 15:10:34,009 DEBUG : BROWSER_OUTPUT: 15:10:34 INFO - 2015-11-09 15:10:34,930 DEBUG : BROWSER_OUTPUT: Cycle 1(20): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:35 INFO - 2015-11-09 15:10:35,509 DEBUG : BROWSER_OUTPUT: RSS: Main: 157814784 15:10:35 INFO - 2015-11-09 15:10:35,509 DEBUG : BROWSER_OUTPUT: 15:10:36 INFO - 2015-11-09 15:10:36,436 DEBUG : BROWSER_OUTPUT: Cycle 1(21): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:37 INFO - 2015-11-09 15:10:37,019 DEBUG : BROWSER_OUTPUT: RSS: Main: 155639808 15:10:37 INFO - 2015-11-09 15:10:37,019 DEBUG : BROWSER_OUTPUT: 15:10:37 INFO - 2015-11-09 15:10:37,898 DEBUG : BROWSER_OUTPUT: Cycle 1(22): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:38 INFO - 2015-11-09 15:10:38,476 DEBUG : BROWSER_OUTPUT: RSS: Main: 157368320 15:10:38 INFO - 2015-11-09 15:10:38,476 DEBUG : BROWSER_OUTPUT: 15:10:39 INFO - 2015-11-09 15:10:39,404 DEBUG : BROWSER_OUTPUT: Cycle 1(23): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:39 INFO - 2015-11-09 15:10:39,983 DEBUG : BROWSER_OUTPUT: RSS: Main: 155496448 15:10:39 INFO - 2015-11-09 15:10:39,983 DEBUG : BROWSER_OUTPUT: 15:10:40 INFO - 2015-11-09 15:10:40,878 DEBUG : BROWSER_OUTPUT: Cycle 1(24): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:41 INFO - 2015-11-09 15:10:41,457 DEBUG : BROWSER_OUTPUT: RSS: Main: 157351936 15:10:41 INFO - 2015-11-09 15:10:41,457 DEBUG : BROWSER_OUTPUT: 15:10:42 INFO - 2015-11-09 15:10:42,372 DEBUG : BROWSER_OUTPUT: Cycle 1(25): loaded file:///C:/slave/test/build/tests/talos/talos/tests/a11y/tablemutation.html (next: file:///C:/slave/test/build/tests/talos/talos/tests/a11y/dhtml.html) 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: RSS: Main: 157446144 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: __start_tp_report 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_page_load_details 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: |i|pagename|runs| 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: |0;dhtml.html;1656;1689;1486;1492;1597;1737;1657;1598;1607;1601;1605;1624;1696;1653;1504;1598;1641;1557;1601;1696;1675;1628;1722;1687;1495 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: |1;tablemutation.html;342;338;338;339;336;341;339;338;353;338;343;339;337;340;358;342;344;347;344;346;340;346;344;345;342 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: __end_tp_report 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: __start_cc_report 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: _x_x_mozilla_cycle_collect,5984 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: __end_cc_report 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110642630__endTimestamp 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: ------- Summary: start ------- 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: Number of tests: 2 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: [#0] dhtml.html Cycles:25 Average:1620.08 Median:1624.00 stddev:71.36 (4.4%) stddev-sans-first:72.49 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: Values: 1656.0 1689.0 1486.0 1492.0 1597.0 1737.0 1657.0 1598.0 1607.0 1601.0 1605.0 1624.0 1696.0 1653.0 1504.0 1598.0 1641.0 1557.0 1601.0 1696.0 1675.0 1628.0 1722.0 1687.0 1495.0 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: [#1] tablemutation.html Cycles:25 Average:342.36 Median:342.00 stddev:5.06 (1.5%) stddev-sans-first:5.17 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: Values: 342.0 338.0 338.0 339.0 336.0 341.0 339.0 338.0 353.0 338.0 343.0 339.0 337.0 340.0 358.0 342.0 344.0 347.0 344.0 346.0 340.0 346.0 344.0 345.0 342.0 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: -------- Summary: end -------- 15:10:42 INFO - 2015-11-09 15:10:42,628 DEBUG : BROWSER_OUTPUT: 15:10:43 INFO - 2015-11-09 15:10:43,161 INFO : Browser exited with error code: 0 15:10:43 INFO - 2015-11-09 15:10:43,821 INFO : Completed test a11yr (00:02:01) 15:10:43 INFO - 2015-11-09 15:10:43,821 INFO : Starting test ts_paint 15:10:43 INFO - 2015-11-09 15:10:43,821 DEBUG : operating with platform_type : w7_ 15:10:43 INFO - 2015-11-09 15:10:43,821 INFO : Initialising browser for ts_paint test... 15:10:43 INFO - 2015-11-09 15:10:43,846 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/getInfo.html 15:10:48 INFO - 2015-11-09 15:10:48,789 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 15:10:48 INFO - 2015-11-09 15:10:48,789 DEBUG : BROWSER_OUTPUT: colorDepth:24 15:10:48 INFO - 2015-11-09 15:10:48,789 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1010/674 15:10:48 INFO - 2015-11-09 15:10:48,789 DEBUG : BROWSER_OUTPUT: __metrics 15:10:48 INFO - 2015-11-09 15:10:48,849 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: console.error: 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: Message: Error: Connection closed before committing the transaction. 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: Stack: 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeTransaction/promise resource://gre/modules/Promise-backend.js:934:23 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:813:7 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:11 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:776:7 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:711:7 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:319:13 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: nsAsyncShutdownBarrier.prototype.wait/<@resource://gre/components/nsAsyncShutdown.js:215:7 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9 15:10:49 INFO - 2015-11-09 15:10:49,549 DEBUG : BROWSER_OUTPUT: 15:10:50 INFO - 2015-11-09 15:10:50,217 INFO : Browser initialized. 15:10:50 INFO - 2015-11-09 15:10:50,217 INFO : Running cycle 1/20 for ts_paint test... 15:10:50 INFO - 2015-11-09 15:10:50,217 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:10:51 INFO - 2015-11-09 15:10:51,619 DEBUG : BROWSER_OUTPUT: __start_report1401__end_report 15:10:51 INFO - 2015-11-09 15:10:51,619 DEBUG : BROWSER_OUTPUT: 15:10:51 INFO - 2015-11-09 15:10:51,640 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110651642__endTimestamp 15:10:52 INFO - 2015-11-09 15:10:52,450 INFO : Browser exited with error code: 0 15:10:52 INFO - 2015-11-09 15:10:52,451 INFO : Running cycle 2/20 for ts_paint test... 15:10:52 INFO - 2015-11-09 15:10:52,451 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:10:53 INFO - 2015-11-09 15:10:53,506 DEBUG : BROWSER_OUTPUT: __start_report1052__end_report 15:10:53 INFO - 2015-11-09 15:10:53,506 DEBUG : BROWSER_OUTPUT: 15:10:53 INFO - 2015-11-09 15:10:53,506 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110653509__endTimestamp 15:10:54 INFO - 2015-11-09 15:10:54,236 INFO : Browser exited with error code: 0 15:10:54 INFO - 2015-11-09 15:10:54,236 INFO : Running cycle 3/20 for ts_paint test... 15:10:54 INFO - 2015-11-09 15:10:54,236 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:10:55 INFO - 2015-11-09 15:10:55,259 DEBUG : BROWSER_OUTPUT: __start_report1023__end_report 15:10:55 INFO - 2015-11-09 15:10:55,259 DEBUG : BROWSER_OUTPUT: 15:10:55 INFO - 2015-11-09 15:10:55,279 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110655278__endTimestamp 15:10:56 INFO - 2015-11-09 15:10:56,020 INFO : Browser exited with error code: 0 15:10:56 INFO - 2015-11-09 15:10:56,022 INFO : Running cycle 4/20 for ts_paint test... 15:10:56 INFO - 2015-11-09 15:10:56,022 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:10:57 INFO - 2015-11-09 15:10:57,055 DEBUG : BROWSER_OUTPUT: __start_report1032__end_report 15:10:57 INFO - 2015-11-09 15:10:57,055 DEBUG : BROWSER_OUTPUT: 15:10:57 INFO - 2015-11-09 15:10:57,059 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110657060__endTimestamp 15:10:57 INFO - 2015-11-09 15:10:57,855 INFO : Browser exited with error code: 0 15:10:57 INFO - 2015-11-09 15:10:57,857 INFO : Running cycle 5/20 for ts_paint test... 15:10:57 INFO - 2015-11-09 15:10:57,857 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:10:58 INFO - 2015-11-09 15:10:58,884 DEBUG : BROWSER_OUTPUT: __start_report1028__end_report 15:10:58 INFO - 2015-11-09 15:10:58,884 DEBUG : BROWSER_OUTPUT: 15:10:58 INFO - 2015-11-09 15:10:58,891 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110658891__endTimestamp 15:10:59 INFO - 2015-11-09 15:10:59,740 INFO : Browser exited with error code: 0 15:10:59 INFO - 2015-11-09 15:10:59,742 INFO : Running cycle 6/20 for ts_paint test... 15:10:59 INFO - 2015-11-09 15:10:59,742 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:00 INFO - 2015-11-09 15:11:00,809 DEBUG : BROWSER_OUTPUT: __start_report1064__end_report 15:11:00 INFO - 2015-11-09 15:11:00,809 DEBUG : BROWSER_OUTPUT: 15:11:00 INFO - 2015-11-09 15:11:00,828 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110660828__endTimestamp 15:11:01 INFO - 2015-11-09 15:11:01,677 INFO : Browser exited with error code: 0 15:11:01 INFO - 2015-11-09 15:11:01,677 INFO : Running cycle 7/20 for ts_paint test... 15:11:01 INFO - 2015-11-09 15:11:01,677 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:02 INFO - 2015-11-09 15:11:02,709 DEBUG : BROWSER_OUTPUT: __start_report1030__end_report 15:11:02 INFO - 2015-11-09 15:11:02,709 DEBUG : BROWSER_OUTPUT: 15:11:02 INFO - 2015-11-09 15:11:02,729 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110662731__endTimestamp 15:11:03 INFO - 2015-11-09 15:11:03,562 INFO : Browser exited with error code: 0 15:11:03 INFO - 2015-11-09 15:11:03,562 INFO : Running cycle 8/20 for ts_paint test... 15:11:03 INFO - 2015-11-09 15:11:03,562 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:04 INFO - 2015-11-09 15:11:04,591 DEBUG : BROWSER_OUTPUT: __start_report1025__end_report 15:11:04 INFO - 2015-11-09 15:11:04,591 DEBUG : BROWSER_OUTPUT: 15:11:04 INFO - 2015-11-09 15:11:04,611 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110664610__endTimestamp 15:11:05 INFO - 2015-11-09 15:11:05,496 INFO : Browser exited with error code: 0 15:11:05 INFO - 2015-11-09 15:11:05,497 INFO : Running cycle 9/20 for ts_paint test... 15:11:05 INFO - 2015-11-09 15:11:05,497 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:06 INFO - 2015-11-09 15:11:06,569 DEBUG : BROWSER_OUTPUT: __start_report1067__end_report 15:11:06 INFO - 2015-11-09 15:11:06,569 DEBUG : BROWSER_OUTPUT: 15:11:06 INFO - 2015-11-09 15:11:06,588 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110666587__endTimestamp 15:11:07 INFO - 2015-11-09 15:11:07,482 INFO : Browser exited with error code: 0 15:11:07 INFO - 2015-11-09 15:11:07,483 INFO : Running cycle 10/20 for ts_paint test... 15:11:07 INFO - 2015-11-09 15:11:07,483 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:08 INFO - 2015-11-09 15:11:08,546 DEBUG : BROWSER_OUTPUT: __start_report1059__end_report 15:11:08 INFO - 2015-11-09 15:11:08,546 DEBUG : BROWSER_OUTPUT: 15:11:08 INFO - 2015-11-09 15:11:08,561 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110668560__endTimestamp 15:11:09 INFO - 2015-11-09 15:11:09,467 INFO : Browser exited with error code: 0 15:11:09 INFO - 2015-11-09 15:11:09,467 INFO : Running cycle 11/20 for ts_paint test... 15:11:09 INFO - 2015-11-09 15:11:09,467 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:10 INFO - 2015-11-09 15:11:10,476 DEBUG : BROWSER_OUTPUT: __start_report1008__end_report 15:11:10 INFO - 2015-11-09 15:11:10,476 DEBUG : BROWSER_OUTPUT: 15:11:10 INFO - 2015-11-09 15:11:10,496 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110670494__endTimestamp 15:11:11 INFO - 2015-11-09 15:11:11,351 INFO : Browser exited with error code: 0 15:11:11 INFO - 2015-11-09 15:11:11,352 INFO : Running cycle 12/20 for ts_paint test... 15:11:11 INFO - 2015-11-09 15:11:11,352 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:12 INFO - 2015-11-09 15:11:12,394 DEBUG : BROWSER_OUTPUT: __start_report1042__end_report 15:11:12 INFO - 2015-11-09 15:11:12,394 DEBUG : BROWSER_OUTPUT: 15:11:12 INFO - 2015-11-09 15:11:12,414 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110672412__endTimestamp 15:11:13 INFO - 2015-11-09 15:11:13,236 INFO : Browser exited with error code: 0 15:11:13 INFO - 2015-11-09 15:11:13,236 INFO : Running cycle 13/20 for ts_paint test... 15:11:13 INFO - 2015-11-09 15:11:13,236 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:14 INFO - 2015-11-09 15:11:14,285 DEBUG : BROWSER_OUTPUT: __start_report1047__end_report 15:11:14 INFO - 2015-11-09 15:11:14,285 DEBUG : BROWSER_OUTPUT: 15:11:14 INFO - 2015-11-09 15:11:14,288 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110674288__endTimestamp 15:11:15 INFO - 2015-11-09 15:11:15,121 INFO : Browser exited with error code: 0 15:11:15 INFO - 2015-11-09 15:11:15,121 INFO : Running cycle 14/20 for ts_paint test... 15:11:15 INFO - 2015-11-09 15:11:15,121 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:16 INFO - 2015-11-09 15:11:16,217 DEBUG : BROWSER_OUTPUT: __start_report1093__end_report 15:11:16 INFO - 2015-11-09 15:11:16,217 DEBUG : BROWSER_OUTPUT: 15:11:16 INFO - 2015-11-09 15:11:16,220 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110676219__endTimestamp 15:11:17 INFO - 2015-11-09 15:11:17,105 INFO : Browser exited with error code: 0 15:11:17 INFO - 2015-11-09 15:11:17,107 INFO : Running cycle 15/20 for ts_paint test... 15:11:17 INFO - 2015-11-09 15:11:17,107 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:18 INFO - 2015-11-09 15:11:18,170 DEBUG : BROWSER_OUTPUT: __start_report1059__end_report 15:11:18 INFO - 2015-11-09 15:11:18,170 DEBUG : BROWSER_OUTPUT: 15:11:18 INFO - 2015-11-09 15:11:18,184 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110678182__endTimestamp 15:11:19 INFO - 2015-11-09 15:11:19,040 INFO : Browser exited with error code: 0 15:11:19 INFO - 2015-11-09 15:11:19,042 INFO : Running cycle 16/20 for ts_paint test... 15:11:19 INFO - 2015-11-09 15:11:19,042 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:20 INFO - 2015-11-09 15:11:20,092 DEBUG : BROWSER_OUTPUT: __start_report1050__end_report 15:11:20 INFO - 2015-11-09 15:11:20,092 DEBUG : BROWSER_OUTPUT: 15:11:20 INFO - 2015-11-09 15:11:20,111 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110680112__endTimestamp 15:11:20 INFO - 2015-11-09 15:11:20,974 INFO : Browser exited with error code: 0 15:11:20 INFO - 2015-11-09 15:11:20,976 INFO : Running cycle 17/20 for ts_paint test... 15:11:20 INFO - 2015-11-09 15:11:20,976 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:22 INFO - 2015-11-09 15:11:22,017 DEBUG : BROWSER_OUTPUT: __start_report1037__end_report 15:11:22 INFO - 2015-11-09 15:11:22,017 DEBUG : BROWSER_OUTPUT: 15:11:22 INFO - 2015-11-09 15:11:22,032 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110682030__endTimestamp 15:11:22 INFO - 2015-11-09 15:11:22,908 INFO : Browser exited with error code: 0 15:11:22 INFO - 2015-11-09 15:11:22,910 INFO : Running cycle 18/20 for ts_paint test... 15:11:22 INFO - 2015-11-09 15:11:22,910 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:23 INFO - 2015-11-09 15:11:23,976 DEBUG : BROWSER_OUTPUT: __start_report1066__end_report 15:11:23 INFO - 2015-11-09 15:11:23,976 DEBUG : BROWSER_OUTPUT: 15:11:24 INFO - 2015-11-09 15:11:24,000 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110683999__endTimestamp 15:11:24 INFO - 2015-11-09 15:11:24,894 INFO : Browser exited with error code: 0 15:11:24 INFO - 2015-11-09 15:11:24,894 INFO : Running cycle 19/20 for ts_paint test... 15:11:24 INFO - 2015-11-09 15:11:24,894 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:25 INFO - 2015-11-09 15:11:25,950 DEBUG : BROWSER_OUTPUT: __start_report1051__end_report 15:11:25 INFO - 2015-11-09 15:11:25,950 DEBUG : BROWSER_OUTPUT: 15:11:25 INFO - 2015-11-09 15:11:25,970 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110685966__endTimestamp 15:11:26 INFO - 2015-11-09 15:11:26,828 INFO : Browser exited with error code: 0 15:11:26 INFO - 2015-11-09 15:11:26,829 INFO : Running cycle 20/20 for ts_paint test... 15:11:26 INFO - 2015-11-09 15:11:26,829 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpffcx3z\profile http://localhost:49660/startup_test/tspaint_test.html 15:11:27 INFO - 2015-11-09 15:11:27,878 DEBUG : BROWSER_OUTPUT: __start_report1045__end_report 15:11:27 INFO - 2015-11-09 15:11:27,878 DEBUG : BROWSER_OUTPUT: 15:11:27 INFO - 2015-11-09 15:11:27,898 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110687897__endTimestamp 15:11:28 INFO - 2015-11-09 15:11:28,763 INFO : Browser exited with error code: 0 15:11:29 INFO - 2015-11-09 15:11:29,346 INFO : Completed test ts_paint (00:00:45) 15:11:29 INFO - 2015-11-09 15:11:29,346 INFO : Starting test tpaint 15:11:29 INFO - 2015-11-09 15:11:29,346 DEBUG : operating with platform_type : w7_ 15:11:29 INFO - 2015-11-09 15:11:29,346 INFO : Initialising browser for tpaint test... 15:11:29 INFO - 2015-11-09 15:11:29,371 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpw7iazs\profile http://localhost:49660/getInfo.html 15:11:33 INFO - 2015-11-09 15:11:33,907 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 15:11:33 INFO - 2015-11-09 15:11:33,907 DEBUG : BROWSER_OUTPUT: colorDepth:24 15:11:33 INFO - 2015-11-09 15:11:33,907 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1010/674 15:11:33 INFO - 2015-11-09 15:11:33,907 DEBUG : BROWSER_OUTPUT: __metrics 15:11:34 INFO - 2015-11-09 15:11:34,033 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 15:11:34 INFO - 2015-11-09 15:11:34,588 DEBUG : BROWSER_OUTPUT: console.error: 15:11:34 INFO - 2015-11-09 15:11:34,588 DEBUG : BROWSER_OUTPUT: Message: Error: Connection closed before committing the transaction. 15:11:34 INFO - 2015-11-09 15:11:34,588 DEBUG : BROWSER_OUTPUT: Stack: 15:11:34 INFO - 2015-11-09 15:11:34,588 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeTransaction/promise resource://gre/modules/Promise-backend.js:934:23 15:11:34 INFO - 2015-11-09 15:11:34,588 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:813:7 15:11:34 INFO - 2015-11-09 15:11:34,588 DEBUG : BROWSER_OUTPUT: Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:11 15:11:34 INFO - 2015-11-09 15:11:34,588 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:776:7 15:11:34 INFO - 2015-11-09 15:11:34,588 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:711:7 15:11:34 INFO - 2015-11-09 15:11:34,588 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:319:13 15:11:34 INFO - 2015-11-09 15:11:34,588 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9 15:11:34 INFO - 2015-11-09 15:11:34,589 DEBUG : BROWSER_OUTPUT: nsAsyncShutdownBarrier.prototype.wait/<@resource://gre/components/nsAsyncShutdown.js:215:7 15:11:34 INFO - 2015-11-09 15:11:34,589 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9 15:11:34 INFO - 2015-11-09 15:11:34,589 DEBUG : BROWSER_OUTPUT: 15:11:35 INFO - 2015-11-09 15:11:35,342 INFO : Browser initialized. 15:11:35 INFO - 2015-11-09 15:11:35,342 INFO : Running cycle 1/1 for tpaint test... 15:11:35 INFO - 2015-11-09 15:11:35,342 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpw7iazs\profile file://C:\slave\test\build\tests\talos\talos/startup_test/tpaint.html?auto=1 15:12:01 INFO - 2015-11-09 15:12:01,779 DEBUG : BROWSER_OUTPUT: __start_report233.26000000000022|234.1150000000016|234.54000000000087|234.85000000000036|235.2550000000001|237.28499999999985|238.86499999999796|239.07500000000073|244.60499999999956|245.0599999999995|245.14999999999782|247.7800000000002|248.57500000000073|249.7449999999999|251.58500000000004|253.16499999999996|265.380000000001|271.78499999999985|283.89500000000044|302.3899999999994__end_report__startTimestamp1447110721777__endTimestamp 15:12:01 INFO - 2015-11-09 15:12:01,779 DEBUG : BROWSER_OUTPUT: openingTimes=234.1150000000016,234.54000000000087,234.85000000000036,235.2550000000001,237.28499999999985,238.86499999999796,239.07500000000073,244.60499999999956,245.0599999999995,245.14999999999782,247.7800000000002,248.57500000000073,249.7449999999999,251.58500000000004,253.16499999999996,265.380000000001,271.78499999999985,283.89500000000044,302.3899999999994 15:12:01 INFO - 2015-11-09 15:12:01,779 DEBUG : BROWSER_OUTPUT: avgOpenTime:249.82 15:12:01 INFO - 2015-11-09 15:12:01,779 DEBUG : BROWSER_OUTPUT: minOpenTime:233.26 15:12:01 INFO - 2015-11-09 15:12:01,779 DEBUG : BROWSER_OUTPUT: maxOpenTime:302.39 15:12:01 INFO - 2015-11-09 15:12:01,779 DEBUG : BROWSER_OUTPUT: medOpenTime:245.10499999999865 15:12:01 INFO - 2015-11-09 15:12:01,779 DEBUG : BROWSER_OUTPUT: __xulWinOpenTime:245.10499999999865 15:12:02 INFO - 2015-11-09 15:12:02,627 INFO : Browser exited with error code: 0 15:12:03 INFO - 2015-11-09 15:12:03,283 INFO : Completed test tpaint (00:00:33) 15:12:03 INFO - 2015-11-09 15:12:03,283 INFO : Starting test sessionrestore 15:12:03 INFO - 2015-11-09 15:12:03,283 DEBUG : operating with platform_type : w7_ 15:12:03 INFO - 2015-11-09 15:12:03,283 INFO : Initialising browser for sessionrestore test... 15:12:03 INFO - 2015-11-09 15:12:03,315 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/getInfo.html 15:12:10 INFO - 2015-11-09 15:12:10,599 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 15:12:10 INFO - 2015-11-09 15:12:10,599 DEBUG : BROWSER_OUTPUT: colorDepth:24 15:12:10 INFO - 2015-11-09 15:12:10,599 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1186/776 15:12:10 INFO - 2015-11-09 15:12:10,599 DEBUG : BROWSER_OUTPUT: __metrics 15:12:10 INFO - 2015-11-09 15:12:10,694 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 15:12:12 INFO - 2015-11-09 15:12:12,436 INFO : Browser initialized. 15:12:12 INFO - 2015-11-09 15:12:12,436 INFO : Running cycle 1/10 for sessionrestore test... 15:12:12 INFO - 2015-11-09 15:12:12,436 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionstore.js 15:12:12 INFO - 2015-11-09 15:12:12,437 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionCheckpoints.json 15:12:12 INFO - 2015-11-09 15:12:12,438 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:12:17 INFO - 2015-11-09 15:12:17,062 DEBUG : BROWSER_OUTPUT: __start_report2318__end_report 15:12:17 INFO - 2015-11-09 15:12:17,062 DEBUG : BROWSER_OUTPUT: 15:12:17 INFO - 2015-11-09 15:12:17,062 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110737061__endTimestamp 15:12:17 INFO - 2015-11-09 15:12:17,062 DEBUG : BROWSER_OUTPUT: 15:12:18 INFO - 2015-11-09 15:12:18,622 INFO : Browser exited with error code: 0 15:12:18 INFO - 2015-11-09 15:12:18,624 INFO : Running cycle 2/10 for sessionrestore test... 15:12:18 INFO - 2015-11-09 15:12:18,625 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionstore.js 15:12:18 INFO - 2015-11-09 15:12:18,627 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionCheckpoints.json 15:12:18 INFO - 2015-11-09 15:12:18,628 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:12:22 INFO - 2015-11-09 15:12:22,875 DEBUG : BROWSER_OUTPUT: __start_report2143__end_report 15:12:22 INFO - 2015-11-09 15:12:22,875 DEBUG : BROWSER_OUTPUT: 15:12:22 INFO - 2015-11-09 15:12:22,875 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110742873__endTimestamp 15:12:22 INFO - 2015-11-09 15:12:22,875 DEBUG : BROWSER_OUTPUT: 15:12:24 INFO - 2015-11-09 15:12:24,510 INFO : Browser exited with error code: 0 15:12:24 INFO - 2015-11-09 15:12:24,512 INFO : Running cycle 3/10 for sessionrestore test... 15:12:24 INFO - 2015-11-09 15:12:24,512 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionstore.js 15:12:24 INFO - 2015-11-09 15:12:24,513 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionCheckpoints.json 15:12:24 INFO - 2015-11-09 15:12:24,515 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:12:28 INFO - 2015-11-09 15:12:28,891 DEBUG : BROWSER_OUTPUT: __start_report2235__end_report 15:12:28 INFO - 2015-11-09 15:12:28,891 DEBUG : BROWSER_OUTPUT: 15:12:28 INFO - 2015-11-09 15:12:28,891 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110748888__endTimestamp 15:12:28 INFO - 2015-11-09 15:12:28,891 DEBUG : BROWSER_OUTPUT: 15:12:30 INFO - 2015-11-09 15:12:30,499 INFO : Browser exited with error code: 0 15:12:30 INFO - 2015-11-09 15:12:30,500 INFO : Running cycle 4/10 for sessionrestore test... 15:12:30 INFO - 2015-11-09 15:12:30,500 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionstore.js 15:12:30 INFO - 2015-11-09 15:12:30,502 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionCheckpoints.json 15:12:30 INFO - 2015-11-09 15:12:30,503 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:12:34 INFO - 2015-11-09 15:12:34,686 DEBUG : BROWSER_OUTPUT: __start_report2113__end_report 15:12:34 INFO - 2015-11-09 15:12:34,686 DEBUG : BROWSER_OUTPUT: 15:12:34 INFO - 2015-11-09 15:12:34,686 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110754686__endTimestamp 15:12:34 INFO - 2015-11-09 15:12:34,686 DEBUG : BROWSER_OUTPUT: 15:12:36 INFO - 2015-11-09 15:12:36,336 INFO : Browser exited with error code: 0 15:12:36 INFO - 2015-11-09 15:12:36,338 INFO : Running cycle 5/10 for sessionrestore test... 15:12:36 INFO - 2015-11-09 15:12:36,338 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionstore.js 15:12:36 INFO - 2015-11-09 15:12:36,341 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionCheckpoints.json 15:12:36 INFO - 2015-11-09 15:12:36,341 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:12:40 INFO - 2015-11-09 15:12:40,563 DEBUG : BROWSER_OUTPUT: __start_report2131__end_report 15:12:40 INFO - 2015-11-09 15:12:40,563 DEBUG : BROWSER_OUTPUT: 15:12:40 INFO - 2015-11-09 15:12:40,563 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110760561__endTimestamp 15:12:40 INFO - 2015-11-09 15:12:40,563 DEBUG : BROWSER_OUTPUT: 15:12:42 INFO - 2015-11-09 15:12:42,325 INFO : Browser exited with error code: 0 15:12:42 INFO - 2015-11-09 15:12:42,325 INFO : Running cycle 6/10 for sessionrestore test... 15:12:42 INFO - 2015-11-09 15:12:42,326 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionstore.js 15:12:42 INFO - 2015-11-09 15:12:42,328 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionCheckpoints.json 15:12:42 INFO - 2015-11-09 15:12:42,328 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:12:46 INFO - 2015-11-09 15:12:46,723 DEBUG : BROWSER_OUTPUT: __start_report2227__end_report 15:12:46 INFO - 2015-11-09 15:12:46,723 DEBUG : BROWSER_OUTPUT: 15:12:46 INFO - 2015-11-09 15:12:46,723 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110766722__endTimestamp 15:12:46 INFO - 2015-11-09 15:12:46,723 DEBUG : BROWSER_OUTPUT: 15:12:48 INFO - 2015-11-09 15:12:48,461 INFO : Browser exited with error code: 0 15:12:48 INFO - 2015-11-09 15:12:48,463 INFO : Running cycle 7/10 for sessionrestore test... 15:12:48 INFO - 2015-11-09 15:12:48,463 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionstore.js 15:12:48 INFO - 2015-11-09 15:12:48,464 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionCheckpoints.json 15:12:48 INFO - 2015-11-09 15:12:48,466 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:12:52 INFO - 2015-11-09 15:12:52,700 DEBUG : BROWSER_OUTPUT: __start_report2135__end_report 15:12:52 INFO - 2015-11-09 15:12:52,700 DEBUG : BROWSER_OUTPUT: 15:12:52 INFO - 2015-11-09 15:12:52,700 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110772702__endTimestamp 15:12:52 INFO - 2015-11-09 15:12:52,700 DEBUG : BROWSER_OUTPUT: 15:12:54 INFO - 2015-11-09 15:12:54,400 INFO : Browser exited with error code: 0 15:12:54 INFO - 2015-11-09 15:12:54,401 INFO : Running cycle 8/10 for sessionrestore test... 15:12:54 INFO - 2015-11-09 15:12:54,401 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionstore.js 15:12:54 INFO - 2015-11-09 15:12:54,403 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionCheckpoints.json 15:12:54 INFO - 2015-11-09 15:12:54,404 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:12:58 INFO - 2015-11-09 15:12:58,786 DEBUG : BROWSER_OUTPUT: __start_report2228__end_report 15:12:58 INFO - 2015-11-09 15:12:58,786 DEBUG : BROWSER_OUTPUT: 15:12:58 INFO - 2015-11-09 15:12:58,786 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110778784__endTimestamp 15:12:58 INFO - 2015-11-09 15:12:58,786 DEBUG : BROWSER_OUTPUT: 15:13:00 INFO - 2015-11-09 15:13:00,487 INFO : Browser exited with error code: 0 15:13:00 INFO - 2015-11-09 15:13:00,489 INFO : Running cycle 9/10 for sessionrestore test... 15:13:00 INFO - 2015-11-09 15:13:00,490 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionstore.js 15:13:00 INFO - 2015-11-09 15:13:00,492 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionCheckpoints.json 15:13:00 INFO - 2015-11-09 15:13:00,492 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:04 INFO - 2015-11-09 15:13:04,887 DEBUG : BROWSER_OUTPUT: __start_report2215__end_report 15:13:04 INFO - 2015-11-09 15:13:04,887 DEBUG : BROWSER_OUTPUT: 15:13:04 INFO - 2015-11-09 15:13:04,887 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110784886__endTimestamp 15:13:04 INFO - 2015-11-09 15:13:04,887 DEBUG : BROWSER_OUTPUT: 15:13:06 INFO - 2015-11-09 15:13:06,575 INFO : Browser exited with error code: 0 15:13:06 INFO - 2015-11-09 15:13:06,576 INFO : Running cycle 10/10 for sessionrestore test... 15:13:06 INFO - 2015-11-09 15:13:06,578 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionstore.js 15:13:06 INFO - 2015-11-09 15:13:06,579 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmpufckgz\profile\sessionCheckpoints.json 15:13:06 INFO - 2015-11-09 15:13:06,579 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmpufckgz\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:10 INFO - 2015-11-09 15:13:10,864 DEBUG : BROWSER_OUTPUT: __start_report2195__end_report 15:13:10 INFO - 2015-11-09 15:13:10,864 DEBUG : BROWSER_OUTPUT: 15:13:10 INFO - 2015-11-09 15:13:10,864 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110790864__endTimestamp 15:13:10 INFO - 2015-11-09 15:13:10,864 DEBUG : BROWSER_OUTPUT: 15:13:12 INFO - 2015-11-09 15:13:12,615 INFO : Browser exited with error code: 0 15:13:13 INFO - 2015-11-09 15:13:13,286 INFO : Completed test sessionrestore (00:01:10) 15:13:13 INFO - 2015-11-09 15:13:13,286 INFO : Starting test sessionrestore_no_auto_restore 15:13:13 INFO - 2015-11-09 15:13:13,286 DEBUG : operating with platform_type : w7_ 15:13:13 INFO - 2015-11-09 15:13:13,286 INFO : Initialising browser for sessionrestore_no_auto_restore test... 15:13:13 INFO - 2015-11-09 15:13:13,316 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/getInfo.html 15:13:17 INFO - 2015-11-09 15:13:17,631 DEBUG : BROWSER_OUTPUT: __metrics Screen width/height:1600/1200 15:13:17 INFO - 2015-11-09 15:13:17,631 DEBUG : BROWSER_OUTPUT: colorDepth:24 15:13:17 INFO - 2015-11-09 15:13:17,631 DEBUG : BROWSER_OUTPUT: Browser inner width/height: 1186/776 15:13:17 INFO - 2015-11-09 15:13:17,631 DEBUG : BROWSER_OUTPUT: __metrics 15:13:17 INFO - 2015-11-09 15:13:17,750 DEBUG : BROWSER_OUTPUT: JavaScript error: resource:///modules/WebappManager.jsm, line 48: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 15:13:18 INFO - 2015-11-09 15:13:18,345 DEBUG : BROWSER_OUTPUT: console.error: 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: Message: Error: Connection closed before committing the transaction. 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: Stack: 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: ConnectionData.prototype<.executeTransaction/promise resource://gre/modules/Promise-backend.js:934:23 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:813:7 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: Promise*this.PromiseWalker.scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:11 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:776:7 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: this.PromiseWalker.completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:711:7 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: TaskImpl_run@resource://gre/modules/Task.jsm:319:13 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: nsAsyncShutdownBarrier.prototype.wait/<@resource://gre/components/nsAsyncShutdown.js:215:7 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: Spinner.prototype.observe@resource://gre/modules/AsyncShutdown.jsm:523:9 15:13:18 INFO - 2015-11-09 15:13:18,348 DEBUG : BROWSER_OUTPUT: 15:13:19 INFO - 2015-11-09 15:13:19,036 INFO : Browser initialized. 15:13:19 INFO - 2015-11-09 15:13:19,036 INFO : Running cycle 1/10 for sessionrestore_no_auto_restore test... 15:13:19 INFO - 2015-11-09 15:13:19,036 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionstore.js 15:13:19 INFO - 2015-11-09 15:13:19,039 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionCheckpoints.json 15:13:19 INFO - 2015-11-09 15:13:19,039 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:20 INFO - 2015-11-09 15:13:20,522 DEBUG : BROWSER_OUTPUT: __start_report992__end_report 15:13:20 INFO - 2015-11-09 15:13:20,523 DEBUG : BROWSER_OUTPUT: 15:13:20 INFO - 2015-11-09 15:13:20,523 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110800523__endTimestamp 15:13:20 INFO - 2015-11-09 15:13:20,523 DEBUG : BROWSER_OUTPUT: 15:13:21 INFO - 2015-11-09 15:13:21,523 INFO : Browser exited with error code: 0 15:13:21 INFO - 2015-11-09 15:13:21,523 INFO : Running cycle 2/10 for sessionrestore_no_auto_restore test... 15:13:21 INFO - 2015-11-09 15:13:21,523 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionstore.js 15:13:21 INFO - 2015-11-09 15:13:21,526 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionCheckpoints.json 15:13:21 INFO - 2015-11-09 15:13:21,526 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:22 INFO - 2015-11-09 15:13:22,710 DEBUG : BROWSER_OUTPUT: __start_report808__end_report 15:13:22 INFO - 2015-11-09 15:13:22,710 DEBUG : BROWSER_OUTPUT: 15:13:22 INFO - 2015-11-09 15:13:22,710 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110802709__endTimestamp 15:13:22 INFO - 2015-11-09 15:13:22,710 DEBUG : BROWSER_OUTPUT: 15:13:23 INFO - 2015-11-09 15:13:23,460 INFO : Browser exited with error code: 0 15:13:23 INFO - 2015-11-09 15:13:23,461 INFO : Running cycle 3/10 for sessionrestore_no_auto_restore test... 15:13:23 INFO - 2015-11-09 15:13:23,463 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionstore.js 15:13:23 INFO - 2015-11-09 15:13:23,463 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionCheckpoints.json 15:13:23 INFO - 2015-11-09 15:13:23,464 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:24 INFO - 2015-11-09 15:13:24,615 DEBUG : BROWSER_OUTPUT: __start_report785__end_report 15:13:24 INFO - 2015-11-09 15:13:24,615 DEBUG : BROWSER_OUTPUT: 15:13:24 INFO - 2015-11-09 15:13:24,615 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110804617__endTimestamp 15:13:24 INFO - 2015-11-09 15:13:24,615 DEBUG : BROWSER_OUTPUT: 15:13:25 INFO - 2015-11-09 15:13:25,448 INFO : Browser exited with error code: 0 15:13:25 INFO - 2015-11-09 15:13:25,450 INFO : Running cycle 4/10 for sessionrestore_no_auto_restore test... 15:13:25 INFO - 2015-11-09 15:13:25,450 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionstore.js 15:13:25 INFO - 2015-11-09 15:13:25,451 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionCheckpoints.json 15:13:25 INFO - 2015-11-09 15:13:25,453 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:26 INFO - 2015-11-09 15:13:26,607 DEBUG : BROWSER_OUTPUT: __start_report787__end_report 15:13:26 INFO - 2015-11-09 15:13:26,607 DEBUG : BROWSER_OUTPUT: 15:13:26 INFO - 2015-11-09 15:13:26,607 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110806609__endTimestamp 15:13:26 INFO - 2015-11-09 15:13:26,607 DEBUG : BROWSER_OUTPUT: 15:13:27 INFO - 2015-11-09 15:13:27,436 INFO : Browser exited with error code: 0 15:13:27 INFO - 2015-11-09 15:13:27,437 INFO : Running cycle 5/10 for sessionrestore_no_auto_restore test... 15:13:27 INFO - 2015-11-09 15:13:27,437 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionstore.js 15:13:27 INFO - 2015-11-09 15:13:27,438 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionCheckpoints.json 15:13:27 INFO - 2015-11-09 15:13:27,440 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:28 INFO - 2015-11-09 15:13:28,585 DEBUG : BROWSER_OUTPUT: __start_report791__end_report 15:13:28 INFO - 2015-11-09 15:13:28,585 DEBUG : BROWSER_OUTPUT: 15:13:28 INFO - 2015-11-09 15:13:28,585 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110808587__endTimestamp 15:13:28 INFO - 2015-11-09 15:13:28,585 DEBUG : BROWSER_OUTPUT: 15:13:29 INFO - 2015-11-09 15:13:29,473 INFO : Browser exited with error code: 0 15:13:29 INFO - 2015-11-09 15:13:29,474 INFO : Running cycle 6/10 for sessionrestore_no_auto_restore test... 15:13:29 INFO - 2015-11-09 15:13:29,474 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionstore.js 15:13:29 INFO - 2015-11-09 15:13:29,476 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionCheckpoints.json 15:13:29 INFO - 2015-11-09 15:13:29,477 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:30 INFO - 2015-11-09 15:13:30,667 DEBUG : BROWSER_OUTPUT: __start_report817__end_report 15:13:30 INFO - 2015-11-09 15:13:30,667 DEBUG : BROWSER_OUTPUT: 15:13:30 INFO - 2015-11-09 15:13:30,667 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110810667__endTimestamp 15:13:30 INFO - 2015-11-09 15:13:30,667 DEBUG : BROWSER_OUTPUT: 15:13:31 INFO - 2015-11-09 15:13:31,561 INFO : Browser exited with error code: 0 15:13:31 INFO - 2015-11-09 15:13:31,562 INFO : Running cycle 7/10 for sessionrestore_no_auto_restore test... 15:13:31 INFO - 2015-11-09 15:13:31,562 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionstore.js 15:13:31 INFO - 2015-11-09 15:13:31,563 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionCheckpoints.json 15:13:31 INFO - 2015-11-09 15:13:31,565 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:32 INFO - 2015-11-09 15:13:32,746 DEBUG : BROWSER_OUTPUT: __start_report814__end_report 15:13:32 INFO - 2015-11-09 15:13:32,746 DEBUG : BROWSER_OUTPUT: 15:13:32 INFO - 2015-11-09 15:13:32,746 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110812746__endTimestamp 15:13:32 INFO - 2015-11-09 15:13:32,746 DEBUG : BROWSER_OUTPUT: 15:13:33 INFO - 2015-11-09 15:13:33,598 INFO : Browser exited with error code: 0 15:13:33 INFO - 2015-11-09 15:13:33,598 INFO : Running cycle 8/10 for sessionrestore_no_auto_restore test... 15:13:33 INFO - 2015-11-09 15:13:33,598 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionstore.js 15:13:33 INFO - 2015-11-09 15:13:33,601 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionCheckpoints.json 15:13:33 INFO - 2015-11-09 15:13:33,601 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:34 INFO - 2015-11-09 15:13:34,785 DEBUG : BROWSER_OUTPUT: __start_report797__end_report 15:13:34 INFO - 2015-11-09 15:13:34,785 DEBUG : BROWSER_OUTPUT: 15:13:34 INFO - 2015-11-09 15:13:34,785 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110814779__endTimestamp 15:13:34 INFO - 2015-11-09 15:13:34,785 DEBUG : BROWSER_OUTPUT: 15:13:35 INFO - 2015-11-09 15:13:35,635 INFO : Browser exited with error code: 0 15:13:35 INFO - 2015-11-09 15:13:35,637 INFO : Running cycle 9/10 for sessionrestore_no_auto_restore test... 15:13:35 INFO - 2015-11-09 15:13:35,637 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionstore.js 15:13:35 INFO - 2015-11-09 15:13:35,638 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionCheckpoints.json 15:13:35 INFO - 2015-11-09 15:13:35,640 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:36 INFO - 2015-11-09 15:13:36,829 DEBUG : BROWSER_OUTPUT: __start_report825__end_report 15:13:36 INFO - 2015-11-09 15:13:36,829 DEBUG : BROWSER_OUTPUT: 15:13:36 INFO - 2015-11-09 15:13:36,829 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110816830__endTimestamp 15:13:36 INFO - 2015-11-09 15:13:36,829 DEBUG : BROWSER_OUTPUT: 15:13:37 INFO - 2015-11-09 15:13:37,723 INFO : Browser exited with error code: 0 15:13:37 INFO - 2015-11-09 15:13:37,723 INFO : Running cycle 10/10 for sessionrestore_no_auto_restore test... 15:13:37 INFO - 2015-11-09 15:13:37,723 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionstore.js on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionstore.js 15:13:37 INFO - 2015-11-09 15:13:37,726 DEBUG : Reinstalling C:\slave\test\build\tests\talos\talos/startup_test/sessionrestore/profile\sessionCheckpoints.json on top of c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile\sessionCheckpoints.json 15:13:37 INFO - 2015-11-09 15:13:37,726 DEBUG : command line: C:\slave\test\build\application\firefox\firefox -profile c:\users\cltbld\appdata\local\temp\tmp68m1u6\profile http://localhost:49660/startup_test/sessionrestore/index.html 15:13:38 INFO - 2015-11-09 15:13:38,875 DEBUG : BROWSER_OUTPUT: __start_report789__end_report 15:13:38 INFO - 2015-11-09 15:13:38,875 DEBUG : BROWSER_OUTPUT: 15:13:38 INFO - 2015-11-09 15:13:38,875 DEBUG : BROWSER_OUTPUT: __startTimestamp1447110818874__endTimestamp 15:13:38 INFO - 2015-11-09 15:13:38,875 DEBUG : BROWSER_OUTPUT: 15:13:40 INFO - 2015-11-09 15:13:40,260 INFO : Browser exited with error code: 0 15:13:40 INFO - 2015-11-09 15:13:40,901 INFO : Completed test sessionrestore_no_auto_restore (00:00:27) 15:13:41 INFO - 2015-11-09 15:13:41,289 INFO : Completed test suite (00:04:59) 15:13:41 INFO - 2015-11-09 15:13:41,289 DEBUG : Working with test: a11yr 15:13:41 INFO - 2015-11-09 15:13:41,289 DEBUG : Generating results file: a11yr 15:13:41 INFO - 2015-11-09 15:13:41,289 DEBUG : Working with test: ts_paint 15:13:41 INFO - 2015-11-09 15:13:41,289 DEBUG : Generating results file: ts_paint 15:13:41 INFO - 2015-11-09 15:13:41,289 DEBUG : Working with test: tpaint 15:13:41 INFO - 2015-11-09 15:13:41,289 DEBUG : Generating results file: tpaint 15:13:41 INFO - 2015-11-09 15:13:41,289 DEBUG : Working with test: sessionrestore 15:13:41 INFO - 2015-11-09 15:13:41,289 DEBUG : Generating results file: sessionrestore 15:13:41 INFO - 2015-11-09 15:13:41,289 DEBUG : Working with test: sessionrestore_no_auto_restore 15:13:41 INFO - 2015-11-09 15:13:41,289 DEBUG : Generating results file: sessionrestore_no_auto_restore 15:13:41 INFO - 2015-11-09 15:13:41,289 INFO : Posting result 0 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 15:13:41 INFO - 2015-11-09 15:13:41,325 DEBUG : process_Request line: a11yr_paint graph.html#tests=[[223,131,25]] 15:13:41 INFO - 2015-11-09 15:13:41,325 DEBUG : process_Request line: a11yr_paint 743.08 graph.html#tests=[[223,131,25]] 15:13:41 INFO - 2015-11-09 15:13:41,325 INFO : Posting result 1 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 15:13:41 INFO - 2015-11-09 15:13:41,392 DEBUG : process_Request line: ts_paint graph.html#tests=[[83,131,25]] 15:13:41 INFO - 2015-11-09 15:13:41,394 DEBUG : process_Request line: ts_paint 1061.43 graph.html#tests=[[83,131,25]] 15:13:41 INFO - 2015-11-09 15:13:41,394 INFO : Posting result 2 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 15:13:41 INFO - 2015-11-09 15:13:41,424 DEBUG : process_Request line: tpaint graph.html#tests=[[82,131,25]] 15:13:41 INFO - 2015-11-09 15:13:41,424 DEBUG : process_Request line: tpaint 248.58 graph.html#tests=[[82,131,25]] 15:13:41 INFO - 2015-11-09 15:13:41,424 INFO : Posting result 3 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 15:13:41 INFO - 2015-11-09 15:13:41,470 DEBUG : process_Request line: sessionrestore graph.html#tests=[[313,131,25]] 15:13:41 INFO - 2015-11-09 15:13:41,470 DEBUG : process_Request line: sessionrestore 2193.18 graph.html#tests=[[313,131,25]] 15:13:41 INFO - 2015-11-09 15:13:41,470 INFO : Posting result 4 of 5 to http://graphs.mozilla.org/server/collect.cgi, attempt 0 15:13:41 INFO - 2015-11-09 15:13:41,507 DEBUG : process_Request line: sessionrestore_no_auto_restore graph.html#tests=[[315,131,25]] 15:13:41 INFO - 2015-11-09 15:13:41,507 DEBUG : process_Request line: sessionrestore_no_auto_restore 818.61 graph.html#tests=[[315,131,25]] 15:13:41 INFO - 2015-11-09 15:13:41,509 INFO : TALOSDATA: [{"talos_counters": {}, "results": {"dhtml.html": [1656.0, 1689.0, 1486.0, 1492.0, 1597.0, 1737.0, 1657.0, 1598.0, 1607.0, 1601.0, 1605.0, 1624.0, 1696.0, 1653.0, 1504.0, 1598.0, 1641.0, 1557.0, 1601.0, 1696.0, 1675.0, 1628.0, 1722.0, 1687.0, 1495.0], "tablemutation.html": [342.0, 338.0, 338.0, 339.0, 336.0, 341.0, 339.0, 338.0, 353.0, 338.0, 343.0, 339.0, 337.0, 340.0, 358.0, 342.0, 344.0, 347.0, 344.0, 346.0, 340.0, 346.0, 344.0, 345.0, 342.0]}, "summary": {"lowerIsBetter": true, "suite": 743.0774489258494, "subtests": {"dhtml.html": {"lowerIsBetter": true, "filtered": 1615.5, "unit": "ms", "value": 1615.5}, "tablemutation.html": {"lowerIsBetter": true, "filtered": 341.5, "unit": "ms", "value": 341.5}}}, "test_machine": {"platform": "x86", "osversion": "6.1.7601", "os": "win", "name": "T-W732-IX-084"}, "testrun": {"date": 1447110522, "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": "20151109133533", "branch": "Mozilla-Inbound-Non-PGO", "revision": "09cd7947ffd969860d6de0effc9402e9f99f1d21"}}, {"talos_counters": {}, "results": {"ts_paint": [1401.0, 1052.0, 1023.0, 1032.0, 1028.0, 1064.0, 1030.0, 1025.0, 1067.0, 1059.0, 1008.0, 1042.0, 1047.0, 1093.0, 1059.0, 1050.0, 1037.0, 1066.0, 1051.0, 1045.0]}, "summary": {"suite": 1047.0, "subtests": {"ts_paint": {"filtered": 1047.0, "value": 1047.0}}}, "test_machine": {"platform": "x86", "osversion": "6.1.7601", "os": "win", "name": "T-W732-IX-084"}, "testrun": {"date": 1447110522, "suite": "ts_paint", "options": {"responsiveness": false, "cycles": 20, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151109133533", "branch": "Mozilla-Inbound-Non-PGO", "revision": "09cd7947ffd969860d6de0effc9402e9f99f1d21"}}, {"talos_counters": {}, "results": {"tpaint": [233.26000000000022, 234.1150000000016, 234.54000000000087, 234.85000000000036, 235.2550000000001, 237.28499999999985, 238.86499999999796, 239.07500000000073, 244.60499999999956, 245.0599999999995, 245.14999999999782, 247.7800000000002, 248.57500000000073, 249.7449999999999, 251.58500000000004, 253.16499999999996, 265.380000000001, 271.78499999999985, 283.89500000000044, 302.3899999999994]}, "summary": {"suite": 248.57500000000073, "subtests": {"tpaint": {"filtered": 248.57500000000073, "value": 248.57500000000073}}}, "test_machine": {"platform": "x86", "osversion": "6.1.7601", "os": "win", "name": "T-W732-IX-084"}, "testrun": {"date": 1447110522, "suite": "tpaint", "options": {"responsiveness": false, "cycles": 1, "tpmozafterpaint": true, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151109133533", "branch": "Mozilla-Inbound-Non-PGO", "revision": "09cd7947ffd969860d6de0effc9402e9f99f1d21"}}, {"talos_counters": {}, "results": {"sessionrestore": [2318.0, 2143.0, 2235.0, 2113.0, 2131.0, 2227.0, 2135.0, 2228.0, 2215.0, 2195.0]}, "summary": {"suite": 2195.0, "subtests": {"sessionrestore": {"filtered": 2195.0, "value": 2195.0}}}, "test_machine": {"platform": "x86", "osversion": "6.1.7601", "os": "win", "name": "T-W732-IX-084"}, "testrun": {"date": 1447110522, "suite": "sessionrestore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151109133533", "branch": "Mozilla-Inbound-Non-PGO", "revision": "09cd7947ffd969860d6de0effc9402e9f99f1d21"}}, {"talos_counters": {}, "results": {"sessionrestore_no_auto_restore": [992.0, 808.0, 785.0, 787.0, 791.0, 817.0, 814.0, 797.0, 825.0, 789.0]}, "summary": {"suite": 797.0, "subtests": {"sessionrestore_no_auto_restore": {"filtered": 797.0, "value": 797.0}}}, "test_machine": {"platform": "x86", "osversion": "6.1.7601", "os": "win", "name": "T-W732-IX-084"}, "testrun": {"date": 1447110522, "suite": "sessionrestore_no_auto_restore", "options": {"responsiveness": false, "cycles": 10, "tpmozafterpaint": false, "shutdown": false, "rss": false}}, "test_build": {"name": "Firefox", "version": "45.0a1", "id": "20151109133533", "branch": "Mozilla-Inbound-Non-PGO", "revision": "09cd7947ffd969860d6de0effc9402e9f99f1d21"}}] 15:13:41 INFO - RETURN: a11yr_paint: 743.08 15:13:41 INFO - RETURN: ts_paint: 1061.43 15:13:41 INFO - RETURN: tpaint: 248.58 15:13:41 INFO - RETURN: sessionrestore: 2193.18 15:13:41 INFO - RETURN: sessionrestore_no_auto_restore: 818.61 15:13:41 INFO - TinderboxPrint: TalosResult: {"graphserver": {"sessionrestore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[313,131,25]]", "result": "2193.18"}, "a11yr_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[223,131,25]]", "result": "743.08"}, "tpaint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[82,131,25]]", "result": "248.58"}, "ts_paint": {"url": "http://graphs.mozilla.org/graph.html#tests=[[83,131,25]]", "result": "1061.43"}, "sessionrestore_no_auto_restore": {"url": "http://graphs.mozilla.org/graph.html#tests=[[315,131,25]]", "result": "818.61"}}} 15:13:41 INFO - Return code: 0 15:13:41 INFO - # TBPL SUCCESS # 15:13:41 INFO - Running post-action listener: _resource_record_post_action 15:13:41 INFO - Running post-run listener: _resource_record_post_run 15:13:42 INFO - Total resource usage - Wall time: 304s; CPU: 10.0%; Read bytes: 130537472; Write bytes: 287636992; Read time: 2198780; Write time: 8541310 15:13:42 INFO - install - Wall time: 2s; CPU: 13.0%; Read bytes: 9965056; Write bytes: 16896; Read time: 109340; Write time: 880 15:13:42 INFO - run-tests - Wall time: 302s; CPU: 10.0%; Read bytes: 120490496; Write bytes: 262550016; Read time: 2085650; Write time: 8067590 15:13:42 INFO - Running post-run listener: _upload_blobber_files 15:13:42 INFO - Blob upload gear active. 15:13:42 INFO - There are no files to upload in the directory. Skipping the blob upload mechanism ... 15:13:42 INFO - Copying logs to upload dir... 15:13:42 INFO - mkdir: C:\slave\test\build\upload\logs program finished with exit code 0 elapsedTime=521.464000 ========= master_lag: 0.14 ========= ========= Finished 'c:/mozilla-build/python27/python -u ...' (results: 0, elapsed: 8 mins, 41 secs) (at 2015-11-09 15:13:42.779458) ========= ========= Started set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-09 15:13:42.780417) ========= 'cmd' '/C' 'for' '%f' 'in' '(*)' 'do' '@type' '%f' in dir C:\slave\test\properties (timeout 1200 secs) watching logfiles {} argv: ['cmd', '/C', 'for', '%f', 'in', '(*)', 'do', '@type', '%f'] environment: ALLUSERSPROFILE=C:\ProgramData APPDATA=C:\Users\cltbld\AppData\Roaming COMMONPROGRAMFILES=C:\Program Files\Common Files COMPUTERNAME=T-W732-IX-084 COMSPEC=C:\windows\system32\cmd.exe CYGWINBASE=C:\cygwin DCLOCATION=SCL3 DNSSUFFIX=wintest.releng.scl3.mozilla.com FP_NO_HOST_CHECK=NO HOMEDRIVE=C: HOMEPATH=\Users\cltbld KTS_HOME=C:\Program Files\KTS KTS_VERSION=1.19c LOCALAPPDATA=C:\Users\cltbld\AppData\Local LOGONSERVER=\\T-W732-IX-084 MONDIR=C:\Monitor_config\ MOZBUILDDIR=C:\mozilla-build\ MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 NUMBER_OF_PROCESSORS=8 OS=Windows_NT OURDRIVE=C: PATH=C:\Python24;C:\Python24\Scripts;C:\cygwin\bin;C:\WINDOWS\System32;C:\program files\gnuwin32\bin;C:\WINDOWS;C:\mozilla-build\msys\bin;C:\mozilla-build\python27;C:\mozilla-build\python27\Scripts;C:\mozilla-build\info-zip;C:\mozilla-build\wget;C:\Program Files (x86)\GnuWin32\bin; PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC PROCESSOR_ARCHITECTURE=x86 PROCESSOR_IDENTIFIER=x86 Family 6 Model 30 Stepping 5, GenuineIntel PROCESSOR_LEVEL=6 PROCESSOR_REVISION=1e05 PROGRAMDATA=C:\ProgramData PROGRAMFILES=C:\Program Files PROMPT=$P$G PSMODULEPATH=C:\windows\system32\WindowsPowerShell\v1.0\Modules\ PUBLIC=C:\Users\Public PWD=C:\slave\test\properties RUNLOGFILE=C:\slave\\runslave.log SLAVEDIR=C:\slave\ SYSTEMDRIVE=C: SYSTEMROOT=C:\windows TEMP=C:\Users\cltbld\AppData\Local\Temp TEST1=testie TMP=C:\Users\cltbld\AppData\Local\Temp USERDOMAIN=T-W732-IX-084 USERNAME=cltbld USERPROFILE=C:\Users\cltbld WINDIR=C:\windows WINDOWS_TRACING_FLAGS=3 WINDOWS_TRACING_LOGFILE=C:\BVTBin\Tests\installpackage\csilogfile.log XPCOM_DEBUG_BREAK=warn using PTY: False build_url:https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.zip program finished with exit code 0 elapsedTime=0.102000 build_url: 'https://queue.taskcluster.net/v1/task/habK7DeEQZWB7gxR37Ej4Q/artifacts/public/build/firefox-45.0a1.en-US.win32.zip' ========= master_lag: 0.02 ========= ========= Finished set props: build_url (results: 0, elapsed: 0 secs) (at 2015-11-09 15:13:42.898783) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-09 15:13:42.899172) ========= 'rm' '-f' 'oauth.txt' in dir C:\slave\test\. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-f', 'oauth.txt'] environment: ALLUSERSPROFILE=C:\ProgramData APPDATA=C:\Users\cltbld\AppData\Roaming COMMONPROGRAMFILES=C:\Program Files\Common Files COMPUTERNAME=T-W732-IX-084 COMSPEC=C:\windows\system32\cmd.exe CYGWINBASE=C:\cygwin DCLOCATION=SCL3 DNSSUFFIX=wintest.releng.scl3.mozilla.com FP_NO_HOST_CHECK=NO HOMEDRIVE=C: HOMEPATH=\Users\cltbld KTS_HOME=C:\Program Files\KTS KTS_VERSION=1.19c LOCALAPPDATA=C:\Users\cltbld\AppData\Local LOGONSERVER=\\T-W732-IX-084 MONDIR=C:\Monitor_config\ MOZBUILDDIR=C:\mozilla-build\ MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NO_EM_RESTART=1 NUMBER_OF_PROCESSORS=8 OS=Windows_NT OURDRIVE=C: PATH=C:\Python24;C:\Python24\Scripts;C:\cygwin\bin;C:\WINDOWS\System32;C:\program files\gnuwin32\bin;C:\WINDOWS;C:\mozilla-build\msys\bin;C:\mozilla-build\python27;C:\mozilla-build\python27\Scripts;C:\mozilla-build\info-zip;C:\mozilla-build\wget;C:\Program Files (x86)\GnuWin32\bin; PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC PROCESSOR_ARCHITECTURE=x86 PROCESSOR_IDENTIFIER=x86 Family 6 Model 30 Stepping 5, GenuineIntel PROCESSOR_LEVEL=6 PROCESSOR_REVISION=1e05 PROGRAMDATA=C:\ProgramData PROGRAMFILES=C:\Program Files PROMPT=$P$G PSMODULEPATH=C:\windows\system32\WindowsPowerShell\v1.0\Modules\ PUBLIC=C:\Users\Public PWD=C:\slave\test RUNLOGFILE=C:\slave\\runslave.log SLAVEDIR=C:\slave\ SYSTEMDRIVE=C: SYSTEMROOT=C:\windows TEMP=C:\Users\cltbld\AppData\Local\Temp TEST1=testie TMP=C:\Users\cltbld\AppData\Local\Temp USERDOMAIN=T-W732-IX-084 USERNAME=cltbld USERPROFILE=C:\Users\cltbld WINDIR=C:\windows WINDOWS_TRACING_FLAGS=3 WINDOWS_TRACING_LOGFILE=C:\BVTBin\Tests\installpackage\csilogfile.log XPCOM_DEBUG_BREAK=warn using PTY: False program finished with exit code 0 elapsedTime=0.101000 ========= master_lag: 0.01 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2015-11-09 15:13:43.014325) ========= ========= Started reboot slave lost (results: 0, elapsed: 0 secs) (at 2015-11-09 15:13:43.014638) ========= ========= Finished reboot slave lost (results: 0, elapsed: 0 secs) (at 2015-11-09 15:13:43.751645) ========= ========= Total master_lag: 0.31 =========