"State blob is already locked" persists for hours after plan/apply

MohnJadden commented 2 years ago

Is there an existing issue for this?

[X] I have searched the existing issues

Community Note

Please vote on this issue by adding a :thumbsup: reaction to the original issue to help the community and maintainers prioritize this request
Please do not leave "+1" or "me too" comments, they generate extra noise for issue followers and do not help prioritize the request
If you are interested in working on this issue or have submitted a pull request, please leave a comment

Terraform Version

1.2.6

AzureRM Provider Version

3.5.0

Affected Resource(s)/Data Source(s)

Any

Terraform Configuration Files

#Configure Terraform to talk to the Azure backend
terraform {
  required_providers {
    azurerm = {
      source  = "hashicorp/azurerm"
      version = ">=3.5.0"
    }
  }
  backend "azurerm"{
    resource_group_name = "Companyname-Terraform-RG"
    storage_account_name = "tfstate"
    container_name = "tfstate"
    key = "terraform.tfstate"
  }
}

# Configure the Microsoft Azure Provider
provider "azurerm" {
  skip_provider_registration = "true"
  features {}
}

resource "azurerm_resource_group" "sample-rg" {
name = "SampleRG"
location = "eastus"
}

Debug Output/Panic Output

Error: Error acquiring the state lock
│
│ Error message: state blob is already locked
│ Lock Info:
│   ID:        8da21ca2-03d5-fb79-a257-5caa5c942fc3
│   Path:      tfstate/terraform.tfstate
│   Operation: OperationTypeApply
│   Who:       COMPANYDOMAIN\myusername@myhostname
│   Version:   1.2.6
│   Created:   2022-10-25 18:24:20.6609951 +0000 UTC
│   Info:
│
│
│ Terraform acquires a state lock to protect the state from being written
│ by multiple users at the same time. Please resolve the issue above and try
│ again. For most commands, you can disable locking with the "-lock=false"
│ flag, but this is not recommended.

Expected Behaviour

Running terraform plan or terraform apply should perform a plan or apply action. If the state is in use, the lock should apply and the error should be produced. When the state is not in use, the lock should release, the storage blob lease should automatically expire, and terraform plan or apply should proceed as normal.

Actual Behaviour

The error above is produced, and the lock/lease stays in place on the Azure storage container. It stays in place until I manually break the lease or use -lock=false.

Steps to Reproduce

Run a terraform plan or terraform apply
Allow the plan or apply to complete
Run another terraform plan or apply
Error recurs

Important Factoids

Running in a standard Azure (non-gov/China/Germany) storage account.

References

https://github.com/hashicorp/terraform/issues/25818 references this issue but was noted that it occurred in a storage account with Hierarchical Namespace enabled. My storage account has this disabled.

MohnJadden commented 2 years ago

Not sure why the bot removed the bug label, as this is definitely a bug.

magodo commented 2 years ago

@MohnJadden Thank you for submitting this! The issue seems relates to the backend, while this repo is only for provider related issues. So I'd suggest you migrate this issue to the hashicorp/terraform repo, as that is where the backend related code resides.

tombuildsstuff commented 2 years ago

@MohnJadden thanks for opening this issue - so that we can take a look into this can you provide the debug logs from Terraform for this & the previous Apply?

MohnJadden commented 1 year ago

Apologies for the delay. I don't have debug logs for the apply when this originated but here are the logs (with excess resources removed and sensitive details edited/redacted) for when I run terraform apply (it does not occur at all for terraform plan):

2023-07-05T11:28:43.552-0400 [INFO]  Terraform version: 1.3.3
2023-07-05T11:28:43.557-0400 [DEBUG] using github.com/hashicorp/go-tfe v1.9.0
2023-07-05T11:28:43.557-0400 [DEBUG] using github.com/hashicorp/hcl/v2 v2.14.1
2023-07-05T11:28:43.557-0400 [DEBUG] using github.com/hashicorp/terraform-config-inspect v0.0.0-20210209133302-4fd17a0faac2
2023-07-05T11:28:43.557-0400 [DEBUG] using github.com/hashicorp/terraform-svchost v0.0.0-20200729002733-f050f53b9734
2023-07-05T11:28:43.557-0400 [DEBUG] using github.com/zclconf/go-cty v1.11.1
2023-07-05T11:28:43.557-0400 [INFO]  Go runtime version: go1.19.1
2023-07-05T11:28:43.558-0400 [INFO]  CLI args: []string{"C:\\ProgramData\\chocolatey\\lib\\terraform\\tools\\terraform.exe", "plan"}
2023-07-05T11:28:43.571-0400 [DEBUG] Attempting to open CLI config file: C:\Users\myname\AppData\Roaming\terraform.rc
2023-07-05T11:28:43.571-0400 [DEBUG] File doesn't exist, but doesn't need to. Ignoring.
2023-07-05T11:28:43.572-0400 [DEBUG] ignoring non-existing provider search directory terraform.d/plugins
2023-07-05T11:28:43.573-0400 [DEBUG] ignoring non-existing provider search directory C:\Users\myname\AppData\Roaming\terraform.d\plugins
2023-07-05T11:28:43.575-0400 [DEBUG] ignoring non-existing provider search directory C:\Users\myname\AppData\Roaming\HashiCorp\Terraform\plugins
2023-07-05T11:28:43.575-0400 [INFO]  CLI command args: []string{"plan"}
2023-07-05T11:28:43.588-0400 [INFO]  Testing if Service Principal / Client Certificate is applicable for Authentication..
2023-07-05T11:28:43.588-0400 [INFO]  Testing if Multi Tenant Service Principal / Client Secret is applicable for Authentication..
2023-07-05T11:28:43.588-0400 [INFO]  Testing if Service Principal / Client Secret is applicable for Authentication..
2023-07-05T11:28:43.588-0400 [INFO]  Testing if OIDC is applicable for Authentication..
2023-07-05T11:28:43.588-0400 [INFO]  Testing if Managed Service Identity is applicable for Authentication..
2023-07-05T11:28:43.588-0400 [INFO]  Testing if Obtaining a Multi-tenant token from the Azure CLI is applicable for Authentication..
2023-07-05T11:28:43.588-0400 [INFO]  Testing if Obtaining a token from the Azure CLI is applicable for Authentication..
2023-07-05T11:28:43.588-0400 [INFO]  Using Obtaining a token from the Azure CLI for Authentication
2023-07-05T11:28:48.011-0400 [INFO]  Getting OAuth config for endpoint https://login.microsoftonline.com/ with  tenant mytenant
2023-07-05T11:28:48.011-0400 [DEBUG] Obtaining an MSAL / Microsoft Graph token for Resource Manager..
2023-07-05T11:28:52.043-0400 [DEBUG] checking for provisioner in "."
2023-07-05T11:28:52.043-0400 [DEBUG] checking for provisioner in "C:\\ProgramData\\chocolatey\\lib\\terraform\\tools"
2023-07-05T11:28:52.054-0400 [INFO]  backend/local: starting Plan operation
2023-07-05T11:28:52.054-0400 [DEBUG] Building the Blob Client from an Access Token (using user credentials)
2023-07-05T11:28:52.055-0400 [DEBUG] Azure Backend Request: 
POST /subscriptions/mysubscription/resourceGroups/mycompany-Terraform-RG/providers/Microsoft.Storage/storageAccounts/mycompanytfstate/listKeys?api-version=2021-01-01 HTTP/1.1
Host: management.azure.com
User-Agent: HashiCorp Terraform/1.3.3 (+https://www.terraform.io)
Content-Length: 0
Accept-Encoding: gzip
2023-07-05T11:28:52.337-0400 [DEBUG] Azure Backend Response for https://management.azure.com/subscriptions/mysubscription/resourceGroups/mycompany-Terraform-RG/providers/Microsoft.Storage/storageAccounts/mycompanytfstate/listKeys?api-version=2021-01-01: 
HTTP/2.0 200 OK
Cache-Control: no-cache
Content-Type: application/json
Date: Wed, 05 Jul 2023 15:28:51 GMT
Expires: -1
Pragma: no-cache
Server: Microsoft-Azure-Storage-Resource-Provider/1.0,Microsoft-HTTPAPI/2.0 Microsoft-HTTPAPI/2.0
Strict-Transport-Security: max-age=31536000; includeSubDomains
Vary: Accept-Encoding
X-Content-Type-Options: nosniff
X-Ms-Correlation-Request-Id: 9dfd8891-09c3-448a-a08b-e4219dd04bdd
X-Ms-Ratelimit-Remaining-Subscription-Resource-Requests: 11994
X-Ms-Request-Id: b6091a4a-310b-40e0-a6ce-cc9a62e77231
X-Ms-Routing-Request-Id: EASTUS:20230705T152852Z:9dfd8891-09c3-448a-a08b-e4219dd04bdd

{"keys":[{"keyName":"key1","value":"redacted","permissions":"FULL"},{"keyName":"key2","value":"redacted","permissions":"FULL"}]}
2023-07-05T11:28:52.338-0400 [DEBUG] Azure Backend Request: 
GET /tfstate/terraform.tfstate HTTP/1.1
Host: mycompanytfstate.blob.core.windows.net
User-Agent: HashiCorp Terraform/1.3.3 (+https://www.terraform.io)
X-Ms-Date: Wed, 05 Jul 2023 15:28:52 GMT
X-Ms-Version: 2018-11-09
Accept-Encoding: gzip
2023-07-05T11:28:52.388-0400 [DEBUG] Azure Backend Response for https://mycompanytfstate.blob.core.windows.net/tfstate/terraform.tfstate: 
HTTP/1.1 200 OK
Content-Length: 165681
Accept-Ranges: bytes
Content-Md5: redacted
Content-Type: application/json
Date: Wed, 05 Jul 2023 15:28:52 GMT
Etag: "0x8DB7D69E8598A4B"
Last-Modified: Wed, 05 Jul 2023 15:10:02 GMT
Server: Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0
X-Ms-Blob-Type: BlockBlob
X-Ms-Creation-Time: Mon, 03 Oct 2022 18:11:04 GMT
X-Ms-Lease-Duration: infinite
X-Ms-Lease-State: leased
X-Ms-Lease-Status: locked
X-Ms-Meta-Terraformlockid: eyJJRCI6IjBiZTFhZmY0LTNlMTQtM2JjMi0yZjgwLWM1OWFhMGFkMzE4ZSIsIk9wZXJhdGlvbiI6Ik9wZXJhdGlvblR5cGVBcHBseSIsIkluZm8iOiIiLCJXaG8iOiJITUktSU5DXFxNUGZlZmZlckBpbmZyYS12LTciLCJWZXJzaW9uIjoiMS4zLjMiLCJDcmVhdGVkIjoiMjAyMy0wNy0wNVQxNToxMDowMi4zMTIxNjkzWiIsIlBhdGgiOiJ0ZnN0YXRlL3RlcnJhZm9ybS50ZnN0YXRlIn0=
X-Ms-Request-Id: b6af2ff9-401e-0067-5e55-aff002000000
X-Ms-Server-Encrypted: true
X-Ms-Version: 2018-11-09

{
  "version": 4,
  "terraform_version": "1.3.3",
  "serial": 179,
  "lineage": "c4e5b5a0-5977-3645-c4f8-aae7b8bd0e18",
  "outputs": {},
  "resources": [
    {
      "mode": "managed",
      "type": "azurerm_resource_group",
      "name": "vdi-rg",
      "provider": "provider[\"registry.terraform.io/hashicorp/azurerm\"]",
      "instances": [
        {
          "index_key": "Team1",
          "schema_version": 0,
          "attributes": {
            "id": "/subscriptions/mysubscription/resourceGroups/TeamName-VDI",
            "location": "eastus",
            "name": "TeamName-VDI",
            "tags": {
              "DepartmentName": "Analytics",
              "Location": "NY",
              "Owner": "bossname,",
              "TeamName": "TeamName",
              "TechnicalContact": "techname,"
            },
            "timeouts": {
              "create": null,
              "delete": null,
              "read": null,
              "update": null
            }
          },
          "sensitive_attributes": [],
          "private": "redacted"
        }
}
2023-07-05T11:28:54.707-0400 [DEBUG] Azure Backend Request: 
HEAD /tfstate/terraform.tfstate HTTP/1.1
Host: mycompanytfstate.blob.core.windows.net
User-Agent: HashiCorp Terraform/1.3.3 (+https://www.terraform.io)
X-Ms-Date: Wed, 05 Jul 2023 15:28:54 GMT
X-Ms-Version: 2018-11-09
2023-07-05T11:28:54.713-0400 [DEBUG] Azure Backend Response for https://mycompanytfstate.blob.core.windows.net/tfstate/terraform.tfstate: 
HTTP/1.1 200 OK
Content-Length: 165681
Accept-Ranges: bytes
Content-Md5: ZmIcKxbn3P+X8e18unmymA==
Content-Type: application/json
Date: Wed, 05 Jul 2023 15:28:54 GMT
Etag: "0x8DB7D69E8598A4B"
Last-Modified: Wed, 05 Jul 2023 15:10:02 GMT
Server: Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0
X-Ms-Access-Tier: Hot
X-Ms-Access-Tier-Inferred: true
X-Ms-Blob-Type: BlockBlob
X-Ms-Creation-Time: Mon, 03 Oct 2022 18:11:04 GMT
X-Ms-Lease-Duration: infinite
X-Ms-Lease-State: leased
X-Ms-Lease-Status: locked
X-Ms-Meta-Terraformlockid: eyJJRCI6IjBiZTFhZmY0LTNlMTQtM2JjMi0yZjgwLWM1OWFhMGFkMzE4ZSIsIk9wZXJhdGlvbiI6Ik9wZXJhdGlvblR5cGVBcHBseSIsIkluZm8iOiIiLCJXaG8iOiJITUktSU5DXFxNUGZlZmZlckBpbmZyYS12LTciLCJWZXJzaW9uIjoiMS4zLjMiLCJDcmVhdGVkIjoiMjAyMy0wNy0wNVQxNToxMDowMi4zMTIxNjkzWiIsIlBhdGgiOiJ0ZnN0YXRlL3RlcnJhZm9ybS50ZnN0YXRlIn0=
X-Ms-Request-Id: b6af36f9-401e-0067-2455-aff002000000
X-Ms-Server-Encrypted: true
X-Ms-Version: 2018-11-09
2023-07-05T11:28:54.713-0400 [DEBUG] Azure Backend Request: 
HEAD /tfstate/terraform.tfstate HTTP/1.1
Host: mycompanytfstate.blob.core.windows.net
User-Agent: HashiCorp Terraform/1.3.3 (+https://www.terraform.io)
X-Ms-Date: Wed, 05 Jul 2023 15:28:54 GMT
X-Ms-Version: 2018-11-09
2023-07-05T11:28:54.717-0400 [DEBUG] Azure Backend Response for https://mycompanytfstate.blob.core.windows.net/tfstate/terraform.tfstate: 
HTTP/1.1 200 OK
Content-Length: 165681
Accept-Ranges: bytes
Content-Md5: ZmIcKxbn3P+X8e18unmymA==
Content-Type: application/json
Date: Wed, 05 Jul 2023 15:28:54 GMT
Etag: "0x8DB7D69E8598A4B"
Last-Modified: Wed, 05 Jul 2023 15:10:02 GMT
Server: Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0
X-Ms-Access-Tier: Hot
X-Ms-Access-Tier-Inferred: true
X-Ms-Blob-Type: BlockBlob
X-Ms-Creation-Time: Mon, 03 Oct 2022 18:11:04 GMT
X-Ms-Lease-Duration: infinite
X-Ms-Lease-State: leased
X-Ms-Lease-Status: locked
X-Ms-Meta-Terraformlockid: eyJJRCI6IjBiZTFhZmY0LTNlMTQtM2JjMi0yZjgwLWM1OWFhMGFkMzE4ZSIsIk9wZXJhdGlvbiI6Ik9wZXJhdGlvblR5cGVBcHBseSIsIkluZm8iOiIiLCJXaG8iOiJITUktSU5DXFxNUGZlZmZlckBpbmZyYS12LTciLCJWZXJzaW9uIjoiMS4zLjMiLCJDcmVhdGVkIjoiMjAyMy0wNy0wNVQxNToxMDowMi4zMTIxNjkzWiIsIlBhdGgiOiJ0ZnN0YXRlL3RlcnJhZm9ybS50ZnN0YXRlIn0=
X-Ms-Request-Id: b6af3700-401e-0067-2b55-aff002000000
X-Ms-Server-Encrypted: true
X-Ms-Version: 2018-11-09

hashicorp / terraform-provider-azurerm