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.

Sign up for GitHub

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

Jump to bottom

err="rpc error: code = Unavailable desc = transport is closing" #16073

Closed
joshghent opened this issue Nov 6, 2020 · 48 comments
Closed

err="rpc error: code = Unavailable desc = transport is closing" #16073

joshghent opened this issue Nov 6, 2020 · 48 comments
Labels
crash Results from or addresses a Terraform crash or kernel panic. provider Pertains to the provider itself, rather than any interaction with AWS.

Comments

@joshghent
Copy link

Community Note

  • Please vote on this issue by adding a 👍 reaction to the original issue to help the community and maintainers prioritize this request
  • Please do not leave "+1" or other comments that do not add relevant new information or questions, they generate extra noise for issue followers and do not help prioritize the request
  • If you are interested in working on this issue or have submitted a pull request, please leave a comment

Terraform CLI and Terraform AWS Provider Version

Terraform v0.13.4
hashicorp/aws v3.14.0
hashicorp/template v2.2.0

Affected Resource(s)

  • aws_XXXXX

Terraform Configuration Files

Won't post the whole thing but think this gets the point across

// main.tf
module "variables" {
  source      = "./modules/variables"
  environment = local.environment
  size        = local.size
}

module "ecs-api" {
  source             = "./modules/ecs-api"
  environment        = local.environment
  instance_type      = module.variables.instance_type
  domain_name        = module.variables.domain_name
  depends_on         = [module.variables]
}

Debug Output

Panic Output

Expected Behavior

Actual Behavior

2020/11/06 12:22:49 [DEBUG] [aws-sdk-go] {}
2020-11-06T12:22:49.581Z [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2020-11-06T12:22:49.602Z [DEBUG] plugin: plugin process exited: path=.terraform/plugins/registry.terraform.io/hashicorp/aws/3.14.0/linux_amd64/terraform-provider-aws_v3.14.0_x5 pid=11623
2020-11-06T12:22:49.624Z [DEBUG] plugin: plugin exited
##[error]Bash exited with code '1'.

Steps to Reproduce

  1. terraform plan -compact-warnings=false -input=false

Important Factoids

Nothing weird about the infra. You can see in the main.tf snippet, that I'm passing in an output from the variables module into the ecs-api module. This domain name is then used in a data to find a route53 zone. Further up the debug output, there is an error saying it can't find the route53 zone. I believe this because the variables module output isn't getting correctly passed in. The ecs module should depend on the variables module but it appears to be getting executed before the variables module outputs.

References
@github-actions github-actions bot added the needs-triage Waiting for first response or review from a maintainer. label Nov 6, 2020
@ewbankkit
Copy link
Contributor

@joshghent Thanks for raising this issue.
Often this error message indicative of a crash in the provider (which runs in a separate process) - Is there anything in the logs that looks like a stack trace?

@joshghent
Copy link
Author

@ewbankkit Thanks for getting back to me. No it doesn't have any stack trace. It appears to error because it cannot find the route53 zones and then the aws provider returns {} and then it crashes.
Do you know why this "depends_on" clause would not work between modules? As far as I can tell, it should be supported?
Thank you for the work of terraform btw, this is an awesome tool! 🎉

@fingerquote
Copy link

I am experiencing the same error, and I also have a module whose outputs are being fed into another module.

@hugbubby
Copy link

hugbubby commented Dec 11, 2020 •
edited
Loading

I have this same error. Took down one of our environments and we can't bring it back up. I don't happen to use route53 so @joshghent's theory doesn't make sense for me personally.

@ewbankkit ewbankkit added the crash Results from or addresses a Terraform crash or kernel panic. label Dec 11, 2020
@scwall
Copy link

scwall commented Dec 16, 2020

hello I don't know if I have the same problem, it seems that I do, here is the output I get

-----------------------------------------------------
2020/12/16 15:02:21 [DEBUG] [aws-sdk-go] DEBUG: Response dynamodb/DeleteItem Details:
---[ RESPONSE ]--------------------------------------
HTTP/1.1 200 OK
Connection: close
Content-Length: 2
Content-Type: application/x-amz-json-1.0
Date: Wed, 16 Dec 2020 15:02:21 GMT
Server: Server
X-Amz-Crc32: 2745614147
X-Amzn-Requestid: I2S5F953C2QDIGDH41KM6MLLO3VV4KQNSO5AEMVJF66Q9ASUAAJG


-----------------------------------------------------
2020/12/16 15:02:21 [DEBUG] [aws-sdk-go] {}
2020-12-16T15:02:21.511Z [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2020-12-16T15:02:21.514Z [DEBUG] plugin: plugin process exited: path=.terraform/plugins/registry.terraform.io/hashicorp/aws/3.21.0/linux_amd64/terraform-provider-aws_v3.21.0_x5 pid=65
2020-12-16T15:02:21.514Z [DEBUG] plugin: plugin exited
make: *** [Makefile:7: apply] Error 1

@scwall scwall mentioned this issue Dec 16, 2020
Closed
@ikarlashov
Copy link

ikarlashov commented Dec 18, 2020 •
edited
Loading 

2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: 2020/12/18 13:25:47 [DEBUG] [aws-sdk-go] DEBUG: Response lambda/Invoke Details:
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: ---[ RESPONSE ]--------------------------------------
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: HTTP/1.1 200 OK
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: Connection: close
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: Content-Length: 58
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: Content-Type: application/json
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: Date: Fri, 18 Dec 2020 12:25:47 GMT
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: X-Amz-Executed-Version: $LATEST
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: X-Amzn-Remapped-Content-Length: 0
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: X-Amzn-Requestid: 2ea0a0f6-10e9-488b-a0ea-10dc2865db84
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: X-Amzn-Trace-Id: root=1-5fdc9fc7-3e7941d64fd341f10166a570;sampled=0
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5:
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5:
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: -----------------------------------------------------
2020-12-18T13:25:47.896+0100 [DEBUG] plugin.terraform-provider-aws_v3.21.0_x5: 2020/12/18 13:25:47 [DEBUG] [aws-sdk-go] {"message": "ECS service has been successfully restarted"}
2020-12-18T13:25:47.898+0100 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2020-12-18T13:25:47.902+0100 [DEBUG] plugin: plugin process exited: path=.terraform/plugins/registry.terraform.io/hashicorp/aws/3.21.0/darwin_amd64/terraform-provider-aws_v3.21.0_x5 pid=87923
2020-12-18T13:25:47.902+0100 [DEBUG] plugin: plugin exited

Because of this error - my Lambda is triggered twice instead of once :( Same issue with provider version 3.4.0.

@ajardan
Copy link

ajardan commented Jan 8, 2021 •
edited
Loading

I see the same issue on

Terraform v0.13.5
+ provider registry.terraform.io/hashicorp/aws v3.22.0

This is also on a M1 Mac, could be important

@ambrosy-eric
Copy link

Receiving the same error when when feeding a module that calls another module output from another module on provider 3.23.0.

// main.tf
module "network" {
  source = "../../../../modules/vpc/basic"
  input vars...
}

module "instance_type" {
  source = "../../../../modules/instance_type"

  vpc_id                       = module.network.vpc_id
  subnet_id                    = module.network.public_subnets[0]
  additional_policy = {
    json = data.aws_iam_policy_document.policy.json
  }
}

My debug shows the plan completed before the error.

2021/01/15 11:56:43 [INFO] backend/local: plan operation completed

Error: Your query returned no results. Please change your search criteria and try again.



Error: Your query returned no results. Please change your search criteria and try again.


2021-01-15T11:56:43.867-0600 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-01-15T11:56:43.867-0600 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-01-15T11:56:43.867-0600 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-01-15T11:56:43.868-0600 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-01-15T11:56:43.868-0600 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-01-15T11:56:43.873-0600 [DEBUG] plugin: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/aws/3.23.0/darwin_amd64/terraform-provider-aws_v3.23.0_x5 pid=24068
2021-01-15T11:56:43.874-0600 [DEBUG] plugin: plugin exited
2021-01-15T11:56:43.874-0600 [DEBUG] plugin: plugin process exited: path=/usr/local/Cellar/tfenv/2.0.0/versions/0.14.2/terraform pid=24064
2021-01-15T11:56:43.874-0600 [DEBUG] plugin: plugin exited

@rastakajakwanna
Copy link

rastakajakwanna commented Jan 19, 2021 •
edited
Loading

Getting the same issue with aws provider 3.24.1, (issue tested also with 3.23.0, 3.22.0, 3.21.0 and failing) and tf 0.12.29.

The issue is inconsistent, it fails only for one remote state (stage in our case) and not for the others. Provider versions configuration are the same. It also fails at different places - I can see kubernetes provider failing, next time it is random provider...

I've also deleted all non-default workspaces as suggested in linked issue but no change.

Trace log shows just the following and I could find randomly failing providers with the rpc error in earlier part of the log.

2021/01/19 19:49:19 [TRACE] dag/walk: upstream of "provider.aws (close)" errored, so skipping
2021/01/19 19:49:19 [TRACE] dag/walk: upstream of "root" errored, so skipping

Also no change whether I am using proxy or not.

Is it possible that changes applied with the aws.provider 3.24.0 have somehow messed up the state somewhere? (regarding #17125 )

I can also see a lot of rpc errors of three kinds:

[WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unimplemented desc = unknown service plugin.GRPCStdio"
[WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
[WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Canceled desc = context canceled"

Terraform refresh is crashing around different resources than plan, however, both of them are crashing always around IAM policy attachments "aws_iam_role_policy_attachment". But it does not fail if I target these resources with plan.

@rastakajakwanna
Copy link

rastakajakwanna commented Jan 21, 2021 •
edited
Loading

Our issue has been resolved. It was a data resource which was looking for a deprecated AMI. I am only wondering why I could not find the exact source of the issue in the TRACE log of Terraform.

@luhhujbb
Copy link

luhhujbb commented Feb 1, 2021 •
edited
Loading

Hello,
It's seems that @rastakajakwanna is right, this issue comes from a not found data.
However I've rolled back to version 2.70 of aws provider ant it adds where :

Version 3.26
Error: Your query returned no results. Please change your search criteria and try again.

Version 2.70

Error: Your query did not return any results. Please try a different search criteria.

  on base.tf line 267, in data "aws_autoscaling_group" "my_asg":
 267: data "aws_autoscaling_group" "my_asg" {

So it looks like a logging regression since user is now unable to find quickly what is the missing "data" resource.

@bflad
Copy link
Contributor

bflad commented Feb 1, 2021

The lack of configuration file/line context when reporting data source errors is likely due to upgrading to Terraform Plugin SDK version 2 in version 3.2.0 of the Terraform AWS Provider. See also: hashicorp/terraform-plugin-sdk#561. That issue will require a fix upstream in the Terraform Plugin SDK.

We could potentially improve actual error message for data sources though to at least give some context about what type of resource lookup failed. It might be good to fold these improvements into the discussion for #17314 -- data source updates could be done quicker than managed resources.

Trying to solve the confusing rpc error: code = Unavailable desc = transport is closing type errors will need self-contained reproduction cases. Terraform CLI should drop a crash.log file or show a panic: line in trace logs when a Terraform Provider crashes unexpectedly. It would also be helpful to know if this error is different with Terraform CLI version 0.14.

@luhhujbb
Copy link

luhhujbb commented Feb 1, 2021

@bflad I've tested the two versions of aws provider (3.26 & 2.70) using the following two version of Terraform CLI : 0.13.1 & 0.14.5. The behavior is the same.

@Shattoww
Copy link

Shattoww commented Feb 4, 2021

Confirmed with aws provider 3.25 & TF 0.14.5 seems like a logging regression as luhhujbb commented on.

@AndrewFarley
Copy link

AndrewFarley commented Feb 25, 2021 •
edited
Loading

I have thumbs upped this, but wanted to add that I would commit a bounty of a couple hundreds dollars for someone who can fix this ASAP.

I've been struggling for weeks with this problem. Been trying terraform 0.13 and 0.14 of various versions, and various versions of the aws provider. The problem for me is intermittent, where an "apply" just hangs for a very long time (~5m) while gathering facts and with trace logging on I just see a bunch of this rpc error transport is closing. I'm having to do terraform apply multiple times before it finally goes through, but meanwhile this is frustrating me to no end.

This is impacting my daily life as I live and breathe Terraform. I would be available to try dev/beta builds as well and give feedback, as I've tried everything besides jumping into code at this point and I'm still frustrated and wasting tons of time. I suspect that not only a logging resolution would need to be made, but if the logging fix would give me more clarity on why my runs fail so regularly I could fix the actual problem whatever that may be.

Cheers, hoping for a speedy resolution!

@DeLoWaN
Copy link

DeLoWaN commented Mar 2, 2021

For the record, I also had this behaviour when using a module that was searching for an AMI. I used it in my infrastructure 11 times and I guess it was too many for Terraform. I deactivated the module and no more errors.

@artshipulin
Copy link

Can this be related to AWS upgrading minimum TLS version for some endpoints? https://aws.amazon.com/blogs/security/tls-1-2-required-for-aws-fips-endpoints/

@watcher00090
Copy link

I'm facing a similar issue here:

Terraform versions I'm using:
Terraform v0.14.7

  • provider registry.terraform.io/hashicorp/aws v3.31.0
  • provider registry.terraform.io/hashicorp/null v3.1.0
  • provider registry.terraform.io/hashicorp/random v3.1.0
  • provider registry.terraform.io/hashicorp/tls v3.1.0

Here's the last part of a TF_LOG file for a run where the error occurred:

module.workshop[13].null_resource.ssh_config[0] (remote-exec):   User: ubuntu
module.workshop[13].null_resource.ssh_config[0] (remote-exec):   Password: false
module.workshop[13].null_resource.ssh_config[0] (remote-exec):   Private key: true
module.workshop[13].null_resource.ssh_config[0] (remote-exec):   Certificate: false
module.workshop[13].null_resource.ssh_config[0] (remote-exec):   SSH Agent: false
module.workshop[13].null_resource.ssh_config[0] (remote-exec):   Checking Host Key: false
module.workshop[13].null_resource.ssh_config[0] (remote-exec):   Target Platform: unix
2021-03-10T23:14:58.078-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:14:58 [DEBUG] Connection established. Handshaking for user ubuntu
2021-03-10T23:14:58.078-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:14:58 [DEBUG] Connection established. Handshaking for user ubuntu
2021-03-10T23:14:58.094-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:14:58 [DEBUG] Connection established. Handshaking for user ubuntu
2021/03/10 23:14:58 [TRACE] dag/walk: vertex "output.instance_info" is waiting for "module.workshop (close)"
2021/03/10 23:14:58 [TRACE] dag/walk: vertex "meta.count-boundary (EachMode fixup)" is waiting for "output.instance_info"
2021/03/10 23:14:58 [TRACE] dag/walk: vertex "provider[\"registry.terraform.io/hashicorp/null\"] (close)" is waiting for "module.workshop[13].null_resource.ssh_config[0]"
2021-03-10T23:14:58.773-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:14:58 [DEBUG] starting ssh KeepAlives
2021-03-10T23:14:58.773-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:14:58 [DEBUG] opening new ssh session
2021-03-10T23:14:58.773-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:14:58 [DEBUG] starting ssh KeepAlives
2021-03-10T23:14:58.773-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:14:58 [DEBUG] opening new ssh session
module.workshop[13].null_resource.ssh_config[1] (remote-exec): Connected!
module.workshop[13].null_resource.flannel (remote-exec): Connected!
2021-03-10T23:14:58.800-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:14:58 [DEBUG] starting ssh KeepAlives
2021-03-10T23:14:58.800-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:14:58 [DEBUG] opening new ssh session
module.workshop[13].null_resource.ssh_config[0] (remote-exec): Connected!
2021-03-10T23:15:00.128-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Starting remote scp process:  scp -vt /tmp
2021-03-10T23:15:00.128-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Starting remote scp process:  scp -vt /tmp
2021-03-10T23:15:00.219-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Starting remote scp process:  scp -vt /tmp
2021-03-10T23:15:00.222-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Started SCP session, beginning transfers...
2021-03-10T23:15:00.222-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Beginning file upload...
2021-03-10T23:15:00.222-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Started SCP session, beginning transfers...
2021-03-10T23:15:00.222-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Beginning file upload...
2021-03-10T23:15:00.314-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Started SCP session, beginning transfers...
2021-03-10T23:15:00.314-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Beginning file upload...
2021-03-10T23:15:00.315-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] SCP session complete, closing stdin pipe.
2021-03-10T23:15:00.315-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Waiting for SSH session to complete.
2021-03-10T23:15:00.315-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] SCP session complete, closing stdin pipe.
2021-03-10T23:15:00.315-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Waiting for SSH session to complete.
2021-03-10T23:15:00.412-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] SCP session complete, closing stdin pipe.
2021-03-10T23:15:00.412-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] Waiting for SSH session to complete.
2021-03-10T23:15:00.412-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [ERROR] scp stderr: "Sink: C0644 261 terraform_2063536812.sh\n"
2021-03-10T23:15:00.412-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] opening new ssh session
2021-03-10T23:15:00.412-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [ERROR] scp stderr: "Sink: C0644 117 terraform_1221452065.sh\n"
2021-03-10T23:15:00.412-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] opening new ssh session
2021/03/10 23:15:00 [TRACE] dag/walk: vertex "module.workshop (close)" is waiting for "module.workshop[13].null_resource.ssh_config[0]"
2021-03-10T23:15:00.506-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [ERROR] scp stderr: "Sink: C0644 260 terraform_1231042967.sh\n"
2021-03-10T23:15:00.506-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] opening new ssh session
2021-03-10T23:15:00.599-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] starting remote command: chmod 0777 /tmp/terraform_2063536812.sh
2021-03-10T23:15:00.600-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] starting remote command: chmod 0777 /tmp/terraform_1221452065.sh
2021-03-10T23:15:00.694-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] starting remote command: chmod 0777 /tmp/terraform_1231042967.sh
2021-03-10T23:15:00.695-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] remote command exited with '0': chmod 0777 /tmp/terraform_2063536812.sh
2021-03-10T23:15:00.695-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] opening new ssh session
2021-03-10T23:15:00.697-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] remote command exited with '0': chmod 0777 /tmp/terraform_1221452065.sh
2021-03-10T23:15:00.697-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] opening new ssh session
2021-03-10T23:15:00.791-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] remote command exited with '0': chmod 0777 /tmp/terraform_1231042967.sh
2021-03-10T23:15:00.791-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] opening new ssh session
2021-03-10T23:15:00.883-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] starting remote command: /tmp/terraform_1221452065.sh
2021-03-10T23:15:00.883-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] starting remote command: /tmp/terraform_2063536812.sh
2021/03/10 23:15:00 [TRACE] dag/walk: vertex "provisioner.remote-exec (close)" is waiting for "module.workshop[13].null_resource.ssh_config[1]"
2021-03-10T23:15:00.978-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:00 [DEBUG] starting remote command: /tmp/terraform_1231042967.sh
2021-03-10T23:15:01.013-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] remote command exited with '0': /tmp/terraform_2063536812.sh
2021-03-10T23:15:01.013-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] opening new ssh session
2021-03-10T23:15:01.107-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Starting remote scp process:  scp -vt /tmp
2021-03-10T23:15:01.128-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] remote command exited with '0': /tmp/terraform_1231042967.sh
2021-03-10T23:15:01.128-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] opening new ssh session
2021-03-10T23:15:01.200-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Started SCP session, beginning transfers...
2021-03-10T23:15:01.201-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Copying input data into temporary file so we can read the length
2021-03-10T23:15:01.222-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Starting remote scp process:  scp -vt /tmp
2021-03-10T23:15:01.242-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Beginning file upload...
2021-03-10T23:15:01.315-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Started SCP session, beginning transfers...
2021-03-10T23:15:01.316-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Copying input data into temporary file so we can read the length
2021-03-10T23:15:01.325-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Beginning file upload...
2021-03-10T23:15:01.335-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] SCP session complete, closing stdin pipe.
2021-03-10T23:15:01.335-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Waiting for SSH session to complete.
module.workshop[13].null_resource.flannel (remote-exec): podsecuritypolicy.policy/psp.flannel.unprivileged created
module.workshop[13].null_resource.flannel (remote-exec): Warning: rbac.authorization.k8s.io/v1beta1 ClusterRole is deprecated in v1.17+, unavailable in v1.22+; use rbac.authorization.k8s.io/v1 ClusterRole
module.workshop[13].null_resource.flannel (remote-exec): clusterrole.rbac.authorization.k8s.io/flannel created
module.workshop[13].null_resource.flannel (remote-exec): Warning: rbac.authorization.k8s.io/v1beta1 ClusterRoleBinding is deprecated in v1.17+, unavailable in v1.22+; use rbac.authorization.k8s.io/v1 ClusterRoleBinding
module.workshop[13].null_resource.flannel (remote-exec): clusterrolebinding.rbac.authorization.k8s.io/flannel created
module.workshop[13].null_resource.flannel (remote-exec): serviceaccount/flannel created
2021-03-10T23:15:01.422-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] SCP session complete, closing stdin pipe.
2021-03-10T23:15:01.422-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Waiting for SSH session to complete.
module.workshop[13].null_resource.flannel (remote-exec): configmap/kube-flannel-cfg created
2021-03-10T23:15:01.429-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [ERROR] scp stderr: "Sink: C0644 0 terraform_2063536812.sh\n"
2021/03/10 23:15:01 [TRACE] EvalWriteState: recording 11 dependencies for module.workshop[13].null_resource.ssh_config[0]
2021/03/10 23:15:01 [TRACE] EvalWriteState: writing current state object for module.workshop[13].null_resource.ssh_config[0]
module.workshop[13].null_resource.ssh_config[0]: Creation complete after 3s [id=2706692844627162236]
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: have already backed up original terraform.tfstate to terraform.tfstate.backup on a previous write
module.workshop[13].null_resource.flannel (remote-exec): daemonset.apps/kube-flannel-ds created
2021-03-10T23:15:01.439-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] remote command exited with '0': /tmp/terraform_1221452065.sh
2021-03-10T23:15:01.439-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] opening new ssh session
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: state has changed since last snapshot, so incrementing serial to 3228
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: writing snapshot at terraform.tfstate
2021/03/10 23:15:01 [TRACE] vertex "module.workshop[13].null_resource.ssh_config[0]": visit complete
2021-03-10T23:15:01.517-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [ERROR] scp stderr: "Sink: C0644 0 terraform_1231042967.sh\n"
2021/03/10 23:15:01 [TRACE] EvalWriteState: recording 11 dependencies for module.workshop[13].null_resource.ssh_config[1]
2021/03/10 23:15:01 [TRACE] EvalWriteState: writing current state object for module.workshop[13].null_resource.ssh_config[1]
module.workshop[13].null_resource.ssh_config[1]: Creation complete after 4s [id=219189109435058608]
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: have already backed up original terraform.tfstate to terraform.tfstate.backup on a previous write
2021-03-10T23:15:01.532-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Starting remote scp process:  scp -vt /tmp
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: state has changed since last snapshot, so incrementing serial to 3229
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: writing snapshot at terraform.tfstate
2021/03/10 23:15:01 [TRACE] vertex "module.workshop[13].null_resource.ssh_config[1]": visit complete
2021-03-10T23:15:01.626-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Started SCP session, beginning transfers...
2021-03-10T23:15:01.627-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Copying input data into temporary file so we can read the length
2021-03-10T23:15:01.642-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Beginning file upload...
2021-03-10T23:15:01.737-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] SCP session complete, closing stdin pipe.
2021-03-10T23:15:01.737-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [DEBUG] Waiting for SSH session to complete.
2021-03-10T23:15:01.830-0800 [DEBUG] plugin.terraform: remote-exec-provisioner (internal) 2021/03/10 23:15:01 [ERROR] scp stderr: "Sink: C0644 0 terraform_1221452065.sh\n"
2021/03/10 23:15:01 [TRACE] EvalWriteState: recording 14 dependencies for module.workshop[13].null_resource.flannel
2021/03/10 23:15:01 [TRACE] EvalWriteState: writing current state object for module.workshop[13].null_resource.flannel
module.workshop[13].null_resource.flannel: Creation complete after 4s [id=3294301461130729364]
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: have already backed up original terraform.tfstate to terraform.tfstate.backup on a previous write
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: state has changed since last snapshot, so incrementing serial to 3230
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: writing snapshot at terraform.tfstate
2021/03/10 23:15:01 [TRACE] vertex "module.workshop[13].null_resource.flannel": visit complete
2021/03/10 23:15:01 [TRACE] dag/walk: upstream of "module.workshop (close)" errored, so skipping
2021/03/10 23:15:01 [TRACE] dag/walk: upstream of "output.instance_info" errored, so skipping
2021/03/10 23:15:01 [TRACE] dag/walk: upstream of "provisioner.remote-exec (close)" errored, so skipping
2021/03/10 23:15:01 [TRACE] dag/walk: upstream of "meta.count-boundary (EachMode fixup)" errored, so skipping
2021/03/10 23:15:01 [TRACE] dag/walk: upstream of "provider[\"registry.terraform.io/hashicorp/null\"] (close)" errored, so skipping
2021/03/10 23:15:01 [TRACE] dag/walk: upstream of "root" errored, so skipping
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: have already backed up original terraform.tfstate to terraform.tfstate.backup on a previous write
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: state has changed since last snapshot, so incrementing serial to 3231
2021/03/10 23:15:01 [TRACE] statemgr.Filesystem: writing snapshot at terraform.tfstate


