No longer able to deploy an Azure Web App because Newtonsoft dll could not be loaded

cloud

(Baffour) #1

Octopus Server version: v2018.7.8
Hi, we deploy some Web Apps to Azure through Octopus using the “Deploy an Azure Web App” step template by Octopus. One Project recently started failing for every Tenant, even with older releases that were deploying successfully, but the other projects deploy fine.
As you can see in the task log the error happens in Octopus.AzureContext.ps1 when the “Login-AzureRmAccount” command is called, and is around it being unable to find a specific version of the NewtonSoft.Json assembly. I may be misunderstanding how Calamari works but I’m under the impression that this command is running on the Octopus Server Node, but when I run Login-AzureRmAccount manually on the machine it works fine so I’m not clear on the context the script is run in.

Any ideas on what the issue could be?
Thanks!

Task Log
Task ID:        ServerTasks-64907
Task status:    Failed
Task queued:    Thursday, September 13, 2018 5:01:36 PM
Task started:   Thursday, September 13, 2018 5:01:36 PM
Task completed: Thursday, September 13, 2018 5:02:06 PM
Task duration:  29 seconds
Server version: 2018.7.8+Branch.master.Sha.7caedf8c767263254aa9f2e8ba3bc8655d46d97f
Server node:    [REDACTED MACHINE NAME]

                    | == Failed: Deploy Identity Server release 0.0.34 to Global for [REDACTED] ==
17:02:06   Info     |   Step 1: Deploy Identity Database - SQL Azure was manually skipped, and will not be executed
17:02:06   Verbose  |   Guided failure is not enabled for this task
17:02:06   Fatal    |   The deployment failed because one or more steps failed. Please see the deployment log for details.
                    | 
                    |   == Success: Acquire packages ==
17:01:37   Info     |     Acquiring packages
17:01:37   Info     |     Making a list of packages to acquire
17:01:37   Verbose  |     No packages are required on any deployment targets
17:01:37   Verbose  |     Acquire [REDACTED WebAppName].Server.1.2.1808.0601 on Octopus Server
17:01:37   Verbose  |     Checking package cache for package [REDACTED WebAppName].Server v1.2.1808.0601
17:01:37   Info     |     Package [REDACTED WebAppName].Server v1.2.1808.0601 was found in cache. No need to download.
17:01:37   Verbose  |     Using file: E:\Octopus\Packages\[REDACTED WebAppName].Server\[REDACTED WebAppName].Server.1.2.1808.0601.nupkg
17:01:37   Info     |     All packages have been acquired
17:01:37   Verbose  |     Acquire Packages completed
                    |   
                    |     Success: Octopus Server
                    |     
                    |       Success: Download package [REDACTED WebAppName].Server v1.2.1808.0601 from Octopus Server (built-in)
17:01:37   Info     |         Successfully downloaded [REDACTED WebAppName].Server 1.2.1808.0601 (2.174 MB)
17:01:37   Verbose  |         Stored package in E:\Octopus\Packages\[REDACTED WebAppName].Server\[REDACTED WebAppName].Server.1.2.1808.0601.nupkg
                    |       
                    |   == Failed: Step 2: Deploy [REDACTED WebAppName] ==
17:02:05   Fatal    |     The step failed: Activity Deploy [REDACTED WebAppName] on Azure Global failed with error 'The remote script failed with exit code 1'.
17:02:05   Verbose  |     Deploy [REDACTED WebAppName] completed
                    |   
                    |     Failed: Octopus Server on behalf of Azure Global
17:01:38   Verbose  |       Octopus Server version: 2018.7.8+Branch.master.Sha.7caedf8c767263254aa9f2e8ba3bc8655d46d97f
17:01:38   Verbose  |       Environment Information:
                    |       OperatingSystem: Microsoft Windows NT 6.3.9600.0
                    |       OsBitVersion: x64
                    |       Is64BitProcess: True
                    |       CurrentUser: NT AUTHORITY\SYSTEM
                    |       MachineName: [REDACTED MACHINE NAME]
                    |       ProcessorCount: 4
                    |       CurrentDirectory: C:\Windows\system32
                    |       TempDirectory: C:\Windows\TEMP\
                    |       HostProcessName: Octopus.Server
                    |       PID: 1600
17:01:38   Verbose  |       Executing Deploy [REDACTED WebAppName] (type Deploy an Azure Web App) on Octopus Server
17:01:38   Verbose  |       Using account ID '[Redacted Azure Service Principal]'
17:01:38   Verbose  |       Using Calamari.Cloud 4.7.34
17:01:38   Verbose  |       Using Octopus.Dependencies.AzureCmdlets 5.7.0
17:01:38   Verbose  |       Running this script as the Octopus Server (NT AUTHORITY\SYSTEM)
17:01:38   Verbose  |       Starting C:\Windows\system32\WindowsPowershell\v1.0\PowerShell.exe in working directory 'E:\Octopus\Work\20180913160138-64907-134' using 'OEM United States' encoding running as 'NT AUTHORITY\SYSTEM' with the same environment variables as the launching process
17:01:39   Verbose  |       Octopus Deploy: Calamari version 4.7.34
17:01:39   Verbose  |       Environment Information:
17:01:39   Verbose  |       OperatingSystem: Microsoft Windows NT 6.3.9600.0
17:01:39   Verbose  |       OsBitVersion: x64
17:01:39   Verbose  |       Is64BitProcess: True
17:01:39   Verbose  |       CurrentUser: NT AUTHORITY\SYSTEM
17:01:39   Verbose  |       MachineName: [REDACTED MACHINE NAME]
17:01:39   Verbose  |       ProcessorCount: 4
17:01:39   Verbose  |       CurrentDirectory: E:\Octopus\Work\20180913160138-64907-134
17:01:39   Verbose  |       TempDirectory: C:\Windows\TEMP\
17:01:39   Verbose  |       HostProcessName: Calamari
17:01:41   Info     |       Deploying package:    E:\Octopus\Packages\[REDACTED WebAppName].Server\[REDACTED WebAppName].Server.1.2.1808.0601.nupkg
17:01:41   Verbose  |       Extracting package to: E:\Octopus\Work\20180913160138-64907-134\staging
17:01:41   Verbose  |       Extracted 194 files
17:01:41   Verbose  |       Executing 'E:\Octopus\Work\20180913160138-64907-134\staging\Octopus.Action.CustomScripts.PreDeploy.ps1'
17:01:43   Verbose  |       Name                           Value
17:01:43   Verbose  |       ----                           -----
17:01:43   Verbose  |       PSVersion                      5.1.14409.1012
17:01:43   Verbose  |       PSEdition                      Desktop
17:01:43   Verbose  |       PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0...}
17:01:43   Verbose  |       BuildVersion                   10.0.14409.1012
17:01:43   Verbose  |       CLRVersion                     4.0.30319.42000
17:01:43   Verbose  |       WSManStackVersion              3.0
17:01:43   Verbose  |       PSRemotingProtocolVersion      2.3
17:01:43   Verbose  |       SerializationVersion           1.1.0.1
17:01:43   Verbose  |       PowerShell Environment Information:
17:01:43   Verbose  |       OperatingSystem: Microsoft Windows NT 6.3.9600.0
17:01:43   Verbose  |       OsBitVersion: x64
17:01:43   Verbose  |       Is64BitProcess: True
17:01:43   Verbose  |       CurrentUser: NT AUTHORITY\SYSTEM
17:01:43   Verbose  |       MachineName: [REDACTED MACHINE NAME]
17:01:43   Verbose  |       ProcessorCount: 4
17:01:43   Verbose  |       CurrentDirectory: E:\Octopus\Work\20180913160138-64907-134\staging
17:01:43   Verbose  |       CurrentLocation: E:\Octopus\Work\20180913160138-64907-134\staging
17:01:43   Verbose  |       TempDirectory: C:\Windows\TEMP\
17:01:45   Verbose  |       HostProcessName: powershell
17:01:45   Verbose  |       TotalPhysicalMemory: 14679604 KB
17:01:45   Verbose  |       AvailablePhysicalMemory: 11388872 KB
17:01:45   Verbose  |       Authenticating with Service Principal
17:01:45   Verbose  |       Attempt 1 of 5 failed: Could not load file or assembly 'Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed' or one of its dependencies. The system cannot find the file specified.
17:01:45   Verbose  |       Waiting for 5 seconds before retrying...
17:01:50   Verbose  |       Retrying...
17:01:50   Verbose  |       Authenticating with Service Principal
17:01:50   Verbose  |       Attempt 2 of 5 failed: Could not load file or assembly 'Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed' or one of its dependencies. The system cannot find the file specified.
17:01:50   Verbose  |       Waiting for 5 seconds before retrying...
17:01:55   Verbose  |       Retrying...
17:01:55   Verbose  |       Authenticating with Service Principal
17:01:55   Verbose  |       Attempt 3 of 5 failed: Could not load file or assembly 'Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed' or one of its dependencies. The system cannot find the file specified.
17:01:55   Verbose  |       Waiting for 5 seconds before retrying...
17:02:00   Verbose  |       Retrying...
17:02:00   Verbose  |       Authenticating with Service Principal
17:02:00   Verbose  |       Attempt 4 of 5 failed: Could not load file or assembly 'Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed' or one of its dependencies. The system cannot find the file specified.
17:02:00   Verbose  |       Waiting for 5 seconds before retrying...
17:02:05   Verbose  |       Retrying...
17:02:05   Verbose  |       Authenticating with Service Principal
17:02:05   Error    |       Login-AzureRmAccount : Could not load file or assembly 'Newtonsoft.Json,
17:02:05   Error    |       Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed' or one of
17:02:05   Error    |       its dependencies. The system cannot find the file specified.
17:02:05   Error    |       At
17:02:05   Error    |       E:\Octopus\Work\20180913160138-64907-134\staging\Octopus.AzureContext.ps1:72
17:02:05   Error    |       char:9
17:02:05   Error    |       +         Login-AzureRmAccount -Credential $creds -TenantId $OctopusAzu ...
17:02:05   Error    |       +         ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
17:02:05   Error    |       + CategoryInfo          : NotSpecified: (:) [Connect-AzureRmAccount], File
17:02:05   Error    |       NotFoundException
17:02:05   Error    |       + FullyQualifiedErrorId : System.IO.FileNotFoundException,Microsoft.Azure.
17:02:05   Error    |       Commands.Profile.ConnectAzureRmAccountCommand
17:02:05   Error    |       PreDeploy script returned non-zero exit code: 1
17:02:05   Error    |       Running rollback conventions...
17:02:05   Error    |       PreDeploy script returned non-zero exit code: 1
17:02:05   Verbose  |       Process C:\Windows\system32\WindowsPowershell\v1.0\PowerShell.exe in E:\Octopus\Work\20180913160138-64907-134 exited with code 1
17:02:05   Verbose  |       Updating manifest with output variables
17:02:05   Verbose  |       Updating manifest with action evaluated variables
17:02:05   Fatal    |       The remote script failed with exit code 1
17:02:05   Fatal    |       The action Deploy [REDACTED WebAppName] on Azure Global failed
                    |     
                    |   Canceled: Step 3: Approve
