😵
Check! TerraformでAzure FunctionsのVNet統合設定で発生しうるデッドロックを回避する
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 を利用する
- Azure Virtual Network とのアプリの統合 - Azure App Service | Microsoft Docs
- Azure 仮想ネットワーク サービス エンドポイント | Microsoft Docs
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-0 ～ 9）を作ることで検証を進めるに至りました。そのため、多量のサブネット作成は本件の現象に直接作用するものではありません。
※ 検証目的なので、値の直書きなどコードの再利用性は無視しています。
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_connection → azurerm_function_app → azurerm_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_subnet に enforce_private_link_endpoint_network_policies = true を設定して進めていたため、これがデッドロックの原因なのか切り分けるに苦労しました。
実際、いろいろと調べていると今回の構成では不要であることがわかりました…。（そもそも PrivateEndpointNetworkPolicies という設定値はデフォルトで Enabled なので、わざわざ明示的に設定する必要がない。参考）
ちょっとこの Private Link についてはまだ理解が深められていないので、クリアにしてから続きを書きます…！がんばるぞ！
Discussion