Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Caching not usable in 0.14.x due to lock file checksums #27769

Closed
milosbackonja opened this issue Feb 13, 2021 · 13 comments
Closed

Caching not usable in 0.14.x due to lock file checksums #27769

milosbackonja opened this issue Feb 13, 2021 · 13 comments
Labels
bug new new issue not yet triaged v0.14 Issues (primarily bugs) reported against v0.14 releases waiting for reproduction unable to reproduce issue without further information

Comments

@milosbackonja
Copy link

Plugin caching is unusable since it fails when verifies checksum in dependency lock file.
Is there way to disable this locking feature? Tbh I can see that caching feature is more needed than this sufficient locking feature.

Terraform Version

Terraform v0.14.6

Terraform Configuration Files

/root/.terraformrc
plugin_cache_dir   = "$HOME/.terraform.d/plugin-cache"

Debug Output

  ----
2021/02/13 21:13:45 [INFO] Terraform version: 0.14.6  
2021/02/13 21:13:45 [INFO] Go runtime version: go1.15.6
2021/02/13 21:13:45 [INFO] CLI args: []string{"/bin/terraform", "validate"}
2021/02/13 21:13:45 [DEBUG] Attempting to open CLI config file: /root/.terraformrc
2021/02/13 21:13:45 Loading CLI configuration from /root/.terraformrc
2021/02/13 21:13:45 [DEBUG] ignoring non-existing provider search directory terraform.d/plugins
2021/02/13 21:13:45 [DEBUG] ignoring non-existing provider search directory /root/.terraform.d/plugins
2021/02/13 21:13:45 [DEBUG] ignoring non-existing provider search directory /root/.local/share/terraform/plugins
2021/02/13 21:13:45 [DEBUG] ignoring non-existing provider search directory /usr/local/share/terraform/plugins
2021/02/13 21:13:45 [DEBUG] ignoring non-existing provider search directory /usr/share/terraform/plugins
2021/02/13 21:13:45 [INFO] Checkpoint disabled. Not running.
2021/02/13 21:13:45 [INFO] CLI command args: []string{"validate"}
2021/02/13 21:13:45 [WARN] Log levels other than TRACE are currently unreliable, and are supported only for backward compatibility.
  Use TF_LOG=TRACE to see Terraform's internal logs.
  ----
2021/02/13 21:13:46 [WARN] Failed to determine selected providers: 1 error occurred:
        * the cached package for registry.terraform.io/hashicorp/aws 3.28.0 (in .terraform/providers) does not match any of the checksums recorded in the dependency lock file

