hashicorp / terraform-provider-azurerm

Terraform provider for Azure Resource Manager
https://registry.terraform.io/providers/hashicorp/azurerm/latest/docs
Mozilla Public License 2.0
4.6k stars 4.65k forks source link

azurerm provider fails when refreshing existing resources #1005

Closed calinmarina closed 6 years ago

calinmarina commented 6 years ago

Terraform Version

bash-4.2$ terraform -v
Terraform v0.11.4
+ provider.azurerm v1.3.0
+ provider.null v1.0.0
+ provider.random v1.1.0
+ provider.template v1.0.0

Note. we initially encountered this problem with terraform v0.11.3 and azurerm v1.2.0, just after azurerm and terraform updated to 1.2 and 11.4 respectively in March 15, 2018 so upgraded but still no luck

Affected Resource(s)

Please list the resources as a list, for example:

It appears to affect multiple resources, it may be an issue with Terraform's core, as we get other modules showing the same unexpected EOF message in other builds but vault definitely comes up everytime

Terraform Configuration Files

https://gist.github.com/calinmarina/bd0fd8236b7a523423f64ffb03875999

Debug Output and Panic Output

https://gist.github.com/calinmarina/e5cbc60084f77ca324bdb5a8083fd47e

Expected Behavior

terraform apply should have run smooth updating resources as before

Actual Behavior

terraform panicked with unexpected EOF for several resources. Note. nothing changed on the code side, it's exactly the same code running to update previously built resources by the same scripts.

Steps to Reproduce

see console log in the attached gist but example of steps to follow on top of existing resources:

  1. terraform init -reconfigure -backend-config storage_account_name=mgmtstatestorenonprod -backend-config container_name=mgmtstatestorecontaineraat -backend-config resource_group_name=mgmt-state-store-nonprod -backend-config key=em-anno-app/aat/terraform.tfstate
  2. terraform get -update=true
  3. terraform plan -var env=aat -var name=em-anno-app -var subscription=nonprod

Important Factoids

phassingerhi commented 6 years ago

I am also unable to refresh. Applying the first time works and saves contents to state file, but reapplying clears out the state file with empty resources and it wants to re-add resources during a terraform plan, every time. I'm running on Windows 10 with this error. I tried running this on my home Windows 10 computer as well with the same erroneous results. Removing existing resources does not appear to solve the problem for me. I ran the same inside of an Ubuntu VM with the same versions of terraform and the azurerm provider plugin and it worked fine. I tried something as simple as the following:

provider "azurerm" { }

resource "azurerm_resource_group" "rg" {
  name     = "my-rg"
  location = "eastus"
}

With the following results during a terraform refresh:

