Terraform-provider-azurerm: terraform plan hangs forever after trying to upgrade provider to 1.37.0

Created on 26 Nov 2019  ·  23Comments  ·  Source: terraform-providers/terraform-provider-azurerm

Terraform (and AzureRM Provider) Version

  • terraform 0.12.10
  • azurerm 1.37.0

Affected Resource(s)

Not sure what to include here apart from this (mentioned in the logs):

  • azurerm_storage_container
  • azurerm_storage_account

Terraform Configuration Files

resource "azurerm_storage_account" "terraforminfra" {
  name                     = "${replace(var.domain, "-", "")}infra"
  resource_group_name      = azurerm_resource_group.main.name
  location                 = var.region
  account_tier             = "Standard"
  account_replication_type = "ZRS"

  tags = {
    environment = var.domain
  }
}

resource "azurerm_storage_container" "terraform-state" {
  name                  = var.terraform_storage_container_name
  storage_account_name  = azurerm_storage_account.terraforminfra.name
  container_access_type = "private"
}

Debug Output

This just repeats forever

2019/11/26 13:46:35 [TRACE] dag/walk: vertex "provider.azurerm (close)" is waiting for "azurerm_storage_container.terraform-state"
2019/11/26 13:46:36 [TRACE] dag/walk: vertex "azurerm_storage_container.terraform-state" is waiting for "azurerm_storage_account.terraforminfra"
2019/11/26 13:46:36 [TRACE] dag/walk: vertex "output.storage_account_id" is waiting for "azurerm_storage_account.terraforminfra"
2019/11/26 13:46:36 [TRACE] dag/walk: vertex "root" is waiting for "provider.azurerm (close)"
2019/11/26 13:46:40 [TRACE] dag/walk: vertex "provider.azurerm (close)" is waiting for "azurerm_storage_container.terraform-state"
2019/11/26 13:46:41 [TRACE] dag/walk: vertex "azurerm_storage_container.terraform-state" is waiting for "azurerm_storage_account.terraforminfra"
2019/11/26 13:46:41 [TRACE] dag/walk: vertex "output.storage_account_id" is waiting for "azurerm_storage_account.terraforminfra"
2019/11/26 13:46:41 [TRACE] dag/walk: vertex "root" is waiting for "provider.azurerm (close)"
2019/11/26 13:46:45 [TRACE] dag/walk: vertex "provider.azurerm (close)" is waiting for "azurerm_storage_container.terraform-state"
2019/11/26 13:46:46 [TRACE] dag/walk: vertex "azurerm_storage_container.terraform-state" is waiting for "azurerm_storage_account.terraforminfra"
2019/11/26 13:46:46 [TRACE] dag/walk: vertex "output.storage_account_id" is waiting for "azurerm_storage_account.terraforminfra"
2019/11/26 13:46:46 [TRACE] dag/walk: vertex "root" is waiting for "provider.azurerm (close)"
2019/11/26 13:46:50 [TRACE] dag/walk: vertex "provider.azurerm (close)" is waiting for "azurerm_storage_container.terraform-state"
2019/11/26 13:46:51 [TRACE] dag/walk: vertex "output.storage_account_id" is waiting for "azurerm_storage_account.terraforminfra"
2019/11/26 13:46:51 [TRACE] dag/walk: vertex "azurerm_storage_container.terraform-state" is waiting for "azurerm_storage_account.terraforminfra"
2019/11/26 13:46:51 [TRACE] dag/walk: vertex "root" is waiting for "provider.azurerm (close)"

Expected Behavior

Terraform plan should work, upgrade provider, apply necessary changes, etc. Works fine with 1.36.0

Actual Behavior

At some point, terraform plan just hangs forever with the above output, had to enable trace logs to be able to see it

Steps to Reproduce

  1. Update provider to 1.37.0
  2. Run terraform plan
bug regression servicstorage
Source
picture guitmz
👍11

Most helpful comment

The delay is caused by this call https://github.com/terraform-providers/terraform-provider-azurerm/blob/6ed5554bad427aae8872c6ead28b53844b209aa5/azurerm/resource_arm_storage_account.go#L1164.

This eventually calls the code from github.com/Azure/go-autorest/autorest v0.9.2, which was upgraded from 0.9.0 in 1.37.0 release: 