17:02:05   Verbose  |     Step "Approve" runs only when all previous steps succeeded; skipping
                    |   
                    |   Canceled: Step 4: Swap Slots
17:02:05   Verbose  |     Step "Swap Slots" runs only when all previous steps succeeded; skipping
                    |   

(John Simons) #2

Hi,

Trying to figure out how to reproduce this issue locally, so I have a few questions.

Because you say that

but when I run Login-AzureRmAccount manually on the machine

I assume you have Azure Powershell Cmdlets installed locally ? And if so what version do you have installed ?

Octopus ships it’s own version of the Powershell Cmdlets but if you do have the cmdlets installed locally, you can disable this to force using the locally installed ones, to do this follow https://octopus.com/docs/deployment-examples/azure-deployments/running-azure-powershell/configuring-the-version-of-the-azure-powershell-modules#ConfiguringtheversionoftheAzurePowerShellmodules-Octopus2018.5.5(ornewer)
Let me know if this fix the issue ?

Another more technical way to figure out what is trying to load this version of Newtonsoft.Json, is by enabling the fusion logs, see https://stackoverflow.com/a/1527249/90882, this should create log files that should tell us what locations are being searched.
But before going down this path, try disabling the Octopus shipped cmdlets.

Regards
John


(Baffour) #3