Error: timeout - last error: dial tcp 3.23.129.42:22: i/o timeout


2021/03/10 23:15:02 [TRACE] statemgr.Filesystem: removing lock metadata file .terraform.tfstate.lock.info

Error: timeout - last error: dial tcp 3.21.169.60:22: i/o timeout



2021/03/10 23:15:02 [TRACE] statemgr.Filesystem: unlocking terraform.tfstate using fcntl flock
Error: timeout - last error: dial tcp 18.223.159.205:22: i/o timeout



Error: timeout - last error: dial tcp 3.14.68.232:22: i/o timeout



Error: timeout - last error: dial tcp 3.22.234.49:22: i/o timeout



Error: timeout - last error: dial tcp 18.219.78.121:22: i/o timeout



Error: timeout - last error: dial tcp 18.188.109.77:22: i/o timeout



Error: Error running command 'ssh -i id_rsa -q -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null ubuntu@3.14.229.149 'cd /home/ubuntu/ide && ((nohup yarn start /home/ubuntu/workshop --hostname 0.0.0.0 --port 3000 < /dev/null > std.out 2> std.err) & echo Theia IDE started.....)'': exit status 255. Output:



Error: timeout - last error: dial tcp 18.218.114.93:22: i/o timeout



Error: Error running command 'ssh -i id_rsa -q -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null ubuntu@3.142.170.162 'cd /home/ubuntu/ide && ((nohup yarn start /home/ubuntu/workshop --hostname 0.0.0.0 --port 3000 < /dev/null > std.out 2> std.err) & echo Theia IDE started.....)'': exit status 255. Output:



Error: timeout - last error: dial tcp 3.140.1.61:22: i/o timeout



Error: timeout - last error: dial tcp 52.15.126.236:22: i/o timeout



Error: timeout - last error: dial tcp 3.134.91.204:22: i/o timeout



Error: timeout - last error: dial tcp 3.135.206.107:22: i/o timeout



Error: timeout - last error: dial tcp 3.141.31.180:22: i/o timeout



Error: Error running command 'ssh -i id_rsa -q -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null ubuntu@3.128.210.59 'cd /home/ubuntu/ide && ((nohup yarn start /home/ubuntu/workshop --hostname 0.0.0.0 --port 3000 < /dev/null > std.out 2> std.err) & echo Theia IDE started.....)'': exit status 255. Output:



2021-03-10T23:15:02.023-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
Error: timeout - last error: dial tcp 18.188.57.187:22: i/o timeout



Error: timeout - last error: dial tcp 3.133.127.220:22: i/o timeout



Error: timeout - last error: dial tcp 3.142.186.20:22: i/o timeout



Error: timeout - last error: dial tcp 52.14.240.157:22: i/o timeout



Error: Error running command 'ssh -i id_rsa -q -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null ubuntu@18.225.18.192 'cd /home/ubuntu/ide && ((nohup yarn start /home/ubuntu/workshop --hostname 0.0.0.0 --port 3000 < /dev/null > std.out 2> std.err) & echo Theia IDE started.....)'': exit status 255. Output:



Error: timeout - last error: dial tcp 3.12.132.220:22: i/o timeout



Error: timeout - last error: dial tcp 13.59.136.137:22: i/o timeout



Error: Error running command 'ssh -i id_rsa -q -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null ubuntu@3.142.31.167 'cd /home/ubuntu/ide && ((nohup yarn start /home/ubuntu/workshop --hostname 0.0.0.0 --port 3000 < /dev/null > std.out 2> std.err) & echo Theia IDE started.....)'': exit status 255. Output:



Error: Error running command 'ssh -i id_rsa -q -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null ubuntu@3.139.134.238 'cd /home/ubuntu/ide && ((nohup yarn start /home/ubuntu/workshop --hostname 0.0.0.0 --port 3000 < /dev/null > std.out 2> std.err) & echo Theia IDE started.....)'': exit status 255. Output:


2021-03-10T23:15:02.025-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-10T23:15:02.026-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-10T23:15:02.026-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-10T23:15:02.034-0800 [DEBUG] plugin: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/aws/3.31.0/linux_amd64/terraform-provider-aws_v3.31.0_x5 pid=8408
2021-03-10T23:15:02.034-0800 [DEBUG] plugin: plugin exited
2021-03-10T23:15:02.034-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-10T23:15:02.034-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-10T23:15:02.039-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-10T23:15:02.039-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-10T23:15:02.039-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-10T23:15:02.040-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-10T23:15:02.040-0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-10T23:15:02.044-0800 [DEBUG] plugin: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.0/linux_amd64/terraform-provider-null_v3.1.0_x5 pid=8375
2021-03-10T23:15:02.046-0800 [DEBUG] plugin: plugin exited
2021-03-10T23:15:02.050-0800 [DEBUG] plugin: plugin process exited: path=/usr/bin/terraform pid=8214
2021-03-10T23:15:02.050-0800 [DEBUG] plugin: plugin exited
2021-03-10T23:15:02.059-0800 [DEBUG] plugin: plugin process exited: path=/usr/bin/terraform pid=8253
2021-03-10T23:15:02.059-0800 [DEBUG] plugin: plugin exited
2021-03-10T23:15:02.060-0800 [DEBUG] plugin: plugin process exited: path=/usr/bin/terraform pid=8167
2021-03-10T23:15:02.060-0800 [DEBUG] plugin: plugin exited
2021-03-10T23:15:02.062-0800 [DEBUG] plugin: plugin process exited: path=/usr/bin/terraform pid=8343
2021-03-10T23:15:02.062-0800 [DEBUG] plugin: plugin exited
2021-03-10T23:15:02.062-0800 [DEBUG] plugin: plugin process exited: path=/usr/bin/terraform pid=8394
2021-03-10T23:15:02.062-0800 [DEBUG] plugin: plugin exited
2021-03-10T23:15:02.064-0800 [DEBUG] plugin: plugin process exited: path=/usr/bin/terraform pid=8368
2021-03-10T23:15:02.064-0800 [DEBUG] plugin: plugin exited
2021-03-10T23:15:02.064-0800 [DEBUG] plugin: plugin process exited: path=/usr/bin/terraform pid=8193
2021-03-10T23:15:02.064-0800 [DEBUG] plugin: plugin exited
2021-03-10T23:15:02.066-0800 [DEBUG] plugin: plugin process exited: path=/usr/bin/terraform pid=8295
2021-03-10T23:15:02.066-0800 [DEBUG] plugin: plugin exited
2021-03-10T23:15:02.066-0800 [DEBUG] plugin: plugin process exited: path=/usr/bin/terraform pid=8277
2021-03-10T23:15:02.067-0800 [DEBUG] plugin: plugin exited

