Skip to content

Instantly share code, notes, and snippets.

@tgross
Created Mar 11, 2022
Embed
What would you like to do?
TF_LOG=trace output
2022-03-11T16:15:27.973-0500 [INFO] Terraform version: 1.1.4
2022-03-11T16:15:27.974-0500 [INFO] Go runtime version: go1.17.2
2022-03-11T16:15:27.974-0500 [INFO] CLI args: []string{"terraform", "apply", "-auto-approve", "-var", "ip_address=[REDACTED]", "-var", "key_file_path=/Users/timgross/tmp/windowsupload/ssh.key"}
2022-03-11T16:15:27.974-0500 [TRACE] Stdout is a terminal of width 107
2022-03-11T16:15:27.974-0500 [TRACE] Stderr is a terminal of width 107
2022-03-11T16:15:27.974-0500 [TRACE] Stdin is a terminal
2022-03-11T16:15:27.974-0500 [DEBUG] Attempting to open CLI config file: /Users/timgross/.terraformrc
2022-03-11T16:15:27.974-0500 [DEBUG] File doesn't exist, but doesn't need to. Ignoring.
2022-03-11T16:15:27.974-0500 [DEBUG] ignoring non-existing provider search directory terraform.d/plugins
2022-03-11T16:15:27.974-0500 [DEBUG] ignoring non-existing provider search directory /Users/timgross/.terraform.d/plugins
2022-03-11T16:15:27.974-0500 [DEBUG] ignoring non-existing provider search directory /Users/timgross/Library/Application Support/io.terraform/plugins
2022-03-11T16:15:27.974-0500 [DEBUG] ignoring non-existing provider search directory /Library/Application Support/io.terraform/plugins
2022-03-11T16:15:27.974-0500 [INFO] CLI command args: []string{"apply", "-auto-approve", "-var", "ip_address=[REDACTED]", "-var", "key_file_path=/Users/timgross/tmp/windowsupload/ssh.key"}
2022-03-11T16:15:27.975-0500 [TRACE] Meta.Backend: no config given or present on disk, so returning nil config
2022-03-11T16:15:27.975-0500 [TRACE] Meta.Backend: backend has not previously been initialized in this working directory
2022-03-11T16:15:27.975-0500 [DEBUG] New state was assigned lineage "61c5fd89-d56d-cf56-ec2b-ef9171ab9920"
2022-03-11T16:15:27.975-0500 [TRACE] Meta.Backend: using default local state only (no backend configuration, and no existing initialized backend)
2022-03-11T16:15:27.975-0500 [TRACE] Meta.Backend: instantiated backend of type <nil>
2022-03-11T16:15:27.975-0500 [TRACE] providercache.fillMetaCache: scanning directory .terraform/providers
2022-03-11T16:15:27.976-0500 [TRACE] getproviders.SearchLocalDirectory: found registry.terraform.io/hashicorp/null v3.1.0 for darwin_amd64 at .terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64
2022-03-11T16:15:27.976-0500 [TRACE] providercache.fillMetaCache: including .terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64 as a candidate package for registry.terraform.io/hashicorp/null 3.1.0
2022-03-11T16:15:28.010-0500 [DEBUG] checking for provisioner in "."
2022-03-11T16:15:28.011-0500 [DEBUG] checking for provisioner in "/Users/timgross/bin"
2022-03-11T16:15:28.011-0500 [TRACE] Meta.Backend: backend <nil> does not support operations, so wrapping it in a local backend
2022-03-11T16:15:28.011-0500 [INFO] backend/local: starting Apply operation
2022-03-11T16:15:28.011-0500 [TRACE] backend/local: requesting state manager for workspace "default"
2022-03-11T16:15:28.012-0500 [TRACE] backend/local: state manager for workspace "default" will:
- read initial snapshot from terraform.tfstate
- write new snapshots to terraform.tfstate
- create any backup at terraform.tfstate.backup
2022-03-11T16:15:28.012-0500 [TRACE] backend/local: requesting state lock for workspace "default"
2022-03-11T16:15:28.014-0500 [TRACE] statemgr.Filesystem: preparing to manage state snapshots at terraform.tfstate
2022-03-11T16:15:28.014-0500 [TRACE] statemgr.Filesystem: existing snapshot has lineage "c4edd0ec-2401-5374-e68e-1dacb52fbfd4" serial 39
2022-03-11T16:15:28.014-0500 [TRACE] statemgr.Filesystem: locking terraform.tfstate using fcntl flock
2022-03-11T16:15:28.014-0500 [TRACE] statemgr.Filesystem: writing lock metadata to .terraform.tfstate.lock.info
2022-03-11T16:15:28.014-0500 [TRACE] backend/local: reading remote state for workspace "default"
2022-03-11T16:15:28.014-0500 [TRACE] statemgr.Filesystem: reading latest snapshot from terraform.tfstate
2022-03-11T16:15:28.014-0500 [TRACE] statemgr.Filesystem: read snapshot with lineage "c4edd0ec-2401-5374-e68e-1dacb52fbfd4" serial 39
2022-03-11T16:15:28.014-0500 [TRACE] backend/local: populating backend.LocalRun for current working directory
2022-03-11T16:15:28.015-0500 [TRACE] Config.VerifyDependencySelections: provider registry.terraform.io/hashicorp/null has 3.1.0 to satisfy ""
2022-03-11T16:15:28.015-0500 [TRACE] terraform.NewContext: starting
2022-03-11T16:15:28.015-0500 [TRACE] terraform.NewContext: complete
2022-03-11T16:15:28.015-0500 [TRACE] backend/local: requesting interactive input, if necessary
2022-03-11T16:15:28.015-0500 [TRACE] LoadSchemas: retrieving schema for provider type "registry.terraform.io/hashicorp/null"
2022-03-11T16:15:28.015-0500 [TRACE] terraform.contextPlugins: Initializing provider "registry.terraform.io/hashicorp/null" to read its schema
2022-03-11T16:15:28.015-0500 [DEBUG] created provider logger: level=trace
2022-03-11T16:15:28.015-0500 [INFO] provider: configuring client automatic mTLS
2022-03-11T16:15:28.023-0500 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5]
2022-03-11T16:15:28.026-0500 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=810
2022-03-11T16:15:28.026-0500 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5
2022-03-11T16:15:28.036-0500 [INFO] provider.terraform-provider-null_v3.1.0_x5: configuring server automatic mTLS: timestamp=2022-03-11T16:15:28.036-0500
2022-03-11T16:15:28.067-0500 [DEBUG] provider.terraform-provider-null_v3.1.0_x5: plugin address: address=/var/folders/1x/82930wjd5l9bk87tlflhhx7w0000gq/T/plugin643451441 network=unix timestamp=2022-03-11T16:15:28.067-0500
2022-03-11T16:15:28.067-0500 [DEBUG] provider: using plugin: version=5
2022-03-11T16:15:28.091-0500 [TRACE] GRPCProvider: GetProviderSchema
2022-03-11T16:15:28.091-0500 [TRACE] provider.stdio: waiting for stdio data
2022-03-11T16:15:28.092-0500 [TRACE] GRPCProvider: Close
2022-03-11T16:15:28.093-0500 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-03-11T16:15:28.094-0500 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=810
2022-03-11T16:15:28.094-0500 [DEBUG] provider: plugin exited
2022-03-11T16:15:28.094-0500 [TRACE] LoadSchemas: retrieving schema for provisioner "file"
2022-03-11T16:15:28.094-0500 [TRACE] terraform.contextPlugins: Initializing provisioner "file" to read its schema
2022-03-11T16:15:28.094-0500 [TRACE] Context.Input: Prompting for provider arguments
2022-03-11T16:15:28.094-0500 [TRACE] Context.Input: Provider provider.null implied by resource block at main.tf:11,1-32
2022-03-11T16:15:28.094-0500 [TRACE] Context.Input: Input for provider.null: map[string]cty.Value{}
2022-03-11T16:15:28.094-0500 [TRACE] backend/local: running validation operation
2022-03-11T16:15:28.094-0500 [DEBUG] Building and walking validate graph
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.ConfigTransformer
2022-03-11T16:15:28.094-0500 [TRACE] ConfigTransformer: Starting for path:
2022-03-11T16:15:28.094-0500 [TRACE] Completed graph transform *terraform.ConfigTransformer with new graph:
null_resource.test - *terraform.NodeValidatableResource
------
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.RootVariableTransformer
2022-03-11T16:15:28.094-0500 [TRACE] Completed graph transform *terraform.RootVariableTransformer with new graph:
null_resource.test - *terraform.NodeValidatableResource
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.ModuleVariableTransformer
2022-03-11T16:15:28.094-0500 [TRACE] Completed graph transform *terraform.ModuleVariableTransformer (no changes)
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.LocalTransformer
2022-03-11T16:15:28.094-0500 [TRACE] Completed graph transform *terraform.LocalTransformer (no changes)
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.OutputTransformer
2022-03-11T16:15:28.094-0500 [TRACE] Completed graph transform *terraform.OutputTransformer (no changes)
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.OrphanResourceInstanceTransformer
2022-03-11T16:15:28.094-0500 [TRACE] Completed graph transform *terraform.OrphanResourceInstanceTransformer (no changes)
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.StateTransformer
2022-03-11T16:15:28.094-0500 [TRACE] StateTransformer: creating nodes for deposed instance objects only
2022-03-11T16:15:28.094-0500 [TRACE] Completed graph transform *terraform.StateTransformer (no changes)
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.AttachStateTransformer
2022-03-11T16:15:28.094-0500 [TRACE] Completed graph transform *terraform.AttachStateTransformer (no changes)
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.OrphanOutputTransformer
2022-03-11T16:15:28.094-0500 [TRACE] Completed graph transform *terraform.OrphanOutputTransformer (no changes)
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.AttachResourceConfigTransformer
2022-03-11T16:15:28.094-0500 [TRACE] AttachResourceConfigTransformer: attaching to "null_resource.test" (*terraform.NodeValidatableResource) config from main.tf:11,1-32
2022-03-11T16:15:28.094-0500 [TRACE] AttachResourceConfigTransformer: attaching provider meta configs to null_resource.test
2022-03-11T16:15:28.094-0500 [TRACE] Completed graph transform *terraform.AttachResourceConfigTransformer (no changes)
2022-03-11T16:15:28.094-0500 [TRACE] Executing graph transform *terraform.graphTransformerMulti
2022-03-11T16:15:28.094-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.ProviderConfigTransformer
2022-03-11T16:15:28.095-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.ProviderConfigTransformer with new graph:
null_resource.test - *terraform.NodeValidatableResource
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.095-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.MissingProviderTransformer
2022-03-11T16:15:28.095-0500 [DEBUG] adding implicit provider configuration provider["registry.terraform.io/hashicorp/null"], implied first by null_resource.test
2022-03-11T16:15:28.095-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.MissingProviderTransformer with new graph:
null_resource.test - *terraform.NodeValidatableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.095-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.ProviderTransformer
2022-03-11T16:15:28.095-0500 [TRACE] ProviderTransformer: exact match for provider["registry.terraform.io/hashicorp/null"] serving null_resource.test
2022-03-11T16:15:28.095-0500 [DEBUG] ProviderTransformer: "null_resource.test" (*terraform.NodeValidatableResource) needs provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.095-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.ProviderTransformer with new graph:
null_resource.test - *terraform.NodeValidatableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.095-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.PruneProviderTransformer
2022-03-11T16:15:28.095-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.PruneProviderTransformer (no changes)
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.graphTransformerMulti with new graph:
null_resource.test - *terraform.NodeValidatableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.RemovedModuleTransformer
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.RemovedModuleTransformer (no changes)
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.AttachSchemaTransformer
2022-03-11T16:15:28.095-0500 [TRACE] AttachSchemaTransformer: attaching provider config schema to provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.095-0500 [TRACE] AttachSchemaTransformer: attaching resource schema to null_resource.test
2022-03-11T16:15:28.095-0500 [TRACE] AttachSchemaTransformer: attaching provisioner "file" config schema to null_resource.test
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.AttachSchemaTransformer (no changes)
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.ModuleExpansionTransformer
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.ModuleExpansionTransformer (no changes)
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.ReferenceTransformer
2022-03-11T16:15:28.095-0500 [DEBUG] ReferenceTransformer: "null_resource.test" references: [var.key_file_path var.ip_address]
2022-03-11T16:15:28.095-0500 [DEBUG] ReferenceTransformer: "var.ip_address" references: []
2022-03-11T16:15:28.095-0500 [DEBUG] ReferenceTransformer: "var.key_file_path" references: []
2022-03-11T16:15:28.095-0500 [DEBUG] ReferenceTransformer: "provider[\"registry.terraform.io/hashicorp/null\"]" references: []
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.ReferenceTransformer with new graph:
null_resource.test - *terraform.NodeValidatableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.AttachDependenciesTransformer
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.AttachDependenciesTransformer (no changes)
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.attachDataResourceDependsOnTransformer
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.attachDataResourceDependsOnTransformer (no changes)
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.TargetsTransformer
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.TargetsTransformer (no changes)
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.ForcedCBDTransformer
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.ForcedCBDTransformer (no changes)
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.CloseProviderTransformer
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.CloseProviderTransformer with new graph:
null_resource.test - *terraform.NodeValidatableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
null_resource.test - *terraform.NodeValidatableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.CloseRootModuleTransformer
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.CloseRootModuleTransformer with new graph:
null_resource.test - *terraform.NodeValidatableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
null_resource.test - *terraform.NodeValidatableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
root - *terraform.nodeCloseModule
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.095-0500 [TRACE] Executing graph transform *terraform.TransitiveReductionTransformer
2022-03-11T16:15:28.095-0500 [TRACE] Completed graph transform *terraform.TransitiveReductionTransformer with new graph:
null_resource.test - *terraform.NodeValidatableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
null_resource.test - *terraform.NodeValidatableResource
root - *terraform.nodeCloseModule
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.095-0500 [DEBUG] Starting graph walk: walkValidate
2022-03-11T16:15:28.095-0500 [TRACE] vertex "var.key_file_path": starting visit (*terraform.NodeRootVariable)
2022-03-11T16:15:28.095-0500 [TRACE] vertex "var.ip_address": starting visit (*terraform.NodeRootVariable)
2022-03-11T16:15:28.095-0500 [TRACE] vertex "var.ip_address": visit complete
2022-03-11T16:15:28.095-0500 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/null\"]": starting visit (*terraform.NodeApplyableProvider)
2022-03-11T16:15:28.095-0500 [TRACE] vertex "var.key_file_path": visit complete
2022-03-11T16:15:28.096-0500 [DEBUG] created provider logger: level=trace
2022-03-11T16:15:28.096-0500 [INFO] provider: configuring client automatic mTLS
2022-03-11T16:15:28.104-0500 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5]
2022-03-11T16:15:28.105-0500 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=811
2022-03-11T16:15:28.105-0500 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5
2022-03-11T16:15:28.117-0500 [INFO] provider.terraform-provider-null_v3.1.0_x5: configuring server automatic mTLS: timestamp=2022-03-11T16:15:28.117-0500
2022-03-11T16:15:28.148-0500 [DEBUG] provider.terraform-provider-null_v3.1.0_x5: plugin address: address=/var/folders/1x/82930wjd5l9bk87tlflhhx7w0000gq/T/plugin378566638 network=unix timestamp=2022-03-11T16:15:28.148-0500
2022-03-11T16:15:28.148-0500 [DEBUG] provider: using plugin: version=5
2022-03-11T16:15:28.172-0500 [TRACE] provider.stdio: waiting for stdio data
2022-03-11T16:15:28.172-0500 [TRACE] BuiltinEvalContext: Initialized "provider[\"registry.terraform.io/hashicorp/null\"]" provider for provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.172-0500 [TRACE] NodeApplyableProvider: validating configuration for provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.172-0500 [TRACE] buildProviderConfig for provider["registry.terraform.io/hashicorp/null"]: no configuration at all
2022-03-11T16:15:28.172-0500 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/null\"]": visit complete
2022-03-11T16:15:28.172-0500 [TRACE] vertex "null_resource.test": starting visit (*terraform.NodeValidatableResource)
2022-03-11T16:15:28.172-0500 [TRACE] GRPCProvider: ValidateResourceConfig
2022-03-11T16:15:28.172-0500 [TRACE] GRPCProvider: GetProviderSchema
2022-03-11T16:15:28.173-0500 [TRACE] vertex "null_resource.test": visit complete
2022-03-11T16:15:28.173-0500 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/null\"] (close)": starting visit (*terraform.graphNodeCloseProvider)
2022-03-11T16:15:28.173-0500 [TRACE] GRPCProvider: Close
2022-03-11T16:15:28.174-0500 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-03-11T16:15:28.175-0500 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=811
2022-03-11T16:15:28.175-0500 [DEBUG] provider: plugin exited
2022-03-11T16:15:28.175-0500 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/null\"] (close)": visit complete
2022-03-11T16:15:28.175-0500 [TRACE] vertex "root": starting visit (*terraform.nodeCloseModule)
2022-03-11T16:15:28.175-0500 [TRACE] vertex "root": visit complete
2022-03-11T16:15:28.175-0500 [INFO] backend/local: apply calling Plan
2022-03-11T16:15:28.175-0500 [DEBUG] Building and walking plan graph for NormalMode
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.ConfigTransformer
2022-03-11T16:15:28.175-0500 [TRACE] ConfigTransformer: Starting for path:
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.ConfigTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
------
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.RootVariableTransformer
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.RootVariableTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.ModuleVariableTransformer
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.ModuleVariableTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.LocalTransformer
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.LocalTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.OutputTransformer
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.OutputTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.OrphanResourceInstanceTransformer
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.OrphanResourceInstanceTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.StateTransformer
2022-03-11T16:15:28.175-0500 [TRACE] StateTransformer: creating nodes for deposed instance objects only
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.StateTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.AttachStateTransformer
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.AttachStateTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.OrphanOutputTransformer
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.OrphanOutputTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.AttachResourceConfigTransformer
2022-03-11T16:15:28.175-0500 [TRACE] AttachResourceConfigTransformer: attaching to "null_resource.test (expand)" (*terraform.nodeExpandPlannableResource) config from main.tf:11,1-32
2022-03-11T16:15:28.175-0500 [TRACE] AttachResourceConfigTransformer: attaching provider meta configs to null_resource.test (expand)
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.AttachResourceConfigTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.graphTransformerMulti
2022-03-11T16:15:28.175-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.ProviderConfigTransformer
2022-03-11T16:15:28.175-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.ProviderConfigTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.175-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.MissingProviderTransformer
2022-03-11T16:15:28.175-0500 [DEBUG] adding implicit provider configuration provider["registry.terraform.io/hashicorp/null"], implied first by null_resource.test (expand)
2022-03-11T16:15:28.175-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.MissingProviderTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.175-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.ProviderTransformer
2022-03-11T16:15:28.175-0500 [TRACE] ProviderTransformer: exact match for provider["registry.terraform.io/hashicorp/null"] serving null_resource.test (expand)
2022-03-11T16:15:28.175-0500 [DEBUG] ProviderTransformer: "null_resource.test (expand)" (*terraform.nodeExpandPlannableResource) needs provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.175-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.ProviderTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.175-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.PruneProviderTransformer
2022-03-11T16:15:28.175-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.PruneProviderTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.graphTransformerMulti with new graph:
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.RemovedModuleTransformer
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.RemovedModuleTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.AttachSchemaTransformer
2022-03-11T16:15:28.175-0500 [TRACE] AttachSchemaTransformer: attaching resource schema to null_resource.test (expand)
2022-03-11T16:15:28.175-0500 [TRACE] AttachSchemaTransformer: attaching provisioner "file" config schema to null_resource.test (expand)
2022-03-11T16:15:28.175-0500 [TRACE] AttachSchemaTransformer: attaching provider config schema to provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.AttachSchemaTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.ModuleExpansionTransformer
2022-03-11T16:15:28.175-0500 [TRACE] Completed graph transform *terraform.ModuleExpansionTransformer (no changes)
2022-03-11T16:15:28.175-0500 [TRACE] Executing graph transform *terraform.ReferenceTransformer
2022-03-11T16:15:28.175-0500 [DEBUG] ReferenceTransformer: "null_resource.test (expand)" references: [var.key_file_path var.ip_address var.key_file_path var.ip_address]
2022-03-11T16:15:28.176-0500 [DEBUG] ReferenceTransformer: "var.ip_address" references: []
2022-03-11T16:15:28.176-0500 [DEBUG] ReferenceTransformer: "var.key_file_path" references: []
2022-03-11T16:15:28.176-0500 [DEBUG] ReferenceTransformer: "provider[\"registry.terraform.io/hashicorp/null\"]" references: []
2022-03-11T16:15:28.176-0500 [TRACE] Completed graph transform *terraform.ReferenceTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.176-0500 [TRACE] Executing graph transform *terraform.AttachDependenciesTransformer
2022-03-11T16:15:28.176-0500 [TRACE] AttachDependenciesTransformer: null_resource.test depends on []
2022-03-11T16:15:28.176-0500 [TRACE] Completed graph transform *terraform.AttachDependenciesTransformer (no changes)
2022-03-11T16:15:28.176-0500 [TRACE] Executing graph transform *terraform.attachDataResourceDependsOnTransformer
2022-03-11T16:15:28.176-0500 [TRACE] Completed graph transform *terraform.attachDataResourceDependsOnTransformer (no changes)
2022-03-11T16:15:28.176-0500 [TRACE] Executing graph transform *terraform.TargetsTransformer
2022-03-11T16:15:28.176-0500 [TRACE] Completed graph transform *terraform.TargetsTransformer (no changes)
2022-03-11T16:15:28.176-0500 [TRACE] Executing graph transform *terraform.ForcedCBDTransformer
2022-03-11T16:15:28.176-0500 [TRACE] ForcedCBDTransformer: "null_resource.test (expand)" (*terraform.nodeExpandPlannableResource) has no CBD descendent, so skipping
2022-03-11T16:15:28.176-0500 [TRACE] Completed graph transform *terraform.ForcedCBDTransformer (no changes)
2022-03-11T16:15:28.176-0500 [TRACE] Executing graph transform *terraform.CloseProviderTransformer
2022-03-11T16:15:28.176-0500 [TRACE] Completed graph transform *terraform.CloseProviderTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.176-0500 [TRACE] Executing graph transform *terraform.CloseRootModuleTransformer
2022-03-11T16:15:28.176-0500 [TRACE] Completed graph transform *terraform.CloseRootModuleTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
root - *terraform.nodeCloseModule
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.176-0500 [TRACE] Executing graph transform *terraform.TransitiveReductionTransformer
2022-03-11T16:15:28.176-0500 [TRACE] Completed graph transform *terraform.TransitiveReductionTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
null_resource.test (expand) - *terraform.nodeExpandPlannableResource
root - *terraform.nodeCloseModule
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.176-0500 [DEBUG] Starting graph walk: walkPlan
2022-03-11T16:15:28.176-0500 [TRACE] vertex "var.key_file_path": starting visit (*terraform.NodeRootVariable)
2022-03-11T16:15:28.176-0500 [TRACE] vertex "var.key_file_path": visit complete
2022-03-11T16:15:28.176-0500 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/null\"]": starting visit (*terraform.NodeApplyableProvider)
2022-03-11T16:15:28.176-0500 [TRACE] vertex "var.ip_address": starting visit (*terraform.NodeRootVariable)
2022-03-11T16:15:28.176-0500 [TRACE] vertex "var.ip_address": visit complete
2022-03-11T16:15:28.176-0500 [DEBUG] created provider logger: level=trace
2022-03-11T16:15:28.176-0500 [INFO] provider: configuring client automatic mTLS
2022-03-11T16:15:28.184-0500 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5]
2022-03-11T16:15:28.186-0500 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=812
2022-03-11T16:15:28.186-0500 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5
2022-03-11T16:15:28.196-0500 [INFO] provider.terraform-provider-null_v3.1.0_x5: configuring server automatic mTLS: timestamp=2022-03-11T16:15:28.196-0500
2022-03-11T16:15:28.227-0500 [DEBUG] provider.terraform-provider-null_v3.1.0_x5: plugin address: address=/var/folders/1x/82930wjd5l9bk87tlflhhx7w0000gq/T/plugin700316707 network=unix timestamp=2022-03-11T16:15:28.227-0500
2022-03-11T16:15:28.227-0500 [DEBUG] provider: using plugin: version=5
2022-03-11T16:15:28.250-0500 [TRACE] BuiltinEvalContext: Initialized "provider[\"registry.terraform.io/hashicorp/null\"]" provider for provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.250-0500 [TRACE] provider.stdio: waiting for stdio data
2022-03-11T16:15:28.250-0500 [TRACE] NodeApplyableProvider: configuring provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.250-0500 [TRACE] buildProviderConfig for provider["registry.terraform.io/hashicorp/null"]: no configuration at all
2022-03-11T16:15:28.251-0500 [TRACE] GRPCProvider: GetProviderSchema
2022-03-11T16:15:28.252-0500 [TRACE] GRPCProvider: ValidateProviderConfig
2022-03-11T16:15:28.253-0500 [TRACE] GRPCProvider: ConfigureProvider
2022-03-11T16:15:28.253-0500 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/null\"]": visit complete
2022-03-11T16:15:28.253-0500 [TRACE] vertex "null_resource.test (expand)": starting visit (*terraform.nodeExpandPlannableResource)
2022-03-11T16:15:28.253-0500 [TRACE] vertex "null_resource.test (expand)": expanding dynamic subgraph
2022-03-11T16:15:28.253-0500 [TRACE] vertex "null_resource.test (expand)": entering dynamic subgraph
2022-03-11T16:15:28.253-0500 [TRACE] vertex "null_resource.test": starting visit (*terraform.NodePlannableResource)
2022-03-11T16:15:28.253-0500 [TRACE] vertex "null_resource.test": expanding dynamic subgraph
2022-03-11T16:15:28.253-0500 [TRACE] Executing graph transform *terraform.ResourceCountTransformer
2022-03-11T16:15:28.253-0500 [TRACE] ResourceCountTransformer: adding null_resource.test as *terraform.NodePlannableResourceInstance
2022-03-11T16:15:28.253-0500 [TRACE] Completed graph transform *terraform.ResourceCountTransformer with new graph:
null_resource.test - *terraform.NodePlannableResourceInstance
------
2022-03-11T16:15:28.253-0500 [TRACE] Executing graph transform *terraform.OrphanResourceInstanceCountTransformer
2022-03-11T16:15:28.253-0500 [TRACE] Completed graph transform *terraform.OrphanResourceInstanceCountTransformer (no changes)
2022-03-11T16:15:28.253-0500 [TRACE] Executing graph transform *terraform.AttachStateTransformer
2022-03-11T16:15:28.253-0500 [TRACE] NodeAbstractResourceInstance.AttachResourceState for null_resource.test
2022-03-11T16:15:28.253-0500 [TRACE] Completed graph transform *terraform.AttachStateTransformer (no changes)
2022-03-11T16:15:28.253-0500 [TRACE] Executing graph transform *terraform.TargetsTransformer
2022-03-11T16:15:28.253-0500 [TRACE] Completed graph transform *terraform.TargetsTransformer (no changes)
2022-03-11T16:15:28.253-0500 [TRACE] Executing graph transform *terraform.ReferenceTransformer
2022-03-11T16:15:28.253-0500 [INFO] ReferenceTransformer: reference not found: "var.ip_address"
2022-03-11T16:15:28.253-0500 [INFO] ReferenceTransformer: reference not found: "var.key_file_path"
2022-03-11T16:15:28.253-0500 [INFO] ReferenceTransformer: reference not found: "var.key_file_path"
2022-03-11T16:15:28.253-0500 [INFO] ReferenceTransformer: reference not found: "var.ip_address"
2022-03-11T16:15:28.253-0500 [DEBUG] ReferenceTransformer: "null_resource.test" references: []
2022-03-11T16:15:28.253-0500 [TRACE] Completed graph transform *terraform.ReferenceTransformer (no changes)
2022-03-11T16:15:28.254-0500 [TRACE] Executing graph transform *terraform.RootTransformer
2022-03-11T16:15:28.254-0500 [TRACE] Completed graph transform *terraform.RootTransformer (no changes)
2022-03-11T16:15:28.254-0500 [TRACE] vertex "null_resource.test": entering dynamic subgraph
2022-03-11T16:15:28.254-0500 [TRACE] vertex "null_resource.test": starting visit (*terraform.NodePlannableResourceInstance)
2022-03-11T16:15:28.254-0500 [TRACE] readResourceInstanceState: reading state for null_resource.test
2022-03-11T16:15:28.254-0500 [TRACE] upgradeResourceState: schema version of null_resource.test is still 0; calling provider "null" for any other minor fixups
2022-03-11T16:15:28.254-0500 [TRACE] GRPCProvider: UpgradeResourceState
2022-03-11T16:15:28.254-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState to prevRunState for null_resource.test
2022-03-11T16:15:28.254-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState: writing state object for null_resource.test
2022-03-11T16:15:28.254-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState to refreshState for null_resource.test
2022-03-11T16:15:28.255-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState: writing state object for null_resource.test
2022-03-11T16:15:28.255-0500 [TRACE] NodeAbstractResourceInstance.refresh for null_resource.test
2022-03-11T16:15:28.255-0500 [TRACE] GRPCProvider: ReadResource
2022-03-11T16:15:28.255-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState to refreshState for null_resource.test
2022-03-11T16:15:28.255-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState: writing state object for null_resource.test
2022-03-11T16:15:28.255-0500 [TRACE] Re-validating config for "null_resource.test"
2022-03-11T16:15:28.255-0500 [TRACE] GRPCProvider: ValidateResourceConfig
2022-03-11T16:15:28.256-0500 [TRACE] GRPCProvider: PlanResourceChange
2022-03-11T16:15:28.257-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState to workingState for null_resource.test
2022-03-11T16:15:28.257-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState: writing state object for null_resource.test
2022-03-11T16:15:28.257-0500 [TRACE] writeChange: recorded DeleteThenCreate change for null_resource.test
2022-03-11T16:15:28.257-0500 [TRACE] vertex "null_resource.test": visit complete
2022-03-11T16:15:28.257-0500 [TRACE] vertex "null_resource.test": dynamic subgraph completed successfully
2022-03-11T16:15:28.257-0500 [TRACE] vertex "null_resource.test": visit complete
2022-03-11T16:15:28.257-0500 [TRACE] vertex "null_resource.test (expand)": dynamic subgraph completed successfully
2022-03-11T16:15:28.257-0500 [TRACE] vertex "null_resource.test (expand)": visit complete
2022-03-11T16:15:28.257-0500 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/null\"] (close)": starting visit (*terraform.graphNodeCloseProvider)
2022-03-11T16:15:28.257-0500 [TRACE] GRPCProvider: Close
2022-03-11T16:15:28.257-0500 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-03-11T16:15:28.258-0500 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=812
2022-03-11T16:15:28.258-0500 [DEBUG] provider: plugin exited
2022-03-11T16:15:28.258-0500 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/null\"] (close)": visit complete
2022-03-11T16:15:28.258-0500 [TRACE] vertex "root": starting visit (*terraform.nodeCloseModule)
2022-03-11T16:15:28.258-0500 [TRACE] vertex "root": visit complete
2022-03-11T16:15:28.259-0500 [TRACE] LoadSchemas: retrieving schema for provider type "registry.terraform.io/hashicorp/null"
2022-03-11T16:15:28.259-0500 [TRACE] LoadSchemas: retrieving schema for provisioner "file"
2022-03-11T16:15:28.259-0500 [INFO] backend/local: apply calling Apply
2022-03-11T16:15:28.259-0500 [DEBUG] Building and walking apply graph for NormalMode plan
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.ConfigTransformer
2022-03-11T16:15:28.259-0500 [TRACE] ConfigTransformer: Starting for path:
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.ConfigTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
------
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.RootVariableTransformer
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.RootVariableTransformer with new graph:
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.ModuleVariableTransformer
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.ModuleVariableTransformer (no changes)
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.LocalTransformer
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.LocalTransformer (no changes)
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.OutputTransformer
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.OutputTransformer (no changes)
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.DiffTransformer
2022-03-11T16:15:28.259-0500 [TRACE] DiffTransformer starting
2022-03-11T16:15:28.259-0500 [TRACE] DiffTransformer: found DeleteThenCreate change for null_resource.test
2022-03-11T16:15:28.259-0500 [TRACE] DiffTransformer: null_resource.test will be represented by null_resource.test
2022-03-11T16:15:28.259-0500 [TRACE] DiffTransformer: null_resource.test will be represented for destruction by null_resource.test (destroy)
2022-03-11T16:15:28.259-0500 [TRACE] DiffTransformer complete
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.DiffTransformer with new graph:
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.AttachStateTransformer
2022-03-11T16:15:28.259-0500 [TRACE] NodeAbstractResourceInstance.AttachResourceState for null_resource.test
2022-03-11T16:15:28.259-0500 [TRACE] NodeAbstractResourceInstance.AttachResourceState for null_resource.test
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.AttachStateTransformer (no changes)
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.OrphanOutputTransformer
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.OrphanOutputTransformer (no changes)
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.AttachResourceConfigTransformer
2022-03-11T16:15:28.259-0500 [TRACE] AttachResourceConfigTransformer: attaching to "null_resource.test (expand)" (*terraform.nodeExpandApplyableResource) config from main.tf:11,1-32
2022-03-11T16:15:28.259-0500 [TRACE] AttachResourceConfigTransformer: attaching provider meta configs to null_resource.test (expand)
2022-03-11T16:15:28.259-0500 [TRACE] AttachResourceConfigTransformer: attaching to "null_resource.test" (*terraform.NodeApplyableResourceInstance) config from main.tf:11,1-32
2022-03-11T16:15:28.259-0500 [TRACE] AttachResourceConfigTransformer: attaching provider meta configs to null_resource.test
2022-03-11T16:15:28.259-0500 [TRACE] AttachResourceConfigTransformer: attaching to "null_resource.test (destroy)" (*terraform.NodeDestroyResourceInstance) config from main.tf:11,1-32
2022-03-11T16:15:28.259-0500 [TRACE] AttachResourceConfigTransformer: attaching provider meta configs to null_resource.test (destroy)
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.AttachResourceConfigTransformer (no changes)
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.graphTransformerMulti
2022-03-11T16:15:28.259-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.ProviderConfigTransformer
2022-03-11T16:15:28.259-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.ProviderConfigTransformer with new graph:
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.259-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.MissingProviderTransformer
2022-03-11T16:15:28.259-0500 [DEBUG] adding implicit provider configuration provider["registry.terraform.io/hashicorp/null"], implied first by null_resource.test
2022-03-11T16:15:28.259-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.MissingProviderTransformer with new graph:
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.259-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.ProviderTransformer
2022-03-11T16:15:28.259-0500 [TRACE] ProviderTransformer: exact match for provider["registry.terraform.io/hashicorp/null"] serving null_resource.test (destroy)
2022-03-11T16:15:28.259-0500 [DEBUG] ProviderTransformer: "null_resource.test (destroy)" (*terraform.NodeDestroyResourceInstance) needs provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.259-0500 [TRACE] ProviderTransformer: exact match for provider["registry.terraform.io/hashicorp/null"] serving null_resource.test (expand)
2022-03-11T16:15:28.259-0500 [DEBUG] ProviderTransformer: "null_resource.test (expand)" (*terraform.nodeExpandApplyableResource) needs provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.259-0500 [TRACE] ProviderTransformer: exact match for provider["registry.terraform.io/hashicorp/null"] serving null_resource.test
2022-03-11T16:15:28.259-0500 [DEBUG] ProviderTransformer: "null_resource.test" (*terraform.NodeApplyableResourceInstance) needs provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.259-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.ProviderTransformer with new graph:
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.259-0500 [TRACE] (graphTransformerMulti) Executing graph transform *terraform.PruneProviderTransformer
2022-03-11T16:15:28.259-0500 [TRACE] (graphTransformerMulti) Completed graph transform *terraform.PruneProviderTransformer (no changes)
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.graphTransformerMulti with new graph:
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.RemovedModuleTransformer
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.RemovedModuleTransformer (no changes)
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.AttachSchemaTransformer
2022-03-11T16:15:28.259-0500 [TRACE] AttachSchemaTransformer: attaching resource schema to null_resource.test (destroy)
2022-03-11T16:15:28.259-0500 [TRACE] AttachSchemaTransformer: attaching provisioner "file" config schema to null_resource.test (destroy)
2022-03-11T16:15:28.259-0500 [TRACE] AttachSchemaTransformer: attaching provider config schema to provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.259-0500 [TRACE] AttachSchemaTransformer: attaching resource schema to null_resource.test (expand)
2022-03-11T16:15:28.259-0500 [TRACE] AttachSchemaTransformer: attaching provisioner "file" config schema to null_resource.test (expand)
2022-03-11T16:15:28.259-0500 [TRACE] AttachSchemaTransformer: attaching resource schema to null_resource.test
2022-03-11T16:15:28.259-0500 [TRACE] AttachSchemaTransformer: attaching provisioner "file" config schema to null_resource.test
2022-03-11T16:15:28.259-0500 [TRACE] Completed graph transform *terraform.AttachSchemaTransformer (no changes)
2022-03-11T16:15:28.259-0500 [TRACE] Executing graph transform *terraform.ModuleExpansionTransformer
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.ModuleExpansionTransformer (no changes)
2022-03-11T16:15:28.260-0500 [TRACE] Executing graph transform *terraform.ReferenceTransformer
2022-03-11T16:15:28.260-0500 [DEBUG] ReferenceTransformer: "provider[\"registry.terraform.io/hashicorp/null\"]" references: []
2022-03-11T16:15:28.260-0500 [DEBUG] ReferenceTransformer: "null_resource.test (expand)" references: []
2022-03-11T16:15:28.260-0500 [DEBUG] ReferenceTransformer: "var.ip_address" references: []
2022-03-11T16:15:28.260-0500 [DEBUG] ReferenceTransformer: "var.key_file_path" references: []
2022-03-11T16:15:28.260-0500 [DEBUG] ReferenceTransformer: "null_resource.test" references: [var.key_file_path var.ip_address var.key_file_path var.ip_address]
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.ReferenceTransformer with new graph:
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.260-0500 [TRACE] Executing graph transform *terraform.AttachDependenciesTransformer
2022-03-11T16:15:28.260-0500 [TRACE] AttachDependenciesTransformer: null_resource.test depends on []
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.AttachDependenciesTransformer (no changes)
2022-03-11T16:15:28.260-0500 [TRACE] Executing graph transform *terraform.ForcedCBDTransformer
2022-03-11T16:15:28.260-0500 [TRACE] ForcedCBDTransformer: "null_resource.test" (*terraform.NodeApplyableResourceInstance) has no CBD descendent, so skipping
2022-03-11T16:15:28.260-0500 [TRACE] ForcedCBDTransformer: "null_resource.test (destroy)" (*terraform.NodeDestroyResourceInstance) has no CBD descendent, so skipping
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.ForcedCBDTransformer (no changes)
2022-03-11T16:15:28.260-0500 [TRACE] Executing graph transform *terraform.DestroyEdgeTransformer
2022-03-11T16:15:28.260-0500 [TRACE] DestroyEdgeTransformer: "null_resource.test (destroy)" (*terraform.NodeDestroyResourceInstance) destroys null_resource.test
2022-03-11T16:15:28.260-0500 [TRACE] DestroyEdgeTransformer: connecting creator "null_resource.test" with destroyer "null_resource.test (destroy)"
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.DestroyEdgeTransformer with new graph:
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.260-0500 [TRACE] Executing graph transform *terraform.CBDEdgeTransformer
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.CBDEdgeTransformer (no changes)
2022-03-11T16:15:28.260-0500 [TRACE] Executing graph transform *terraform.pruneUnusedNodesTransformer
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.pruneUnusedNodesTransformer (no changes)
2022-03-11T16:15:28.260-0500 [TRACE] Executing graph transform *terraform.TargetsTransformer
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.TargetsTransformer (no changes)
2022-03-11T16:15:28.260-0500 [TRACE] Executing graph transform *terraform.CloseProviderTransformer
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.CloseProviderTransformer with new graph:
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.260-0500 [TRACE] Executing graph transform *terraform.CloseRootModuleTransformer
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.CloseRootModuleTransformer with new graph:
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
root - *terraform.nodeCloseModule
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.260-0500 [TRACE] Executing graph transform *terraform.TransitiveReductionTransformer
2022-03-11T16:15:28.260-0500 [TRACE] Completed graph transform *terraform.TransitiveReductionTransformer with new graph:
null_resource.test - *terraform.NodeApplyableResourceInstance
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
null_resource.test (destroy) - *terraform.NodeDestroyResourceInstance
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
null_resource.test (expand) - *terraform.nodeExpandApplyableResource
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] - *terraform.NodeApplyableProvider
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
null_resource.test - *terraform.NodeApplyableResourceInstance
root - *terraform.nodeCloseModule
provider["registry.terraform.io/hashicorp/null"] (close) - *terraform.graphNodeCloseProvider
var.ip_address - *terraform.NodeRootVariable
var.key_file_path - *terraform.NodeRootVariable
------
2022-03-11T16:15:28.260-0500 [DEBUG] Starting graph walk: walkApply
2022-03-11T16:15:28.260-0500 [TRACE] vertex "var.key_file_path": starting visit (*terraform.NodeRootVariable)
2022-03-11T16:15:28.260-0500 [TRACE] vertex "var.key_file_path": visit complete
2022-03-11T16:15:28.260-0500 [TRACE] vertex "var.ip_address": starting visit (*terraform.NodeRootVariable)
2022-03-11T16:15:28.260-0500 [TRACE] vertex "var.ip_address": visit complete
2022-03-11T16:15:28.260-0500 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/null\"]": starting visit (*terraform.NodeApplyableProvider)
2022-03-11T16:15:28.260-0500 [DEBUG] created provider logger: level=trace
2022-03-11T16:15:28.260-0500 [INFO] provider: configuring client automatic mTLS
2022-03-11T16:15:28.268-0500 [DEBUG] provider: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5]
2022-03-11T16:15:28.270-0500 [DEBUG] provider: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=813
2022-03-11T16:15:28.271-0500 [DEBUG] provider: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5
2022-03-11T16:15:28.283-0500 [INFO] provider.terraform-provider-null_v3.1.0_x5: configuring server automatic mTLS: timestamp=2022-03-11T16:15:28.282-0500
2022-03-11T16:15:28.313-0500 [DEBUG] provider.terraform-provider-null_v3.1.0_x5: plugin address: address=/var/folders/1x/82930wjd5l9bk87tlflhhx7w0000gq/T/plugin399769160 network=unix timestamp=2022-03-11T16:15:28.313-0500
2022-03-11T16:15:28.313-0500 [DEBUG] provider: using plugin: version=5
2022-03-11T16:15:28.338-0500 [TRACE] provider.stdio: waiting for stdio data
2022-03-11T16:15:28.338-0500 [TRACE] BuiltinEvalContext: Initialized "provider[\"registry.terraform.io/hashicorp/null\"]" provider for provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.338-0500 [TRACE] NodeApplyableProvider: configuring provider["registry.terraform.io/hashicorp/null"]
2022-03-11T16:15:28.338-0500 [TRACE] buildProviderConfig for provider["registry.terraform.io/hashicorp/null"]: no configuration at all
2022-03-11T16:15:28.338-0500 [TRACE] GRPCProvider: GetProviderSchema
2022-03-11T16:15:28.338-0500 [TRACE] GRPCProvider: ValidateProviderConfig
2022-03-11T16:15:28.339-0500 [TRACE] GRPCProvider: ConfigureProvider
2022-03-11T16:15:28.339-0500 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/null\"]": visit complete
2022-03-11T16:15:28.339-0500 [TRACE] vertex "null_resource.test (destroy)": starting visit (*terraform.NodeDestroyResourceInstance)
2022-03-11T16:15:28.339-0500 [TRACE] vertex "null_resource.test (expand)": starting visit (*terraform.nodeExpandApplyableResource)
2022-03-11T16:15:28.339-0500 [TRACE] vertex "null_resource.test (expand)": expanding dynamic subgraph
2022-03-11T16:15:28.339-0500 [TRACE] vertex "null_resource.test (expand)": entering dynamic subgraph
2022-03-11T16:15:28.339-0500 [TRACE] readDiff: Read DeleteThenCreate change from plan for null_resource.test
2022-03-11T16:15:28.339-0500 [TRACE] reducePlan: null_resource.test change simplified from DeleteThenCreate to Delete for destroy node
2022-03-11T16:15:28.339-0500 [TRACE] vertex "null_resource.test": starting visit (*terraform.NodeApplyableResource)
2022-03-11T16:15:28.339-0500 [TRACE] readResourceInstanceState: reading state for null_resource.test
2022-03-11T16:15:28.339-0500 [TRACE] vertex "null_resource.test": visit complete
2022-03-11T16:15:28.339-0500 [TRACE] vertex "null_resource.test (expand)": dynamic subgraph completed successfully
2022-03-11T16:15:28.339-0500 [TRACE] vertex "null_resource.test (expand)": visit complete
2022-03-11T16:15:28.339-0500 [TRACE] upgradeResourceState: schema version of null_resource.test is still 0; calling provider "null" for any other minor fixups
2022-03-11T16:15:28.339-0500 [TRACE] GRPCProvider: UpgradeResourceState
2022-03-11T16:15:28.340-0500 [INFO] Starting apply for null_resource.test
2022-03-11T16:15:28.340-0500 [DEBUG] null_resource.test: applying the planned Delete change
2022-03-11T16:15:28.340-0500 [TRACE] GRPCProvider: ApplyResourceChange
2022-03-11T16:15:28.340-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState to workingState for null_resource.test
2022-03-11T16:15:28.340-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState: removing state object for null_resource.test
2022-03-11T16:15:28.340-0500 [TRACE] statemgr.Filesystem: creating backup snapshot at terraform.tfstate.backup
2022-03-11T16:15:28.340-0500 [TRACE] statemgr.Filesystem: state has changed since last snapshot, so incrementing serial to 40
2022-03-11T16:15:28.340-0500 [TRACE] statemgr.Filesystem: writing snapshot at terraform.tfstate
2022-03-11T16:15:28.364-0500 [TRACE] vertex "null_resource.test (destroy)": visit complete
2022-03-11T16:15:28.365-0500 [TRACE] vertex "null_resource.test": starting visit (*terraform.NodeApplyableResourceInstance)
2022-03-11T16:15:28.365-0500 [TRACE] readDiff: Read DeleteThenCreate change from plan for null_resource.test
2022-03-11T16:15:28.365-0500 [TRACE] readResourceInstanceState: reading state for null_resource.test
2022-03-11T16:15:28.365-0500 [TRACE] readResourceInstanceState: no state present for null_resource.test
2022-03-11T16:15:28.365-0500 [TRACE] readDiff: Read DeleteThenCreate change from plan for null_resource.test
2022-03-11T16:15:28.365-0500 [TRACE] Re-validating config for "null_resource.test"
2022-03-11T16:15:28.365-0500 [TRACE] GRPCProvider: ValidateResourceConfig
2022-03-11T16:15:28.366-0500 [TRACE] GRPCProvider: PlanResourceChange
2022-03-11T16:15:28.367-0500 [TRACE] plan: null_resource.test treating Create change as DeleteThenCreate change to match with earlier plan
2022-03-11T16:15:28.367-0500 [TRACE] checkPlannedChange: Verifying that actual change (action DeleteThenCreate) matches planned change (action DeleteThenCreate)
2022-03-11T16:15:28.367-0500 [TRACE] readResourceInstanceState: reading state for null_resource.test
2022-03-11T16:15:28.367-0500 [TRACE] readResourceInstanceState: no state present for null_resource.test
2022-03-11T16:15:28.367-0500 [TRACE] reducePlan: null_resource.test change simplified from DeleteThenCreate to Create for apply node
2022-03-11T16:15:28.368-0500 [INFO] Starting apply for null_resource.test
2022-03-11T16:15:28.368-0500 [DEBUG] null_resource.test: applying the planned Create change
2022-03-11T16:15:28.368-0500 [TRACE] GRPCProvider: ApplyResourceChange
2022-03-11T16:15:28.369-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState to workingState for null_resource.test
2022-03-11T16:15:28.369-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState: writing state object for null_resource.test
2022-03-11T16:15:28.369-0500 [TRACE] applyProvisioners: provisioning null_resource.test with "file"
2022-03-11T16:15:28.371-0500 [INFO] using private key for authentication
2022-03-11T16:15:28.371-0500 [DEBUG] Connecting to [REDACTED]:22 for SSH
2022-03-11T16:15:28.382-0500 [DEBUG] Connection established. Handshaking for user Administrator
2022-03-11T16:15:28.571-0500 [DEBUG] Telling SSH config to forward to agent
2022-03-11T16:15:28.571-0500 [DEBUG] Setting up a session to request agent forwarding
2022-03-11T16:15:28.627-0500 [WARN] error forwarding agent: forwarding request denied
2022-03-11T16:15:28.627-0500 [DEBUG] starting ssh KeepAlives
2022-03-11T16:15:28.628-0500 [DEBUG] opening new ssh session
2022-03-11T16:15:28.648-0500 [DEBUG] Starting remote scp process: "scp" -vt /tmp
2022-03-11T16:15:28.663-0500 [DEBUG] Started SCP session, beginning transfers...
2022-03-11T16:15:28.664-0500 [DEBUG] Copying input data into temporary file so we can read the length
2022-03-11T16:15:28.685-0500 [DEBUG] Beginning file upload...
2022-03-11T16:15:28.938-0500 [DEBUG] SCP session complete, closing stdin pipe.
2022-03-11T16:15:28.938-0500 [DEBUG] Waiting for SSH session to complete.
2022-03-11T16:15:28.946-0500 [ERROR] scp stderr: "At line:1 char:7\r\n+ \"scp\" -vt /tmp\r\n+ ~~~\r\nUnexpected token '-vt' in expression or statement.\r\nAt line:1 char:11\r\n+ \"scp\" -vt /tmp\r\n+ ~~~~\r\nUnexpected token '/tmp' in expression or statement.\r\n + CategoryInfo : ParserError: (:) [], ParentContainsErrorRecordEx \r\n ception\r\n + FullyQualifiedErrorId : UnexpectedToken\r\n \r\n"
2022-03-11T16:15:28.946-0500 [ERROR] Process exited with status 1
2022-03-11T16:15:28.947-0500 [WARN] Errors while provisioning null_resource.test with "file", so aborting
2022-03-11T16:15:28.947-0500 [TRACE] evalApplyProvisioners: null_resource.test provisioning failed, but we will continue anyway at the caller's request
2022-03-11T16:15:28.947-0500 [TRACE] maybeTainted: null_resource.test encountered an error during creation, so it is now marked as tainted
2022-03-11T16:15:28.947-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState to workingState for null_resource.test
2022-03-11T16:15:28.947-0500 [TRACE] NodeAbstractResouceInstance.writeResourceInstanceState: writing state object for null_resource.test
2022-03-11T16:15:28.947-0500 [TRACE] statemgr.Filesystem: have already backed up original terraform.tfstate to terraform.tfstate.backup on a previous write
2022-03-11T16:15:28.947-0500 [TRACE] statemgr.Filesystem: state has changed since last snapshot, so incrementing serial to 41
2022-03-11T16:15:28.947-0500 [TRACE] statemgr.Filesystem: writing snapshot at terraform.tfstate
2022-03-11T16:15:28.970-0500 [ERROR] vertex "null_resource.test" error: file provisioner error
2022-03-11T16:15:28.970-0500 [TRACE] vertex "null_resource.test": visit complete, with errors
2022-03-11T16:15:28.971-0500 [TRACE] dag/walk: upstream of "provider[\"registry.terraform.io/hashicorp/null\"] (close)" errored, so skipping
2022-03-11T16:15:28.971-0500 [TRACE] dag/walk: upstream of "root" errored, so skipping
2022-03-11T16:15:28.971-0500 [TRACE] statemgr.Filesystem: have already backed up original terraform.tfstate to terraform.tfstate.backup on a previous write
2022-03-11T16:15:28.972-0500 [TRACE] statemgr.Filesystem: state has changed since last snapshot, so incrementing serial to 42
2022-03-11T16:15:28.972-0500 [TRACE] statemgr.Filesystem: writing snapshot at terraform.tfstate
2022-03-11T16:15:28.994-0500 [TRACE] statemgr.Filesystem: removing lock metadata file .terraform.tfstate.lock.info
2022-03-11T16:15:28.996-0500 [TRACE] statemgr.Filesystem: unlocking terraform.tfstate using fcntl flock
2022-03-11T16:15:28.997-0500 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-03-11T16:15:28.999-0500 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/darwin_amd64/terraform-provider-null_v3.1.0_x5 pid=813
2022-03-11T16:15:28.999-0500 [DEBUG] provider: plugin exited
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment