DDC generation fails for 4.27.0 on Windows due to opencv_world311.dll missing dependencies

[CanisHelix]

ue4-docker version:         0.0.89 (latest available version is 0.0.89)
Operating system:           Windows Server 2019 Standard (Build 17763.1935)
Docker daemon version:      20.10.5
NVIDIA Docker supported:    No
Maximum image size:         400GB
Available disk space:       644.51 GiB
Total system memory:        16 GiB physical, 36 GiB virtual
Number of processors:       9 physical, 18 logical

Additional details:

• Are you accessing the network through a proxy server? No

Command Used:
ue4-docker build 4.27.0 --visual-studio=2019 --no-engine --exclude debug --exclude templates --monitor

Initial Build Log:

[ue4-docker build] COMMAND-LINE INVOCATION:
[ue4-docker build] ['ue4-docker', '4.27.0', '--visual-studio=2019', '--no-engine', '--exclude', 'debug', '--exclude', 'templates', '--monitor', '-username', 'CanisHelix', '-password', '*******', '--verbose']

[ue4-docker build] UNREAL ENGINE VERSION SETTINGS:
[ue4-docker build] Custom build:  No
[ue4-docker build] Release:       4.27.0
[ue4-docker build] Repository:    https://github.com/EpicGames/UnrealEngine.git
[ue4-docker build] Branch/tag:    4.27.0-release

[ue4-docker build] ADVANCED CONFIGURATION OPTIONS:
[ue4-docker build] buildgraph_args: " -set:VS2019=true"
[ue4-docker build] excluded_components: {"ddc": false, "debug": true, "templates": true}

[ue4-docker build] WINDOWS CONTAINER SETTINGS
[ue4-docker build] Isolation mode:               process
[ue4-docker build] Base OS image:                mcr.microsoft.com/windows/servercore:ltsc2019
[ue4-docker build] Dll source image:             mcr.microsoft.com/windows:1809
[ue4-docker build] Host OS:                      Windows Server 2019 Standard (Build 17763.1935)
[ue4-docker build] Memory limit:                 No limit
[ue4-docker build] Detected max image size:      400GB
[ue4-docker build] Visual Studio:                2019
[ue4-docker build] GENERAL SETTINGS
[ue4-docker build] Excluding the following Engine components:
[ue4-docker build] - Debug symbols
[ue4-docker build] - Template projects and samples

It fails after an overnight build with the final log of

  Generating DDC data for TP_InCamVFXBP on Windows+WindowsNoEditor
  Running UE4Editor DerivedDataCache for project C:\UnrealEngine\Templates\TP_InCamVFXBP\TP_InCamVFXBP.uproject
  Commandlet log file is C:\UnrealEngine\Engine\Programs\AutomationTool\Saved\DerivedDataCache-2021.09.02-07.15.25.txt
  Running: C:\UnrealEngine\LocalBuilds\InstalledDDC\Engine\Binaries\Win64\UE4Editor-Cmd.exe C:\UnrealEngine\Templates\TP_InCamVFXBP\TP_InCamVFXBP.uproject -run=DerivedDataCache  -TargetPlatform=Windows+WindowsNoEditor -fill -DDC=CreateInstalledEnginePak -ProjectOnly -abslog=C:\UnrealEngine\Engine\Programs\AutomationTool\Saved\DerivedDataCache-2021.09.02-07.15.25.txt -stdout -CrashForUAT -unattended -NoLogTimes
    LogConsoleResponse: Display: Failed to find resolution value strings in scalability ini. Falling back to default.
    LogConsoleResponse: Display: Failed to find resolution value strings in scalability ini. Falling back to default.
    LogInit: Display: Running engine for game: TP_InCamVFXBP
    LogInit: Display: Loading text-based GConfig....
    LogWindows: Error: begin: stack for UAT
    LogWindows: Error: === Critical error: ===
    LogWindows: Error:
    LogWindows: Error: Fatal error!
    LogWindows: Error:
    LogWindows: Error: Unhandled Exception: 0xc06d007e
    LogWindows: Error:
    LogWindows: Error: [Callstack] 0x00007ffa563b9689 KERNELBASE.dll!UnknownFunction []
    LogWindows: Error: [Callstack] 0x00007ffa331b515a UE4Editor-OpenCVHelper.dll!__delayLoadHelper2() [d:\a01\_work\2\s\src\vctools\delayimp\delayhlp.cpp:312]
    LogWindows: Error: [Callstack] 0x00007ffa331b461d UE4Editor-OpenCVHelper.dll!_tailMerge_opencv_world331_dll() []
    LogWindows: Error: [Callstack] 0x00007ffa331b4096 UE4Editor-OpenCVHelper.dll!FOpenCVHelperModule::StartupModule() [C:\UnrealEngine\Engine\Plugins\Compositing\OpenCVLensDistortion\Source\OpenCVHelper\Private\OpenCVHelperModule.cpp:91]
    LogWindows: Error: [Callstack] 0x00007ffa46336c22 UE4Editor-Core.dll!FModuleManager::LoadModuleWithFailureReason() [C:\UnrealEngine\Engine\Source\Runtime\Core\Private\Modules\ModuleManager.cpp:538]
    LogWindows: Error: [Callstack] 0x00007ffa4c6261b3 UE4Editor-Projects.dll!FModuleDescriptor::LoadModulesForPhase() [C:\UnrealEngine\Engine\Source\Runtime\Projects\Private\ModuleDescriptor.cpp:643]
    LogWindows: Error: [Callstack] 0x00007ffa4c63c5ea UE4Editor-Projects.dll!FPluginManager::TryLoadModulesForPlugin() [C:\UnrealEngine\Engine\Source\Runtime\Projects\Private\PluginManager.cpp:1450]
    LogWindows: Error: [Callstack] 0x00007ffa4c625f30 UE4Editor-Projects.dll!FPluginManager::LoadModulesForEnabledPlugins() [C:\UnrealEngine\Engine\Source\Runtime\Projects\Private\PluginManager.cpp:1525]
    LogWindows: Error: [Callstack] 0x00007ff68b217baf UE4Editor-Cmd.exe!FEngineLoop::AppInit() [C:\UnrealEngine\Engine\Source\Runtime\Launch\Private\LaunchEngineLoop.cpp:5655]
    LogWindows: Error: [Callstack] 0x00007ff68b22e2d4 UE4Editor-Cmd.exe!FEngineLoop::PreInitPreStartupScreen() [C:\UnrealEngine\Engine\Source\Runtime\Launch\Private\LaunchEngineLoop.cpp:2224]
    LogWindows: Error: [Callstack] 0x00007ff68b220d37 UE4Editor-Cmd.exe!GuardedMain() [C:\UnrealEngine\Engine\Source\Runtime\Launch\Private\Launch.cpp:132]
    LogWindows: Error: [Callstack] 0x00007ff68b2210ea UE4Editor-Cmd.exe!GuardedMainWrapper() [C:\UnrealEngine\Engine\Source\Runtime\Launch\Private\Windows\LaunchWindows.cpp:137]
    LogWindows: Error: [Callstack] 0x00007ff68b22410d UE4Editor-Cmd.exe!LaunchWindowsStartup() [C:\UnrealEngine\Engine\Source\Runtime\Launch\Private\Windows\LaunchWindows.cpp:273]
    LogWindows: Error: [Callstack] 0x00007ff68b2354b4 UE4Editor-Cmd.exe!WinMain() [C:\UnrealEngine\Engine\Source\Runtime\Launch\Private\Windows\LaunchWindows.cpp:320]
    LogWindows: Error: [Callstack] 0x00007ff68b2373e2 UE4Editor-Cmd.exe!__scrt_common_main_seh() [d:\a01\_work\2\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl:288]
    LogWindows: Error: [Callstack] 0x00007ffa624c7974 KERNEL32.DLL!UnknownFunction []
    LogWindows: Error: [Callstack] 0x00007ffa7051a2f1 ntdll.dll!UnknownFunction []
    LogWindows: Error:
    LogWindows: Error: end: stack for UAT
[ue4-docker build] [2021-09-02 07:15:29] [Available disk: 644.56 GiB] [Available memory: 12.61 GiB physical, 32.52 GiB virtual] [CPU usage: 22.90%]
  Took 4.182265s to run UE4Editor-Cmd.exe, ExitCode=3
  Editor terminated with exit code 3 while running DerivedDataCache for C:\UnrealEngine\Templates\TP_InCamVFXBP\TP_InCamVFXBP.uproject; see log C:\UnrealEngine\Engine\Programs\AutomationTool\Saved\Logs\BuildDerivedDataCache\DerivedDataCache-2021.09.02-07.15.29.txt
  AutomationTool exiting with ExitCode=1 (Error_Unknown)
Took 3475.0161021s to run AutomationTool.EXE, ExitCode=1
AutomationTool exiting with ExitCode=1 (Error_Unknown)
BUILD FAILED

I am re-building now after cleaning all images again with a pipe to build.log so that I can capture a full error log with the verbose option.

I have manually implemented #195 in order to progress this far due previous failure, all images were cleaned after implementing the PR to ensure clean images.

[CanisHelix]

Repeated and replicated. Attaching full pipe out buid.log

build.log

[TBBle]

Apparently this is "module not found", and a poke at FOpenCVHelperModule::StartupModule suggests it failed loading opencv_world331.dll or one of its dependencies.

The DLL shouldn't have changed between 4.26 and 4.27, but OpenCVHelperModule.cpp did; in fact, the new code comes into effect on line 91, so perhaps cv::unreal::SetMallocAndFree is triggering some code in opencv_world331.dll which tries to on-demand load some other DLL, and it's missing from our container, and hence barfing.

Actually, the relevant change (fabe0dbb438b80de06385ebf36b529bbf36e55f2 in Unreal Engine on GitHub, CL 16620921) did update the opencv_world311.dll without renaming it, so maybe worth checking the DLL dependency chain for that library in UE 4.26 and UE 4.27 in case we need to add a new DLL to the copied-DLL list.

[slonopotamus]

Offtop: @CanisHelix even if this gets fixed you will want to run ue4-docker with --exclude debug because of #99. Just saving you another 4 hours on the next run)

[CanisHelix]

@slonopotamus As you can see I used that already, no choice with windows anyway in the original post.

ue4-docker build 4.27.0 --visual-studio=2019 --no-engine --exclude debug --exclude templates --monitor

But, just an update running with --exclude ddc in addition to the above allows this step to process and finishes all the way to building the ue4-full image.

[slonopotamus]

Oh, sorry, I've inverted true/false in excluded_components somehow.

Yeah, --exclude ddc should be OK as a workaround for now.

[slonopotamus]

I'm not sure that the problem is in 4.26 -> 4.27 move. These deps look identical.

However, ue4-docker-prerequisites is missing avifil32.dll. I wonder if it is a regression or it never had one.

[slonopotamus]

Internets say we might also need:

avicap32.dll
avifil32.dll
msacm32.dll
msvfw32.dll

We're missing avifil32.dll and msacm32.dll from this list.

[TBBle]

Those are core Windows files, so I can't see how any other variations (Visual Studio, Windows SDK) would have changed their presence.

Another reference concurs that these files are not normally in the Server Core container image (although that's ltsc2016 era).

[slonopotamus]

I'm looking into ue4-build-prerequisites:ltsc2019-vs2019 and it neither has C:\Windows\system32\avifil32.dll nor C:\Windows\system32\msacm32.dll.

[TBBle]

Hmm. Before #187 we weren't copying any of the V4W (or Media Foundation) DLLs explicitly from the host. So either we never had them, or they were coming from somewhere else implicitly and we were picking up more from that mechanism than the explicit list we have now.

Either way, seems like an easy fix to just add those DLLs to the copy list. They're core components shipped with Windows, so they shouldn't be missing from the host.

[slonopotamus]

Here's what was copied before #187 from host: https://github.com/adamrehn/ue4-docker/pull/187/files#diff-d82b5260e32a8382b1f0fa3045572374766e152bb6063bf6ef9e31bbbeb5baebL35-L44

		common = ['dsound.dll', 'opengl32.dll', 'glu32.dll']
		return ['ddraw.dll'] + common if basetag == 'ltsc2016' else common

[TBBle]

That's my point. avicap32.dll and msvfw32.dll aren't in that list either. and supposedly aren't in the servercore image, but we weren't having this problem with 4.26.

[slonopotamus]

I'm currently downloading and older ue4-build-prerequisites (it is even pre-VS2019 support, built somewhere around commit 6d2a8ee) to check whether avifil32.dll/msvfw32.dll were there...

UPD: they weren't.

[slonopotamus]

It might end in something like "that OpenCVLensDistortion plugin always broken in ue4-docker and we only noticed that now because 4.27 added TP_InCamVFXBP template project that tries to load OpenCVLensDistortion".

[TBBle]

The other possibility is that these files have always been missing, but 4.27.0 changed behaviour and crashes when the OpenCV runtime fails to load, where previously, it would error and continue on.

That's probably what happened, looking at a44e2327dcee0645765267963fdd526fcd1bba36 (CL 16620946) in 4.27. The new call to cv::unreal::SetMallocAndFree in FOpenCVHelperModule::StartupModule is not protected by a check of OpenCvDllHandle, and fails if the DLL failed to load. The existing use of that pointer is checked before calling.

cv::unreal::SetMallocAndFree is implicitly referencing the DLL symbols, so I suspect that inside the container, any use of OpenCV would have had the same issue. This is the line number in the crash, too, so I'm pretty confident that's the reason it's now failing.

So I think this is a bug in that new UE4 code in FOpenCVHelperModule::StartupModule, but it only replicates if OpenCV fails to load, which might not be a supported scenario since it depends on Windows core components? Maybe worth flicking up to them to resolve for future though.

[slonopotamus]

Blind fix: #198. My Windows build machines are a bit occupied currently, so it will take several days before I can test that it actually fixes the problem.

[TBBle]

Thinking about this, the core issue is that the Epic code here is mixing two different styles of DLL usage: They're explicitly loading the DLL and getting the handle pointer, but all their actual OpenCV API access (including the custom cv::unreal::SetMallocAndFree API that as of 4.27 is being called in StartupModule) is doing delay-loaded lazy symbol resolution.

It would be less bug-prone if they picked one or the other, either explicitly loading the DLL and using GetProcAddress to populate function pointers (which would enforce checking the module pointer any of the APIs could be called), or using only delay-loading and correctly implementing the "Failed to delay-load" hook that's currently raising an exception in __delayLoadHelper2 in the absence of a failure hook.

[jlsalmon]

I've just run into this while building 5.0.0-release (right at the end of a 16+ hour build). I'd really like to get a build with DDC, is there any way I can disable either the OpenCV plugin or the sample code that uses it, without having to use --exclude ddc? 🙏

[slonopotamus]

Are you sure you run into this? This was fixed in #198. Note that there also was edcedca (released in ue4-docker 0.0.97), specifically targeted at fixing DDC generation for UE-5.0.

[jlsalmon]

Ah, I missed that commit, thanks for the heads up @slonopotamus! I was using v0.0.96, I'll try with 0.0.97 🤞

[jlsalmon]

Can confirm, edcedca fixes my issue.