Spurious "UpgradeResourceState" call during "destroy" workflow

[alexsomesan]

Terraform Version

Terraform v1.1.4
on darwin_arm64

Terraform Configuration Files

# any configuration

Debug Output

Apply

{"@level":"info","@message":"configuring server automatic mTLS","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.274317+01:00","timestamp":"2022-02-01T23:55:17.274+0100"}
{"@level":"debug","@message":"2022/02/01 23:55:17 [ERROR] Error parsing provider name \"\": Invalid provider source string: The \"source\" attribute must be in the format \"[hostname/][namespace/]name\"","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.281278+01:00"}
{"@level":"debug","@message":"plugin address","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.281336+01:00","address":"/var/folders/cy/swrcw95d5wb15c9ff6g1m3x00000gq/T/plugin1956709388","network":"unix","timestamp":"2022-02-01T23:55:17.281+0100"}
{"@level":"info","@message":"configuring server automatic mTLS","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.369469+01:00","timestamp":"2022-02-01T23:55:17.369+0100"}
{"@level":"debug","@message":"2022/02/01 23:55:17 [ERROR] Error parsing provider name \"\": Invalid provider source string: The \"source\" attribute must be in the format \"[hostname/][namespace/]name\"","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.376751+01:00"}
{"@level":"debug","@message":"plugin address","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.376810+01:00","address":"/var/folders/cy/swrcw95d5wb15c9ff6g1m3x00000gq/T/plugin2990233185","network":"unix","timestamp":"2022-02-01T23:55:17.376+0100"}
{"@level":"info","@message":"configuring server automatic mTLS","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.489638+01:00","timestamp":"2022-02-01T23:55:17.489+0100"}
{"@level":"debug","@message":"2022/02/01 23:55:17 [ERROR] Error parsing provider name \"\": Invalid provider source string: The \"source\" attribute must be in the format \"[hostname/][namespace/]name\"","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.496614+01:00"}
{"@level":"debug","@message":"plugin address","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.496762+01:00","address":"/var/folders/cy/swrcw95d5wb15c9ff6g1m3x00000gq/T/plugin2237512697","network":"unix","timestamp":"2022-02-01T23:55:17.496+0100"}
{"@level":"debug","@message":"2022/02/01 23:55:17 [DEBUG] Using kubeconfig: /Users/alex/.kube/config","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.561074+01:00"}
{"@level":"debug","@message":"2022/02/01 23:55:17 [WARN] Invalid log level: \"JSON\". Defaulting to level: TRACE. Valid levels are: [TRACE DEBUG INFO WARN ERROR]","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.561927+01:00"}
{"@level":"debug","@message":"2022/02/01 23:55:17 [DEBUG] Enabling HTTP requests/responses tracing","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.561937+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.561+0100 [INFO]  [ConfigureProvider] start: EXTRA_VALUE_AT_END=93230","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.561941+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.562+0100 [INFO]  [ConfigureProvider] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.562280+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.563+0100 [INFO]  [UpgradeResourceState] start: EXTRA_VALUE_AT_END=93230","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.563289+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.564+0100 [INFO]  [UpgradeResourceState] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.564658+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.823+0100 [INFO]  [PlanResourceChange] start","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.823798+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.836+0100 [INFO]  [PlanResourceChange] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.836079+01:00"}
{"@level":"info","@message":"configuring server automatic mTLS","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.894404+01:00","timestamp":"2022-02-01T23:55:17.894+0100"}
{"@level":"debug","@message":"2022/02/01 23:55:17 [ERROR] Error parsing provider name \"\": Invalid provider source string: The \"source\" attribute must be in the format \"[hostname/][namespace/]name\"","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.901321+01:00"}
{"@level":"debug","@message":"plugin address","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.901376+01:00","address":"/var/folders/cy/swrcw95d5wb15c9ff6g1m3x00000gq/T/plugin4090640892","network":"unix","timestamp":"2022-02-01T23:55:17.901+0100"}
{"@level":"debug","@message":"2022/02/01 23:55:17 [DEBUG] Using kubeconfig: /Users/alex/.kube/config","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.967187+01:00"}
{"@level":"debug","@message":"2022/02/01 23:55:17 [WARN] Invalid log level: \"JSON\". Defaulting to level: TRACE. Valid levels are: [TRACE DEBUG INFO WARN ERROR]","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.967928+01:00"}
{"@level":"debug","@message":"2022/02/01 23:55:17 [DEBUG] Enabling HTTP requests/responses tracing","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.967935+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.967+0100 [INFO]  [ConfigureProvider] start: EXTRA_VALUE_AT_END=93231","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.967939+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.968+0100 [INFO]  [ConfigureProvider] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.968219+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.970+0100 [INFO]  [UpgradeResourceState] start: EXTRA_VALUE_AT_END=93231","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.970572+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.971+0100 [INFO]  [UpgradeResourceState] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.971449+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:17.974+0100 [INFO]  [PlanResourceChange] start","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:17.974515+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:18.223+0100 [INFO]  [PlanResourceChange] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:18.223978+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:18.225+0100 [INFO]  [UpgradeResourceState] start: EXTRA_VALUE_AT_END=93231","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:18.225291+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:18.226+0100 [INFO]  [UpgradeResourceState] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:18.226320+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:18.228+0100 [INFO]  [ApplyResourceChange] start","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:18.228428+01:00"}
{"@level":"debug","@message":"2022-02-01T23:55:18.252+0100 [INFO]  [ApplyResourceChange] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:55:18.252265+01:00"}

