Closed Bug 1259532 Opened 8 years ago Closed 7 years ago

Unzipping vs2015u1.zip from tooltool takes 5+ minutes, times out

Categories

(Release Engineering :: General, defect)

Product:
Release Engineering
Component:
General
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED WORKSFORME

People

(Reporter: gps, Unassigned)

References

Details

On Try, unzipping vs2015u1.zip from tooltool appears to take <20s seconds:

(from http://archive.mozilla.org/pub/firefox/try-builds/gszorc@mozilla.com-0194c65dd2f23930c79bf14ea1fc3b4cb7aa9844/try-win32/try-win32-bm78-try1-build4738.txt.gz)
09:12:51     INFO -  Executing: ['c:\\mozilla-build\\python27\\python.exe', 'C:/mozilla-build/tooltool.py', '--authentication-file', 'c:\\builds\\relengapi.tok', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--overwrite', '-m', 'c:\\builds\\moz2_slave\\try-w32-0000000000000000000000\\build\\src\\browser/config/tooltool-manifests/win32/releng.manifest', 'fetch']
09:12:51     INFO -  INFO - Attempting to fetch from 'https://api.pub.build.mozilla.org/tooltool/'...
09:12:54     INFO -  INFO - File mozmake.exe fetched from https://api.pub.build.mozilla.org/tooltool/ as c:\builds\moz2_slave\try-w32-0000000000000000000000\build\src\tmpffc7au
09:12:54     INFO -  INFO - Attempting to fetch from 'https://api.pub.build.mozilla.org/tooltool/'...
09:12:56     INFO -  INFO - File rustc-beta-i686-pc-windows-msvc.tar.bz2 fetched from https://api.pub.build.mozilla.org/tooltool/ as c:\builds\moz2_slave\try-w32-0000000000000000000000\build\src\tmphtlrk1
09:12:56     INFO -  INFO - Attempting to fetch from 'https://api.pub.build.mozilla.org/tooltool/'...
09:12:57     INFO -  INFO - File sccache.tar.bz2 fetched from https://api.pub.build.mozilla.org/tooltool/ as c:\builds\moz2_slave\try-w32-0000000000000000000000\build\src\tmpy6z9bg
09:12:57     INFO -  INFO - Attempting to fetch from 'https://api.pub.build.mozilla.org/tooltool/'...
09:13:10     INFO -  INFO - File vs2015u1.zip fetched from https://api.pub.build.mozilla.org/tooltool/ as c:\builds\moz2_slave\try-w32-0000000000000000000000\build\src\tmpmx7z0m
09:13:10     INFO -  INFO - File integrity verified, renaming tmpffc7au to mozmake.exe
09:13:11     INFO -  INFO - File integrity verified, renaming tmphtlrk1 to rustc-beta-i686-pc-windows-msvc.tar.bz2
09:13:11     INFO -  INFO - File integrity verified, renaming tmpy6z9bg to sccache.tar.bz2
09:13:12     INFO -  INFO - File integrity verified, renaming tmpmx7z0m to vs2015u1.zip
09:13:12     INFO -  INFO - untarring "rustc-beta-i686-pc-windows-msvc.tar.bz2"
09:13:22     INFO -  INFO - untarring "sccache.tar.bz2"
09:13:22     INFO -  INFO - unzipping "vs2015u1.zip"
09:13:39     INFO - Return code: 0
09:13:39     INFO - Copying c:\builds\moz2_slave\try-w32-0000000000000000000000\buildprops.json to c:\builds\moz2_slave\try-w32-0000000000000000000000\build\buildprops.json

However, an inbound job takes several minutes:

(from http://archive.mozilla.org/pub/firefox/tinderbox-builds/mozilla-inbound-win32/1458836034/mozilla-inbound-win32-bm72-build1-build437.txt.gz)
09:36:49     INFO -  Executing: ['c:\\mozilla-build\\python27\\python.exe', 'C:/mozilla-build/tooltool.py', '--authentication-file', 'c:\\builds\\relengapi.tok', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--overwrite', '-m', 'c:\\builds\\moz2_slave\\m-in-w32-000000000000000000000\\build\\src\\browser/config/tooltool-manifests/win32/releng.manifest', 'fetch']
09:36:49     INFO -  INFO - Attempting to fetch from 'https://api.pub.build.mozilla.org/tooltool/'...
09:36:49     INFO -  INFO - File mozmake.exe fetched from https://api.pub.build.mozilla.org/tooltool/ as c:\builds\moz2_slave\m-in-w32-000000000000000000000\build\src\tmpdvygn_
09:36:49     INFO -  INFO - Attempting to fetch from 'https://api.pub.build.mozilla.org/tooltool/'...
09:36:51     INFO -  INFO - File rustc-beta-i686-pc-windows-msvc.tar.bz2 fetched from https://api.pub.build.mozilla.org/tooltool/ as c:\builds\moz2_slave\m-in-w32-000000000000000000000\build\src\tmpiezeh3
09:36:56     INFO -  INFO - Attempting to fetch from 'https://api.pub.build.mozilla.org/tooltool/'...
09:36:57     INFO -  INFO - File sccache.tar.bz2 fetched from https://api.pub.build.mozilla.org/tooltool/ as c:\builds\moz2_slave\m-in-w32-000000000000000000000\build\src\tmpqqwv46
09:36:57     INFO -  INFO - Attempting to fetch from 'https://api.pub.build.mozilla.org/tooltool/'...
09:37:14     INFO -  INFO - File vs2015u1.zip fetched from https://api.pub.build.mozilla.org/tooltool/ as c:\builds\moz2_slave\m-in-w32-000000000000000000000\build\src\tmpah2tiy
09:37:14     INFO -  INFO - File integrity verified, renaming tmpdvygn_ to mozmake.exe
09:37:14     INFO -  INFO - File integrity verified, renaming tmpiezeh3 to rustc-beta-i686-pc-windows-msvc.tar.bz2
09:37:14     INFO -  INFO - File integrity verified, renaming tmpqqwv46 to sccache.tar.bz2
09:37:23     INFO -  INFO - File integrity verified, renaming tmpah2tiy to vs2015u1.zip
09:37:30     INFO -  INFO - untarring "rustc-beta-i686-pc-windows-msvc.tar.bz2"
09:38:40     INFO -  INFO - untarring "sccache.tar.bz2"
09:38:47     INFO -  INFO - unzipping "vs2015u1.zip"
09:41:49     INFO -  WARNING: Timeout (300) exceeded, killing process 708
09:43:05     INFO -  retry: Calling <function run_with_timeout at 0x028DEC70> with args: (['c:\\mozilla-build\\python27\\python.exe', 'C:/mozilla-build/tooltool.py', '--authentication-file', 'c:\\builds\\relengapi.tok', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--overwrite', '-m', 'c:\\builds\\moz2_slave\\m-in-w32-000000000000000000000\\build\\src\\browser/config/tooltool-manifests/win32/releng.manifest', 'fetch'], 300, None, None, False, True), kwargs: {}, attempt #2
09:43:05     INFO -  Executing: ['c:\\mozilla-build\\python27\\python.exe', 'C:/mozilla-build/tooltool.py', '--authentication-file', 'c:\\builds\\relengapi.tok', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--overwrite', '-m', 'c:\\builds\\moz2_slave\\m-in-w32-000000000000000000000\\build\\src\\browser/config/tooltool-manifests/win32/releng.manifest', 'fetch']
09:43:07     INFO -  INFO - untarring "rustc-beta-i686-pc-windows-msvc.tar.bz2"
09:43:16     INFO -  INFO - rm tree: sccache
09:43:39     INFO -  INFO - untarring "sccache.tar.bz2"
09:43:39     INFO -  INFO - rm tree: vs2015u1
09:43:43     INFO -  INFO - unzipping "vs2015u1.zip"
09:44:08     INFO - Return code: 0
09:44:08     INFO - mkdir: c:\builds\moz2_slave\m-in-w32-000000000000000000000\.mozbuild
09:44:08     INFO - Copying c:\builds\moz2_slave\m-in-w32-000000000000000000000\buildprops.json to c:\builds\moz2_slave\m-in-w32-000000000000000000000\build\buildprops.json

I'm not sure why the drastic difference. Does the Try builder have the contents of that archive cached locally?

I know there is at least one other bug tracking tooltool archive extraction performance. This /might/ be a dupe.
This very long decompression time seems to be an outlier. Other Windows jobs on inbound are doing the work much faster. Weird.
Summary: Unzipping vs2015u1.zip from tooltool takes 5+ minutes, times out on inbound (but not Try) → Unzipping vs2015u1.zip from tooltool takes 5+ minutes, times out on inbound
Summary: Unzipping vs2015u1.zip from tooltool takes 5+ minutes, times out on inbound → Unzipping vs2015u1.zip from tooltool takes 5+ minutes, times out
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → WORKSFORME
Component: General Automation → General
You need to log in before you can comment on or make changes to this bug.