taskcluster windows builds never complete due to RecursiveMake call

RESOLVED FIXED

Status

RESOLVED FIXED
2 years ago
3 months ago

People

(Reporter: grenade, Unassigned)

Tracking

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment)

presumably this is caused by a path being treated as if it were on a case sensitive filesystem (it isn't), but i haven't identified which path as yet.

The attached log was taken from the second tc instance running win64 opt here: https://treeherder.mozilla.org/#/jobs?repo=try&revision=6535ebd4cb414e190013abd9589255d3a09065c1

It will probably not be uploaded as it still hasn't completed.
Created attachment 8744384 [details]
log taken from tc worker in recursivemake
great bug!

this seems to be build related, but it could be a side effect of the drive letter case issue, or something similar.

it would be nice to get an idea from one of the build hackers (cc'd some on here) on what might be causing this recusivemake call.

possibly when the logs get posted we might end up with a pattern or idea.
 Build configuration changed. Regenerating backend.

I assume this is related to the drive letter?
The salient bit of that log seems to be: "Build configuration changed. Regenerating backend." Something is going wrong in the dependency calculation here:
https://dxr.mozilla.org/mozilla-central/rev/0891f0fa044cba28024849803e170ed7700e01e0/Makefile.in#116

Comment 5

2 years ago
`mozmake.exe -d` should tell you what's going on. Alternatively, you can "echo $?" in the Makefile to print the list of prerequisites that are newer and triggering this.
Totally possible that this is just the drive letter issue, the backend files contain full paths on my Windows machine:
```
$ head /c/build/debug-x64-mozilla-central/backend.RecursiveMakeBackend.in
c:/build/debug-x64-mozilla-central/_virtualenv/lib/_abcoll.py
c:/build/debug-x64-mozilla-central/_virtualenv/lib/_weakrefset.py
<...>
```
so something like this:
 $(subst .,%,$(BUILD_BACKEND_FILES)):
 	@echo 'Build configuration changed. Regenerating backend.'
+	@echo $?
 	$(PYTHON) config.status
 
 Makefile: $(BUILD_BACKEND_FILES)
 	@$(TOUCH) $@
Flags: needinfo?(gps)

Comment 8

2 years ago
Yeah, I /think/ that will work. Although it may have to be on a rule that has explicit pre-requisites. Make can be finicky.
Flags: needinfo?(gps)
From Joel:

"One thing I noticed was that this build failure is using cl from mozilla-build, not from vs2015u1.  That seemed odd since other cl.exe instances in the log are using:
C:\Users\jmaher\build\src\vs2015u1\VC\bin\amd64_x86\cl.exe

I tried running the command that failed with the proper cl.exe and it complains that vcruntime140.dll is missing.  Searching for it I see it in c:\users\jmaher\build\src\vs2015u1\...  I would have expected the other commands to fail.

A couple thoughts on this:
1) our mozmake trickery executes cl.exe properly, doing it by hand is causing troubles
2) my hack to rerun this by resetting the permissions is causing cl.exe to not find vcruntime140.dll as a read only dll (or the OS is doing something silly)
3) I am doing silly stuff I shouldn't be

I do think the wow_helper directory builds differently than other dirs, it seems to be one of the few spots that we define x86_amd64 in the whole tree:
https://dxr.mozilla.org/mozilla-central/search?q=x86_amd64&redirect=true&case=true

so there must be a reason for all of this"
Joel, I hope you don't mind me moving the conversation here so that we can get a few eyes on the problem.

As I understand it, The parts of the build using cl from outside of tree, are supposed to be limited to the calls that get tooltool up and running and download vs2015u1 and friends. We don't have any other option there because we haven't got the cl used by tree at that point.

the tooltool bits rely on some uncompiled python modules and to make them work, we have a cl installed on the builder. Currently, this is VC for Python (https://github.com/MozRelOps/OpenCloudConfig/blob/master/userdata/Manifest/win2012.json#L248-L255)

Just to make that all work, we have set some environment variables that tell python how to find that CL.

If there are parts of the build system using that cl later, that's not good and we need to find a good point to clear out env settings that would confuse the build.

We also have to install a few other dependencies to support the toolchain. These include vcredist 2010 and 2013. Today I'm experimenting with also including 2015. These are pretty small installers but their inclusion can impact things like the problems you've described.

A full list of every dependency that goes onto these instances when the ami is created is here: https://github.com/MozRelOps/OpenCloudConfig/blob/master/userdata/Manifest/win2012.json
The in-tree mozconfigs adjust PATH and other variables to find vcruntime140.dll (which is at e.g. vs2015u2/VC/redist/x64/Microsoft.VC140.CRT/vcruntime140.dll). If you are calling into the executables from the self-contained tooltool vs2015uX.zip archive, you a) are reinventing the build system/environment and this is highly haphazard b) would need to do something like build/win64/mozconfig.vs2015 to ensure the proper paths are being registered with environment variables.
as a note, I was just calling the magic cl.exe to see if that would work- sounds like my error was more of a red herring vs a real issue.  Thanks for the info gps!
Hey Rob,

How did you get around this in the end in your working manual build?

Pete
Flags: needinfo?(rthijssen)
See https://g3e3heaaaaavi43cf6o53htdlbuadkreplmelezoj5rb7twf.taskcluster-worker.net:60023/log/QbEWI3fGTC6MlHTKC9p4kA for a live example of this happening right now...