$ git diff v1.36.1 v1.37.0 go.mod
diff --git a/go.mod b/go.mod
index 05c0f84a5..97df6065b 100644
--- a/go.mod
+++ b/go.mod
@@ -1,13 +1,13 @@
 module github.com/terraform-providers/terraform-provider-azurerm

 require (
-       github.com/Azure/azure-sdk-for-go v34.1.0+incompatible
-       github.com/Azure/go-autorest/autorest v0.9.0
+       github.com/Azure/azure-sdk-for-go v36.2.0+incompatible
+       github.com/Azure/go-autorest/autorest v0.9.2
picture alex-goncharov on 28 Nov 2019
👍5

All 23 comments

I see the same behavior on storage_account resource, it actually manages to come out of this after some 20 minutes.

`
$ TF_LOG=TRACE terraform plan --target module.tfe.module.data.azurerm_storage_account.this
...
2019-11-27T09:02:29.498+0100 [DEBUG] plugin.terraform-provider-azurerm_v1.37.0_x4: POST /subscriptions/XXX/resourceGroups/XXX/providers/Microsoft.Storage/storageAccounts/XXX/listKeys?%24expand=kerb&api-version=2019-04-01 HTTP/1.1
...

2019-11-27T09:02:29.648+0100 [DEBUG] plugin.terraform-provider-azurerm_v1.37.0_x4: [DEBUG] AzureRM Response for https://management.azure.com/subscriptions/XXX/resourceGroups/XXX/providers/Microsoft.Storage/storageAccounts/XXX/listKeys?%24expand=kerb&api-version=2019-04-01:
2019-11-27T09:02:29.648+0100 [DEBUG] plugin.terraform-provider-azurerm_v1.37.0_x4: HTTP/2.0 200 OK
2019-11-27T09:02:29.648+0100 [DEBUG] plugin.terraform-provider-azurerm_v1.37.0_x4: {"keys":[{"keyName":"key1","value":"XXX","permissions":"FULL"},{"keyName":"key2","value":"XXX","permissions":"FULL"}]}

...
2019/11/27 09:23:57 [TRACE] dag/walk: vertex "provider.azurerm.fxi_production1_services (close)" is waiting for "module.tfe.module.data.azurerm_storage_account.this"
2019/11/27 09:23:59 [TRACE] dag/walk: vertex "root" is waiting for "provider.azurerm.fxi_production1_services (close)"
2019/11/27 09:24:02 [TRACE] dag/walk: vertex "provider.azurerm.fxi_production1_services (close)" is waiting for "module.tfe.module.data.azurerm_storage_account.this"
2019/11/27 09:24:04 [TRACE] dag/walk: vertex "root" is waiting for "provider.azurerm.fxi_production1_services (close)"
2019/11/27 09:24:04 [TRACE] module.tfe.module.data: eval: *terraform.EvalWriteState
2019/11/27 09:24:04 [TRACE] EvalWriteState: recording 1 dependencies for module.tfe.module.data.azurerm_storage_account.this
2019/11/27 09:24:04 [TRACE] EvalWriteState: writing current state object for module.tfe.module.data.azurerm_storage_account.this
2019/11/27 09:24:04 [TRACE] [walkRefresh] Exiting eval tree: module.tfe.module.data.azurerm_storage_account.this
2019/11/27 09:24:04 [TRACE] vertex "module.tfe.module.data.azurerm_storage_account.this": visit complete
2019/11/27 09:24:04 [TRACE] vertex "module.tfe.module.data.azurerm_storage_account.this": dynamic subgraph completed successfully
2019/11/27 09:24:04 [TRACE] vertex "module.tfe.module.data.azurerm_storage_account.this": visit complete
`

alex-goncharov picture alex-goncharov on 27 Nov 2019
👍1

The delay is caused by this call https://github.com/terraform-providers/terraform-provider-azurerm/blob/6ed5554bad427aae8872c6ead28b53844b209aa5/azurerm/resource_arm_storage_account.go#L1164.

This eventually calls the code from github.com/Azure/go-autorest/autorest v0.9.2, which was upgraded from 0.9.0 in 1.37.0 release: 

$ git diff v1.36.1 v1.37.0 go.mod
diff --git a/go.mod b/go.mod
index 05c0f84a5..97df6065b 100644
--- a/go.mod
+++ b/go.mod
@@ -1,13 +1,13 @@
 module github.com/terraform-providers/terraform-provider-azurerm

 require (
-       github.com/Azure/azure-sdk-for-go v34.1.0+incompatible
-       github.com/Azure/go-autorest/autorest v0.9.0
+       github.com/Azure/azure-sdk-for-go v36.2.0+incompatible
+       github.com/Azure/go-autorest/autorest v0.9.2
alex-goncharov picture alex-goncharov on 28 Nov 2019
👍5

the delay is introduced in https://github.com/Azure/go-autorest/blob/master/autorest/sender.go

$ git diff autorest/v0.9.0 autorest/v0.9.2 sender.go
diff --git a/autorest/sender.go b/autorest/sender.go
index e582489..5e595d7 100644
--- a/autorest/sender.go
+++ b/autorest/sender.go
@@ -289,10 +289,6 @@ func doRetryForStatusCodesImpl(s Sender, r *http.Request, count429 bool, attempt
                        return
                }
                resp, err = s.Do(rr.Request())
-               // if the error isn't temporary don't bother retrying
-               if err != nil && !IsTemporaryNetworkError(err) {
-                       return
-               }
                // we want to retry if err is not nil (e.g. transient network failure).  note that for failed authentication
                // resp and err will both have a value, so in this case we don't want to retry as it will never succeed.
                if err == nil && !ResponseHasStatusCode(resp, codes...) || IsTokenRefreshError(err) {

The debug output here is:

2019-11-28T14:50:12.538+0100 [DEBUG] plugin.terraform-provider-azurerm_v1.36.2: DDDDD ERR Get https://<storage_account_name>.queue.core.windows.net/?comp=properties&restype=service: dial tcp: lookup <storage_account_name>.queue.core.windows.net: no such host

This will never be a successful call for storage accounts that do not have a queue.

alex-goncharov picture alex-goncharov on 28 Nov 2019
👍4

@tombuildsstuff could you please assess this one, as it kills all plans with storage accounts that do not have queues.

alex-goncharov picture alex-goncharov on 28 Nov 2019
👍3

I have the same issue.
On further examination, it terraform does not seem to hang when setting LRS as _account_replication_type_
(I have two identical deployment with this being the only perceived difference.)

fox918 picture fox918 on 2 Dec 2019

I am seeing terraform plan running for 8 mins on an average with 1.37.0 ... its really slow and gives a feeling that terraform plan is hung.

It seems its better to use 1.36.0 till 1.37.0 is stable in terms of performance.

sunnynazar picture sunnynazar on 2 Dec 2019

I have the same issue.
On further examination, it terraform does not seem to hang when setting LRS as _account_replication_type_
(I have two identical deployment with this being the only perceived difference.)

Hey @fox918,
this setting doesn't change anything in my case. I already set it to LRS but it's still slow as hell.
So it might not be related to that.

r0bnet picture r0bnet on 11 Dec 2019

Can confirm also have this same problem when updating the AzureRM provider. Exactly the same issue related to queue call.

sylus picture sylus on 11 Dec 2019

I have the same issue with the destroy of the storage account.
I have wait it for 16 hours before killing it and no results at the end.

KrisPetkov picture KrisPetkov on 13 Dec 2019

Happy New Year!

I am experiencing an issue which seems to be related:

  • Arbitrary, long delays when generating a plan (in either apply/plan)
  • Started happening around the same time (late November)
  • Same version of AzureRM (I have also tried 1.38.0 & 1.39.0)

However, my plan output hangs on seemingly random resources (depending on the workspace, and if any resources have been --target targetted).

I have seen the output freeze after azurerm_function_app, azurerm_app_service and custom module resources.

This happens on every single run.

When targetting one resource (with dependencies), the plan got stuck for 7:30 minutes.

2020-01-03T11:11:31.231Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: [DEBUG] AzureRM Response for https://management.azure.com/subscriptions/REDACTED/resourceGroups/REDACTED/providers/Microsoft.Web/sites/REDACTED-WEBSITE-A/config/web?api-version=2018-02-01: 
2020-01-03T11:11:31.231Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: HTTP/2.0 200 OK
2020-01-03T11:11:31.231Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Cache-Control: no-cache
2020-01-03T11:11:31.231Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Content-Type: application/json
2020-01-03T11:11:31.231Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Date: Fri, 03 Jan 2020 11:11:31 GMT
2020-01-03T11:11:31.231Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Expires: -1
2020-01-03T11:11:31.231Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Pragma: no-cache
2020-01-03T11:11:31.231Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Server: Microsoft-IIS/10.0
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Strict-Transport-Security: max-age=31536000; includeSubDomains
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Vary: Accept-Encoding
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Aspnet-Version: 4.0.30319
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Content-Type-Options: nosniff
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Correlation-Request-Id: e9f9452f-61cc-6e9c-778b-cc1c475d94fb
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Ratelimit-Remaining-Subscription-Reads: 11988
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Request-Id: ea58e47b-868e-4ee7-8af7-f74513e566c9
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Routing-Request-Id: UKSOUTH2:20200103T111131Z:f7bafdbf-9c3a-4b3b-9e28-94c32cadec6b
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Powered-By: ASP.NET
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: 
2020-01-03T11:11:31.232Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: {"id":"/subscriptions/REDACTED/resourceGroups/REDACTED/providers/Microsoft.Web/sites/REDACTED-WEBSITE-A/config/web","name":"REDACTED-WEBSITE-A","type":"Microsoft.Web/sites/config","location":"UK South","tags":{"product":"REDACTED"},"properties":{"numberOfWorkers":1,"defaultDocuments":["Default.htm","Default.html","Default.asp","index.htm","index.html","iisstart.htm","default.aspx","index.php"],"netFrameworkVersion":"v4.0","phpVersion":"5.6","pythonVersion":"","nodeVersion":"","linuxFxVersion":"","windowsFxVersion":null,"requestTracingEnabled":false,"remoteDebuggingEnabled":false,"remoteDebuggingVersion":null,"httpLoggingEnabled":false,"azureMonitorLogCategories":null,"logsDirectorySizeLimit":35,"detailedErrorLoggingEnabled":false,"publishingUsername":"$REDACTED-WEBSITE-A","publishingPassword":null,"appSettings":null,"metadata":null,"connectionStrings":null,"machineKey":null,"handlerMappings":null,"documentRoot":null,"scmType":"VSTSRM","use32BitWorkerProcess":true,"webSocketsEnabled":false,"alwaysOn":false,"javaVersion":null,"javaContainer":null,"javaContainerVersion":null,"appCommandLine":"","managedPipelineMode":"Integrated","virtualApplications":[{"virtualPath":"/","physicalPath":"site\\wwwroot","preloadEnabled":false,"virtualDirectories":null}],"winAuthAdminState":0,"winAuthTenantState":0,"customAppPoolIdentityAdminState":false,"customAppPoolIdentityTenantState":false,"runtimeADUser":null,"runtimeADUserPassword":null,"loadBalancing":"LeastRequests","routingRules":[],"experiments":{"rampUpRules":[]},"limits":null,"autoHealEnabled":false,"autoHealRules":null,"tracingOptions":null,"vnetName":"","siteAuthEnabled":false,"siteAuthSettings":{"enabled":null,"unauthenticatedClientAction":null,"tokenStoreEnabled":null,"allowedExternalRedirectUrls":null,"defaultProvider":null,"clientId":null,"clientSecret":null,"clientSecretCertificateThumbprint":null,"issuer":null,"allowedAudiences":null,"additionalLoginParams":null,"isAadAutoProvisioned":false,"googleClientId":null,"googleClientSecret":null,"googleOAuthScopes":null,"facebookAppId":null,"facebookAppSecret":null,"facebookOAuthScopes":null,"twitterConsumerKey":null,"twitterConsumerSecret":null,"microsoftAccountClientId":null,"microsoftAccountClientSecret":null,"microsoftAccountOAuthScopes":null},"cors":{"allowedOrigins":["https://functions-staging.azure.com","https://functions.azure.com","https://functions-next.azure.com"],"supportCredentials":false},"push":null,"apiDefinition":null,"apiManagementConfig":null,"autoSwapSlotName":null,"localMySqlEnabled":false,"managedServiceIdentityId":null,"xManagedServiceIdentityId":null,"ipSecurityRestrictions":null,"scmIpSecurityRestrictions":null,"scmIpSecurityRestrictionsUseMain":false,"http20Enabled":false,"minTlsVersion":"1.2","ftpsState":"AllAllowed","reservedInstanceCount":0,"preWarmedInstanceCount":null,"healthCheckPath":null,"fileChangeAuditEnabled":false,"functionsRuntimeScaleMonitoringEnabled":false,"websiteTimeZone":null}}
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: [DEBUG] AzureRM Response for https://management.azure.com/subscriptions/REDACTED/resourceGroups/REDACTED/providers/Microsoft.Web/sites/REDACTED-WEBSITE-B/config/web?api-version=2018-02-01: 
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: HTTP/2.0 200 OK
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Cache-Control: no-cache
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Content-Type: application/json
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Date: Fri, 03 Jan 2020 11:11:31 GMT
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Expires: -1
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Pragma: no-cache
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Server: Microsoft-IIS/10.0
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Strict-Transport-Security: max-age=31536000; includeSubDomains
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Vary: Accept-Encoding
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Aspnet-Version: 4.0.30319
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Content-Type-Options: nosniff
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Correlation-Request-Id: e9f9452f-61cc-6e9c-778b-cc1c475d94fb
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Ratelimit-Remaining-Subscription-Reads: 11988
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Request-Id: 66706098-c95d-4528-a400-15df7c741c5c
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Routing-Request-Id: UKSOUTH2:20200103T111131Z:d69501f5-68a2-4a11-a5bb-a7c8d60f4ccf
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Powered-By: ASP.NET
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: 
2020-01-03T11:11:31.301Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: {"id":"/subscriptions/REDACTED/resourceGroups/REDACTED/providers/Microsoft.Web/sites/REDACTED-WEBSITE-B/config/web","name":"REDACTED-WEBSITE-B","type":"Microsoft.Web/sites/config","location":"UK South","tags":{"product":"REDACTED"},"properties":{"numberOfWorkers":1,"defaultDocuments":["Default.htm","Default.html","Default.asp","index.htm","index.html","iisstart.htm","default.aspx","index.php"],"netFrameworkVersion":"v4.0","phpVersion":"5.6","pythonVersion":"","nodeVersion":"","linuxFxVersion":"","windowsFxVersion":null,"requestTracingEnabled":false,"remoteDebuggingEnabled":false,"remoteDebuggingVersion":null,"httpLoggingEnabled":false,"azureMonitorLogCategories":null,"logsDirectorySizeLimit":35,"detailedErrorLoggingEnabled":false,"publishingUsername":"$REDACTED-WEBSITE-B","publishingPassword":null,"appSettings":null,"metadata":null,"connectionStrings":null,"machineKey":null,"handlerMappings":null,"documentRoot":null,"scmType":"VSTSRM","use32BitWorkerProcess":true,"webSocketsEnabled":false,"alwaysOn":false,"javaVersion":null,"javaContainer":null,"javaContainerVersion":null,"appCommandLine":"","managedPipelineMode":"Integrated","virtualApplications":[{"virtualPath":"/","physicalPath":"site\\wwwroot","preloadEnabled":false,"virtualDirectories":null}],"winAuthAdminState":0,"winAuthTenantState":0,"customAppPoolIdentityAdminState":false,"customAppPoolIdentityTenantState":false,"runtimeADUser":null,"runtimeADUserPassword":null,"loadBalancing":"LeastRequests","routingRules":[],"experiments":{"rampUpRules":[]},"limits":null,"autoHealEnabled":false,"autoHealRules":null,"tracingOptions":null,"vnetName":"","siteAuthEnabled":false,"siteAuthSettings":{"enabled":null,"unauthenticatedClientAction":null,"tokenStoreEnabled":null,"allowedExternalRedirectUrls":null,"defaultProvider":null,"clientId":null,"clientSecret":null,"clientSecretCertificateThumbprint":null,"issuer":null,"allowedAudiences":null,"additionalLoginParams":null,"isAadAutoProvisioned":false,"googleClientId":null,"googleClientSecret":null,"googleOAuthScopes":null,"facebookAppId":null,"facebookAppSecret":null,"facebookOAuthScopes":null,"twitterConsumerKey":null,"twitterConsumerSecret":null,"microsoftAccountClientId":null,"microsoftAccountClientSecret":null,"microsoftAccountOAuthScopes":null},"cors":{"allowedOrigins":["https://functions-staging.azure.com","https://functions.azure.com","https://functions-next.azure.com"],"supportCredentials":false},"push":null,"apiDefinition":null,"apiManagementConfig":null,"autoSwapSlotName":null,"localMySqlEnabled":false,"managedServiceIdentityId":null,"xManagedServiceIdentityId":null,"ipSecurityRestrictions":null,"scmIpSecurityRestrictions":null,"scmIpSecurityRestrictionsUseMain":false,"http20Enabled":false,"minTlsVersion":"1.2","ftpsState":"AllAllowed","reservedInstanceCount":0,"preWarmedInstanceCount":null,"healthCheckPath":null,"fileChangeAuditEnabled":false,"functionsRuntimeScaleMonitoringEnabled":false,"websiteTimeZone":null}}
2020/01/03 11:18:57 [DEBUG] ReferenceTransformer: "module.REDACTED.module.REDACTED.azurerm_function_app.REDACTED-WEBSITE-C" references: []
2020-01-03T11:18:57.619Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: [DEBUG] AzureRM Request: 
2020-01-03T11:18:57.619Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: GET /subscriptions/REDACTED/resourceGroups/REDACTED/providers/Microsoft.Web/sites/REDACTED-WEBSITE-C?api-version=2018-02-01 HTTP/1.1
2020-01-03T11:18:57.619Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Host: management.azure.com
2020-01-03T11:18:57.619Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: User-Agent: Go/go1.12.6 (amd64-windows) go-autorest/v13.3.0 Azure-SDK-For-Go/v36.2.0 web/2018-02-01 HashiCorp Terraform/0.12.17 (+https://www.terraform.io) Terraform Plugin SDK/1.1.1 terraform-provider-azurerm/1.39.0 pid-222c6c49-1b0a-5959-a213-6608f9eb8820
2020-01-03T11:18:57.619Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Correlation-Request-Id: e9f9452f-61cc-6e9c-778b-cc1c475d94fb
2020-01-03T11:18:57.619Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Accept-Encoding: gzip
2020-01-03T11:18:57.619Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: 
2020-01-03T11:18:57.619Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: 
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: [DEBUG] AzureRM Response for https://management.azure.com/subscriptions/REDACTED/resourceGroups/REDACTED/providers/Microsoft.Web/sites/REDACTED-WEBSITE-C?api-version=2018-02-01: 
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: HTTP/2.0 200 OK
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Cache-Control: no-cache
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Content-Type: application/json
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Date: Fri, 03 Jan 2020 11:18:57 GMT
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Etag: "1D5C158DBBD5980"
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Expires: -1
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Pragma: no-cache
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Server: Microsoft-IIS/10.0
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Strict-Transport-Security: max-age=31536000; includeSubDomains
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Vary: Accept-Encoding
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Aspnet-Version: 4.0.30319
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Content-Type-Options: nosniff
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Correlation-Request-Id: e9f9452f-61cc-6e9c-778b-cc1c475d94fb
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Ratelimit-Remaining-Subscription-Reads: 11997
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Request-Id: 8c5effb9-899e-47a6-b77e-c613ed483e81
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Routing-Request-Id: UKSOUTH2:20200103T111857Z:06d9f84f-f97f-444b-a242-47562a2fe5e3
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Powered-By: ASP.NET
2020-01-03T11:18:57.873Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: 
2020-01-03T11:18:57.874Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: {"id":"/subscriptions/REDACTED/resourceGroups/REDACTED/providers/Microsoft.Web/sites/REDACTED-WEBSITE-C","name":"REDACTED-WEBSITE-C","type":"Microsoft.Web/sites","kind":"functionapp","location":"UK South","tags":{"env":"prod","product":"REDACTED","qos":"a"},"properties":{"name":"REDACTED-WEBSITE-C","state":"Running","hostNames":["REDACTED-WEBSITE-C.azurewebsites.net"],"webSpace":"REDACTED-UKSouthwebspace","selfLink":"https://waws-prod-ln1-013.api.azurewebsites.windows.net:454/subscriptions/REDACTED/webspaces/REDACTED-UKSouthwebspace/sites/REDACTED-WEBSITE-C","repositorySiteName":"REDACTED-WEBSITE-C","owner":null,"usageState":"Normal","enabled":true,"adminEnabled":true,"enabledHostNames":["REDACTED-WEBSITE-C.azurewebsites.net","REDACTED-WEBSITE-C.scm.azurewebsites.net"],"siteProperties":{"metadata":null,"properties":[{"name":"LinuxFxVersion","value":""},{"name":"WindowsFxVersion","value":null}],"appSettings":null},"availabilityState":"Normal","sslCertificates":null,"csrs":[],"cers":null,"siteMode":null,"hostNameSslStates":[{"name":"REDACTED-WEBSITE-C.azurewebsites.net","sslState":"Disabled","ipBasedSslResult":null,"virtualIP":null,"thumbprint":null,"toUpdate":null,"toUpdateIpBasedSsl":null,"ipBasedSslState":"NotConfigured","hostType":"Standard"},{"name":"REDACTED-WEBSITE-C.scm.azurewebsites.net","sslState":"Disabled","ipBasedSslResult":null,"virtualIP":null,"thumbprint":null,"toUpdate":null,"toUpdateIpBasedSsl":null,"ipBasedSslState":"NotConfigured","hostType":"Repository"}],"computeMode":null,"serverFarm":null,"serverFarmId":"/subscriptions/REDACTED/resourceGroups/REDACTED/providers/Microsoft.Web/serverfarms/REDACTED","reserved":false,"isXenon":false,"hyperV":false,"lastModifiedTimeUtc":"2020-01-02T10:39:06.52","storageRecoveryDefaultState":"Running","contentAvailabilityState":"Normal","runtimeAvailabilityState":"Normal","siteConfig":null,"deploymentId":"REDACTED-WEBSITE-C","trafficManagerHostNames":null,"sku":"Dynamic","scmSiteAlsoStopped":false,"targetSwapSlot":null,"hostingEnvironment":null,"hostingEnvironmentProfile":null,"clientAffinityEnabled":false,"clientCertEnabled":false,"clientCertExclusionPaths":null,"hostNamesDisabled":false,"domainVerificationIdentifiers":null,"customDomainVerificationId":"E1BEA734373D07AB8390573B757E2B31D5F631BD41D46F01E24D64D22263954D","kind":"functionapp","inboundIpAddress":"51.140.59.233","possibleInboundIpAddresses":"51.140.59.233","outboundIpAddresses":"51.140.59.233,51.140.68.158,51.140.70.218,51.140.120.15,51.140.60.60","possibleOutboundIpAddresses":"51.140.59.233,51.140.68.158,51.140.70.218,51.140.120.15,51.140.60.60,51.140.73.7,51.140.60.160","containerSize":1536,"dailyMemoryTimeQuota":0,"suspendedTill":null,"siteDisabledReason":0,"functionExecutionUnitsCache":null,"maxNumberOfWorkers":null,"homeStamp":"waws-prod-ln1-013","cloningInfo":null,"hostingEnvironmentId":null,"tags":{"env":"prod","product":"REDACTED","qos":"a"},"resourceGroup":"REDACTED","defaultHostName":"REDACTED-WEBSITE-C.azurewebsites.net","slotSwapStatus":null,"httpsOnly":false,"redundancyMode":"None","inProgressOperationId":null,"geoDistributions":null,"privateEndpointConnections":[],"buildVersion":null,"targetBuildVersion":null}}
2020-01-03T11:18:57.875Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: [DEBUG] AzureRM Request: 
2020-01-03T11:18:57.875Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: POST /subscriptions/REDACTED/resourceGroups/REDACTED/providers/Microsoft.Web/sites/REDACTED-WEBSITE-C/config/appsettings/list?api-version=2018-02-01 HTTP/1.1
2020-01-03T11:18:57.875Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Host: management.azure.com
2020-01-03T11:18:57.875Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: User-Agent: Go/go1.12.6 (amd64-windows) go-autorest/v13.3.0 Azure-SDK-For-Go/v36.2.0 web/2018-02-01 HashiCorp Terraform/0.12.17 (+https://www.terraform.io) Terraform Plugin SDK/1.1.1 terraform-provider-azurerm/1.39.0 pid-222c6c49-1b0a-5959-a213-6608f9eb8820
2020-01-03T11:18:57.875Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Content-Length: 0
2020-01-03T11:18:57.875Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: X-Ms-Correlation-Request-Id: e9f9452f-61cc-6e9c-778b-cc1c475d94fb
2020-01-03T11:18:57.875Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: Accept-Encoding: gzip
2020-01-03T11:18:57.875Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: 
2020-01-03T11:18:57.875Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: 
2020-01-03T11:18:58.043Z [DEBUG] plugin.terraform-provider-azurerm_v1.39.0_x4.exe: [DEBUG] AzureRM Response for https://management.azure.com/subscriptions/REDACTED/resourceGroups/REDACTED/providers/Microsoft.Web/sites/REDACTED-WEBSITE-C/config/appsettings/list?api-version=2018-02-01:
BadgerCode picture BadgerCode on 3 Jan 2020

If I understand this issue correctly, it's supposed to be resolved by https://github.com/terraform-providers/terraform-provider-azurerm/pull/5316. Just as a note for everyone looking into this.

embik picture embik on 8 Jan 2020
👍3

👋

From what I can tell this should be fixed in #5316 - since that's been merged I'm going to close this issue for the moment; but if you're still seeing this after upgrading to v1.41 (once that's released) please let us know and we'll take another look :)

Thanks!

tombuildsstuff picture tombuildsstuff on 14 Jan 2020
👍2

@tombuildsstuff do you mean v1.41 (instead v1.40)?

KrisPetkov picture KrisPetkov on 14 Jan 2020

@KrisPetkov yes 🤦‍♂ - thanks for pointing that out, will update now :)

tombuildsstuff picture tombuildsstuff on 14 Jan 2020

This has been released in version 1.41.0 of the provider. Please see the Terraform documentation on provider versioning or reach out if you need any assistance upgrading. As an example:

provider "azurerm" {
    version = "~> 1.41.0"
}
# ... other configuration ...
hashibot[bot] picture hashibot[bot] on 16 Jan 2020
🎉2 ❤1

Thank you!
This has fixed the problem.

BadgerCode picture BadgerCode on 16 Jan 2020

I'm still facing the same issue. Unfortunately the last update of the provider didn't fix the issue for me.
@tombuildsstuff can you please check this issue #5434 ?
I just want to know if I'm doing something wrong or the issue is still present for some reason.

KrisPetkov picture KrisPetkov on 20 Jan 2020

I seem to be having this issue (terraform just hangs when refreshing it's state) with the 1.41 version of the azurerm provider using terraform version 0.12.19

Any ideas, as I'm pretty much blocked applying updates to our clusters?

I'm using remote state (azure storage account) and I can see terraform acquiring a state lock, refreshing all the resources and then it just hangs there......

marty2bell picture marty2bell on 20 Jan 2020
👍1

@KrisPetkov @marty2bell is it storage account resource that delays the plan, or something else? Running terraform with TF_LOG=TRACE could give you a clue.

1.41.0 had resolved the issue for us.

alex-goncharov picture alex-goncharov on 20 Jan 2020

@alex-goncharov running the destroy with TF_LOG=TRACE I'm gettings recurring logs like this one:

2020/01/17 12:05:07 [TRACE] dag/walk: vertex "output.my_storage_primary_file_endpoint (destroy)", waiting for: "output.my_storage_account_secondary_key (destroy)"
2020/01/17 12:05:07 [TRACE] dag/walk: vertex "output.my_storage_account_primary_key (destroy)", waiting for: "output.my_storage_account (destroy)"
2020/01/17 12:05:07 [TRACE] dag/walk: vertex "root", waiting for: "meta.count-boundary (count boundary fixup)"
2020/01/17 12:05:07 [TRACE] dag/walk: vertex "provider.azurerm (close)", waiting for: "azurerm_storage_account.my_storage_azure (destroy)"

KrisPetkov picture KrisPetkov on 20 Jan 2020

that looks normal, destroying azure storage account is never quick

The issue in question would appear during the plan.

alex-goncharov picture alex-goncharov on 20 Jan 2020

@alex-goncharov I have found the problem and the reason. Tou can see it described here but for now I don't have a solution...

Do you use network rules for your storage account by any chance?

KrisPetkov picture KrisPetkov on 23 Jan 2020

I'm going to lock this issue because it has been closed for _30 days_ ⏳. This helps our maintainers find and focus on the active issues.

If you feel this issue should be reopened, we encourage creating a new issue linking back to this one for added context. If you feel I made an error 🤖 🙉 , please reach out to my human friends 👉 [email protected]. Thanks!

hashibot[bot] picture hashibot[bot] on 28 Mar 2020
Was this page helpful?
0 / 5 - 0 ratings

Related issues

Lachlan-White picture Lachlan-White  ·  3Comments
MMollyy picture MMollyy  ·  3Comments
mlazowik picture mlazowik  ·  3Comments
Kanikamiglani31 picture Kanikamiglani31  ·  3Comments
bentterp picture bentterp  ·  3Comments