I have noticed some delays in my deployments since changing from management certificates to service principal authentication. I get the following in the deployment log:
09:32:04 Verbose | Executing 'XXXXXXXXX\staging\Octopus.Action.CustomScripts.Deploy.ps1’
09:32:06 Verbose | Name Value
09:32:06 Verbose | ---- -----
09:32:06 Verbose | PSVersion 4.0
09:32:06 Verbose | WSManStackVersion 3.0
09:32:06 Verbose | SerializationVersion 1.1.0.1
09:32:06 Verbose | CLRVersion 4.0.30319.42000
09:32:06 Verbose | BuildVersion 6.3.9600.17400
09:32:06 Verbose | PSCompatibleVersions {1.0, 2.0, 3.0, 4.0}
09:32:06 Verbose | PSRemotingProtocolVersion 2.2
09:32:07 Verbose | Importing Azure Service Management PowerShell module
09:32:20 Verbose | Importing Azure Resource Manager PowerShell modules
09:37:07 Verbose | Authenticating with Service Principal
09:37:08 Info | Environment : AzureCloud
09:37:08 Info | Account : XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
09:37:08 Info | TenantId : XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
09:37:08 Info | SubscriptionId : XXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
09:37:08 Info | CurrentStorageAccount :
09:37:09 Info | Account : XXXXXXXXXXXXXXXXXXXXXXXXX
09:37:09 Info | Environment : AzureCloud
09:37:09 Info | Subscription :XXXXXXXXXXXXXXXXXXXXX
09:37:09 Info | Tenant :XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
09:37:09 Verbose | Invoking target script XXXXX\Octopus\Work\20160606083051-17\staging\Octopus.Action.CustomScripts.Deploy.ps1
There appears to be a 5 minute delay between the following 2 log entries
09:32:20 Verbose | Importing Azure Resource Manager PowerShell modules
09:37:07 Verbose | Authenticating with Service Principal
Any ideas ?
Hi Brendan,
Thanks for getting in touch! The only thing we do between these two log steps is load up Azure Resource Manager powershell modules, you can see the code that gets run here. It certainly shouldn’t take 5 minutes.
I’ve created a powershell script that times loading each module and uploaded it here, would you be able to run that on your Octopus server and give me the output? You’ll have to edit the $OctopusAzureModulePath variable, the right path should be near the XXXXX\Octopus\Work shown in the last line of your log, it will be something like XXXXX\Octopus\Calamari\Azure\1.0.20160602.084032\AzurePowershell.
Hopefully that will help us see what is going on.
Kind regards,
Mark
Hi Mark,
Thanks for looking into this. I ran the benchmark 3 times on the same drive. The drive is a vhd in Azure 500 IOPS max 60mb/s results below:
RUN ONE
AzureRM.Profile 00:00:04.5848754
Azure.Storage 00:00:02.4487767
AzureRM.ApiManagement 00:00:00.0194334
AzureRM.Automation 00:00:00.0036870
AzureRM.Backup 00:00:02.4360763
AzureRM.Batch 00:00:03.0990717
AzureRM.Compute 00:00:06.0393975
AzureRM.DataFactories 00:00:05.5489554
AzureRM.Dns 00:00:00.0103615
AzureRM.HDInsight 00:00:00.0044437
AzureRM.Insights 00:00:06.2930781
AzureRM.KeyVault 00:00:07.2906405
AzureRM.Network 00:00:07.8150009
AzureRM.OperationalInsights 00:00:08.4508745
AzureRM.RedisCache 00:00:09.4121072
AzureRM.Resources 00:00:10.0532730
AzureRM.SiteRecovery 00:00:00.0204972
AzureRM.Sql 00:00:11.6267445
AzureRM.Storage 00:00:11.4758606
AzureRM.StreamAnalytics 00:00:12.2923479
AzureRM.Tags 00:00:13.0905479
AzureRM.TrafficManager 00:00:00.0280657
AzureRM.UsageAggregates 00:00:13.8529077
AzureRM.Websites 00:00:00.0101712
RUN TWO
AzureRM.Profile 00:00:00.0012694
Azure.Storage 00:00:00.0011744
AzureRM.ApiManagement 00:00:00.0073393
AzureRM.Automation 00:00:00.0013258
AzureRM.Backup 00:00:00.0011409
AzureRM.Batch 00:00:00.0115585
AzureRM.Compute 00:00:00.0074373
AzureRM.DataFactories 00:00:00.0011977
AzureRM.DataLakeAnalytics 00:00:14.6589433
AzureRM.DataLakeStore 00:00:15.4330378
AzureRM.Dns 00:00:00.0019591
AzureRM.HDInsight 00:00:00.0082999
AzureRM.Insights 00:00:00.0077714
AzureRM.KeyVault 00:00:00.0077153
AzureRM.Network 00:00:00.0086204
Import-Module : The specified module ‘E:\Octopus\Calamari\Azure\3.3.13\AzurePowershell\ResourceManager\AzureResourceManager\AzureRM.NotificationHubs’ was not loaded because no valid module file was
found in any module directory.
At E:\octopus-benchmark.ps1:45 char:2
-
Import-Module -Name ([IO.Path]::Combine($ResourceManagerModulePath, $_))
-
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
- CategoryInfo : ResourceUnavailable: (E:\Octopus\Cala…otificationHubs:String) [Import-Module], FileNotFoundException
- FullyQualifiedErrorId : Modules_ModuleNotFound,Microsoft.PowerShell.Commands.ImportModuleCommand
AzureRM.NotificationHubs 00:00:00.2775471
AzureRM.OperationalInsights 00:00:00.0013303
Import-Module : The specified module ‘E:\Octopus\Calamari\Azure\3.3.13\AzurePowershell\ResourceManager\AzureResourceManager\AzureRM.RecoveryServices’ was not loaded because no valid module file was
found in any module directory.
At E:\octopus-benchmark.ps1:45 char:2
-
Import-Module -Name ([IO.Path]::Combine($ResourceManagerModulePath, $_))
-
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
- CategoryInfo : ResourceUnavailable: (E:\Octopus\Cala…ecoveryServices:String) [Import-Module], FileNotFoundException
- FullyQualifiedErrorId : Modules_ModuleNotFound,Microsoft.PowerShell.Commands.ImportModuleCommand
AzureRM.RecoveryServices 00:00:00.0315735
AzureRM.RedisCache 00:00:00.0119573
AzureRM.Resources 00:00:00.0020043
AzureRM.SiteRecovery 00:00:00.0011079
AzureRM.Sql 00:00:00.0012587
AzureRM.Storage 00:00:00.0010558
AzureRM.StreamAnalytics 00:00:00.0010911
AzureRM.Tags 00:00:00.0009832
AzureRM.TrafficManager 00:00:00.0011080
AzureRM.UsageAggregates 00:00:00.0010066
AzureRM.Websites 00:00:00.0010757
RUN THREE
AzureRM.Profile 00:00:00.0013111
Azure.Storage 00:00:00.0012594
AzureRM.ApiManagement 00:00:00.0013763
AzureRM.Automation 00:00:00.0071816
AzureRM.Backup 00:00:00.0011973
AzureRM.Batch 00:00:00.0224116
AzureRM.Compute 00:00:00.0012655
AzureRM.DataFactories 00:00:00.0010750
AzureRM.DataLakeAnalytics 00:00:00.0010287
AzureRM.DataLakeStore 00:00:00.0010258
AzureRM.Dns 00:00:00.0009931
AzureRM.HDInsight 00:00:00.0010529
AzureRM.Insights 00:00:00.0014276
AzureRM.KeyVault 00:00:00.0009967
AzureRM.Network 00:00:00.0068439
Import-Module : The specified module ‘E:\Octopus\Calamari\Azure\3.3.13\AzurePowershell\ResourceManager\AzureResourceManager\AzureRM.NotificationHubs’ was not loaded because no valid module file was
found in any module directory.
At E:\octopus-benchmark.ps1:45 char:2
-
Import-Module -Name ([IO.Path]::Combine($ResourceManagerModulePath, $_))
-
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
- CategoryInfo : ResourceUnavailable: (E:\Octopus\Cala…otificationHubs:String) [Import-Module], FileNotFoundException
- FullyQualifiedErrorId : Modules_ModuleNotFound,Microsoft.PowerShell.Commands.ImportModuleCommand
AzureRM.NotificationHubs 00:00:00.0243643
AzureRM.OperationalInsights 00:00:00.0010143
Import-Module : The specified module ‘E:\Octopus\Calamari\Azure\3.3.13\AzurePowershell\ResourceManager\AzureResourceManager\AzureRM.RecoveryServices’ was not loaded because no valid module file was
found in any module directory.
At E:\octopus-benchmark.ps1:45 char:2
-
Import-Module -Name ([IO.Path]::Combine($ResourceManagerModulePath, $_))
-
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
- CategoryInfo : ResourceUnavailable: (E:\Octopus\Cala…ecoveryServices:String) [Import-Module], FileNotFoundException
- FullyQualifiedErrorId : Modules_ModuleNotFound,Microsoft.PowerShell.Commands.ImportModuleCommand
AzureRM.RecoveryServices 00:00:00.0061679
AzureRM.RedisCache 00:00:00.0009798
AzureRM.Resources 00:00:00.0009499
AzureRM.SiteRecovery 00:00:00.0010862
AzureRM.Sql 00:00:00.0011571
AzureRM.Storage 00:00:00.0015209
AzureRM.StreamAnalytics 00:00:00.0010239
AzureRM.Tags 00:00:00.0008124
AzureRM.TrafficManager 00:00:00.0008330
AzureRM.UsageAggregates 00:00:00.0008266
AzureRM.Websites 00:00:00.0009874
Hi Brendan,
It just looks like powershell is taking a long time to load the modules off your drive unfortunately. One thing that might work for you is to install the Azure modules on your server and tell Octopus to use those. When you use the bundled versions we need to explicitly load them all, which is what is taking so long for you. But you can install them on your Octopus server using the guide here and then tell Octopus to use the installed versions as described here. That way we skip the loading step.
Let me know if that helps.
Regards,
Mark
Hi Mark,
Thanks for this worked a treat took 15 minutes off my deploy time as i have 3 separate steps using Rm Commands