Thanks for the reply John,
I believe it’s 5.1.2 but for completeness, this is the full list of Azure related modules installed on the server:

Azure Modules
Name Version
Azure 5.1.2
Azure.AnalysisServices 0.5.3
Azure.AnalysisServices 0.5.0
Azure.Storage 4.4.0
Azure.Storage 4.2.1
AzureRM 6.6.0
AzureRM 5.7.0
AzureRM.AnalysisServices 0.6.11
AzureRM.AnalysisServices 0.6.6
AzureRM.ApiManagement 6.1.2
AzureRM.ApiManagement 5.1.2
AzureRM.ApplicationInsights 0.1.5
AzureRM.ApplicationInsights 0.1.3
AzureRM.Automation 5.0.3
AzureRM.Automation 4.3.2
AzureRM.Backup 4.0.7
AzureRM.Backup 4.0.4
AzureRM.Batch 4.1.2
AzureRM.Batch 4.0.6
AzureRM.Billing 0.14.4
AzureRM.Billing 0.14.1
AzureRM.Cdn 5.0.2
AzureRM.Cdn 4.2.2
AzureRM.CognitiveServices 0.9.7
AzureRM.CognitiveServices 0.9.4
AzureRM.Compute 5.4.0
AzureRM.Compute 4.6.0
AzureRM.Consumption 0.3.6
AzureRM.Consumption 0.3.1
AzureRM.ContainerInstance 0.2.7
AzureRM.ContainerInstance 0.2.5
AzureRM.ContainerRegistry 1.0.7
AzureRM.ContainerRegistry 1.0.4
AzureRM.DataFactories 5.0.2
AzureRM.DataFactories 4.2.2
AzureRM.DataFactoryV2 0.5.7
AzureRM.DataFactoryV2 0.5.3
AzureRM.DataLakeAnalytics 5.1.1
AzureRM.DataLakeAnalytics 4.2.3
AzureRM.DataLakeStore 6.1.1
AzureRM.DataLakeStore 5.2.0
AzureRM.DevTestLabs 4.0.6
AzureRM.DevTestLabs 4.0.4
AzureRM.Dns 5.0.1
AzureRM.Dns 4.1.2
AzureRM.EventGrid 0.3.6
AzureRM.EventGrid 0.3.2
AzureRM.EventHub 0.6.7
AzureRM.EventHub 0.6.3
AzureRM.HDInsight 4.1.5
AzureRM.HDInsight 4.1.2
AzureRM.Insights 5.1.0
AzureRM.Insights 4.0.4
AzureRM.IotHub 3.1.5
AzureRM.IotHub 3.1.2
AzureRM.KeyVault 5.1.0
AzureRM.KeyVault 4.3.0
AzureRM.LogicApp 4.1.1
AzureRM.LogicApp 4.0.3
AzureRM.MachineLearning 0.18.2
AzureRM.MachineLearning 0.17.2
AzureRM.MachineLearningCompute 0.4.5
AzureRM.MachineLearningCompute 0.4.2
AzureRM.MarketplaceOrdering 0.2.4
AzureRM.MarketplaceOrdering 0.2.1
AzureRM.Media 0.10.1
AzureRM.Media 0.9.2
AzureRM.Network 6.4.1
AzureRM.Network 5.4.2
AzureRM.NotificationHubs 5.0.2
AzureRM.NotificationHubs 4.1.1
AzureRM.OperationalInsights 5.0.3
AzureRM.OperationalInsights 4.3.2
AzureRM.PolicyInsights 1.0.3
AzureRM.PowerBIEmbedded 4.1.7
AzureRM.PowerBIEmbedded 4.1.4
AzureRM.profile 5.3.4
AzureRM.profile 4.6.0
AzureRM.RecoveryServices 4.1.5
AzureRM.RecoveryServices 4.1.2
AzureRM.RecoveryServices.Backup 4.3.1
AzureRM.RecoveryServices.Backup 4.1.2
AzureRM.RecoveryServices.SiteRecovery 0.2.7
AzureRM.RecoveryServices.SiteRecovery 0.2.4
AzureRM.RedisCache 5.0.2
AzureRM.RedisCache 4.1.2
AzureRM.Relay 0.3.7
AzureRM.Relay 0.3.3
AzureRM.Resources 6.3.0
AzureRM.Resources 5.5.2
AzureRM.Scheduler 0.16.7
AzureRM.Scheduler 0.16.3
AzureRM.ServerManagement 4.1.2
AzureRM.ServiceBus 0.6.8
AzureRM.ServiceBus 0.6.4
AzureRM.ServiceFabric 0.3.9
AzureRM.ServiceFabric 0.3.4
AzureRM.SiteRecovery 5.0.6
AzureRM.Sql 4.11.0
AzureRM.Sql 4.4.0
AzureRM.Storage 5.0.1
AzureRM.Storage 4.2.3
AzureRM.StreamAnalytics 4.0.7
AzureRM.StreamAnalytics 4.0.4
AzureRM.Tags 4.0.4
AzureRM.Tags 4.0.1
AzureRM.TrafficManager 4.0.8
AzureRM.TrafficManager 4.0.3
AzureRM.UsageAggregates 4.0.4
AzureRM.UsageAggregates 4.0.2
AzureRM.Websites 5.0.6
AzureRM.Websites 4.2.2
AzureRmStorageTable 1.0.0.22

I’ve just tried enabling the OctopusUseBundledAzureModules variable as suggested but this hasn’t fixed the issue.

I also went ahead and tried enabling the fusion logs and re-deploying, and I see logs for Octopus.Server.exe, Tentacle.exe and Calamari.exe, each of which successfully loads the dll from the executable directory. However an attempt is made to load it by powershell.exe which fails, the log for that is below:

Fusion Log for powershell.exe loading Newtonsoft.Json
<meta http-equiv="Content-Type" content="charset=unicode-1-1-utf-8"><!-- saved from url=(0015)assemblybinder: --><html><pre>
*** Assembly Binder Log Entry  (9/17/2018 @ 1:29:34 PM) ***

The operation failed.
Bind result: hr = 0x80070002. The system cannot find the file specified.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  C:\Windows\system32\WindowsPowershell\v1.0\PowerShell.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
(Fully-specified)
LOG: Appbase = file:///C:/Windows/System32/WindowsPowerShell/v1.0/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = PowerShell.exe
Calling assembly : Microsoft.Rest.ClientRuntime.Azure, Version=3.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35.
===
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: No application configuration file found.
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
LOG: GAC Lookup was unsuccessful.
LOG: Attempting download of new URL file:///C:/Windows/System32/WindowsPowerShell/v1.0/Newtonsoft.Json.DLL.
LOG: Attempting download of new URL file:///C:/Windows/System32/WindowsPowerShell/v1.0/Newtonsoft.Json/Newtonsoft.Json.DLL.
LOG: Attempting download of new URL file:///C:/Windows/System32/WindowsPowerShell/v1.0/Newtonsoft.Json.EXE.
LOG: Attempting download of new URL file:///C:/Windows/System32/WindowsPowerShell/v1.0/Newtonsoft.Json/Newtonsoft.Json.EXE.
LOG: Attempting download of new URL file:///E:/Octopus/Work/20180917122922-65287-1/staging/Newtonsoft.Json.DLL.
LOG: Attempting download of new URL file:///E:/Octopus/Work/20180917122922-65287-1/staging/Newtonsoft.Json/Newtonsoft.Json.DLL.
LOG: Attempting download of new URL file:///E:/Octopus/Work/20180917122922-65287-1/staging/Newtonsoft.Json.EXE.
LOG: Attempting download of new URL file:///E:/Octopus/Work/20180917122922-65287-1/staging/Newtonsoft.Json/Newtonsoft.Json.EXE.
LOG: All probing URLs attempted and failed.

