MSBuild can report the wrong assembly path when loading a task

[jkeech]

MSBuild diagnostic logs report that a task was loaded from an assembly at a specific path, but the task can be loaded from a different assembly if that assembly is found in DEVPATH first. It appears that MSBuild is not taking DEVPATH into consideration, so it assumes the assembly location is going to be the relative to the directory of the project file that has the declaration. I believe the exact code in question can be seen here. I ended up spending a couple hours investigating why I was getting a certain build error because I assumed that the path listed in the logs was accurate. I only discovered it was wrong after exhausting all other possibilities and turning on fusion logging to confirm.

Details/example:
I’m using a packaged version of msbuild which contains msbuild.exe and the targets/tasks. MSBuild.exe lives at E:\packages\MsBuild\v14.0\Bin\MSBuild.exe, and E:\packages\MsBuild\v14.0\Bin\Microsoft.Common.tasks contains:

<UsingTask TaskName="Microsoft.CodeAnalysis.BuildTasks.Vbc" AssemblyFile="Microsoft.Build.Tasks.CodeAnalysis.dll" Condition="'$(MSBuildAssemblyVersion)' != ''" />

E:\packages\MsBuild\v14.0\Bin\Microsoft.Build.Tasks.CodeAnalysis.dll is the expected file where the Vbc task lives, and the MSBuild diagnostic log says that it is using the assembly from that location:

Using "Vbc" task from assembly "e:\packages\MsBuild\v14.0\bin\Microsoft.Build.Tasks.CodeAnalysis.dll".

Unfortunately, due to DEVPATH being set up in my environment, the dll is actually loaded from a different location, and msbuild ends up reporting the wrong path. Fusion logs:

*** Assembly Binder Log Entry  (4/19/2016 @ 2:59:40 PM) ***

The operation was successful.
Bind result: hr = 0x0. The operation completed successfully.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
Running under executable  e:\packages\MsBuild\v14.0\bin\MSBuild.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: Where-ref bind. Location = e:\packages\MsBuild\v14.0\bin\Microsoft.Build.Tasks.CodeAnalysis.dll
LOG: Appbase = file:///e:/packages/MsBuild/v14.0/bin/
LOG: DEVPATH = D:\customDevPath;
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = MSBuild.exe
Calling assembly : (Unknown).
===
LOG: This bind starts in LoadFrom load context.
WRN: Native image will not be probed in LoadFrom context. Native image will only be probed in default load context, like with Assembly.Load().
LOG: Using application configuration file: e:\packages\MsBuild\v14.0\bin\MSBuild.exe.Config
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework\v4.0.30319\config\machine.config.
LOG: Found assembly in DEVOVERRIDE path D:\customDevPath\Microsoft.Build.Tasks.CodeAnalysis.DLL
LOG: Switch from LoadFrom context to default context.

[rainersigwald]

I looked into this a long time ago but evidently never reported back.

The problem is that we log where we will try to load the assembly from,

https://github.com/Microsoft/msbuild/blob/647bd0fa090e7518245ab2b86601aef92c6724ec/src/Build/Instance/TaskRegistry.cs#L430

https://github.com/Microsoft/msbuild/blob/6851538897f5d7b08024a6d8435bc44be5869e53/src/Build/Instance/TaskFactories/AssemblyTaskFactoryInstance.cs#L68-L75

before it's loaded

https://github.com/Microsoft/msbuild/blob/6851538897f5d7b08024a6d8435bc44be5869e53/src/Build/Instance/TaskFactories/AssemblyTaskFactoryInstance.cs#L145-L150

and the loader has a complex set of behaviors that sometimes does something else entirely.

I don't remember the details but it was painful to change the logging to happen only after the load. That's the right thing to do, though--report the path of the assembly that the loaded, in-memory type reports.

[clisc]

I may have a repro of this. I want to confirm this is the same issue.

