😵

Check! TerraformでAzure FunctionsのVNet統合設定で発生しうるデッドロックを回避する

17 min read

Prologue

Microsoft Azure にリソース展開する Terraform を記述しています。

ストレージがサブネットの作成を待ったままタイムアップしてしまうエラーが発生し手こずったので、その解決方法を書き留めます。

なお、タイプアップだけなら terraform apply コマンドの -lock-timeout パラメータで対処もできそうですが、可能な限り構成の仕方で解消した方が無難と思い検証しました。

ストレージがサブネットの作成を待ったままタイムアップしてしまう

検証環境

検証に利用した構成、及び terraform のスクリプトは下記のとおりです。

  • サブネットには、Azure App service からのVNet統合を受け付けるための delegation と、Azure Storage account へのサービスエンドポイントを設定する
  • Azure Function では VNet 統合の設定を行い、サブネットと紐づける
  • Azure Storage account はサブネットからのアクセスのみ許可する
  • Azure Function はその実行に Azure Storage account を利用する

terraform では、下記の部分で上記のネットワークの設定をしています。

リソース 設定項目 説明
azurerm_subnet (for_func) delegation Azure App service からの VNet統合を受け付けるため
azurerm_subnet (for_func) service_endpoints Azure Storage account へのサービスエンドポイントと設定する
azurerm_function_app (main) storage_account_name, storage_account_access_key 実行時に利用する Azure Storage account を指定する
azurerm_app_service_virtual_network_swift_connection (for_func) サブネットに対するVNet統合を設定する
azurerm_storage_account (for_func) network_rules 指定したサブネットからのアクセスのみ許可する

なお、当初エラーが発生した環境では、上記の構成を 2つ含んでいて、それぞれモジュールに分けて記述していました。さらに一方の function が他方の function にアクセスできるようサブネットのサービスポイントとして設定するなど、複雑な構成になっています。これでは問題の切り分けが相当困難だったので、この検証環境では、リソース構成を簡素化し、現象を発生させやすくするために、仮想ネットワークに多量のサブネット(snet-as-dummy-09)を作ることで検証を進めるに至りました。そのため、多量のサブネット作成は本件の現象に直接作用するものではありません。

※ 検証目的なので、値の直書きなどコードの再利用性は無視しています。

main.tf
terraform {
  required_providers {
    azurerm = {
      source  = "hashicorp/azurerm"
      version = ">= 2.42"
    }
  }
}

provider "azurerm" {
  features {}
}

variable "identifier" {
  type    = string
  default = "my-service"
}

resource "azurerm_resource_group" "main" {
  name     = "rg-${var.identifier}"
  location = "japaneast"
}

resource "azurerm_virtual_network" "main" {
  name                = "vnet-main"
  location            = azurerm_resource_group.main.location
  resource_group_name = azurerm_resource_group.main.name
  address_space       = ["10.0.0.0/16"]
}

resource "azurerm_subnet" "for_func" {
  name                  = "snet-for-func"
  resource_group_name   = azurerm_resource_group.main.name
  virtual_network_name  = azurerm_virtual_network.main.name
  address_prefixes      = [cidrsubnet("10.0.0.0/16", 8, 0)]
  service_endpoints     = ["Microsoft.Storage", "Microsoft.Web"]

  delegation {
    name = "Delegation"
    service_delegation {
      name = "Microsoft.Web/serverFarms"
    }
  }
}

resource "azurerm_subnet" "dummy" {
  count = 10
  name                  = "snet-as-dummy-${count.index}"
  resource_group_name   = azurerm_resource_group.main.name
  virtual_network_name  = azurerm_virtual_network.main.name
  address_prefixes      = [cidrsubnet("10.0.0.0/16", 8, 1 + count.index)]
  service_endpoints     = ["Microsoft.Web"]
}

resource "azurerm_app_service_plan" "for_func" {
  name                = "plan-${var.identifier}"
  location            = azurerm_resource_group.main.location
  resource_group_name = azurerm_resource_group.main.name
  sku {
    tier = "PremiumV2"
    size = "P1V2"
  }
}

