Update-ApplicationSubmission fails in PowerShell Core 6.2+

[riverar]

Windows 10 1909 18363.418 PSVersion 6.2.0 StoreBroker 1.19.1

2019-10-27 11:29:55 : Rafael : Successfully cloned the existing submission and modified its content.
You can view it on the Dev Portal here:
    https://dev.windows.com/en-us/dashboard/apps/APPID_REDACTED/submissions/SUBMISSION_ID_REDACTED/
or by running this command:
    Get-ApplicationSubmission -AppId APPID_REDACTED -SubmissionId SUBMISSION_ID_REDACTED | Format-ApplicationSubmission

PLEASE NOTE: Due to the nature of how the Store API works, you won't see any of your changes in the
Dev Portal until your submission has entered into certification.  It doesn't have to *complete*
certification for you to see your changes, but it does have to enter certification first.
If it's important for you to verify your changes in the Dev Portal prior to publishing,
consider publishing with the "Manual" targetPublishMode by setting that value in your
config file and then additionally specifying the -UpdatePublishModeAndVisibility switch
when calling Update-ApplicationSubmission, or by specifying the
-TargetPublishMode Manual parameter when calling Update-ApplicationSubmission.
VERBOSE: 2019-10-27 11:29:55 : Rafael : Uploading the package [.\pdp_out\Package.zip] since it was provided.
VERBOSE: 2019-10-27 11:29:55 : Rafael : Executing:             Set-SubmissionPackage -PackagePath $PackagePath -UploadUrl $uploadUrl -NoStatus:$NoStatus

VERBOSE: 2019-10-27 11:29:55 : Rafael : Attempting to upload the package (C:\users\rafael\desktop\pdp_out\Package.zip) for the submission to https://ingestionpackagesprod1.blob.core.windows.net/ingestion/INGEST_GUID_REDACTED?sv=2017-04-17&sr=b&sig=1ZNuQISE9HIk1Bo5PeUcI3vKCPJgoUyebBDljgJxRGI%3D&se=2019-10-28T18:44:41Z&sp=rwl...
VERBOSE: 2019-10-27 11:29:55 : Rafael : Looking for Microsoft.WindowsAzure.Storage.dll
VERBOSE: 2019-10-27 11:29:55 : Rafael : Found Microsoft.WindowsAzure.Storage.dll in temp directory (C:\Users\Rafael\AppData\Local\Temp\TEMP_GUID_REDACTED).
VERBOSE: 2019-10-27 11:29:55 : Rafael : Looking for Microsoft.WindowsAzure.Storage.DataMovement.dll
VERBOSE: 2019-10-27 11:29:55 : Rafael : Found Microsoft.WindowsAzure.Storage.DataMovement.dll in temp directory (C:\Users\Rafael\AppData\Local\Temp\TEMP_GUID_REDACTED).
DONE - Operation took 0 second(s) [Uploading C:\users\rafael\desktop\pdp_out\Package.zip]
VERBOSE: 2019-10-27 11:29:56 : Rafael : Telemetry has been disabled via $global:SBDisableTelemetry. Skipping reporting event.
Write-Log : 2019-10-27 11:29:56 : Rafael : The following exception occurred while retrieving member "UploadAsync": "Could not load file or assembly 'Microsoft.WindowsAzure.Storage, Version=8.1.1.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35'. The system cannot find the file specified."
At C:\Users\Rafael\Documents\PowerShell\Modules\StoreBroker\StoreBroker\StoreBroker\StoreIngestionApi.psm1:917 char:9
+         Write-Log -Message $newLineOutput -Level Error
+         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo          : NotSpecified: (:) [Write-Error], WriteErrorException
+ FullyQualifiedErrorId : Microsoft.PowerShell.Commands.WriteErrorException,Write-Log