2021/02/13 21:13:46 [DEBUG] checking for provisioner in "."
2021/02/13 21:13:46 [DEBUG] checking for provisioner in "/bin"
2021/02/13 21:13:46 [INFO] Failed to read plugin lock file .terraform/plugins/linux_amd64/lock.json: open .terraform/plugins/linux_amd64/lock.json: no such file or directory
2021-02-13T21:13:46.557Z [INFO]  plugin: configuring client automatic mTLS
2021-02-13T21:13:46.585Z [DEBUG] plugin: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/external/2.0.0/linux_amd64/terraform-provider-external_v2.0.0_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/external/2.0.0/linux_amd64/terraform-provider-external_v2.0.0_x5]
2021-02-13T21:13:46.586Z [DEBUG] plugin: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/external/2.0.0/linux_amd64/terraform-provider-external_v2.0.0_x5 pid=29594
2021-02-13T21:13:46.586Z [DEBUG] plugin: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/external/2.0.0/linux_amd64/terraform-provider-external_v2.0.0_x5
2021-02-13T21:13:46.597Z [INFO]  plugin.terraform-provider-external_v2.0.0_x5: configuring server automatic mTLS: timestamp=2021-02-13T21:13:46.597Z
2021-02-13T21:13:46.630Z [DEBUG] plugin: using plugin: version=5
2021-02-13T21:13:46.630Z [DEBUG] plugin.terraform-provider-external_v2.0.0_x5: plugin address: address=/tmp/plugin272684661 network=unix timestamp=2021-02-13T21:13:46.630Z
2021-02-13T21:13:46.689Z [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-02-13T21:13:46.691Z [DEBUG] plugin: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/external/2.0.0/linux_amd64/terraform-provider-external_v2.0.0_x5 pid=29594
2021-02-13T21:13:46.691Z [DEBUG] plugin: plugin exited
2021-02-13T21:13:46.693Z [INFO]  plugin: configuring client automatic mTLS
2021-02-13T21:13:46.718Z [DEBUG] plugin: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/local/2.0.0/linux_amd64/terraform-provider-local_v2.0.0_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/local/2.0.0/linux_amd64/terraform-provider-local_v2.0.0_x5]
2021-02-13T21:13:46.720Z [DEBUG] plugin: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/local/2.0.0/linux_amd64/terraform-provider-local_v2.0.0_x5 pid=29605
2021-02-13T21:13:46.720Z [DEBUG] plugin: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/local/2.0.0/linux_amd64/terraform-provider-local_v2.0.0_x5
2021-02-13T21:13:46.728Z [INFO]  plugin.terraform-provider-local_v2.0.0_x5: configuring server automatic mTLS: timestamp=2021-02-13T21:13:46.728Z
2021-02-13T21:13:46.758Z [DEBUG] plugin.terraform-provider-local_v2.0.0_x5: plugin address: address=/tmp/plugin326208764 network=unix timestamp=2021-02-13T21:13:46.757Z
2021-02-13T21:13:46.758Z [DEBUG] plugin: using plugin: version=5
2021-02-13T21:13:46.816Z [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-02-13T21:13:46.818Z [DEBUG] plugin: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/local/2.0.0/linux_amd64/terraform-provider-local_v2.0.0_x5 pid=29605
2021-02-13T21:13:46.818Z [DEBUG] plugin: plugin exited
2021-02-13T21:13:46.820Z [INFO]  plugin: configuring client automatic mTLS
2021-02-13T21:13:46.847Z [DEBUG] plugin: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.0.0/linux_amd64/terraform-provider-null_v3.0.0_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/null/3.0.0/linux_amd64/terraform-provider-null_v3.0.0_x5]
2021-02-13T21:13:46.848Z [DEBUG] plugin: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.0.0/linux_amd64/terraform-provider-null_v3.0.0_x5 pid=29616
2021-02-13T21:13:46.848Z [DEBUG] plugin: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.0.0/linux_amd64/terraform-provider-null_v3.0.0_x5
2021-02-13T21:13:46.857Z [INFO]  plugin.terraform-provider-null_v3.0.0_x5: configuring server automatic mTLS: timestamp=2021-02-13T21:13:46.857Z
2021-02-13T21:13:46.886Z [DEBUG] plugin: using plugin: version=5
2021-02-13T21:13:46.886Z [DEBUG] plugin.terraform-provider-null_v3.0.0_x5: plugin address: address=/tmp/plugin963257931 network=unix timestamp=2021-02-13T21:13:46.886Z
2021-02-13T21:13:46.942Z [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-02-13T21:13:46.944Z [DEBUG] plugin: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.0.0/linux_amd64/terraform-provider-null_v3.0.0_x5 pid=29616
2021-02-13T21:13:46.944Z [DEBUG] plugin: plugin exited
2021-02-13T21:13:46.945Z [INFO]  plugin: configuring client automatic mTLS
2021-02-13T21:13:46.973Z [DEBUG] plugin: starting plugin: path=.terraform/providers/registry.terraform.io/hashicorp/random/3.0.1/linux_amd64/terraform-provider-random_v3.0.1_x5 args=[.terraform/providers/registry.terraform.io/hashicorp/random/3.0.1/linux_amd64/terraform-provider-random_v3.0.1_x5]
2021-02-13T21:13:46.974Z [DEBUG] plugin: plugin started: path=.terraform/providers/registry.terraform.io/hashicorp/random/3.0.1/linux_amd64/terraform-provider-random_v3.0.1_x5 pid=29627
2021-02-13T21:13:46.974Z [DEBUG] plugin: waiting for RPC address: path=.terraform/providers/registry.terraform.io/hashicorp/random/3.0.1/linux_amd64/terraform-provider-random_v3.0.1_x5
2021-02-13T21:13:46.983Z [INFO]  plugin.terraform-provider-random_v3.0.1_x5: configuring server automatic mTLS: timestamp=2021-02-13T21:13:46.983Z
2021-02-13T21:13:47.011Z [DEBUG] plugin: using plugin: version=5
2021-02-13T21:13:47.012Z [DEBUG] plugin.terraform-provider-random_v3.0.1_x5: plugin address: address=/tmp/plugin586212750 network=unix timestamp=2021-02-13T21:13:47.011Z
2021-02-13T21:13:47.068Z [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-02-13T21:13:47.071Z [DEBUG] plugin: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/random/3.0.1/linux_amd64/terraform-provider-random_v3.0.1_x5 pid=29627
2021-02-13T21:13:47.071Z [DEBUG] plugin: plugin exited
2021-02-13T21:13:47.071Z [DEBUG] plugin: starting plugin: path=/bin/terraform args=[/bin/terraform, internal-plugin, provisioner, local-exec]
2021-02-13T21:13:47.071Z [DEBUG] plugin: plugin started: path=/bin/terraform pid=29638
2021-02-13T21:13:47.071Z [DEBUG] plugin: waiting for RPC address: path=/bin/terraform
2021-02-13T21:13:47.104Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [WARN] Log levels other than TRACE are currently unreliable, and are supported only for backward compatibility.
2021-02-13T21:13:47.104Z [DEBUG] plugin.terraform:   Use TF_LOG=TRACE to see Terraform's internal logs.
2021-02-13T21:13:47.104Z [DEBUG] plugin.terraform:   ----
2021-02-13T21:13:47.130Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [INFO] Terraform version: 0.14.6  
2021-02-13T21:13:47.131Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [INFO] Go runtime version: go1.15.6
2021-02-13T21:13:47.131Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [INFO] CLI args: []string{"/bin/terraform", "internal-plugin", "provisioner", "local-exec"}
2021-02-13T21:13:47.131Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [DEBUG] Attempting to open CLI config file: /root/.terraformrc
2021-02-13T21:13:47.131Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 Loading CLI configuration from /root/.terraformrc
2021-02-13T21:13:47.132Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [DEBUG] ignoring non-existing provider search directory terraform.d/plugins
2021-02-13T21:13:47.132Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [DEBUG] ignoring non-existing provider search directory /root/.terraform.d/plugins
2021-02-13T21:13:47.132Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [DEBUG] ignoring non-existing provider search directory /root/.local/share/terraform/plugins
2021-02-13T21:13:47.133Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [DEBUG] ignoring non-existing provider search directory /usr/local/share/terraform/plugins
2021-02-13T21:13:47.133Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [DEBUG] ignoring non-existing provider search directory /usr/share/terraform/plugins
2021-02-13T21:13:47.134Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [INFO] CLI command args: []string{"internal-plugin", "provisioner", "local-exec"}
2021-02-13T21:13:47.134Z [DEBUG] plugin.terraform: 2021/02/13 21:13:47 [INFO] Checkpoint disabled. Not running.
2021-02-13T21:13:47.135Z [DEBUG] plugin.terraform: local-exec-provisioner (internal) 2021/02/13 21:13:47 [INFO] Starting provisioner plugin local-exec
2021-02-13T21:13:47.136Z [DEBUG] plugin.terraform: plugin address: address=/tmp/plugin515712573 network=unix timestamp=2021-02-13T21:13:47.135Z
2021-02-13T21:13:47.137Z [DEBUG] plugin: using plugin: version=5
2021-02-13T21:13:47.139Z [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-02-13T21:13:47.144Z [DEBUG] plugin: plugin process exited: path=/bin/terraform pid=29638
2021-02-13T21:13:47.144Z [DEBUG] plugin: plugin exited

Error: Could not load plugin


Plugin reinitialization required. Please run "terraform init".

Plugins are external binaries that Terraform uses to access and manipulate
resources. The configuration provided requires plugins which can't be located,
don't satisfy the version constraints, or are otherwise incompatible.

Terraform automatically discovers provider requirements from your
configuration, including providers used in child modules. To see the
requirements and constraints, run "terraform providers".

Failed to instantiate provider "registry.terraform.io/hashicorp/aws" to obtain
schema: the cached package for registry.terraform.io/hashicorp/aws 3.28.0 (in
.terraform/providers) does not match any of the checksums recorded in the
dependency lock file

Expected Behavior

Actual Behavior

Steps to Reproduce

  1. terraform init
  2. terraform apply/validate/plan

Additional Context

References

@alex-derzhi-sp
Copy link

+1, we're having to write a post-plan/apply script to delete the lockfiles

@mildwonkey
Copy link
Contributor

Hi all, thanks for reporting this issue.
I'm unable to reproduce this locally using terraform v0.14.6. Does anyone have an example configuration that I can use to reproduce this?

This is the (very simple) configuration I've tried; init and plan all work without error:

provider "aws" {
  version = "3.28.0"
}

I tried changing the provider version without re-running init, and each time terraform gave a clear message (for example, " run init -upgrade").

@mildwonkey mildwonkey added the waiting for reproduction unable to reproduce issue without further information label Mar 23, 2021
@marcoreni
Copy link

@mildwonkey In our case, this exact issue happens when we create the lockfile (with caching enabled) in a MacOS environment, then run a plan/apply a CI environment running Linux - just like #27135.

Sadly we still have to find a practical solution (right now our workaround is to run terraform providers lock to add the multiple platforms inside the lock every time we update a provider, but it's time and bandwidth consuming, having a lot of different modules laying around).

I think that #27811 provides a thorough analysis and references different tickets with nuances of the same underlying problem.

@mildwonkey
Copy link
Contributor

Ahh, thank you for that.

🤔 since what you are describing is the current documented workflow, do you think we can close this ticket in favor of that enhancement request? It doesn't sound like there is a bug to me, but I don't want to close this if you disagree with my assessment!

@marcoreni
Copy link

I agree that it's better to have a single point of discussion.

I'd just wait for a confirmation that @milosbackonja and/or @alex-derzhi-sp are stuck in the same scenario :)

@milosbackonja
Copy link
Author

@mildwonkey Did you try to use it multiple times in configuration? If you call same module in several places using cashed providers it will fail. If you use it only once reference, and hash will be ok I guess...

@apparentlymart apparentlymart added the v0.14 Issues (primarily bugs) reported against v0.14 releases label Apr 9, 2021
@doherty100
Copy link

FYI @tombuildsstuff I'm experiencing this issue in a strange way in Azure Cloud Shell, which is a container based CLI hooked up to the Azure Portal. After running terraform init a few different times for different configurations in different directories, I start getting 'Error: Could not load plugin'. I've tried everything to try to "reset" the environment including deleting ~/.terraform.d but still haven't figured out how to reset things to get them working again.

@doherty100
Copy link

@doherty100
Copy link

@mildwonkey I can repro this consistently on Azure cloud shell using this repo:

https://github.com/doherty100/azurequickstarts

If you just apply each of these quick starts in the order described, you will eventually get this error on Azure Cloud Shell.

@jbardin
Copy link
Member

jbardin commented Aug 12, 2021

I have not ben able to reproduce this in current terraform releases, using a shared cached for multiple provider versions and architectures from multiple root modules. We can track the future enhancements in the linked issue, so I'm going to close this for now. If someone encounters the same issue with a current release and can supply a standalone reproduction case, feel free to file a new issue.

Thanks!

@jbardin jbardin closed this as completed Aug 12, 2021
@tjstansell
Copy link

tjstansell commented Sep 9, 2021

I've been running into this in my environment as well. We use a docker image that includes a bunch of providers pre-installed via the terraform providers mirror command locally. We also use terragrunt to run many simultaneous terraform runs and get intermittent failures because of this checksum issue. I did some debugging and after our init phase, I dumped out the .terraform.lock.hcl file in our many repos, and re-ran our build until it failed. In this particular test, we had 19 different terraform directories, all being initialized with terragrunt run-all init with a parallelization of 15. It looks like during the init phase, some of them are getting incorrect checksums for the hashicorp/random provider (it always seems to fail on this one provider for whatever reason). parsing the contents of those lock files, it calculated a bad checksum 2 times and the correct one 17 others:

   2 "registry.terraform.io/hashicorp/random" "3.1.0" "h1:8rMB2FatB9xlweImzOjTLEKjOsMnE+Dq6/8fJ/Q9oRY=",
  17 "registry.terraform.io/hashicorp/random" "3.1.0" "h1:BZMEPucF+pbu9gsPk0G0BHx7YP04+tKdq2MrRDF1EDM=",

I'm not sure what could be causing it to mis-calculate the checksum... but this is the crux of the problem. Something must not be safe with simultaneous access to the cache directory. I wasn't sure if I should open a new ticket or just update this one, but I wanted everyone watching this to see what I found, so I opted for the latter. We can fork this if that makes sense...

Oh, and I run into this with 0.14.11 as well as 1.0.6 ... same issue.

@tjstansell
Copy link

And now I see this is all likely a side affect of the fact that the caching mechanisms are not designed to be concurrency-safe per #26819 and #25849. That's disappointing and pretty much makes caching useless.

@github-actions
Copy link
Contributor

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.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Oct 10, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug new new issue not yet triaged v0.14 Issues (primarily bugs) reported against v0.14 releases waiting for reproduction unable to reproduce issue without further information
Projects
None yet
Development

No branches or pull requests

8 participants