Problem description
Deployment Vmextensionprovisioningerror was encountered while using azure service fabric. The full text is as follows:
Deployment Name: 385A084F35B2BC55-xxxx
Operation Id: 096CED
Operation: Create
Correlation Id: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
Status: Failed
Error:
Code: VMExtensionProvisioningError
Message: Multiple VM extensions failed to be provisioned on the VM.
Please see the VM extension instance view for other failures. The first extension failed due to the error:
VM Extension 'RunPowerShell_Frontdoor' is marked as failed since it depends upon the VM Extension 'ServiceFabricNodeVmExt_vmNodeType1Name' which has failed.
Help Link: https://aka.ms/ev2/errors/troubleshooting
Problem solving
Step 1: collect logs
In the node that requires remote connection (RDP) to SF, in the directory C: Collect VM extension installation logs in \ windowsazure \ logs \ plugins
Step 2: analyze logs
stay In the microsoft.azure.servicefabric.servicefabricnode plugin log, it is found that the error occurred due to the failure to obtain the certificate.
[09/09/2021 12:32:01.86] Executing: C:\Packages\Plugins\Microsoft.Azure.ServiceFabric.ServiceFabricNode\1.1.0.11\ServiceFabricExtensionHandler.exe enable
[09/09/2021 12:32:03.62] Execution Complete.
######
Execution Output:
1> 2021-09-09T12:32:01.9973303Z: Information: Starting...
1> 2021-09-09T12:32:01.9973303Z: Information: MachineName: Frontdoor000000
1> 2021-09-09T12:32:01.9973303Z: Information: CurrentDirectory: C:\Packages\Plugins\Microsoft.Azure.ServiceFabric.ServiceFabricNode\1.1.0.11
1> 2021-09-09T12:32:01.9973303Z: Information: UserName: SYSTEM
1> 2021-09-09T12:32:01.9973303Z: Information: Created mutex; this is the only instance of this process running
1> 2021-09-09T12:32:02.3723445Z: Information: HandlerManifest Version: 1
1> 2021-09-09T12:32:02.4348520Z: Information: [HandlerEnvironment]
1> 2021-09-09T12:32:02.4348520Z: Information: LogFolder: C:\WindowsAzure\Logs\Plugins\Microsoft.Azure.ServiceFabric.ServiceFabricNode\1.1.0.11
1> 2021-09-09T12:32:02.4348520Z: Information: ConfigFolder: C:\Packages\Plugins\Microsoft.Azure.ServiceFabric.ServiceFabricNode\1.1.0.11\RuntimeSettings
1> 2021-09-09T12:32:02.4348520Z: Information: StatusFolder: C:\Packages\Plugins\Microsoft.Azure.ServiceFabric.ServiceFabricNode\1.1.0.11\Status
1> 2021-09-09T12:32:02.4348520Z: Information: HeartbeatFile: C:\Packages\Plugins\Microsoft.Azure.ServiceFabric.ServiceFabricNode\1.1.0.11\Status\HeartBeat.Json
1> 2021-09-09T12:32:02.4348520Z: Information: DeploymentId: xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
1> 2021-09-09T12:32:02.4348520Z: Information: RoleName: _Frontdoor_0
1> 2021-09-09T12:32:02.4348520Z: Information: Instance: _Frontdoor_0
1> 2021-09-09T12:32:02.5442327Z: Information: Opening config file: C:\Packages\Plugins\Microsoft.Azure.ServiceFabric.ServiceFabricNode\1.1.0.11\RuntimeSettings\1.settings
1> 2021-09-09T12:32:02.5598642Z: Information: Config specified client cert FindBySubjectName 'xxxxx.cluster.prod.ngpproxy.microsoftonline.cn' (store name = My)
1> 2021-09-09T12:32:02.5754780Z: Error: ERROR: Microsoft.Azure.ServiceFabric.Extension.Core.AgentException: Cannot find certificate with 'FindBySubjectName' 'xxxxx.cluster.prod.ngpproxy.microsoftonline.cn' in store 'My' at Microsoft.Azure.ServiceFabric.Extension.Core.CertificateUtility.LoadClientCertificate(String findValue, String certStoreName, X509FindType findBy) at Microsoft.Azure.ServiceFabric.Extension.Core.CertificateUtility.LoadCertificateWrapper(CertificateSettings certificateSetting)
1> 2021-09-09T12:32:02.5754780Z: Warning: Heartbeat: Not Ready: Cannot find certificate with 'FindBySubjectName' 'xxxxx.cluster.prod.ngpproxy.microsoftonline.cn' in store 'My'
1> 2021-09-09T12:32:02.5754780Z: Error: Heartbeat file updated, with error msg
1> 2021-09-09T12:32:02.5911044Z: Error: ERROR: Microsoft.Azure.ServiceFabric.Extension.Core.AgentException: Cannot find certificate with 'FindBySubjectName' 'xxxxx.cluster.prod.ngpproxy.microsoftonline.cn' in store 'My' at Microsoft.Azure.ServiceFabric.Extension.Core.CertificateUtility.LoadClientCertificate(String findValue, String certStoreName, X509FindType findBy) at Microsoft.Azure.ServiceFabric.Extension.Core.CertificateUtility.LoadCertificateWrapper(CertificateSettings certificateSetting) at Microsoft.Azure.ServiceFabric.Extension.Core.Common.PublicSettingsExtensions.AllowAccessToCerts(PublicSettings publicSettings, ICertificateUtility certificateUtility) at Microsoft.Azure.ServiceFabric.Extension.Core.VMExtensionHandler.ValidateDeployment(HandlerSettings settings) at Microsoft.Azure.ServiceFabric.Extension.Core.VMExtensionHandler.InstallService() at Microsoft.Azure.ServiceFabric.Extension.Core.VMExtensionHandler.InstallServiceWithRetry() at Microsoft.Azure.ServiceFabric.Extension.Core.VMExtensionHandler.Enable() at Microsoft.Azure.ServiceFabric.Extension.Handler.Program.Main(String[] args) in X:\bt\1162492\repo\src\HandlerExe\Program.cs:line 52
Execution Error:
Microsoft.Azure.ServiceFabric.Extension.Core.AgentException: Cannot find certificate with 'FindBySubjectName' 'xxxxx.cluster.prod.ngpproxy.microsoftonline.cn' in store 'My'
at Microsoft.Azure.ServiceFabric.Extension.Core.CertificateUtility.LoadClientCertificate(String findValue, String certStoreName, X509FindType findBy)
at Microsoft.Azure.ServiceFabric.Extension.Core.CertificateUtility.LoadCertificateWrapper(CertificateSettings certificateSetting)
at Microsoft.Azure.ServiceFabric.Extension.Core.Common.PublicSettingsExtensions.AllowAccessToCerts(PublicSettings publicSettings, ICertificateUtility certificateUtility)
at Microsoft.Azure.ServiceFabric.Extension.Core.VMExtensionHandler.ValidateDeployment(HandlerSettings settings)
at Microsoft.Azure.ServiceFabric.Extension.Core.VMExtensionHandler.InstallService()
at Microsoft.Azure.ServiceFabric.Extension.Core.VMExtensionHandler.InstallServiceWithRetry()
at Microsoft.Azure.ServiceFabric.Extension.Core.VMExtensionHandler.Enable()
at Microsoft.Azure.ServiceFabric.Extension.Handler.Program.Main(String[] args) in X:\bt\1162492\repo\src\HandlerExe\Program.cs:line 52
The key message is Microsoft.Azure.ServiceFabric.Extension.Core.AgentException: Cannot find certificate with ‘FindBySubjectName’ ‘xxxxx.cluster.prod.ngpproxy.microsoftonline.cn’ in store ‘My’ 。
Step 3: continue to find the problem that the certificate cannot be found
In the log of obtaining the certificate, it is found that SF is the certificate obtained from kV (key vault). When obtaining the auth challenge in step 5, it took more than 5 minutes from 18:59:02 to 19:04:45.
2021-09-09 18:59:02: < info> [CertificateManager] Beginning refresh for: https://xxxxx-chinanorth-kv.vault.azure.cn/secrets/cluster
2021-09-09 18:59:02: < info> [WindowsCertificateStore] attempting to open store ‘LocalMachine\MY’
2021-09-09 18:59:02: < debug> [WindowsCertificateStore] opening the ‘LocalMachine’ store..
2021-09-09 18:59:02: < debug> [WindowsCertificateStore] store opened successfully.
2021-09-09 18:59:02: < info> [KeyVaultClient] Getting new auth challenge
2021-09-09 19:04:45: < error> [CertificateManager] Refreshing ‘ https://xxxxx-chinanorth-kv.vault.azure.cn/secrets/cluster ‘ failed with KeyVault exception: KeyVaultHttpClient.GetChallenge. – http_ exception: what = ‘WinHttpSendRequest: 12030: The connection with the server was terminated abnormall’ code = ‘windows:12030’
2021-09-09 19:04:45: < info> [CertificateManager] Beginning refresh for:
It can be inferred that when SF is deployed due to network delay, authentication is requested from key vault, and deployment fails due to request timeout.
Redeployment of SF was successful after multiple retries.