19:35:35     INFO -  ===============================
19:35:35     INFO -  Visual Studio Support Available
19:35:35     INFO -  You are building Firefox on Windows. Please help us test the experimental
19:35:35     INFO -  Visual Studio project files (yes, IntelliSense works) by running the
19:35:35     INFO -  following:
19:35:35     INFO -     mach build-backend --backend=VisualStudio
19:35:35     INFO -  ===============================
19:35:35     INFO -  Reticulating splines...
19:35:35     INFO -  Finished reading 2999 moz.build files in 8.53s
19:35:35     INFO -  Processed into 9713 build config descriptors in 5.27s
19:35:35     INFO -  RecursiveMake backend executed in 11.48s
19:35:35     INFO -    2750 total backend files; 2750 created; 0 updated; 0 unchanged; 0 deleted; 68 -> 1028 Makefile
19:35:35     INFO -  FasterMake backend executed in 0.65s
19:35:35     INFO -    11 total backend files; 11 created; 0 updated; 0 unchanged; 0 deleted
19:35:35     INFO -  Total wall time: 28.19s; CPU time: 28.19s; Efficiency: 100%; Untracked: 2.27s
19:35:35     INFO -  Creating config.status
19:35:35     INFO -  mozmake.EXE[2]: Leaving directory 'C:/Users/Task_1462216541/build/src'
19:35:35     INFO -  C:/Users/Task_1462216541/build/src/mozmake.EXE -j8 -C C:/Users/Task_1462216541/build/src/obj-firefox
19:35:35     INFO -  mozmake.EXE[2]: Entering directory 'C:/Users/Task_1462216541/build/src/obj-firefox'
19:35:35     INFO -  Build configuration changed. Regenerating backend.
19:35:35     INFO -  c:/Users/Task_1462216541/build/src/obj-firefox/_virtualenv/Scripts/python.exe config.status
19:36:00     INFO -  ===============================
19:36:00     INFO -  Visual Studio Support Available
19:36:00     INFO -  You are building Firefox on Windows. Please help us test the experimental
19:36:00     INFO -  Visual Studio project files (yes, IntelliSense works) by running the
19:36:00     INFO -  following:
19:36:00     INFO -     mach build-backend --backend=VisualStudio
19:36:00     INFO -  ===============================
19:36:00     INFO -  Reticulating splines...
19:36:00     INFO -  Finished reading 2999 moz.build files in 8.41s
19:36:00     INFO -  Processed into 9713 build config descriptors in 5.26s
19:36:00     INFO -  RecursiveMake backend executed in 9.39s
19:36:00     INFO -    2749 total backend files; 0 created; 1037 updated; 1712 unchanged; 0 deleted; 68 -> 1028 Makefile
19:36:00     INFO -  FasterMake backend executed in 0.63s
19:36:00     INFO -    10 total backend files; 0 created; 6 updated; 4 unchanged; 0 deleted
19:36:00     INFO -  Total wall time: 24.63s; CPU time: 24.63s; Efficiency: 100%; Untracked: 0.94s
19:36:01     INFO -  Build configuration changed. Regenerating backend.
19:36:01     INFO -  c:/Users/Task_1462216541/build/src/obj-firefox/_virtualenv/Scripts/python.exe config.status
19:36:25     INFO -  ===============================
19:36:25     INFO -  Visual Studio Support Available
19:36:25     INFO -  You are building Firefox on Windows. Please help us test the experimental
19:36:25     INFO -  Visual Studio project files (yes, IntelliSense works) by running the
19:36:25     INFO -  following:
19:36:25     INFO -     mach build-backend --backend=VisualStudio
19:36:25     INFO -  ===============================
19:36:26     INFO -  Reticulating splines...
19:36:26     INFO -  Finished reading 2999 moz.build files in 8.43s
19:36:26     INFO -  Processed into 9713 build config descriptors in 5.26s
19:36:26     INFO -  RecursiveMake backend executed in 9.23s
19:36:26     INFO -    2749 total backend files; 0 created; 0 updated; 2749 unchanged; 0 deleted; 68 -> 1028 Makefile
19:36:26     INFO -  FasterMake backend executed in 0.62s
19:36:26     INFO -    10 total backend files; 0 created; 0 updated; 10 unchanged; 0 deleted
19:36:26     INFO -  Total wall time: 24.51s; CPU time: 24.51s; Efficiency: 100%; Untracked: 0.97s
19:36:26     INFO -  Build configuration changed. Regenerating backend.
19:36:26     INFO -  c:/Users/Task_1462216541/build/src/obj-firefox/_virtualenv/Scripts/python.exe config.status
19:36:51     INFO -  ===============================
19:36:51     INFO -  Visual Studio Support Available
19:36:51     INFO -  You are building Firefox on Windows. Please help us test the experimental
19:36:51     INFO -  Visual Studio project files (yes, IntelliSense works) by running the
19:36:51     INFO -  following:
19:36:51     INFO -     mach build-backend --backend=VisualStudio
19:36:51     INFO -  ===============================
19:36:51     INFO -  Reticulating splines...
19:36:51     INFO -  Finished reading 2999 moz.build files in 8.39s
19:36:51     INFO -  Processed into 9713 build config descriptors in 5.25s
19:36:51     INFO -  RecursiveMake backend executed in 9.23s
19:36:51     INFO -    2749 total backend files; 0 created; 0 updated; 2749 unchanged; 0 deleted; 68 -> 1028 Makefile
19:36:51     INFO -  FasterMake backend executed in 0.63s
19:36:51     INFO -    10 total backend files; 0 created; 0 updated; 10 unchanged; 0 deleted
19:36:51     INFO -  Total wall time: 24.50s; CPU time: 24.50s; Efficiency: 100%; Untracked: 1.00s
19:36:51     INFO -  Build configuration changed. Regenerating backend.
19:36:51     INFO -  c:/Users/Task_1462216541/build/src/obj-firefox/_virtualenv/Scripts/python.exe config.status
19:37:16     INFO -  ===============================
19:37:16     INFO -  Visual Studio Support Available
19:37:16     INFO -  You are building Firefox on Windows. Please help us test the experimental
19:37:16     INFO -  Visual Studio project files (yes, IntelliSense works) by running the
19:37:16     INFO -  following:
19:37:16     INFO -     mach build-backend --backend=VisualStudio
19:37:16     INFO -  ===============================
19:37:16     INFO -  Reticulating splines...
19:37:16     INFO -  Finished reading 2999 moz.build files in 8.39s
19:37:16     INFO -  Processed into 9713 build config descriptors in 5.30s
19:37:16     INFO -  RecursiveMake backend executed in 9.12s
19:37:16     INFO -    2749 total backend files; 0 created; 0 updated; 2749 unchanged; 0 deleted; 68 -> 1028 Makefile
19:37:16     INFO -  FasterMake backend executed in 0.61s
19:37:16     INFO -    10 total backend files; 0 created; 0 updated; 10 unchanged; 0 deleted
19:37:16     INFO -  Total wall time: 24.42s; CPU time: 24.42s; Efficiency: 100%; Untracked: 0.99s
19:37:16     INFO -  Build configuration changed. Regenerating backend.
19:37:16     INFO -  c:/Users/Task_1462216541/build/src/obj-firefox/_virtualenv/Scripts/python.exe config.status
19:37:41     INFO -  ===============================
19:37:41     INFO -  Visual Studio Support Available
19:37:41     INFO -  You are building Firefox on Windows. Please help us test the experimental
19:37:41     INFO -  Visual Studio project files (yes, IntelliSense works) by running the
19:37:41     INFO -  following:
19:37:41     INFO -     mach build-backend --backend=VisualStudio
19:37:41     INFO -  ===============================
19:37:41     INFO -  Reticulating splines...
19:37:41     INFO -  Finished reading 2999 moz.build files in 8.41s
19:37:41     INFO -  Processed into 9713 build config descriptors in 5.29s
19:37:41     INFO -  RecursiveMake backend executed in 9.15s
19:37:41     INFO -    2749 total backend files; 0 created; 0 updated; 2749 unchanged; 0 deleted; 68 -> 1028 Makefile
19:37:41     INFO -  FasterMake backend executed in 0.62s
19:37:41     INFO -    10 total backend files; 0 created; 0 updated; 10 unchanged; 0 deleted
19:37:41     INFO -  Total wall time: 24.43s; CPU time: 24.43s; Efficiency: 100%; Untracked: 0.96s
19:37:41     INFO -  Build configuration changed. Regenerating backend.
19:37:41     INFO -  c:/Users/Task_1462216541/build/src/obj-firefox/_virtualenv/Scripts/python.exe config.status
19:38:06     INFO -  ===============================
19:38:06     INFO -  Visual Studio Support Available
19:38:06     INFO -  You are building Firefox on Windows. Please help us test the experimental
19:38:06     INFO -  Visual Studio project files (yes, IntelliSense works) by running the
19:38:06     INFO -  following:
19:38:06     INFO -     mach build-backend --backend=VisualStudio
19:38:06     INFO -  ===============================
19:38:06     INFO -  Reticulating splines...
19:38:06     INFO -  Finished reading 2999 moz.build files in 8.41s
19:38:06     INFO -  Processed into 9713 build config descriptors in 5.23s
19:38:06     INFO -  RecursiveMake backend executed in 9.16s
19:38:06     INFO -    2749 total backend files; 0 created; 0 updated; 2749 unchanged; 0 deleted; 68 -> 1028 Makefile
19:38:06     INFO -  FasterMake backend executed in 0.62s
19:38:06     INFO -    10 total backend files; 0 created; 0 updated; 10 unchanged; 0 deleted
19:38:06     INFO -  Total wall time: 24.40s; CPU time: 24.40s; Efficiency: 100%; Untracked: 0.97s
19:38:06     INFO -  Build configuration changed. Regenerating backend.
19:38:06     INFO -  c:/Users/Task_1462216541/build/src/obj-firefox/_virtualenv/Scripts/python.exe config.status
19:38:31     INFO -  ===============================
19:38:31     INFO -  Visual Studio Support Available
19:38:31     INFO -  You are building Firefox on Windows. Please help us test the experimental
19:38:31     INFO -  Visual Studio project files (yes, IntelliSense works) by running the
19:38:31     INFO -  following:
19:38:31     INFO -     mach build-backend --backend=VisualStudio
19:38:31     INFO -  ===============================
19:38:31     INFO -  Reticulating splines...
19:38:31     INFO -  Finished reading 2999 moz.build files in 8.43s
19:38:31     INFO -  Processed into 9713 build config descriptors in 5.25s
19:38:31     INFO -  RecursiveMake backend executed in 9.14s
19:38:31     INFO -    2749 total backend files; 0 created; 0 updated; 2749 unchanged; 0 deleted; 68 -> 1028 Makefile
19:38:31     INFO -  FasterMake backend executed in 0.62s
19:38:31     INFO -    10 total backend files; 0 created; 0 updated; 10 unchanged; 0 deleted
19:38:31     INFO -  Total wall time: 24.41s; CPU time: 24.41s; Efficiency: 100%; Untracked: 0.97s
19:38:31     INFO -  Build configuration changed. Regenerating backend.
19:38:31     INFO -  c:/Users/Task_1462216541/build/src/obj-firefox/_virtualenv/Scripts/python.exe config.status
19:38:56     INFO -  ===============================
19:38:56     INFO -  Visual Studio Support Available
19:38:56     INFO -  You are building Firefox on Windows. Please help us test the experimental
19:38:56     INFO -  Visual Studio project files (yes, IntelliSense works) by running the
19:38:56     INFO -  following:
19:38:56     INFO -     mach build-backend --backend=VisualStudio
19:38:56     INFO -  ===============================
19:38:56     INFO -  Reticulating splines...
19:38:56     INFO -  Finished reading 2999 moz.build files in 8.43s
19:38:56     INFO -  Processed into 9713 build config descriptors in 5.27s
19:38:56     INFO -  RecursiveMake backend executed in 9.22s
19:38:56     INFO -    2749 total backend files; 0 created; 0 updated; 2749 unchanged; 0 deleted; 68 -> 1028 Makefile
19:38:56     INFO -  FasterMake backend executed in 0.63s
19:38:56     INFO -    10 total backend files; 0 created; 0 updated; 10 unchanged; 0 deleted
19:38:56     INFO -  Total wall time: 24.53s; CPU time: 24.53s; Efficiency: 100%; Untracked: 0.98s
19:38:56     INFO -  Build configuration changed. Regenerating backend.
19:38:56     INFO -  c:/Users/Task_1462216541/build/src/obj-firefox/_virtualenv/Scripts/python.exe config.status
19:39:21     INFO -  ===============================
19:39:21     INFO -  Visual Studio Support Available
19:39:21     INFO -  You are building Firefox on Windows. Please help us test the experimental
19:39:21     INFO -  Visual Studio project files (yes, IntelliSense works) by running the
19:39:21     INFO -  following:
19:39:21     INFO -     mach build-backend --backend=VisualStudio
19:39:21     INFO -  ===============================
19:39:21     INFO -  Reticulating splines...
19:39:21     INFO -  Finished reading 2999 moz.build files in 8.45s
19:39:21     INFO -  Processed into 9713 build config descriptors in 5.31s
19:39:21     INFO -  RecursiveMake backend executed in 9.10s
19:39:21     INFO -    2749 total backend files; 0 created; 0 updated; 2749 unchanged; 0 deleted; 68 -> 1028 Makefile
19:39:21     INFO -  FasterMake backend executed in 0.62s
19:39:21     INFO -    10 total backend files; 0 created; 0 updated; 10 unchanged; 0 deleted
19:39:21     INFO -  Total wall time: 24.45s; CPU time: 24.45s; Efficiency: 100%; Untracked: 0.97s
19:39:21     INFO -  Build configuration changed. Regenerating backend.
19:39:21     INFO -  c:/Users/Task_1462216541/build/src/obj-firefox/_virtualenv/Scripts/python.exe config.status
Trying https://treeherder.mozilla.org/#/jobs?repo=try&revision=cda1260b691c ....

Stole :grenade's fix of adapting PATH from "PATH": "%PATH:C:=c:%" in https://tools.taskcluster.net/task-inspector/#FrJXQ0L9SWW5A3gqu_iqpA/

I'm hoping that should fix it...

Note: this is my own ami definition, not the official one.

My AMI definition: https://github.com/taskcluster/generic-worker/blob/9acb637975eee2685c2dbdcb9d1bf789d433f5cc/worker_types/win2012r2-3/userdata

My task definition:
https://queue.taskcluster.net/v1/task/f__tC98XTU2X4GgnKSto4Q

Combining the AMI definition with the task definition, you have all the combined steps from a fresh Windows Server 2012 R2 installation, through to running the build.
Looks like it wasn't enough to fix it... Nevermind, Rob is back tomorrow, I'll ask him. :)
I don't know what fixed this but a combination of patching reader.py (1), converting C: to c: in env PATH (2), not providing a path to python in the mozharness call (3) and using a lower case drive letter in the workspace path, seem to have stopped this from happening.

1) https://hg.mozilla.org/try/rev/eeb452d5562d10b4de106c418d20a8d4adfccb03#l1.1
2) https://hg.mozilla.org/try/rev/eeb452d5562d10b4de106c418d20a8d4adfccb03#l19.35
3) https://hg.mozilla.org/try/rev/eeb452d5562d10b4de106c418d20a8d4adfccb03#l19.103
4) https://hg.mozilla.org/try/rev/eeb452d5562d10b4de106c418d20a8d4adfccb03#l19.36
Status: NEW → RESOLVED
Last Resolved: 2 years ago
Flags: needinfo?(rthijssen)
Resolution: --- → FIXED
(Assignee)

Updated

3 months ago
Component: General Automation → General
Product: Release Engineering → Release Engineering
You need to log in before you can comment on or make changes to this bug.