I'm trying to load a DLL which can't be found. I enabled Fusion logging and found that it was not in any of the DEVPATH search paths. I don't want to load it from the GAC, so I'm not concerned I can't find it there. The missing assembly is Microsoft.VisualStudio.CodeAnalysis.Sdk.dll. This is causing build failures when Code Analysis is enabled in the command prompt MSBuild (not in VS IDE).

The path where the DLL is located is here:

F:\CoreXtCache\.A\MsBuild.Corext._zhIG90VQlM6jUBQEd5j0Q\Extensions\Microsoft\VisualStudio\v15.0\CodeAnalysis

I added the path where the DLL is and confirmed in the MSBuild detailed log that the property was changed:

Property reassignment: $(DEVPATH)=";F:\CoreXtCache\.A\MsBuild.Corext._zhIG90VQlM6jUBQEd5j0Q\v15.0\bin;F:\CoreXtCache\.A\MsBuild.Corext._zhIG90VQlM6jUBQEd5j0Q\Extensions\Override\etc\TaskCopy;F:\CoreXtCache\VisualStudio.Sdk.Corext.14.0.23107.3\IDE;F:\CoreXtCache\.A\MsBuild.Corext._zhIG90VQlM6jUBQEd5j0Q\Extensions\Microsoft\VisualStudio\v15.0\CodeAnalysis" (previous value: ";F:\CoreXtCache\.A\MsBuild.Corext._zhIG90VQlM6jUBQEd5j0Q\v15.0\bin;F:\CoreXtCache\.A\MsBuild.Corext._zhIG90VQlM6jUBQEd5j0Q\Extensions\Override\etc\TaskCopy;F:\CoreXtCache\VisualStudio.Sdk.Corext.14.0.23107.3\IDE") at F:\DS_Main\Tools\scopas\Extensions\Scopas.CSharp.props (67,5)

However, the Extensions subfolder goes missing from the path by the time it gets to Fusion:

LOG: Did not find assembly in DEVOVERRIDE path F:\CoreXtCache\.A\MsBuild.Corext._zhIG90VQlM6jUBQEd5j0Q\v15.0\bin
LOG: Did not find assembly in DEVOVERRIDE path F:\CoreXtCache\.A\MsBuild.Corext._zhIG90VQlM6jUBQEd5j0Q\Extensions\Override\etc\TaskCopy
LOG: Did not find assembly in DEVOVERRIDE path F:\CoreXtCache\VisualStudio.Sdk.Corext.14.0.23107.3\IDE
LOG: GAC Lookup was unsuccessful.
LOG: Attempting download of new URL file:///F:/CoreXtCache/.A/MsBuild.Corext._zhIG90VQlM6jUBQEd5j0Q/Microsoft/VisualStudio/v15.0/CodeAnalysis/Microsoft.VisualStudio.CodeAnalysis.Sdk.dll.
LOG: All probing URLs attempted and failed.

Is this related to this issue or is this something different entirely?

[jkeech]

@clisc, I think your issue is different. I suspect this is because you are only updating the DEVPATH property in MSBuild, not actually updating the environment variable which the CLR is looking at. You'll need to figure out which process is trying to load that assembly and then make sure that process is spawned with an environment block containing the values you want.

[clisc]

Thanks, this will probably help me fix the issue from another angle. I have some questions though: 1. Is DEVPATH not designed to be used as an MSBUILD property? 2. If not, why would it still recognize my path? 3. Finally, since it did recognize my path, why would it modify it and cut one of the subdirectories out? Seems like very odd behavior. In the meantime, I’ll run with your suggestion and modify the environment variable instead. Thanks, Cliff

[jkeech]

@clisc, DEVPATH is not an MSBuild feature -- it is a .NET/CLR feature. Here's some documentation about it: https://docs.microsoft.com/en-us/dotnet/framework/configure-apps/how-to-locate-assemblies-by-using-devpath. In general, DEVPATH causes a bunch of problems (such as not respecting assembly version), so it's not recommended to use in most circumstances.

[clisc]

Great thanks!