2018/03/20 19:15:13 [INFO] Terraform version: 0.11.4  7878d66b386e5474102b5047722c2de2b3237278
2018/03/20 19:15:13 [INFO] Go runtime version: go1.10
2018/03/20 19:15:13 [INFO] CLI args: []string{"C:\\Windows\\system32\\terraform.exe", "refresh"}
2018/03/20 19:15:13 [DEBUG] Attempting to open CLI config file: C:\Users\me\AppData\Roaming\terraform.rc
2018/03/20 19:15:13 [DEBUG] File doesn't exist, but doesn't need to. Ignoring.
2018/03/20 19:15:13 [INFO] CLI command args: []string{"refresh"}
2018/03/20 19:15:13 [INFO] command: empty terraform config, returning nil
2018/03/20 19:15:13 [DEBUG] command: no data state file found for backend config
2018/03/20 19:15:13 [DEBUG] New state was assigned lineage "d66b4564-f0ce-c4d3-d601-bb4ccb3ca09a"
2018/03/20 19:15:13 [INFO] command: backend initialized: <nil>
2018/03/20 19:15:13 [DEBUG] checking for provider in "."
2018/03/20 19:15:13 [DEBUG] checking for provider in "C:\\Windows\\system32"
2018/03/20 19:15:13 [DEBUG] checking for provider in ".terraform\\plugins\\windows_amd64"
2018/03/20 19:15:13 [DEBUG] found provider "terraform-provider-azurerm_v1.3.0_x4.exe"
2018/03/20 19:15:13 [DEBUG] found valid plugin: "azurerm", "1.3.0", "C:\\WIP\\a\\.terraform\\plugins\\windows_amd64\\terraform-provider-azurerm_v1.3.0_x4.exe"
2018/03/20 19:15:13 [DEBUG] checking for provisioner in "."
2018/03/20 19:15:13 [DEBUG] checking for provisioner in "C:\\Windows\\system32"
2018/03/20 19:15:13 [DEBUG] checking for provisioner in ".terraform\\plugins\\windows_amd64"
2018/03/20 19:15:13 [INFO] command: backend <nil> is not enhanced, wrapping in local
2018/03/20 19:15:15 [DEBUG] New state was assigned lineage "cd370026-d232-694d-609f-4cecc3e60091"
2018/03/20 19:15:15 [INFO] terraform: building graph: GraphTypeInput
2018/03/20 19:15:15 [TRACE] ConfigTransformer: Starting for path: []
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ConfigTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.LocalTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.OutputTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.OrphanResourceTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.OrphanOutputTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
2018/03/20 19:15:15 [TRACE] AttachResourceConfigTransformer: Beginning...
2018/03/20 19:15:15 [TRACE] AttachResourceConfigTransformer: Attach resource config request: azurerm_resource_group.rg
2018/03/20 19:15:15 [TRACE] Attaching resource config: &config.Resource{Mode:0, Name:"rg", Type:"azurerm_resource_group", RawCount:(*config.RawConfig)(0xc0423d1a40), RawConfig:(*config.RawConfig)(0xc0423d19d0), Provisioners:[]*config.Provisioner(nil), Provider:"", Depend
sOn:[]string(nil), Lifecycle:config.ResourceLifecycle{CreateBeforeDestroy:false, PreventDestroy:false, IgnoreChanges:[]string(nil)}}
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.AttachResourceConfigTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
2018/03/20 19:15:15 [DEBUG] Resource state not found for "azurerm_resource_group.rg": azurerm_resource_group.rg
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.AttachStateTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.RootVariableTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
2018/03/20 19:15:15 [TRACE] ProviderConfigTransformer: Starting for path: []
2018/03/20 19:15:15 [TRACE] Attach provider request: []string{} azurerm
2018/03/20 19:15:15 [TRACE] Attaching provider config: *config.ProviderConfig{Name:"azurerm", Alias:"", Version:"", RawConfig:(*config.RawConfig)(0xc0423d1960)}
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ProviderConfigTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.MissingProviderTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [DEBUG] resource azurerm_resource_group.rg using provider provider.azurerm
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ProviderTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.PruneProviderTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ParentProviderTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.graphTransformerMulti:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ModuleVariableTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.RemovedModuleTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [DEBUG] ReferenceTransformer: "azurerm_resource_group.rg" references: []
2018/03/20 19:15:15 [DEBUG] ReferenceTransformer: "provider.azurerm" references: []
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ReferenceTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.CountBoundaryTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.TargetsTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.CloseProviderTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm (close) - *terraform.graphNodeCloseProvider
  azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.CloseProvisionerTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm (close) - *terraform.graphNodeCloseProvider
  azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.RootTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm (close) - *terraform.graphNodeCloseProvider
  azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
root - terraform.graphNodeRoot
  meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  provider.azurerm (close) - *terraform.graphNodeCloseProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.TransitiveReductionTransformer:

azurerm_resource_group.rg - *terraform.NodeAbstractResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeAbstractResource
provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm (close) - *terraform.graphNodeCloseProvider
  azurerm_resource_group.rg - *terraform.NodeAbstractResource
root - terraform.graphNodeRoot
  meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  provider.azurerm (close) - *terraform.graphNodeCloseProvider