resource "azurerm_function_app" "main" {
  name                       = "func-${var.identifier}"
  location                   = azurerm_resource_group.main.location
  resource_group_name        = azurerm_resource_group.main.name
  app_service_plan_id        = azurerm_app_service_plan.for_func.id
  storage_account_name       = azurerm_storage_account.for_func.name
  storage_account_access_key = azurerm_storage_account.for_func.primary_access_key
}

resource "azurerm_app_service_virtual_network_swift_connection" "for_func" {
  app_service_id = azurerm_function_app.main.id
  subnet_id      = azurerm_subnet.for_func.id
}

#------------------------------------------------------------------------------
# Storage
#------------------------------------------------------------------------------
resource "azurerm_storage_account" "for_func" {
  name                     = "stmainfunction"
  location                 = azurerm_resource_group.main.location
  resource_group_name      = azurerm_resource_group.main.name
  account_kind             = "StorageV2"
  account_tier             = "Standard"
  account_replication_type = "LRS"

  network_rules {
    default_action             = "Deny"
    virtual_network_subnet_ids = [azurerm_subnet.for_func.id]
  }
}
#------------------------------------------------------------------------------

エラー内容

上記の構成で terraform apply を実行すると、下記のエラーが発生します。

Error: Error waiting for Azure Storage Account "stmainfunction" to be created: Future#WaitForCompletion: the number of retries has been exceeded: StatusCode=400 -- Original Error: Code="NetworkAclsValidationFailure" Message="Validation of network acls failure: SubnetsNotProvisioned:Cannot proceed with operation because subnets snet-for-func of the virtual network /subscriptions/12345678-1234-1234-1234-123456789012/resourceGroups/rg-my-service/providers/Microsoft.Network/virtualNetworks/vnet-main are not provisioned. They are in Updating state.."

  on main.tf line 82, in resource "azurerm_storage_account" "for_func":
  82: resource "azurerm_storage_account" "for_func" {

Azure Storage Account の作成が、リトライ回数を超えてしまい失敗しました。

Error waiting for Azure Storage Account "stmainfunction" to be created: Future#WaitForCompletion: the number of retries has been exceeded

その直接の原因は、NetworkAclsValidationFailure ということで、対象のサブネットが更新中のステータスのままプロビジョニングされておらず、Azure Storage account でネットワークルールを設定できなかったようです。

Original Error: Code="NetworkAclsValidationFailure" Message="Validation of network acls failure: SubnetsNotProvisioned:Cannot proceed with operation because subnets snet-for-func of the virtual network /subscriptions/12345678-1234-1234-1234-123456789012/resourceGroups/rg-my-service/providers/Microsoft.Network/virtualNetworks/vnet-main are not provisioned. They are in Updating state.."

詳細に状況を知るために、実行時に TF_LOG=TRACE TF_LOG_PATH=./trace.log を指定してログを取得し、確認してみます。

<中略>
2021/01/14 18:10:43 [TRACE] dag/walk: vertex "azurerm_function_app.main" is waiting for "azurerm_storage_account.for_func"
2021/01/14 18:10:43 [TRACE] dag/walk: vertex "azurerm_app_service_virtual_network_swift_connection.for_func" is waiting for "azurerm_function_app.main"
2021/01/14 18:10:43 [TRACE] dag/walk: vertex "root" is waiting for "meta.count-boundary (EachMode fixup)"
2021/01/14 18:10:43 [TRACE] dag/walk: vertex "meta.count-boundary (EachMode fixup)" is waiting for "azurerm_app_service_virtual_network_swift_connection.for_func"
2021/01/14 18:10:47 [TRACE] dag/walk: vertex "provider[\"registry.terraform.io/hashicorp/azurerm\"] (close)" is waiting for "azurerm_app_service_virtual_network_swift_connection.for_func"
2021/01/14 18:10:48 [TRACE] dag/walk: vertex "azurerm_app_service_virtual_network_swift_connection.for_func" is waiting for "azurerm_function_app.main"
2021/01/14 18:10:48 [TRACE] dag/walk: vertex "azurerm_function_app.main" is waiting for "azurerm_storage_account.for_func"
2021/01/14 18:10:48 [TRACE] dag/walk: vertex "root" is waiting for "meta.count-boundary (EachMode fixup)"
2021/01/14 18:10:48 [TRACE] dag/walk: vertex "meta.count-boundary (EachMode fixup)" is waiting for "azurerm_app_service_virtual_network_swift_connection.for_func"
2021/01/14 18:10:52 [TRACE] dag/walk: vertex "provider[\"registry.terraform.io/hashicorp/azurerm\"] (close)" is waiting for "azurerm_app_service_virtual_network_swift_connection.for_func"
2021-01-14T18:10:53.029+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: [DEBUG] AzureRM Request: 
2021-01-14T18:10:53.029+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: GET /subscriptions/12345678-1234-1234-1234-123456789012/providers/Microsoft.Storage/locations/japaneast/asyncoperations/2f1c04d9-36d2-44b1-9048-62c3b417c70a?monitor=true&api-version=2019-06-01 HTTP/1.1
2021-01-14T18:10:53.029+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: Host: management.azure.com
2021-01-14T18:10:53.029+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: User-Agent: Go/go1.15.5 (amd64-linux) go-autorest/v14.2.1 Azure-SDK-For-Go/v49.2.0 storage/2019-06-01 HashiCorp Terraform/0.14.4 (+https://www.terraform.io) Terraform Plugin SDK/1.13.1 terraform-provider-azurerm/2.42.0 pid-222c6c49-1b0a-5959-a213-6608f9eb8820
2021-01-14T18:10:53.029+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: X-Ms-Correlation-Request-Id: d6b5e144-5801-efd6-470b-7676de43b5b2
2021-01-14T18:10:53.029+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: Accept-Encoding: gzip
2021-01-14T18:10:53.029+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: 
2021-01-14T18:10:53.029+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: 
2021/01/14 18:10:53 [TRACE] dag/walk: vertex "azurerm_function_app.main" is waiting for "azurerm_storage_account.for_func"
2021/01/14 18:10:53 [TRACE] dag/walk: vertex "azurerm_app_service_virtual_network_swift_connection.for_func" is waiting for "azurerm_function_app.main"
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: [DEBUG] AzureRM Response for https://management.azure.com/subscriptions/12345678-1234-1234-1234-123456789012/providers/Microsoft.Storage/locations/japaneast/asyncoperations/2f1c04d9-36d2-44b1-9048-62c3b417c70a?monitor=true&api-version=2019-06-01: 
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: HTTP/2.0 400 Bad Request
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: Content-Length: 387
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: Cache-Control: no-cache
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: Content-Type: application/json
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: Date: Thu, 14 Jan 2021 09:10:52 GMT
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: Expires: -1
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: Pragma: no-cache
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: Server: Microsoft-Azure-Storage-Resource-Provider/1.0,Microsoft-HTTPAPI/2.0 Microsoft-HTTPAPI/2.0
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: Strict-Transport-Security: max-age=31536000; includeSubDomains
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: X-Content-Type-Options: nosniff
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: X-Ms-Correlation-Request-Id: d6b5e144-5801-efd6-470b-7676de43b5b2
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: X-Ms-Ratelimit-Remaining-Subscription-Reads: 11935
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: X-Ms-Request-Id: 0e455332-9bff-45df-8de0-557c015089b0
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: X-Ms-Routing-Request-Id: JAPANEAST:20210114T091052Z:aefa38f4-9374-49ff-b421-a432f8e3cc7d
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: 
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: {"error":{"code":"NetworkAclsValidationFailure","message":"Validation of network acls failure: SubnetsNotProvisioned:Cannot proceed with operation because subnets snet-for-func of the virtual network /subscriptions/12345678-1234-1234-1234-123456789012/resourceGroups/rg-my-service/providers/Microsoft.Network/virtualNetworks/vnet-main are not provisioned. They are in Updating state.."}}
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: [DEBUG] Unlocking "azurerm_storage_account.stmainfunction"
2021-01-14T18:10:53.069+0900 [DEBUG] plugin.terraform-provider-azurerm_v2.42.0_x5: [DEBUG] Unlocked "azurerm_storage_account.stmainfunction"
2021/01/14 18:10:53 [DEBUG] azurerm_storage_account.for_func: apply errored, but we're indicating that via the Error pointer rather than returning it: Error waiting for Azure Storage Account "stmainfunction" to be created: Future#WaitForCompletion: the number of retries has been exceeded: StatusCode=400 -- Original Error: Code="NetworkAclsValidationFailure" Message="Validation of network acls failure: SubnetsNotProvisioned:Cannot proceed with operation because subnets snet-for-func of the virtual network /subscriptions/12345678-1234-1234-1234-123456789012/resourceGroups/rg-my-service/providers/Microsoft.Network/virtualNetworks/vnet-main are not provisioned. They are in Updating state.."
<中略>

長くてわかりにくいですが、下記のように azurerm_app_service_virtual_network_swift_connectionazurerm_function_appazurerm_storage_account の順で待機が発生しているのがわかります。

"azurerm_function_app.main" is waiting for "azurerm_storage_account.for_func"
"azurerm_app_service_virtual_network_swift_connection.for_func" is waiting for "azurerm_function_app.main"

ここからは azurerm_storage_account が何かを待機しているログは見て取れないのですが、前述のように最終的に発生したエラーメッセージによるとサブネットの準備ができるのを待っている状態であることがわかっています。

考察

このように諸々検証した結果、この問題では下記のデッドロックが発生しているようです。

  • Azure App service の VNet統合の設定(Virtual network swift connection)は Azure Function の完了を待つ
  • Azure Function は Azure Storage account の完了を待つ
  • Azure Storage Account は、network_rules に指定したいサブネットを待つ
  • サブネットは、 なんらかの要因でロックされている

このサブネットのロックの要因が肝ではありますが、この検証環境の場合では、下記のように Azure Storage account のネットワーク設定を外出しすると、現象を回避できる ことがわかりました。Azure Storage account がネットワーク設定をせずすぐ作成し終わることで、それを待機していた諸々のリソースの作成が進み、その間に Azure Storage account のネットワーク設定も並行して行われ全体が無事完了するといった具合と推測しています。

azurerm_storage_accountの変更を抜粋
#------------------------------------------------------------------------------
# Storage
#------------------------------------------------------------------------------
resource "azurerm_storage_account" "for_func" {
  name                     = "stmainfunction"
  location                 = azurerm_resource_group.main.location
  resource_group_name      = azurerm_resource_group.main.name
  account_kind             = "StorageV2"
  account_tier             = "Standard"
  account_replication_type = "LRS"

  # network_rules {
  #   default_action             = "Deny"
  #   virtual_network_subnet_ids = [azurerm_subnet.for_func.id]
  # }
}

resource "azurerm_storage_account_network_rules" "for_func" {
  resource_group_name      = azurerm_resource_group.main.name
  storage_account_name = azurerm_storage_account.for_func.name

  default_action             = "Deny"
  virtual_network_subnet_ids = [azurerm_subnet.for_func.id]
}
#------------------------------------------------------------------------------

なお、この検証環境のように Function を絡めたデッドロックではなく、別の要因でネットワークへの設定が阻害され続けると、この azurerm_storage_account_network_rules も待ちきれずに同様のエラーが発生します。このとき、失敗しているのは azurerm_storage_account ではなく azurerm_storage_account_network_rules でした。この場合は、前述の terraform apply コマンドの -lock-timeout パラメータでタイムアウトの時間を調整するしかなさそうです。

若干歯切れの悪い考察ですが、お役に立てばさいわいです🙃

Epilogue

余談、上記の結論にたどり着く間に苦戦したのが、何気なく記述していたネットワーク関連の設定でした。

よく調べもせず、とりあえず azurerm_subnetenforce_private_link_endpoint_network_policies = true を設定して進めていたため、これがデッドロックの原因なのか切り分けるに苦労しました。

実際、いろいろと調べていると今回の構成では不要であることがわかりました…。(そもそも PrivateEndpointNetworkPolicies という設定値はデフォルトで Enabled なので、わざわざ明示的に設定する必要がない。参考

ちょっとこの Private Link についてはまだ理解が深められていないので、クリアにしてから続きを書きます…!がんばるぞ!

Discussion

ログインするとコメントできます