</pre></html><meta http-equiv="Content-Type" content="charset=unicode-1-1-utf-8"><!-- saved from url=(0015)assemblybinder: --><html><pre>
*** Assembly Binder Log Entry  (9/17/2018 @ 1:29:34 PM) ***

The operation failed.
Bind result: hr = 0x80070002. The system cannot find the file specified.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  C:\Windows\system32\WindowsPowershell\v1.0\PowerShell.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
(Fully-specified)
LOG: Appbase = file:///C:/Windows/System32/WindowsPowerShell/v1.0/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = PowerShell.exe
Calling assembly : Microsoft.Rest.ClientRuntime.Azure, Version=3.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35.
===
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: No application configuration file found.
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
LOG: GAC Lookup was unsuccessful.
LOG: Attempting download of new URL file:///C:/Windows/System32/WindowsPowerShell/v1.0/Newtonsoft.Json.DLL.
LOG: Attempting download of new URL file:///C:/Windows/System32/WindowsPowerShell/v1.0/Newtonsoft.Json/Newtonsoft.Json.DLL.
LOG: Attempting download of new URL file:///C:/Windows/System32/WindowsPowerShell/v1.0/Newtonsoft.Json.EXE.
LOG: Attempting download of new URL file:///C:/Windows/System32/WindowsPowerShell/v1.0/Newtonsoft.Json/Newtonsoft.Json.EXE.
LOG: Attempting download of new URL file:///E:/Octopus/Work/20180917122922-65287-1/staging/Newtonsoft.Json.DLL.
LOG: Attempting download of new URL file:///E:/Octopus/Work/20180917122922-65287-1/staging/Newtonsoft.Json/Newtonsoft.Json.DLL.
LOG: Attempting download of new URL file:///E:/Octopus/Work/20180917122922-65287-1/staging/Newtonsoft.Json.EXE.
LOG: Attempting download of new URL file:///E:/Octopus/Work/20180917122922-65287-1/staging/Newtonsoft.Json/Newtonsoft.Json.EXE.
LOG: All probing URLs attempted and failed.

</pre></html><meta http-equiv="Content-Type" content="charset=unicode-1-1-utf-8"><!-- saved from url=(0015)assemblybinder: --><html><pre>
*** Assembly Binder Log Entry  (9/17/2018 @ 1:29:39 PM) ***

The operation failed.
Bind result: hr = 0x80070002. The system cannot find the file specified.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  C:\Windows\system32\WindowsPowershell\v1.0\PowerShell.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
(Fully-specified)
LOG: Appbase = file:///C:/Windows/System32/WindowsPowerShell/v1.0/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = PowerShell.exe
Calling assembly : Microsoft.Rest.ClientRuntime.Azure, Version=3.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35.
===
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: No application configuration file found.
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
LOG: The same bind was seen before, and was failed with hr = 0x80070002.
ERR: Unrecoverable error occurred during pre-download check (hr = 0x80070002).

