I had a strange problem that night with actions stuck and doing nothing.
They have been killed after 6 hours. See log (TF_LOG=DEBUG) hereunder
The problem is transient (it works now) and related to AWS, although it worked well from my machine at the time of the problem.
The issue here is that the operation was not protected by any timeout, apart from the 6h timeout of github.
2019-10-28T22:22:04.9949049Z ##[group]Run hashicorp/terraform-github-actions/[email protected]
2019-10-28T22:22:04.9949218Z with:
2019-10-28T22:22:04.9949332Z args: -var-file=preproduction.tfvars -var-file=secrets.tfvars
2019-10-28T22:22:04.9949473Z env:
2019-10-28T22:22:04.9949594Z ENV: preproduction
2019-10-28T22:22:04.9949804Z GITHUB_TOKEN: ***
2019-10-28T22:22:04.9949933Z TF_ACTION_WORKING_DIR: ./infrastructure/terraform
2019-10-28T22:22:04.9950070Z TF_ACTION_WORKSPACE: preproduction
2019-10-28T22:22:04.9950391Z AWS_ACCESS_KEY_ID: ***
2019-10-28T22:22:04.9950540Z AWS_SECRET_ACCESS_KEY: ***
2019-10-28T22:22:04.9950667Z AWS_DEFAULT_REGION: eu-central-1
2019-10-28T22:22:04.9951066Z TF_LOG: DEBUG
2019-10-28T22:22:04.9951186Z ##[endgroup]
2019-10-28T22:22:04.9969617Z ##[command]/usr/bin/docker run --name dd9e73ee50f9da07654ff089797db44968ed00_438486 --label dd9e73 --workdir /github/workspace --rm -e ENV -e GITHUB_TOKEN -e TF_ACTION_WORKING_DIR -e TF_ACTION_WORKSPACE -e AWS_ACCESS_KEY_ID -e AWS_SECRET_ACCESS_KEY -e AWS_DEFAULT_REGION -e TF_LOG -e INPUT_ARGS -e HOME -e GITHUB_REF -e GITHUB_SHA -e GITHUB_REPOSITORY -e GITHUB_ACTOR -e GITHUB_WORKFLOW -e GITHUB_HEAD_REF -e GITHUB_BASE_REF -e GITHUB_EVENT_NAME -e GITHUB_WORKSPACE -e GITHUB_ACTION -e GITHUB_EVENT_PATH -e RUNNER_OS -e RUNNER_TOOL_CACHE -e RUNNER_TEMP -e RUNNER_WORKSPACE -e ACTIONS_RUNTIME_URL -e ACTIONS_RUNTIME_TOKEN -e GITHUB_ACTIONS=true -v "/var/run/docker.sock":"/var/run/docker.sock" -v "/home/runner/work/_temp/_github_home":"/github/home" -v "/home/runner/work/_temp/_github_workflow":"/github/workflow" -v "/home/runner/work/redacted-data/redacted-data":"/github/workspace" dd9e73:ee50f9da07654ff089797db44968ed00 -var-file=preproduction.tfvars -var-file=secrets.tfvars
2019-10-28T22:22:05.5523122Z 2019/10/28 22:22:05 [INFO] Terraform version: 0.12.12
2019-10-28T22:22:05.5528393Z 2019/10/28 22:22:05 [INFO] Go runtime version: go1.12.9
2019-10-28T22:22:05.5532140Z 2019/10/28 22:22:05 [INFO] CLI args: []string{"/bin/terraform", "workspace", "select", "preproduction"}
2019-10-28T22:22:05.5533430Z 2019/10/28 22:22:05 [DEBUG] Attempting to open CLI config file: /github/home/.terraformrc
2019-10-28T22:22:05.5534573Z 2019/10/28 22:22:05 [DEBUG] File doesn't exist, but doesn't need to. Ignoring.
2019-10-28T22:22:05.5538337Z 2019/10/28 22:22:05 [INFO] CLI command args: []string{"workspace", "select", "preproduction"}
2019-10-28T22:22:05.5599029Z 2019/10/28 22:22:05 [INFO] Setting AWS metadata API timeout to 100ms
2019-10-28T22:22:05.5638849Z 2019/10/28 22:22:05 [INFO] Ignoring AWS metadata API endpoint at default location as it doesn't return any instance-id
2019-10-28T22:22:05.5639134Z 2019/10/28 22:22:05 [INFO] AWS Auth provider used: "EnvProvider"
2019-10-28T22:22:05.5639316Z 2019/10/28 22:22:05 [DEBUG] Trying to get account information via sts:GetCallerIdentity
2019-10-28T22:22:05.5639769Z 2019/10/28 22:22:05 [DEBUG] [aws-sdk-go] DEBUG: Request sts/GetCallerIdentity Details:
2019-10-28T22:22:05.5640164Z ---[ REQUEST POST-SIGN ]-----------------------------
2019-10-28T22:22:05.5640319Z POST / HTTP/1.1
2019-10-28T22:22:05.5640414Z Host: sts.amazonaws.com
2019-10-28T22:22:05.5641123Z User-Agent: aws-sdk-go/1.25.3 (go1.12.9; linux; amd64) APN/1.0 HashiCorp/1.0 Terraform/0.12.12
2019-10-28T22:22:05.5641882Z Content-Length: 43
2019-10-28T22:22:05.5642668Z Authorization: AWS4-HMAC-SHA256 Credential=***/20191028/us-east-1/sts/aws4_request, SignedHeaders=content-length;content-type;host;x-amz-date, Signature=5fdca80c13478fc788a61b38caf5b9d6f27d303877f3e4993874abe89e6befde
2019-10-28T22:22:05.5643170Z Content-Type: application/x-www-form-urlencoded; charset=utf-8
2019-10-28T22:22:05.5643540Z X-Amz-Date: 20191028T222205Z
2019-10-28T22:22:05.5643850Z Accept-Encoding: gzip
2019-10-28T22:22:05.5643958Z
2019-10-28T22:22:05.5644320Z Action=GetCallerIdentity&Version=2011-06-15
2019-10-28T22:22:05.5644669Z -----------------------------------------------------
2019-10-28T22:22:05.6491703Z 2019/10/28 22:22:05 [DEBUG] [aws-sdk-go] DEBUG: Response sts/GetCallerIdentity Details:
2019-10-28T22:22:05.6492390Z ---[ RESPONSE ]--------------------------------------
2019-10-28T22:22:05.6492514Z HTTP/1.1 200 OK
2019-10-28T22:22:05.6492652Z Connection: close
2019-10-28T22:22:05.6492971Z Content-Length: 410
2019-10-28T22:22:05.6493288Z Content-Type: text/xml
2019-10-28T22:22:05.6493436Z Date: Mon, 28 Oct 2019 22:22:05 GMT
2019-10-28T22:22:05.6493825Z X-Amzn-Requestid: 5f749ea8-f9d1-11e9-9846-6b491b476e14
2019-10-28T22:22:05.6493900Z
2019-10-28T22:22:05.6493995Z
2019-10-28T22:22:05.6494333Z -----------------------------------------------------
2019-10-28T22:22:05.6495086Z 2019/10/28 22:22:05 [DEBUG] [aws-sdk-go] <GetCallerIdentityResponse xmlns="https://sts.amazonaws.com/doc/2011-06-15/">
2019-10-28T22:22:05.6495261Z <GetCallerIdentityResult>
2019-10-28T22:22:05.6495898Z <Arn>arn:aws:iam::redacted:user/github-action</Arn>
2019-10-28T22:22:05.6496066Z <UserId>redacted</UserId>
2019-10-28T22:22:05.6496215Z <Account>redacted</Account>
2019-10-28T22:22:05.6496371Z </GetCallerIdentityResult>
2019-10-28T22:22:05.6496510Z <ResponseMetadata>
2019-10-28T22:22:05.6496890Z <RequestId>5f749ea8-f9d1-11e9-9846-6b491b476e14</RequestId>
2019-10-28T22:22:05.6497048Z </ResponseMetadata>
2019-10-28T22:22:05.6497188Z </GetCallerIdentityResponse>
2019-10-28T22:22:05.6500411Z 2019/10/28 22:22:05 [DEBUG] checking for provider in "."
2019-10-28T22:22:05.6519572Z 2019/10/28 22:22:05 [DEBUG] checking for provider in "/bin"
2019-10-28T22:22:05.6525514Z 2019/10/28 22:22:05 [DEBUG] checking for provider in ".terraform/plugins/linux_amd64"
2019-10-28T22:22:05.6529582Z 2019/10/28 22:22:05 [DEBUG] found provider "terraform-provider-aws_v2.33.0_x4"
2019-10-28T22:22:05.6531903Z 2019/10/28 22:22:05 [DEBUG] found provider "terraform-provider-postgresql_v1.2.0_x4"
2019-10-28T22:22:05.6532358Z 2019/10/28 22:22:05 [DEBUG] found provider "terraform-provider-rancher2_v1.6.0_x4"
2019-10-28T22:22:05.6536588Z 2019/10/28 22:22:05 [DEBUG] found valid plugin: "aws", "2.33.0", "/github/workspace/infrastructure/terraform/.terraform/plugins/linux_amd64/terraform-provider-aws_v2.33.0_x4"
2019-10-28T22:22:05.6537280Z 2019/10/28 22:22:05 [DEBUG] found valid plugin: "postgresql", "1.2.0", "/github/workspace/infrastructure/terraform/.terraform/plugins/linux_amd64/terraform-provider-postgresql_v1.2.0_x4"
2019-10-28T22:22:05.6539149Z 2019/10/28 22:22:05 [DEBUG] found valid plugin: "rancher2", "1.6.0", "/github/workspace/infrastructure/terraform/.terraform/plugins/linux_amd64/terraform-provider-rancher2_v1.6.0_x4"
2019-10-28T22:22:05.6542910Z 2019/10/28 22:22:05 [DEBUG] checking for provisioner in "."
2019-10-28T22:22:05.6549064Z 2019/10/28 22:22:05 [DEBUG] checking for provisioner in "/bin"
2019-10-28T22:22:05.6554360Z 2019/10/28 22:22:05 [DEBUG] checking for provisioner in ".terraform/plugins/linux_amd64"
2019-10-28T22:22:05.6577981Z 2019/10/28 22:22:05 [DEBUG] [aws-sdk-go] DEBUG: Request s3/ListObjects Details:
2019-10-28T22:22:05.6578432Z ---[ REQUEST POST-SIGN ]-----------------------------
2019-10-28T22:22:05.6578616Z GET /?prefix=env%3A%2F HTTP/1.1
2019-10-28T22:22:05.6578986Z Host: redacted-terraform-state.s3.eu-central-1.amazonaws.com
2019-10-28T22:22:05.6579410Z User-Agent: aws-sdk-go/1.25.3 (go1.12.9; linux; amd64) APN/1.0 HashiCorp/1.0 Terraform/0.12.12
2019-10-28T22:22:05.6580243Z Authorization: AWS4-HMAC-SHA256 Credential=***/20191028/eu-central-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=0d01e1fe5e064f27654fd5eb1d5924ff6d81f01cda5c443b0c26733f17fdbcfb
2019-10-28T22:22:05.6581258Z X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2019-10-28T22:22:05.6581655Z X-Amz-Date: 20191028T222205Z
2019-10-28T22:22:05.6582564Z Accept-Encoding: gzip
2019-10-28T22:22:05.6582636Z
2019-10-28T22:22:05.6582731Z
2019-10-28T22:22:05.6583106Z -----------------------------------------------------
2019-10-28T22:22:06.0426832Z 2019/10/28 22:22:06 [DEBUG] [aws-sdk-go] DEBUG: Response s3/ListObjects Details:
2019-10-28T22:22:06.0427705Z ---[ RESPONSE ]--------------------------------------
2019-10-28T22:22:06.0427914Z HTTP/1.1 200 OK
2019-10-28T22:22:06.0428569Z Connection: close
2019-10-28T22:22:06.0429632Z Transfer-Encoding: chunked
2019-10-28T22:22:06.0430218Z Content-Type: application/xml
2019-10-28T22:22:06.0430331Z Date: Mon, 28 Oct 2019 22:22:06 GMT
2019-10-28T22:22:06.0430475Z Server: AmazonS3
2019-10-28T22:22:06.0431050Z X-Amz-Bucket-Region: eu-central-1
2019-10-28T22:22:06.0431639Z X-Amz-Id-2: RbYvrJI+E/eEueCsG29/QUemM5PqjTlpqV679xdow7qjYyR9Q+3toGLmJja5Q/a4Wf7ItocVhaw=
2019-10-28T22:22:06.0432447Z X-Amz-Request-Id: 14FBDDB88993EF40
2019-10-28T22:22:06.0432585Z
2019-10-28T22:22:06.0432634Z
2019-10-28T22:22:06.0433024Z -----------------------------------------------------
2019-10-28T22:22:06.0433648Z 2019/10/28 22:22:06 [DEBUG] [aws-sdk-go] <?xml version="1.0" encoding="UTF-8"?>
2019-10-28T22:22:06.0435682Z <ListBucketResult xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Name>redacted-terraform-state</Name><Prefix>env:/</Prefix><Marker></Marker><MaxKeys>1000</MaxKeys><IsTruncated>false</IsTruncated><Contents><Key>env:/preproduction/analytics.tfstate</Key><LastModified>2019-10-28T21:38:09.000Z</LastModified><ETag>"5af58da12a6d5c237799a733b8db868c"</ETag><Size>26847</Size><StorageClass>STANDARD</StorageClass></Contents><Contents><Key>env:/production/analytics.tfstate</Key><LastModified>2019-10-08T13:46:47.000Z</LastModified><ETag>"21a5a80d3472d78a7c68a42fd89eb251"</ETag><Size>7629</Size><StorageClass>STANDARD</StorageClass></Contents></ListBucketResult>
2019-10-29T04:20:49.4837055Z ##[error]The runner has received a shutdown signal. This can happen when the runner service is stopped, or a manually started runner is canceled.
2019-10-29T04:20:59.5262837Z ##[error]The operation was canceled.