Write-Log : 2019-10-27 11:29:56 : Rafael : The following exception occurred while retrieving member "UploadAsync": "Could not load file or assembly 'Microsoft.WindowsAzure.Storage, Version=8.1.1.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35'. The system cannot find the file specified."
At C:\Users\Rafael\Documents\PowerShell\Modules\StoreBroker\StoreBroker\StoreBroker\StoreIngestionApi.psm1:918 char:9
+         throw $newLineOutput
+         ~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo          : OperationStopped: (The following excep\u2026he file specified.":String) [], RuntimeException
+ FullyQualifiedErrorId : The following exception occurred while retrieving member "UploadAsync": "Could not load file or assembly 'Microsoft.WindowsAzure.Storage, Version=8.1.1.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35'. The system cannot find the file specified."

At C:\Users\Rafael\Documents\PowerShell\Modules\StoreBroker\StoreBroker\StoreBroker\StoreIngestionApplicationApi.ps1:1354 char:9
+         Write-Log -Exception $_ -Level Error
+         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo          : NotSpecified: (:) [Write-Error], WriteErrorException
+ FullyQualifiedErrorId : Microsoft.PowerShell.Commands.WriteErrorException,Write-Log

The following exception occurred while retrieving member "UploadAsync": "Could not load file or assembly 'Microsoft.WindowsAzure.Storage, Version=8.1.1.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35'. The system cannot find the file specified."
At C:\Users\Rafael\Documents\PowerShell\Modules\StoreBroker\StoreBroker\StoreBroker\StoreIngestionApi.psm1:918 char:9
+         throw $newLineOutput
+         ~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo          : OperationStopped: (The following excep\u2026he file specified.":String) [], RuntimeException
+ FullyQualifiedErrorId : The following exception occurred while retrieving member "UploadAsync": "Could not load file or assembly 'Microsoft.WindowsAzure.Storage, Version=8.1.1.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35'. The system cannot find the file specified."

[HowardWolosky]

@riverar, based on that log, it looks like this wasn't the first time that you attempted a submission update, because it had already found the azure dll dependencies. StoreBroker depends on some Azure dll's in order to do the necessary upload to Azure Blob Storage. It looks for the dll's in your StoreBroker enlistment as well as in a script-cached temp directory. If it can't find them in either location, it automatically downloads them from NuGet and then shows this message:

https://github.com/microsoft/StoreBroker/blob/master/StoreBroker/NugetTools.ps1#L364-L370

I find it curious that the logs indicate that it was able to find those dll dependencies and yet was unable to load the requested assembly.

I'd be curious if you could try the following code in a new PowerShell session:

https://github.com/microsoft/StoreBroker/blob/master/StoreBroker/StoreIngestionApi.psm1#L832-L839, substituting $azureStorageDll and $azureStorageDataMovementDll with the dll's from the temp folder that you redacted in the above log.

I haven't heard of any user having this problem before and would like to better understand what's going on.

[riverar]

@HowardWolosky Seems to be a PowerShell Core issue. Digging deeper.

Here's the code I'm using, should print out the overloads for that method. Works in Windows PowerShell 5.x, not Core 6.x. (Haven't tried Core Preview 7.x builds yet.)

$bytes = [System.IO.File]::ReadAllBytes("C:\Users\Rafael\AppData\Local\Temp\d966a35f-66dc-42c6-8694-0236ec847400\WindowsAzure.Storage.8.1.1\lib\net45\Microsoft.WindowsAzure.Storage.dll")
[System.Reflection.Assembly]::Load($bytes) | Out-Null

$bytes = [System.IO.File]::ReadAllBytes("C:\Users\Rafael\AppData\Local\Temp\d966a35f-66dc-42c6-8694-0236ec847400\Microsoft.Azure.Storage.DataMovement.0.5.1\lib\net45\Microsoft.WindowsAzure.Storage.DataMovement.dll")
[System.Reflection.Assembly]::Load($bytes) | Out-Null

[Microsoft.WindowsAzure.Storage.DataMovement.TransferManager]::UploadAsync

[HowardWolosky]

Ah, interesting. Please do let me know what you find. We actively run it on PS 4 and PS 5 without issue, but have done no testing or validation against PS Core. Will need to add that to the backlog.

[riverar]

Appears .NET Core 2's implementation of Assembly.Load is slightly different from .NET Desktop (presumably due to lack of an appdomain impl. in that space).

If my understanding is correct:

1. CoreCLR is creating a new (isolated) AssemblyLoadContext per .Load call (https://github.com/sdmaclea/coreclr/blob/1fdb027dd31869d62f6065257d37118c80cc2504/src/System.Private.CoreLib/shared/System/Reflection/Assembly.cs#L230)
2. The repro. code above is triggering a dependency search for Microsoft.WindowsAzure.Storage.dll
3. Microsoft.WindowsAzure.Storage doesn't exist in the GAC and the search fails

One workaround is to change StoreIngestionApi.psm1, replacing all instances of [System.Reflection.Assembly]::Load with [System.Reflection.Assembly]::LoadFrom. This, at least in CoreCLR, will load assemblies in the default load context. (https://github.com/sdmaclea/coreclr/blob/1fdb027dd31869d62f6065257d37118c80cc2504/src/System.Private.CoreLib/shared/System/Reflection/Assembly.cs#L337)

In my limited testing, this works in Windows PowerShell and PowerShell Core 6.2.0.

[HowardWolosky]

Thanks for the deep-dive, @riverar! Let me do some investigations this week to make sure that doing so works in PS 4 and PS 5. Provided it does, I can make that suggested change (or you can submit the PR yourself to do it, and I'll accept the merge after I've satisfied my validation requirements).

[riverar]

Submitted a PR, no rush. You may need to consider internal use cases and what could be lurking in the default appdomain that could potentially conflict. Maybe a better fix involves creating a custom AppDomain/AssemblyLoadContext for the session.

Have a good rest of the weekend!