</pre></html><meta http-equiv="Content-Type" content="charset=unicode-1-1-utf-8"><!-- saved from url=(0015)assemblybinder: --><html><pre>
*** Assembly Binder Log Entry  (9/17/2018 @ 1:29:44 PM) ***

The operation failed.
Bind result: hr = 0x80070002. The system cannot find the file specified.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  C:\Windows\system32\WindowsPowershell\v1.0\PowerShell.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
(Fully-specified)
LOG: Appbase = file:///C:/Windows/System32/WindowsPowerShell/v1.0/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = PowerShell.exe
Calling assembly : Microsoft.Rest.ClientRuntime.Azure, Version=3.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35.
===
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: No application configuration file found.
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
LOG: The same bind was seen before, and was failed with hr = 0x80070002.
ERR: Unrecoverable error occurred during pre-download check (hr = 0x80070002).

</pre></html><meta http-equiv="Content-Type" content="charset=unicode-1-1-utf-8"><!-- saved from url=(0015)assemblybinder: --><html><pre>
*** Assembly Binder Log Entry  (9/17/2018 @ 1:29:49 PM) ***

The operation failed.
Bind result: hr = 0x80070002. The system cannot find the file specified.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  C:\Windows\system32\WindowsPowershell\v1.0\PowerShell.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
(Fully-specified)
LOG: Appbase = file:///C:/Windows/System32/WindowsPowerShell/v1.0/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = PowerShell.exe
Calling assembly : Microsoft.Rest.ClientRuntime.Azure, Version=3.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35.
===
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: No application configuration file found.
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
LOG: The same bind was seen before, and was failed with hr = 0x80070002.
ERR: Unrecoverable error occurred during pre-download check (hr = 0x80070002).

</pre></html><meta http-equiv="Content-Type" content="charset=unicode-1-1-utf-8"><!-- saved from url=(0015)assemblybinder: --><html><pre>
*** Assembly Binder Log Entry  (9/17/2018 @ 1:29:54 PM) ***

The operation failed.
Bind result: hr = 0x80070002. The system cannot find the file specified.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  C:\Windows\system32\WindowsPowershell\v1.0\PowerShell.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
(Fully-specified)
LOG: Appbase = file:///C:/Windows/System32/WindowsPowerShell/v1.0/
LOG: Initial PrivatePath = NULL
LOG: Dynamic Base = NULL
LOG: Cache Base = NULL
LOG: AppName = PowerShell.exe
Calling assembly : Microsoft.Rest.ClientRuntime.Azure, Version=3.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35.
===
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: No application configuration file found.
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Newtonsoft.Json, Version=9.0.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed
LOG: The same bind was seen before, and was failed with hr = 0x80070002.
ERR: Unrecoverable error occurred during pre-download check (hr = 0x80070002).

</pre></html>

Hope that helps. What’s the expected behaviour here? should the dll be in E:/Octopus/Work/20180917122922-65287-1/staging?

Thanks again John!


(John Simons) #4

Hi,

Thanks heaps for all the information you have provided so far. We have been trying to replicate the issue you are seeing, we installed both 6.6.0 and 5.7.0 Azure Powershell modules but still cannot reproduce the issue.

Just to be sure, when you created the OctopusUseBundledAzureModules variable, you set it to False correct ?

should the dll be in E:/Octopus/Work/20180917122922-65287-1/staging ?

No it should not, we are calling the Login-AzureRmAccount and that PS command references the missing DLL, but that dependency should be there, actually the bundle we ship, does not reference v9.0.0 of Newtonsoft.Json, which really does not make sense!

You don’t have Newtonsoft.Json in the GAC ?

We can try to debug the PS script and see if we can figure out what is going on then, to enable script debugging you need to follow - https://octopus.com/docs/deployment-examples/custom-scripts/debugging-powershell-scripts, once you are debugging, try running Get-Module -ListAvailable -Name Azure* -Verbose, this hopefully should show the paths where the PS modules are being executed from.

If you have problems running it in debug, we can jump on a call to help out.

Regards
John