Destroy

{"@level":"info","@message":"configuring server automatic mTLS","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:49.983567+01:00","timestamp":"2022-02-01T23:52:49.983+0100"}
{"@level":"debug","@message":"2022/02/01 23:52:49 [ERROR] Error parsing provider name \"\": Invalid provider source string: The \"source\" attribute must be in the format \"[hostname/][namespace/]name\"","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:49.991418+01:00"}
{"@level":"debug","@message":"plugin address","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:49.991461+01:00","address":"/var/folders/cy/swrcw95d5wb15c9ff6g1m3x00000gq/T/plugin1712067832","network":"unix","timestamp":"2022-02-01T23:52:49.991+0100"}
{"@level":"info","@message":"configuring server automatic mTLS","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.083187+01:00","timestamp":"2022-02-01T23:52:50.082+0100"}
{"@level":"debug","@message":"2022/02/01 23:52:50 [ERROR] Error parsing provider name \"\": Invalid provider source string: The \"source\" attribute must be in the format \"[hostname/][namespace/]name\"","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.089985+01:00"}
{"@level":"debug","@message":"plugin address","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.090050+01:00","address":"/var/folders/cy/swrcw95d5wb15c9ff6g1m3x00000gq/T/plugin3147096802","network":"unix","timestamp":"2022-02-01T23:52:50.089+0100"}
{"@level":"info","@message":"configuring server automatic mTLS","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.204555+01:00","timestamp":"2022-02-01T23:52:50.204+0100"}
{"@level":"debug","@message":"2022/02/01 23:52:50 [ERROR] Error parsing provider name \"\": Invalid provider source string: The \"source\" attribute must be in the format \"[hostname/][namespace/]name\"","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.211475+01:00"}
{"@level":"debug","@message":"plugin address","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.211519+01:00","address":"/var/folders/cy/swrcw95d5wb15c9ff6g1m3x00000gq/T/plugin2337880449","network":"unix","timestamp":"2022-02-01T23:52:50.211+0100"}
{"@level":"debug","@message":"2022/02/01 23:52:50 [DEBUG] Using kubeconfig: /Users/alex/.kube/config","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.277992+01:00"}
{"@level":"debug","@message":"2022/02/01 23:52:50 [WARN] Invalid log level: \"JSON\". Defaulting to level: TRACE. Valid levels are: [TRACE DEBUG INFO WARN ERROR]","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.278978+01:00"}
{"@level":"debug","@message":"2022/02/01 23:52:50 [DEBUG] Enabling HTTP requests/responses tracing","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.278983+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.278+0100 [INFO]  [ConfigureProvider] start: EXTRA_VALUE_AT_END=93018","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.278990+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.279+0100 [INFO]  [ConfigureProvider] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.279364+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.280+0100 [INFO]  [UpgradeResourceState] start: EXTRA_VALUE_AT_END=93018","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.280335+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.281+0100 [INFO]  [UpgradeResourceState] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.281728+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.538+0100 [INFO]  [PlanResourceChange] start","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.538122+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.549+0100 [INFO]  [PlanResourceChange] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.549747+01:00"}

## suspect call 
{"@level":"info","@message":"configuring server automatic mTLS","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.599902+01:00","timestamp":"2022-02-01T23:52:50.599+0100"}
{"@level":"debug","@message":"2022/02/01 23:52:50 [ERROR] Error parsing provider name \"\": Invalid provider source string: The \"source\" attribute must be in the format \"[hostname/][namespace/]name\"","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.606782+01:00"}
{"@level":"debug","@message":"plugin address","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.606826+01:00","address":"/var/folders/cy/swrcw95d5wb15c9ff6g1m3x00000gq/T/plugin122694124","network":"unix","timestamp":"2022-02-01T23:52:50.606+0100"}
{"@level":"debug","@message":"2022-02-01T23:52:50.644+0100 [INFO]  [UpgradeResourceState] start: EXTRA_VALUE_AT_END=93019","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.644977+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.646+0100 [INFO]  [UpgradeResourceState] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.646298+01:00"}

{"@level":"info","@message":"configuring server automatic mTLS","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.703268+01:00","timestamp":"2022-02-01T23:52:50.702+0100"}
{"@level":"debug","@message":"2022/02/01 23:52:50 [ERROR] Error parsing provider name \"\": Invalid provider source string: The \"source\" attribute must be in the format \"[hostname/][namespace/]name\"","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.710055+01:00"}
{"@level":"debug","@message":"plugin address","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.710087+01:00","address":"/var/folders/cy/swrcw95d5wb15c9ff6g1m3x00000gq/T/plugin3579041967","network":"unix","timestamp":"2022-02-01T23:52:50.710+0100"}
{"@level":"debug","@message":"2022/02/01 23:52:50 [DEBUG] Using kubeconfig: /Users/alex/.kube/config","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.775492+01:00"}
{"@level":"debug","@message":"2022/02/01 23:52:50 [WARN] Invalid log level: \"JSON\". Defaulting to level: TRACE. Valid levels are: [TRACE DEBUG INFO WARN ERROR]","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.776263+01:00"}
{"@level":"debug","@message":"2022/02/01 23:52:50 [DEBUG] Enabling HTTP requests/responses tracing","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.776268+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.776+0100 [INFO]  [ConfigureProvider] start: EXTRA_VALUE_AT_END=93020","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.776272+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.776+0100 [INFO]  [ConfigureProvider] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.776593+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.777+0100 [INFO]  [UpgradeResourceState] start: EXTRA_VALUE_AT_END=93020","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.777814+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.778+0100 [INFO]  [UpgradeResourceState] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.778729+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:50.781+0100 [INFO]  [ApplyResourceChange] start","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:50.781752+01:00"}
{"@level":"debug","@message":"2022-02-01T23:52:51.808+0100 [INFO]  [ApplyResourceChange] end","@module":"provider.terraform-provider-kubernetes","@timestamp":"2022-02-01T23:52:51.808389+01:00"}

Expected Behavior

UpgradeResourceState should not be called before ConfigureProvider

Actual Behavior

During a destroy workflow, a new provider process is spawed between the plan and apply stages onto which a single UpgradeResourceState call is made without any preceding ConfigureProvider calls.

If the state upgrade logic makes use of any values from the provider block, the whole destroy workflow will fail.

Steps to Reproduce

1. Add code to UpgradeResourceState that tries to use values from the provider block.
2. Create minimal terraform configuration using any resource.
3. Run terraform apply to produce some state.
4. Run terraform destroy

Additional Context

References

[jbardin]

Hi @alexsomesan,

What you're seeing here is is part of the destroy plan process, but I think because planning destroy operations were previously only done internally, the providers never needed to be configured at that point.

I'm reviewing the possibility of including the providers in the process of planning individual destroy operations already and I should be able to add the configuration call there too.

Thanks!

[alexsomesan]

Hi James!

Thanks for the explanation. I was mostly confused by the fact that the destroy process already does a planning phase with all the usual ConfigureProvider -> UpgradeResourceState -> PlanResourceChange right before the call in question here (see logs above).
Also, the following apply phase has it's own call to UpgradeResourceState. Both of these follow the typical call sequence and both include a call to ConfigureProvider.

Given all this, is the intermediate call to UpgradeResourceState really intentional and serving a specific purpose?

On a side note, I was able to unblock myself by adding a check for valid provider configuration in my UpgradeResourceState and cutting it short when config is missing. However, I'd rather not keep that in there long term as it might lead to some false positives in corner cases that aren't apparent to me now.

[jbardin]

UpgradeResourceState is called whenever we read the resource state. This is usually ends up being a noop when the schema hasn't changed, but for backwards compatibility with providers that needed to update the state without changing schema versions we must call it every time.

The two separate calls you see during destroy are because we first need to do a full plan to get the refresh information, mostly for data sources which may be referenced by the providers themselves, but it will also clean out any missing resources early on. The second call is during the actual destroy plan. We never previously called the provider to plan anything because all changes are delete changes, hence we never configured the provider, but we do need to fetch the state data again which in turn calls the UpgradeResourceState.

I'm not sure yet how a new proposed destroy plan will look exactly, but we may be able to combine these operations into a single plan. Regardless, if we do add the PlanResourceChange call into the destroy operation, the provider must be configured first.

[apparentlymart]

I think regardless of whether we call PlanResourceChange it's still incorrect to call UpgradeResourceState on an unconfigured provider. If we can address both needs together then that would be awesome 😀 but being able to make authenticated network calls is a long-standing part of the state upgrade contract (which, in the legacy SDK, is represented by a function taking the meta interface{} extra argument to hold the client) and so I think we ought to consider this a bug to be fixed reasonably soon, to narrow the window of Terraform CLI versions which are likely to cause providers which use this mechanism to crash. 😖

[jbardin]

Just to update for v1.2 -- The current destroy graph implementation was written to be a completely offline operation, with no input from the provider (other than fetching schemas of course), so there is not enough information at the moment to configure the provider at all. This means fixing the missing config turns out to be a bit more involved than just calling ConfigureProvider, and will likely need to wait to be bundled with a solution to allow providers to plan destroy operations.

[github-actions]

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 have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.