@johnbarney
Copy link
Contributor

johnbarney commented Mar 12, 2021 •
edited
Loading

I've also begun getting this issue on latest Terraform using the latest AWS plugin while running on Intel Mac. Only happening to some of my modules. As my modules depend on each other, the credentials, terminal session, env variables are identical. It happens across an assortment of AWS resources. I also find it interesting that the release and acquire lock steps succeed 100% of the time despite making DynamoDB calls that could in theory fail for the same reason.

Found this possible hint as well:

-----------------------------------------------------: timestamp=2021-03-12T14:40:49.043+0800
2021-03-12T14:40:49.043+0800 [INFO]  plugin.terraform-provider-aws_v3.32.0_x5: 2021/03/12 14:40:49 [DEBUG] [aws-sdk-go] {"TagList":[{"Key":"CostCenter","Value":"test"}]}: timestamp=2021-03-12T14:40:49.043+0800
2021/03/12 14:40:49 [TRACE] EvalWriteState: using RefreshState for aws_ssm_parameter.processor_zone_id
2021/03/12 14:40:49 [TRACE] EvalWriteState: recording 1 dependencies for aws_ssm_parameter.processor_zone_id
2021/03/12 14:40:49 [TRACE] EvalWriteState: writing current state object for aws_ssm_parameter.processor_zone_id
2021/03/12 14:40:49 [TRACE] Re-validating config for "aws_ssm_parameter.processor_zone_id"
2021/03/12 14:40:49 [TRACE] GRPCProvider: ValidateResourceTypeConfig
2021/03/12 14:40:49 [TRACE] GRPCProvider: PlanResourceChange
2021/03/12 14:40:49 [TRACE] EvalWriteState: writing current state object for aws_ssm_parameter.processor_zone_id
2021/03/12 14:40:49 [TRACE] EvalWriteDiff: recorded NoOp change for aws_ssm_parameter.processor_zone_id
2021/03/12 14:40:49 [TRACE] vertex "aws_ssm_parameter.processor_zone_id": visit complete
2021/03/12 14:40:49 [TRACE] vertex "aws_ssm_parameter.processor_zone_id": dynamic subgraph completed successfully
2021/03/12 14:40:49 [TRACE] vertex "aws_ssm_parameter.processor_zone_id": visit complete
2021/03/12 14:40:49 [TRACE] vertex "aws_ssm_parameter.processor_zone_id (expand)": dynamic subgraph completed successfully
2021/03/12 14:40:49 [TRACE] vertex "aws_ssm_parameter.processor_zone_id (expand)": visit complete
2021/03/12 14:40:49 [TRACE] dag/walk: visiting "provider[\"registry.terraform.io/hashicorp/aws\"] (close)"
2021/03/12 14:40:49 [TRACE] dag/walk: visiting "meta.count-boundary (EachMode fixup)"
2021/03/12 14:40:49 [TRACE] vertex "meta.count-boundary (EachMode fixup)": starting visit (*terraform.NodeCountBoundary)
2021/03/12 14:40:49 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/aws\"] (close)": starting visit (*terraform.graphNodeCloseProvider)
2021/03/12 14:40:49 [TRACE] GRPCProvider: Close
2021/03/12 14:40:49 [TRACE] vertex "meta.count-boundary (EachMode fixup)": visit complete
2021-03-12T14:40:49.047+0800 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-03-12T14:40:49.051+0800 [DEBUG] plugin: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/aws/3.32.0/darwin_amd64/terraform-provider-aws_v3.32.0_x5 pid=4458
2021-03-12T14:40:49.051+0800 [DEBUG] plugin: plugin exited
2021/03/12 14:40:49 [TRACE] vertex "provider[\"registry.terraform.io/hashicorp/aws\"] (close)": visit complete
2021/03/12 14:40:49 [TRACE] dag/walk: visiting "root"
2021/03/12 14:40:49 [TRACE] vertex "root": starting visit (*terraform.nodeCloseModule)
2021/03/12 14:40:49 [TRACE] vertex "root": visit complete
2021/03/12 14:40:49 [INFO] backend/local: plan operation completed

I've also seen TLS transport errors across several runs, though my current runs while filling out this post will not oblige with examples. Despite this being a WARN here, the run itself bails out with between 8 and 20 of these RPC errors reclassified as ERROR just as OP describes. I'm beginning to suspect this is an upstream change to Terraform itself. Possibly it's becoming less tolerant of legacy plugin code.

For example:

2021/03/12 14:53:57 [WARN] Provider "registry.terraform.io/hashicorp/aws" produced an invalid plan for aws_s3_bucket.img, but we are tolerating it because it is using the legacy plugin SDK.
    The following problems may be the cause of any confusing errors from downstream operations:
      - .versioning: block count in plan (1) disagrees with count in config (0)

Since this is my deep dive into Terraform trace in a while, I'm not sure how much noise like this is expected. Put since it's only happening in some of my modules I'm lead to assume state is somehow factoring in.

Lastly, this plan should include no changes to the resources themselves. The only changes have been to Terraform and AWS plugin versions. Rolling back to the versions used successfully does not seem to help. (0.14.5 and 3.25.0)

I hope these additional details help the team. Happy to also be a resource to provide and troubleshoot on this issue.

@cdimitroulas
Copy link

I encountered a similar error but it was related to this issue which is caused by a bug in the cloudflare provider version 2.19.1.

Pinning the cloudflare provider to 2.19.0 fixed the issue for me

@Kmaschta
Copy link

I can confirm, I needed to update Terraform from 0.12 to 0.14, and I had to rollback the Cloudflare plugin from 2.19.1 to 2.19.0, and it worked well.

The error message was related to an AWS EC2 instance, but it really was the Cloudflare plugin rollback that fixed the issue.
Thanks for the input @cdimitroulas!

@johnbarney
Copy link
Contributor

@cdimitroulas You are my hero mate. Hopefully this also addresses OP's concern.

@jmhale
Copy link
Contributor

jmhale commented Mar 13, 2021

Wow. I've been fighting this issue for days, undeploying my modules, one by one, hoping to find the problematic one, and it was Cloudflare the whole time. Pinning to 2.19.0 worked for me too. Thanks!!

@sumodirjo
Copy link
Contributor

I got a similar error message when deploying a lambda function. In my case the error happened due to my lambda name is longer than 64 characters [1]. After shortening my lambda function name the error disappears.

[1] https://docs.aws.amazon.com/AWSCloudFormation/latest/UserGuide/aws-resource-lambda-function.html#cfn-lambda-function-functionname

@mungojam
Copy link
Contributor

mungojam commented Sep 3, 2021

I just got this when it was trying to set an S3 bucket policy to one that was invalid because it had a zero length array of principals.

I was only able to work that out by setting TF_LOG to TRACE, otherwise I didn't get enough detail in the logs and it just kept going for ever.

      "Principal": {
        "AWS": []
      }

@AlexBurkey
Copy link

@luhhujbb Thank you for this. Rolling back the AWS provider version to 2.70 gave me much better log messages.

@Warns
Copy link

Warns commented Sep 15, 2021 •
edited
Loading

I seem to have the same issue using terraform >= 0.13.0 and aws provider >= 3.55.0