2018/03/20 19:15:15 [DEBUG] Starting graph walk: walkInput
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "meta.count-boundary (count boundary fixup)"
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "provider.azurerm (close)"
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "root"
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "azurerm_resource_group.rg"
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "provider.azurerm"
2018/03/20 19:15:15 [TRACE] dag/walk: added edge: "meta.count-boundary (count boundary fixup)" waiting on "azurerm_resource_group.rg"
2018/03/20 19:15:15 [TRACE] dag/walk: added edge: "provider.azurerm (close)" waiting on "azurerm_resource_group.rg"
2018/03/20 19:15:15 [TRACE] dag/walk: added edge: "root" waiting on "provider.azurerm (close)"
2018/03/20 19:15:15 [TRACE] dag/walk: added edge: "root" waiting on "meta.count-boundary (count boundary fixup)"
2018/03/20 19:15:15 [TRACE] dag/walk: added edge: "azurerm_resource_group.rg" waiting on "provider.azurerm"
2018/03/20 19:15:15 [TRACE] dag/walk: dependencies changed for "meta.count-boundary (count boundary fixup)", sending new deps
2018/03/20 19:15:15 [TRACE] dag/walk: dependencies changed for "provider.azurerm (close)", sending new deps
2018/03/20 19:15:15 [TRACE] dag/walk: dependencies changed for "root", sending new deps
2018/03/20 19:15:15 [TRACE] dag/walk: dependencies changed for "azurerm_resource_group.rg", sending new deps
2018/03/20 19:15:15 [TRACE] dag/walk: walking "provider.azurerm"
2018/03/20 19:15:15 [TRACE] vertex 'root.provider.azurerm': walking
2018/03/20 19:15:15 [TRACE] vertex 'root.provider.azurerm': evaluating
2018/03/20 19:15:15 [TRACE] [walkInput] Entering eval tree: provider.azurerm
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalSequence
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalInitProvider
2018-03-20T19:15:15.808-0500 [DEBUG] plugin: starting plugin: path=C:\WIP\a\.terraform\plugins\windows_amd64\terraform-provider-azurerm_v1.3.0_x4.exe args=[C:\WIP\a\.terraform\plugins\windows_amd64\terraform-provider-azurerm_v1.3.0_x4.exe]
2018-03-20T19:15:15.830-0500 [DEBUG] plugin: waiting for RPC address: path=C:\WIP\a\.terraform\plugins\windows_amd64\terraform-provider-azurerm_v1.3.0_x4.exe
2018-03-20T19:15:15.873-0500 [DEBUG] plugin.terraform-provider-azurerm_v1.3.0_x4.exe: plugin address: timestamp=2018-03-20T19:15:15.872-0500 address=127.0.0.1:10000 network=tcp
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalOpFilter
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalSequence
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalGetProvider
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalInterpolateProvider
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalBuildProviderConfig
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalInputProvider
2018/03/20 19:15:15 [TRACE] root: eval: terraform.EvalNoop
2018/03/20 19:15:15 [TRACE] root: eval: terraform.EvalNoop
2018/03/20 19:15:15 [TRACE] root: eval: terraform.EvalNoop
2018/03/20 19:15:15 [TRACE] [walkInput] Exiting eval tree: provider.azurerm
2018/03/20 19:15:15 [TRACE] dag/walk: walking "azurerm_resource_group.rg"
2018/03/20 19:15:15 [TRACE] vertex 'root.azurerm_resource_group.rg': walking
2018/03/20 19:15:15 [TRACE] dag/walk: walking "meta.count-boundary (count boundary fixup)"
2018/03/20 19:15:15 [TRACE] vertex 'root.meta.count-boundary (count boundary fixup)': walking
2018/03/20 19:15:15 [TRACE] vertex 'root.meta.count-boundary (count boundary fixup)': evaluating
2018/03/20 19:15:15 [TRACE] [walkInput] Entering eval tree: meta.count-boundary (count boundary fixup)
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalCountFixZeroOneBoundaryGlobal
2018/03/20 19:15:15 [TRACE] [walkInput] Exiting eval tree: meta.count-boundary (count boundary fixup)
2018/03/20 19:15:15 [TRACE] dag/walk: walking "provider.azurerm (close)"
2018/03/20 19:15:15 [TRACE] vertex 'root.provider.azurerm (close)': walking
2018/03/20 19:15:15 [TRACE] vertex 'root.provider.azurerm (close)': evaluating
2018/03/20 19:15:15 [TRACE] [walkInput] Entering eval tree: provider.azurerm (close)
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalCloseProvider
2018/03/20 19:15:15 [TRACE] [walkInput] Exiting eval tree: provider.azurerm (close)
2018/03/20 19:15:15 [TRACE] dag/walk: walking "root"
2018/03/20 19:15:15 [TRACE] vertex 'root.root': walking
2018/03/20 19:15:15 [INFO] terraform: building graph: GraphTypeValidate
2018/03/20 19:15:15 [TRACE] ConfigTransformer: Starting for path: []
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ConfigTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.LocalTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.OutputTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.OrphanResourceTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.OrphanOutputTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
2018/03/20 19:15:15 [TRACE] AttachResourceConfigTransformer: Beginning...
2018/03/20 19:15:15 [TRACE] AttachResourceConfigTransformer: Attach resource config request: azurerm_resource_group.rg
2018/03/20 19:15:15 [TRACE] Attaching resource config: &config.Resource{Mode:0, Name:"rg", Type:"azurerm_resource_group", RawCount:(*config.RawConfig)(0xc0423d1a40), RawConfig:(*config.RawConfig)(0xc0423d19d0), Provisioners:[]*config.Provisioner(nil), Provider:"", Depend
sOn:[]string(nil), Lifecycle:config.ResourceLifecycle{CreateBeforeDestroy:false, PreventDestroy:false, IgnoreChanges:[]string(nil)}}
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.AttachResourceConfigTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
2018/03/20 19:15:15 [DEBUG] Resource state not found for "azurerm_resource_group.rg": azurerm_resource_group.rg
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.AttachStateTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.RootVariableTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
2018/03/20 19:15:15 [TRACE] ProviderConfigTransformer: Starting for path: []
2018/03/20 19:15:15 [TRACE] Attach provider request: []string{} azurerm
2018/03/20 19:15:15 [TRACE] Attaching provider config: *config.ProviderConfig{Name:"azurerm", Alias:"", Version:"", RawConfig:(*config.RawConfig)(0xc0423d1960)}
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ProviderConfigTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.MissingProviderTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [DEBUG] resource azurerm_resource_group.rg using provider provider.azurerm
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ProviderTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.PruneProviderTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ParentProviderTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.graphTransformerMulti:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.MissingProvisionerTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ProvisionerTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.graphTransformerMulti:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ModuleVariableTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.RemovedModuleTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [DEBUG] ReferenceTransformer: "azurerm_resource_group.rg" references: []
2018/03/20 19:15:15 [DEBUG] ReferenceTransformer: "provider.azurerm" references: []
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ReferenceTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.CountBoundaryTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.TargetsTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.CloseProviderTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm (close) - *terraform.graphNodeCloseProvider
  azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.CloseProvisionerTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm (close) - *terraform.graphNodeCloseProvider
  azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.RootTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm (close) - *terraform.graphNodeCloseProvider
  azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
root - terraform.graphNodeRoot
  meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  provider.azurerm (close) - *terraform.graphNodeCloseProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.TransitiveReductionTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResource
  provider.azurerm - *terraform.NodeApplyableProvider
meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  azurerm_resource_group.rg - *terraform.NodeValidatableResource
provider.azurerm - *terraform.NodeApplyableProvider
provider.azurerm (close) - *terraform.graphNodeCloseProvider
  azurerm_resource_group.rg - *terraform.NodeValidatableResource
root - terraform.graphNodeRoot
  meta.count-boundary (count boundary fixup) - *terraform.NodeCountBoundary
  provider.azurerm (close) - *terraform.graphNodeCloseProvider
2018/03/20 19:15:15 [DEBUG] Starting graph walk: walkValidate
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "azurerm_resource_group.rg"
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "provider.azurerm"
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "meta.count-boundary (count boundary fixup)"
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "provider.azurerm (close)"
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "root"
2018/03/20 19:15:15 [TRACE] dag/walk: added edge: "provider.azurerm (close)" waiting on "azurerm_resource_group.rg"
2018/03/20 19:15:15 [TRACE] dag/walk: added edge: "root" waiting on "meta.count-boundary (count boundary fixup)"
2018/03/20 19:15:15 [TRACE] dag/walk: added edge: "root" waiting on "provider.azurerm (close)"
2018/03/20 19:15:15 [TRACE] dag/walk: added edge: "azurerm_resource_group.rg" waiting on "provider.azurerm"
2018/03/20 19:15:15 [TRACE] dag/walk: added edge: "meta.count-boundary (count boundary fixup)" waiting on "azurerm_resource_group.rg"
2018/03/20 19:15:15 [TRACE] dag/walk: dependencies changed for "root", sending new deps
2018/03/20 19:15:15 [TRACE] dag/walk: dependencies changed for "azurerm_resource_group.rg", sending new deps
2018/03/20 19:15:15 [TRACE] dag/walk: dependencies changed for "meta.count-boundary (count boundary fixup)", sending new deps
2018/03/20 19:15:15 [TRACE] dag/walk: dependencies changed for "provider.azurerm (close)", sending new deps
2018/03/20 19:15:15 [TRACE] dag/walk: walking "provider.azurerm"
2018/03/20 19:15:15 [TRACE] vertex 'root.provider.azurerm': walking
2018/03/20 19:15:15 [TRACE] vertex 'root.provider.azurerm': evaluating
2018/03/20 19:15:15 [TRACE] [walkValidate] Entering eval tree: provider.azurerm
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalSequence
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalInitProvider
2018/03/20 19:15:15 [TRACE] root: eval: terraform.EvalNoop
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalOpFilter
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalSequence
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalGetProvider
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalInterpolateProvider
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalBuildProviderConfig
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalValidateProvider
2018/03/20 19:15:15 [TRACE] root: eval: terraform.EvalNoop
2018/03/20 19:15:15 [TRACE] root: eval: terraform.EvalNoop
2018/03/20 19:15:15 [TRACE] [walkValidate] Exiting eval tree: provider.azurerm
2018/03/20 19:15:15 [TRACE] dag/walk: walking "azurerm_resource_group.rg"
2018/03/20 19:15:15 [TRACE] vertex 'root.azurerm_resource_group.rg': walking
2018/03/20 19:15:15 [TRACE] vertex 'root.azurerm_resource_group.rg': evaluating
2018/03/20 19:15:15 [TRACE] [walkValidate] Entering eval tree: azurerm_resource_group.rg
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalSequence
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalInterpolate
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalIf
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalValidateCount
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalCountFixZeroOneBoundary
2018/03/20 19:15:15 [TRACE] [walkValidate] Exiting eval tree: azurerm_resource_group.rg
2018/03/20 19:15:15 [TRACE] vertex 'root.azurerm_resource_group.rg': expanding/walking dynamic subgraph
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ResourceCountTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResourceInstance
2018/03/20 19:15:15 [DEBUG] Resource state not found for "azurerm_resource_group.rg": azurerm_resource_group.rg
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.AttachStateTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResourceInstance
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.TargetsTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResourceInstance
2018/03/20 19:15:15 [DEBUG] ReferenceTransformer: "azurerm_resource_group.rg" references: []
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ReferenceTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResourceInstance
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.RootTransformer:

azurerm_resource_group.rg - *terraform.NodeValidatableResourceInstance
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "azurerm_resource_group.rg"
2018/03/20 19:15:15 [TRACE] dag/walk: walking "azurerm_resource_group.rg"
2018/03/20 19:15:15 [TRACE] vertex 'root.azurerm_resource_group.rg': walking
2018/03/20 19:15:15 [TRACE] vertex 'root.azurerm_resource_group.rg': evaluating
2018/03/20 19:15:15 [TRACE] [walkValidate] Entering eval tree: azurerm_resource_group.rg
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalSequence
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalValidateResourceSelfRef
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalGetProvider
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalInterpolate
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalValidateResource
2018/03/20 19:15:15 [TRACE] [walkValidate] Exiting eval tree: azurerm_resource_group.rg
2018/03/20 19:15:15 [TRACE] dag/walk: walking "meta.count-boundary (count boundary fixup)"
2018/03/20 19:15:15 [TRACE] vertex 'root.meta.count-boundary (count boundary fixup)': walking
2018/03/20 19:15:15 [TRACE] dag/walk: walking "provider.azurerm (close)"
2018/03/20 19:15:15 [TRACE] vertex 'root.provider.azurerm (close)': walking
2018/03/20 19:15:15 [TRACE] vertex 'root.meta.count-boundary (count boundary fixup)': evaluating
2018/03/20 19:15:15 [TRACE] vertex 'root.provider.azurerm (close)': evaluating
2018/03/20 19:15:15 [TRACE] [walkValidate] Entering eval tree: provider.azurerm (close)
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalCloseProvider
2018/03/20 19:15:15 [TRACE] [walkValidate] Entering eval tree: meta.count-boundary (count boundary fixup)
2018/03/20 19:15:15 [TRACE] root: eval: *terraform.EvalCountFixZeroOneBoundaryGlobal
2018/03/20 19:15:15 [TRACE] [walkValidate] Exiting eval tree: meta.count-boundary (count boundary fixup)
2018/03/20 19:15:15 [TRACE] [walkValidate] Exiting eval tree: provider.azurerm (close)
2018/03/20 19:15:15 [TRACE] dag/walk: walking "root"
2018/03/20 19:15:15 [TRACE] vertex 'root.root': walking
2018/03/20 19:15:15 [INFO] terraform: building graph: GraphTypeRefresh
2018/03/20 19:15:15 [TRACE] No managed resources in state during refresh, skipping managed resource transformer
2018/03/20 19:15:15 [TRACE] ConfigTransformer: Starting for path: []
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ConfigTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.OrphanResourceTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.AttachStateTransformer:

2018/03/20 19:15:15 [TRACE] AttachResourceConfigTransformer: Beginning...
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.AttachResourceConfigTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.RootVariableTransformer:

2018/03/20 19:15:15 [TRACE] ProviderConfigTransformer: StartingE for path: []
mp2018/03/20 19:15:15 [TRACE] Attach provider request: []string{} azurerm
2018/03/20 19:15:15 [TRACE] Attaching provider config: *config.ProviderConfig{Name:"azurerm", Alias:"", Version:"", RawConfig:(*config.RawConfig)(0xc0423d1960)}
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ProviderConfigTransformer:

provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.MissingProviderTransformer:

provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ProviderTransformer:

provider.azurerm - *terraform.NodeApplyableProvider
2018/03/20 19:15:15 [DEBUG] pruning unused provider provider.azurerm
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.PruneProviderTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ParentProviderTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.graphTransformerMulti:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.LocalTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.OutputTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ModuleVariableTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.ReferenceTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.TargetsTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.CloseProviderTransformer:

2018/03/20 19:15:15 [TRACE] Graph after step *terraform.RootTransformer:

root - terraform.graphNodeRoot
2018/03/20 19:15:15 [TRACE] Graph after step *terraform.TransitiveReductionTransformer:

root - terraform.graphNodeRoot
2018/03/20 19:15:15 [DEBUG] Starting graph walk: walkRefresh
2018/03/20 19:15:15 [TRACE] dag/walk: added new vertex: "root"
2018/03/20 19:15:15 [TRACE] dag/walk: walking "root"
2018/03/20 19:15:15 [TRACE] vertex 'root.root': walking
2018/03/20 19:15:15 [INFO] backend/local: refresh calling Refresh
2018/03/20 19:15:15 [TRACE] Preserving existing state lineage "cd370026-d232-694d-609f-4cecc3e6009t1"
y or non-existent state file.

Refresh will do noth2018/03/20 19:15:15 [DEBUG] plugin: waiting for all plugin processes to complete...
ing. Refresh does not2018-03-20T19:15:15.980-0500 [WARN ] plugin: error closing client during Kill: err="unexpected EOF"
 error or return an erroneous
exit status because many automati2018-03-20T19:15:15.988-0500 [DEBUG] plugin: plugin process exited: path=C:\WIP\a\.terraform\plugins\windows_amd64\terraform-provider-azurerm_v1.3.0_x4.exe
on scripts use refresh, plan, then apply
and may not have a state file yet for the first run.
calinmarina commented 6 years ago

@phassingerhi it doesn't seem to be the same issue described in #974 to be honest... they didn't have any panic there and although I listed both keyvault and appinsights as it was shown in the console log, checking panic log only shows problems related to getting response on keyvault through Azure's management API (management.azure.com) ... see my comments on #974

tombuildsstuff commented 6 years ago

hey @calinmarina

Thanks for opening this issue - apologies for the delayed response here!

Taking a look into this unfortunately the logs aren't particularly insightful - would it be possible to answer the following so that we could investigate this further:

  1. What permissions does the Service Principal you're using have on the Azure Key Vault instance?
  2. Are there multiple active users on the Azure Subscription? There's a rate limit set by Azure but it's fairly high - given this is only affecting KeyVault I believe it's more likely to be a permissions issue - but would you be able to check this limit? It's returned in the HTTP headers which can either be viewed via TF_LOG=DEBUG terraform plan .. or via an HTTP Proxy such as Fiddler / Charles depending on your platform.

@phassingerhi the issue you've encountered is unfortunately an unrelated regression which shipped in v0.11.4, which was fixed in v0.11.5 - would you be able to upgrade to the latest version and take another look?

Thanks!

phassingerhi commented 6 years ago

@tombuildsstuff - Confirmed, running on v0.11.6 now works.

simongh commented 6 years ago

I seem to still have the same issue. I'm using 0.11.7 & 1.3.3 of the azure provider. Having a keyvault seems to cause a panic if I try running terraform plan again after a successful first run.

If I remove the keyvault, then the plan works fine.

I tried making a test plan with a keyvault & that works ok. The only significant difference between my test area & the one above, is above there is significant drift between terraform & Azure after 4 web apps have had MSI enabled on them and added to KV.

I haven't yet found a way round this or way of testing if this is the issue.

tombuildsstuff commented 6 years ago

@simongh so that we could take a look into this - would you be able to provide a link to the panic/crash log?

simongh commented 6 years ago

I have a crash log. I'd rather not post the whole thing in a public forum. I've attached the fragment as it fails the Key Vault call.

fragment.log

When TF creates the vault, it adds 3 access policies, 1 for a application & 2 for AD groups. I then create a web app with a powershell provisioner script that enables MSI and adds the MSI to the keyvault using:

az keyvault set-policy --name $vaultName --key-permissions unwrapkey --object-id $objectId`

If I remove this access-policy from the vault, TF can do a plan, or refresh and sees no changes. If I add the access-policy using the portal, TF still works as expected. If I run the above line again, TF will crash.

Looking at what is shown in the console I see this fragment:

{ "applicationId": null, "objectId": "4d354db1-33ce-4426-aa22-e15684840fb7", "permissions": { "certificates": null, "keys": [ "unwrapKey" ], "secrets": null, "storage": null }, "tenantId": "e3057e09-a748-4aca-8c67-0f5a3f7a9890" }

It seems az CLI creates the policy with a null certificates and null secrets. An access policy created using the portal or by TF has these 2 properties set to an empty array. On the problematic access_policy, if I set these to say just the get permission (ie make them non-null), then TF works once again.

It seems TF expects a value for keys, certificates and secrets when these might in fact be null. Sorry this is rambling a bit, I've been finding this out as I type.

tombuildsstuff commented 6 years ago

@simongh thanks for posting that - this is the relevant crash line:

https://github.com/terraform-providers/terraform-provider-azurerm/blob/v1.3.3/azurerm/resource_arm_key_vault.go#L376

I'm actually looking into this resource at the moment - so I'll try and open a PR to fix this.

Thanks!

tombuildsstuff commented 6 years ago

@simongh PR #1081 also now includes a fix for the crash you've provided above - thanks again :)

tombuildsstuff commented 6 years ago

hey @simongh

Just to let you know that v1.4.0 of the Azure Provider has been released which includes the fix for this :)

Thanks!

ghost commented 4 years ago

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 👉 hashibot-feedback@hashicorp.com. Thanks!