And all this is happening after Azure Pipeline says plan operation completed

2021-09-15T09:42:57.0708612Z 2021-09-15T09:41:51.538Z [INFO]  backend/local: plan operation completed
2021-09-15T09:42:57.0709052Z �[31m╷�[0m�[0m
2021-09-15T09:42:57.0709706Z �[31m│�[0m �[0m�[1m�[31mError: �[0m�[0m�[1mcommand "sh" produced invalid JSON: invalid character 'a' looking for beginning of value�[0m
2021-09-15T09:42:57.0710259Z �[31m│�[0m �[0m
2021-09-15T09:42:57.0710686Z �[31m│�[0m �[0m�[0m  with data.external.masterKey,
2021-09-15T09:42:57.0711245Z �[31m│�[0m �[0m  on data.tf line 47, in data "external" "masterKey":
2021-09-15T09:42:57.0711810Z �[31m│�[0m �[0m  47: data "external" "masterKey" �[4m{�[0m�[0m
2021-09-15T09:42:57.0712342Z �[31m│�[0m �[0m
2021-09-15T09:42:57.0712790Z �[31m╵�[0m�[0m
2021-09-15T09:42:57.0713494Z 2021-09-15T09:41:51.568Z [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-09-15T09:42:57.0714415Z 2021-09-15T09:41:51.569Z [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-09-15T09:42:57.0715394Z 2021-09-15T09:41:51.571Z [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/aws/3.55.0/linux_amd64/terraform-provider-aws_v3.55.0_x5 pid=3219
2021-09-15T09:42:57.0716133Z 2021-09-15T09:41:51.571Z [DEBUG] provider: plugin exited
2021-09-15T09:42:57.0717005Z 2021-09-15T09:41:51.571Z [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/external/2.1.0/linux_amd64/terraform-provider-external_v2.1.0_x5 pid=3204
2021-09-15T09:42:57.0717741Z 2021-09-15T09:41:51.571Z [DEBUG] provider: plugin exited
2021-09-15T09:42:57.0747819Z ##[error]Error: The process '/opt/hostedtoolcache/terraform/0.13.0/x64/terraform' failed with exit code 1
2021-09-15T09:42:57.0760388Z ##[section]Finishing: Terraform : plan

Edit: This error doesn't seem to break the terraform plan I had the other problem with data external changing sh to /bin/bash solved that JSON issue if anyone interested.

@breathingdust breathingdust added provider Pertains to the provider itself, rather than any interaction with AWS. and removed needs-triage Waiting for first response or review from a maintainer. labels Sep 16, 2021
@soumyadipDe
Copy link

Facing same issue on doing cdktf get,

2021-10-20T17:19:53.794+0100 [TRACE] GRPCProvider: GetProviderSchema
⠧ downloading and generating modules and providers...
2021-10-20T17:19:53.890+0100 [TRACE] GRPCProvider: Close
2021-10-20T17:19:53.891+0100 [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2021-10-20T17:19:53.892+0100 [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/aws/3.63.0/linux_amd64/terraform-provider-aws_v3.63.0_x5 pid=7564
2021-10-20T17:19:53.893+0100 [DEBUG] provider: plugin exited

I was following guide from https://learn.hashicorp.com/tutorials/terraform/cdktf-build-python?in=terraform/cdktf and it did not work for me.

terraform: v1.0.9
cdktf: 0.7.0
python: 3.8.5
os: Ubuntu 20.04.1LTS

@kksudo
Copy link

kksudo commented Nov 5, 2021

Exactly same issue as @soumyadipDe

@kksudo
Copy link

kksudo commented Nov 5, 2021

Switched back to the CKDTF@0.6.4 the issue solved

@CodebashingDevOps
Copy link

CodebashingDevOps commented Feb 9, 2022 •
edited
Loading

I am facing the same issue

Terraform Version

Terraform v0.12.29
+ provider.aws v3.9.0
+ provider.helm v2.1.1
+ provider.kubernetes v2.1.0
+ provider.local v2.1.0
+ provider.null v3.1.0
+ provider.random v3.1.0
+ provider.template v2.2.0

When running a terraform plan, it outputs:

Error: Your query returned no results. Please change your search criteria and try again.

Fails on the following request

2022-02-10T16:25:49.206+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: 2022/02/10 16:25:49 [DEBUG] [aws-sdk-go] <DescribeAutoScalingGroupsResponse xmlns="http://autoscaling.amazonaws.com/doc/2011-01-01/">
2022-02-10T16:25:49.206+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5:   <DescribeAutoScalingGroupsResult>
2022-02-10T16:25:49.206+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5:     <AutoScalingGroups>
2022-02-10T16:25:49.206+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5:       <member>
<xml-info>
......
.....

Error logs:

...
<xml-info>
...
2022-02-10T15:23:06.960+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5:     <RequestId>b69-447cffd8</RequestId>
2022-02-10T15:23:06.960+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5:   </ResponseMetadata>
2022-02-10T15:23:06.960+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: </DescribeAutoScalingGroupsResponse>
2022/02/10 15:23:06 [TRACE] module.bastion: eval: *terraform.EvalWriteState
2022/02/10 15:23:06 [TRACE] EvalWriteState: recording 3 dependencies for module.bastion.aws_autoscaling_group.bastion_auto_scaling_group
2022/02/10 15:23:06 [TRACE] EvalWriteState: writing current state object for module.bastion.aws_autoscaling_group.bastion_auto_scaling_group
2022/02/10 15:23:06 [TRACE] [walkRefresh] Exiting eval tree: module.bastion.aws_autoscaling_group.bastion_auto_scaling_group
2022/02/10 15:23:06 [TRACE] vertex "module.bastion.aws_autoscaling_group.bastion_auto_scaling_group": visit complete
2022/02/10 15:23:06 [TRACE] vertex "module.bastion.aws_autoscaling_group.bastion_auto_scaling_group": dynamic subgraph completed successfully
2022/02/10 15:23:06 [TRACE] vertex "module.bastion.aws_autoscaling_group.bastion_auto_scaling_group": visit complete
2022/02/10 15:23:06 [TRACE] dag/walk: upstream of "provider.aws (close)" errored, so skipping
2022/02/10 15:23:06 [TRACE] dag/walk: upstream of "root" errored, so skipping
2022-02-10T15:23:06.968+0200 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-02-10T15:23:06.968+0200 [WARN]  plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-02-10T15:23:06.971+0200 [DEBUG] plugin: plugin process exited: path=/ath-to-folder/.terraform/plugins/darwin_amd64/terraform-provider-random_v3.1.0_x5 pid=3726
2022-02-10T15:23:06.971+0200 [DEBUG] plugin: plugin exited
2022-02-10T15:23:07.017+0200 [DEBUG] plugin: plugin process exited: path=ath-to-folder/.terraform/plugins/darwin_amd64/terraform-provider-aws_v3.9.0_x5 pid=3727
2022-02-10T15:23:07.017+0200 [DEBUG] plugin: plugin exited


2022/02/09 13:22:57 [ERROR] AttachSchemaTransformer: No provider config schema available for provider.terraform
2022/02/09 13:23:00 [ERROR] AttachSchemaTransformer: No provider config schema available for provider.terraform
2022/02/09 13:23:03 [ERROR] module.eks: eval: *terraform.EvalReadData, err: Your query returned no results. Please change your search criteria and try again.
2022/02/09 13:23:03 [ERROR] module.eks: eval: *terraform.EvalSequence, err: Your query returned no results. Please change your search criteria and try again.

No modifications were made since the last successful apply.

Update: trying to running plan from old working branch, works, and where the master branch fails, this passes with the following error:

2022/02/10 16:25:49 [TRACE] vertex "module.bastion.aws_autoscaling_group.bastion_auto_scaling_group": visit complete
2022/02/10 16:25:49 [TRACE] vertex "module.bastion.aws_autoscaling_group.bastion_auto_scaling_group": dynamic subgraph completed successfully
2022/02/10 16:25:49 [TRACE] vertex "module.bastion.aws_autoscaling_group.bastion_auto_scaling_group": visit complete
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: 2022/02/10 16:25:49 [DEBUG] [aws-sdk-go] DEBUG: Response s3/GetBucketReplication Details:
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: ---[ RESPONSE ]--------------------------------------
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: HTTP/1.1 404 Not Found
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: Connection: close
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: Transfer-Encoding: chunked
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: Content-Type: application/xml
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: Date: Thu, 10 Feb 2022 14:25:47 GMT
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: Server: AmazonS3
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: X-Amz-Id-2: 8asdasdAg=
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: X-Amz-Request-Id: Dasdas6P
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5: 
2022-02-10T16:25:49.518+0200 [DEBUG] plugin.terraform-provider-aws_v3.9.0_x5:

@eschnou
Copy link

eschnou commented Mar 24, 2022 •
edited
Loading

Setting up this GODEBUG environment variable before launching terraform fixes it for me.

export GODEBUG=asyncpreemptoff=1;

Running Terraform 0.14.11

Terraform v0.14.11
+ provider registry.terraform.io/hashicorp/archive v2.2.0
+ provider registry.terraform.io/hashicorp/aws v3.72.0
+ provider registry.terraform.io/hashicorp/random v3.1.0
+ provider registry.terraform.io/hashicorp/template v2.2.0

@dipkoam
Copy link

dipkoam commented Apr 2, 2022

I the feeling that this could be related to the instance class that is being used. Increased my instance class from t2.micro to t3.small

@dipkoam
Copy link

dipkoam commented Apr 2, 2022

Also export GODEBUG=asyncpreemptoff=1; @eschnou suggestion helped

Setting up this GODEBUG environment variable before launching terraform fixes it for me.

export GODEBUG=asyncpreemptoff=1;

Running Terraform 0.14.11

Terraform v0.14.11
+ provider registry.terraform.io/hashicorp/archive v2.2.0
+ provider registry.terraform.io/hashicorp/aws v3.72.0
+ provider registry.terraform.io/hashicorp/random v3.1.0
+ provider registry.terraform.io/hashicorp/template v2.2.0

@ismail-traveloka
Copy link

Had this same issue today when I was trying to rename a CodeBuild project. Turns out the new name is just too long, solved the issue by using a shorter name. I know this might not be the cause of this issue for everyone, but just adding it here in case it'd help anyone.

I'm using:

Terraform v0.13.7
+ provider registry.terraform.io/hashicorp/aws v3.75.1
+ provider registry.terraform.io/hashicorp/random v2.3.1

@sara-hann
Copy link

I am getting this same issue.
$ terraform --version
Terraform v1.2.1
on linux_amd64

  • provider registry.terraform.io/hashicorp/aws v4.15.1
  • provider registry.terraform.io/hashicorp/local v2.2.3
  • provider registry.terraform.io/hashicorp/null v3.1.1
  • provider registry.terraform.io/hashicorp/random v3.2.0

I'm not using cloudflare.
Job actually seems to complete, from viewing the output, and I can access that the ansible playbooks were executed because I can hit the app they deployed on both instances. But the terraform gets to the very end and fails. Even when deploying with TF_LOG=DEBUG OS_DEBUG=true terraform apply the terraform.log just quits recording for the majority of the time the deployment runs, then records a few errors at the end - see the gap in the timestamps:

2022-05-31T22:02:03.798Z [DEBUG] opening new ssh session
2022-05-31T22:02:03.819Z [DEBUG] starting remote command: /tmp/terraform_882212444.sh
2022-05-31T22:02:04.346Z [DEBUG] remote command exited with '0': /tmp/terraform_882212444.sh
2022-05-31T22:02:04.346Z [DEBUG] opening new ssh session
2022-05-31T22:02:04.355Z [DEBUG] Starting remote scp process: 'scp' -vt /tmp
2022-05-31T22:02:04.399Z [DEBUG] Started SCP session, beginning transfers...
2022-05-31T22:02:04.399Z [DEBUG] Copying input data into temporary file so we can read the length
2022-05-31T22:02:04.400Z [DEBUG] Beginning file upload...
2022-05-31T22:02:04.653Z [DEBUG] SCP session complete, closing stdin pipe.
2022-05-31T22:02:04.653Z [DEBUG] Waiting for SSH session to complete.
2022-05-31T22:02:04.665Z [ERROR] scp stderr: "Sink: C0644 0 terraform_882212444.sh\n"
2022-05-31T22:03:15.271Z [WARN] Errors while provisioning null_resource.ExecuteAnsible[0] with "ocal-exec", so aborting
2022-05-31T22:03:15.275Z [ERROR] vertex "null_resource.ExecuteAnsible[0]" error: local-exec proviioner error
2022-05-31T22:03:15.275Z [ERROR] vertex "null_resource.ExecuteAnsible[0]" error: local-exec proviioner error
2022-05-31T22:09:59.841Z [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-05-31T22:09:59.842Z [DEBUG] provider: plugin process exited: path=.terraform/providers/registry.terraform.io/hashicorp/null/3.1.1/linux_amd64/terraform-provider-null_v3.1.1_x5 pid=8933
2022-05-31T22:09:59.842Z [DEBUG] provider: plugin exited

However, the app actually deploys correctly on both instances. I get the following, where you can see the execution on both instances was successful, then, instead of printing the outputs, it prints the null_resource local-exec error:
null_resource.ExecuteAnsible[1] (local-exec): PLAY RECAP *********************************************************************
null_resource.ExecuteAnsible[1] (local-exec): 3.83.34.169 : ok=51 changed=34 unreachable=0 failed=0 skipped=5 rescued=0 ignored=5
null_resource.ExecuteAnsible[1] (local-exec): 3.83.94.204 : ok=51 changed=34 unreachable=0 failed=0 skipped=5 rescued=0 ignored=5

null_resource.ExecuteAnsible[1]: Creation complete after 7m57s [id=7711336021038131401]
╷
│ Error: local-exec provisioner error
│
│ with null_resource.ExecuteAnsible[0],
│ on instances.tf line 226, in resource "null_resource" "ExecuteAnsible":
│ 226: provisioner "local-exec" {

@inviul
Copy link

inviul commented Jun 15, 2022

I am also getting same error while testing my brand new terraform-provider with resource.

@arunAtCSGI
Copy link

I'm also getting errors that look like it could be plugin related. Has anyone solved this issue? The biggest problem is that its so intermittent. Is there a way to change timeouts here? Timeouts is the only reason I can think of which would cause this issue intermittently.


  | 2022-06-17T10:19:40.410-0500 [DEBUG] plugin.terraform-provider-aws_v3.55.0_x5: plugin address: address=/tmp/plugin265376611 network=unix timestamp=2022-06-17T10:19:40.410-0500
-- | --
  | 2022-06-17T10:19:40.410-0500 [DEBUG] plugin: using plugin: version=5
  | 2022-06-17T10:19:40.475-0500 [INFO] plugin: configuring client automatic mTLS
  | 2022-06-17T10:19:40.501-0500 [DEBUG] plugin: starting plugin: path=/codebuild/output/src836329315/src/git-codecommit.us-east-1.amazonaws.com/v1/repos/dna-vic-build-bootstrap/stage1/.terraform/plugins/linux_amd64/terraform-provider-aws_v3.55.0_x5 args=[/codebuild/output/src836329315/src/git-codecommit.us-east-1.amazonaws.com/v1/repos/dna-vic-build-bootstrap/stage1/.terraform/plugins/linux_amd64/terraform-provider-aws_v3.55.0_x5]
  | 2022-06-17T10:19:40.501-0500 [DEBUG] plugin: plugin started: path=/codebuild/output/src836329315/src/git-codecommit.us-east-1.amazonaws.com/v1/repos/dna-vic-build-bootstrap/stage1/.terraform/plugins/linux_amd64/terraform-provider-aws_v3.55.0_x5 pid=796
  | 2022-06-17T10:19:40.501-0500 [DEBUG] plugin: waiting for RPC address: path=/codebuild/output/src836329315/src/git-codecommit.us-east-1.amazonaws.com/v1/repos/dna-vic-build-bootstrap/stage1/.terraform/plugins/linux_amd64/terraform-provider-aws_v3.55.0_x5
  | 2022-06-17T10:19:40.824-0500 [INFO] plugin.terraform-provider-aws_v3.55.0_x5: configuring server automatic mTLS: timestamp=2022-06-17T10:19:40.807-0500
  | 2022-06-17T10:19:40.982-0500 [DEBUG] plugin.terraform-provider-aws_v3.55.0_x5: plugin address: address=/tmp/plugin557394141 network=unix timestamp=2022-06-17T10:19:40.981-0500
  | 2022-06-17T10:19:40.982-0500 [DEBUG] plugin: using plugin: version=5
  | 2022-06-17T10:19:41.042-0500 [INFO] plugin: configuring client automatic mTLS
  | 2022-06-17T10:19:41.070-0500 [DEBUG] plugin: starting plugin: path=/codebuild/output/src836329315/src/git-codecommit.us-east-1.amazonaws.com/v1/repos/dna-vic-build-bootstrap/stage1/.terraform/plugins/linux_amd64/terraform-provider-aws_v3.55.0_x5 args=[/codebuild/output/src836329315/src/git-codecommit.us-east-1.amazonaws.com/v1/repos/dna-vic-build-bootstrap/stage1/.terraform/plugins/linux_amd64/terraform-provider-aws_v3.55.0_x5]
  | 2022-06-17T10:19:41.070-0500 [DEBUG] plugin: plugin started: path=/codebuild/output/src836329315/src/git-codecommit.us-east-1.amazonaws.com/v1/repos/dna-vic-build-bootstrap/stage1/.terraform/plugins/linux_amd64/terraform-provider-aws_v3.55.0_x5 pid=803
  | 2022-06-17T10:19:41.070-0500 [DEBUG] plugin: waiting for RPC address: path=/codebuild/output/src836329315/src/git-codecommit.us-east-1.amazonaws.com/v1/repos/dna-vic-build-bootstrap/stage1/.terraform/plugins/linux_amd64/terraform-provider-aws_v3.55.0_x5
  | 2022-06-17T10:19:41.684-0500 [INFO] plugin.terraform-provider-aws_v3.55.0_x5: configuring server automatic mTLS: timestamp=2022-06-17T10:19:41.675-0500
  | 2022-06-17T10:19:42.335-0500 [DEBUG] plugin.terraform-provider-aws_v3.55.0_x5: plugin address: address=/tmp/plugin543999105 network=unix timestamp=2022-06-17T10:19:42.304-0500
  | 2022-06-17T10:19:42.350-0500 [DEBUG] plugin: using plugin: version=5
  | 2022-06-17T10:19:50.094-0500 [DEBUG] plugin: plugin process exited: path=/codebuild/output/src836329315/src/git-codecommit.us-east-1.amazonaws.com/v1/repos/dna-vic-build-bootstrap/stage1/.terraform/plugins/linux_amd64/terraform-provider-aws_v3.55.0_x5 pid=531 error="signal: killed"
  | 2022-06-17T10:19:50.097-0500 [WARN] plugin.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"

<!--EndFragment-->
</body>
</html>

@gdavison
Copy link
Contributor

gdavison commented Aug 5, 2022

Hello all, for those of you encountering the error message err="rpc error: code = Unavailable desc = transport is closing", are you running Terraform on either Kubernetes or an M1 Mac?

In the Kubernetes case, the error is often associated with running out of memory.

On M1 Macs, it appears that there is an issue in Rosetta 2 (the system that allows running amd64 executables on arm64). See also https://yaleman.org/post/2021/2021-01-01-apple-m1-terraform-and-golang/. This can be resolved by setting the environment variable GODEBUG=asyncpreemptoff=1. This might also be resolved by ensuring that you are using an arm64-native version of Terraform and the AWS provider.

If you are encountering this error on platforms other than Kubernetes or M1 Macs, please include the output of terraform version, including the machine architecture.

@arunAtCSGI
Copy link

Hi @gdavison ,

I was encountering this on AWS CodeBuild. Like with Kubernetes, the issue was the build process was running out of memory. I increased the memory available and that resolved it.

Thanks for getting back to me anyway.

@k-yomo k-yomo mentioned this issue Aug 31, 2022
Closed
@pavelpp
Copy link

pavelpp commented Sep 2, 2022

in my case it was migration from one mac to another using Apple's Migration Assistant. The Assistant copied over all my files, including the terraform project and I had to delete its .terraform folder, then run terraform init and it worked like a charm.

@gdavison
Copy link
Contributor

gdavison commented Nov 1, 2022

I'm going to close this issue. Many of the older reports of this error have been resolved in the provider. I've created the pinned issue #27577 to highlight the M1 Mac and Kubernetes issues.

If you are still seeing this error after updating to the latest version of the provider, please open a separate issue

@agustinlare
Copy link

agustinlare commented Dec 2, 2022 •
edited
Loading

This problem presented to me out of the blue after working perfectly fine for a couple of hours and then... never worked again.

Using tf cloud in different workspaces, some with no new changes. To be honest I was assuming that something was change from the aws side since started to failed after 5 PM GMT-3 on december first like something was deprecated... but could not found anything about it...

Here are my logs and configuration if it helps:

terraform {
  required_providers {
    aws = {
      source  = "hashicorp/aws"
      version = "~> 3.63.0"
    }
    kubernetes = {
      source  = "hashicorp/kubernetes"
      version = "~> 1.13.4"
    }
  }
  required_version = "1.0.11"
}

provider "kubernetes" {
  host                   = module.eks_tools.cluster_endpoint
  token                  = module.eks_tools.cluster_token
  cluster_ca_certificate = base64decode(module.eks_tools.cluster_certificate_authority_data)
  exec {
    api_version = "client.authentication.k8s.io/v1alpha1"
    command     = "aws"
    args        = ["eks", "get-token", "--cluster-name", "REDACTED"]
  }
  load_config_file = false
}

Error: "https:/REDACTED/api/v1/namespaces/kube-system/configmaps/aws-auth": getting credentials: exec: executable aws failed with exit code 1

  with module.eks.module.eks.kubernetes_config_map.aws_auth[0],
  on .terraform/modules/eks.eks/aws_auth.tf line 63, in resource "kubernetes_config_map" "aws_auth":
  63: resource "kubernetes_config_map" "aws_auth"

2022-12-02T02:26:56.467Z [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-12-02T02:26:56.467Z [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-12-02T02:26:56.468Z [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-12-02T02:26:56.468Z [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-12-02T02:26:56.468Z [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"
2022-12-02T02:26:56.467Z [DEBUG] provider.stdio: received EOF, stopping recv loop: err="rpc error: code = Unavailable desc = transport is closing"

@arunAtCSGI
Copy link

@agustinlare : I would bet that you're running out of resources on whatever platform you're building on. Are you using Codebuild? If so, increase memory and CPU allocation and see if that helps.

@agustinlare
Copy link

@arunAtCSGI that would be a safe bet, had that issue before with codebuild. No this time tho... the problem was with the EKS module and failed almost instantly (which is was differente when was a resources issuese cause end it up timing out). This morning started working like if nothing happen changing absolutely nothing.
Please disregard my comment.

@arunAtCSGI
Copy link

Ah I see. Thanks for posting back though. This error seems to have many issues related to it

@breathingdust
Copy link
Member

As @gdavison mentioned earlier, closing this issue as many of the issues it encompasses have been resolved.

@R-leary R-leary mentioned this issue Jan 13, 2023
Open
@github-actions
Copy link

github-actions bot commented Feb 3, 2023

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 Feb 3, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
crash Results from or addresses a Terraform crash or kernel panic. provider Pertains to the provider itself, rather than any interaction with AWS.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests