search

gruntwork-io / terratest

Terratest is a Go library that makes it easier to write automated tests for your infrastructure code.
https://terratest.gruntwork.io/
Apache License 2.0
7.5k stars 1.32k forks source link

Terraform Apply hang unresponsive #145

Closed wutianchen closed 4 years ago

wutianchen commented 6 years ago

Terraform Project Structure:

-- terraform-root
---- main.tf
---- variables.tf
---- outputs.tf
---- test/
-------- basic_test.go
---- examples/
-------- elasticsearch-auth-iam-user/main.tf

my basic_test.go looks like the following

package test

import (
    "fmt"
    "testing"
    "github.com/gruntwork-io/terratest/modules/terraform"
)

func TestTerraformBasicExample(t *testing.T) {

    terraformOptions := &terraform.Options{
        TerraformDir: "../ examples/elasticsearch-auth-iam-user",

        Vars: map[string]interface{}{
                        "domain_name": "test",
                        "stack": "elasticsearch",
                        "workspace": "stg",
        },
    }

    defer terraform.Destroy(t, terraformOptions)
    terraform.InitAndApply(t, terraformOptions)
}

cd into test run "go test -timeout 5m".

I get "terraform init" succeeded but "terraform apply" hanged without any outputs until timing out.

Log looks like

[ec2-user@ip-10-104-88-81 test]$ go test -timeout 5m
init...................TestTerraformBasicExample 2018-08-20T10:37:20Z retry.go:69: Running terraform [init -upgrade=false]
TestTerraformBasicExample 2018-08-20T10:37:20Z command.go:52: Running command terraform with args [init -upgrade=false]
TestTerraformBasicExample 2018-08-20T10:37:20Z command.go:96: Initializing modules...
TestTerraformBasicExample 2018-08-20T10:37:20Z command.go:96: - module.elasticsearch_security_group
TestTerraformBasicExample 2018-08-20T10:37:20Z command.go:96:   Getting source "git::ssh://git@ssh.git.domain/iot-infrastructure/tf-module-aws-security-group.git?ref=master"
TestTerraformBasicExample 2018-08-20T10:37:21Z command.go:96:
TestTerraformBasicExample 2018-08-20T10:37:21Z command.go:96: Initializing provider plugins...
TestTerraformBasicExample 2018-08-20T10:37:21Z command.go:96: - Checking for available provider plugins on https://releases.hashicorp.com...
TestTerraformBasicExample 2018-08-20T10:37:21Z command.go:96: - Downloading plugin for provider "aws" (1.32.0)...
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96:
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: The following providers do not have any version constraints in configuration,
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: so the latest version was installed.
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96:
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: To prevent automatic upgrades to new major versions that may contain breaking
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: changes, it is recommended to add version = "..." constraints to the
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: corresponding provider blocks in configuration, with the constraint strings
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: suggested below.
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96:
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: * provider.aws: version = "~> 1.32"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96:
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: Terraform has been successfully initialized!
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96:
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: You may now begin working with Terraform. Try running "terraform plan" to see
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: any changes that are required for your infrastructure. All Terraform commands
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: should now work.
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96:
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: If you ever set or change modules or backend configuration for Terraform,
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: rerun this command to reinitialize your working directory. If you forget, other
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:96: commands will detect it and remind you to do so if necessary.
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:20 [INFO] Terraform version: 0.11.7  41e50bd32a8825a84535e353c3674af8ce799161
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:20 [INFO] Go runtime version: go1.10.1
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:20 [INFO] CLI args: []string{"/usr/local/bin/terraform", "init", "-upgrade=false"}
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:20 [DEBUG] Attempting to open CLI config file: /home/ec2-user/.terraformrc
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:20 [DEBUG] File doesn't exist, but doesn't need to. Ignoring.
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:20 [INFO] CLI command args: []string{"init", "-upgrade=false"}
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:20 [DEBUG] command: loading backend config file: /home/ec2-user/go/src/tf-module-aws-elasticsearch
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:20 [ERR] Checkpoint error: Get https://checkpoint-api.hashicorp.com/v1/check/terraform?arch=386&os=linux&signature=1876a657-05db-8573-ee03-ee17a78287f6&version=0.11.7: Forbidden
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] found "git::ssh://git@ssh.git.tech.rz.db.de/iot-infrastructure/tf-module-aws-security-group.git?ref=master" in ".terraform/modules/30207133dde280c8832b06615f77d133": true
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [TRACE] "git::ssh://git@ssh.git.tech.rz.db.de/iot-infrastructure/tf-module-aws-security-group.git?ref=master" stored in ".terraform/modules/30207133dde280c8832b06615f77d133"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [INFO] command: empty terraform config, returning nil
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] command: no data state file found for backend config
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] New state was assigned lineage "33329760-d197-8ad8-7d93-841dc70d9b45"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [INFO] command: backend initialized: <nil>
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] checking for provider in "."
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] checking for provider in "/usr/local/bin"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] checking for provisioner in "."
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] checking for provisioner in "/usr/local/bin"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [INFO] Failed to read plugin lock file .terraform/plugins/linux_386/lock.json: open .terraform/plugins/linux_386/lock.json: no such file or directory
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [INFO] command: backend <nil> is not enhanced, wrapping in local
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] checking for provider in "."
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] checking for provider in "/usr/local/bin"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] plugin requirements: "aws"=""
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] fetching provider info for aws version 1.32.0
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] getting provider "aws" version "1.32.0"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:21 [DEBUG] plugin cache is disabled, so downloading aws 1.32.0 from https://releases.hashicorp.com/terraform-provider-aws/1.32.0/terraform-provider-aws_1.32.0_linux_386.zip?checksum=sha256:b9b35d1040c7d764e7dc0a1083826f8d9b63f49f46a53ee521c6c6c138130d64
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:22 [DEBUG] looking for the aws 1.32.0 plugin we just installed
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:22 [DEBUG] checking for provider in ".terraform/plugins/linux_386"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:22 [DEBUG] found provider "terraform-provider-aws_v1.32.0_x4"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:22 [DEBUG] all plugins found discovery.PluginMetaSet{discovery.PluginMeta{Name:"aws", Version:"1.32.0", Path:"/home/ec2-user/go/src/tf-module-aws-elasticsearch/.terraform/plugins/linux_386/terraform-provider-aws_v1.32.0_x4"}:struct {}{}}
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:22 [DEBUG] filtered plugins discovery.PluginMetaSet{discovery.PluginMeta{Name:"aws", Version:"1.32.0", Path:"/home/ec2-user/go/src/tf-module-aws-elasticsearch/.terraform/plugins/linux_386/terraform-provider-aws_v1.32.0_x4"}:struct {}{}}
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:22 [DEBUG] checking for provider in "."
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:22 [DEBUG] checking for provider in "/usr/local/bin"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:22 [DEBUG] checking for provider in ".terraform/plugins/linux_386"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:22 [DEBUG] found provider "terraform-provider-aws_v1.32.0_x4"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:22 [DEBUG] found valid plugin: "aws", "1.32.0", "/home/ec2-user/go/src/tf-module-aws-elasticsearch/.terraform/plugins/linux_386/terraform-provider-aws_v1.32.0_x4"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:23 [DEBUG] checking for provider in ".terraform/plugins/linux_386"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:23 [DEBUG] found provider "terraform-provider-aws_v1.32.0_x4"
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:100: 2018/08/20 10:37:23 [DEBUG] plugin: waiting for all plugin processes to complete...
apply...................TestTerraformBasicExample 2018-08-20T10:37:23Z retry.go:69: Running terraform [apply -input=false -lock=false -auto-approve -var access_policies="a" -var domain_name="test" -var stack="elasticsearch" -var workspace="stg"]
TestTerraformBasicExample 2018-08-20T10:37:23Z command.go:52: Running command terraform with args [apply -input=false -lock=false -auto-approve -var access_policies="a" -var domain_name="test" -var stack="elasticsearch" -var workspace="stg"]

main.tf looks like

# If comment out this module usage, terratest works
/*
module "elasticsearch_security_group" {
  source = "git::ssh://git@ssh.git.domain/iot-infrastructure/tf-module-aws-security-group.git?ref=master"
  name = "elasticsearch_security_group"
  vpc_id = "${var.vpc_id}"
  ingress_cidr_blocks = ["0.0.0.0/0"]
}
*/
resource "aws_elasticsearch_domain" "es_test" {
  domain_name           = "test"

  cluster_config {
    instance_type = "r3.large.elasticsearch"
    instance_count = "1"
    dedicated_master_enabled = "false"
    zone_awareness_enabled = "false"
  }
}

# meta parameters for module

variable "vpc_id" {
  type = "string"
  default = "vpc-42f2792a"
}

# Provider
provider "aws" {
  region = "eu-central-1"
}

If I comment module "elasticsearch_security_group" out. It works. Can it possible terratest has problem with module ?

brikis98 commented 6 years ago

TerraformDir: "../ examples/elasticsearch-auth-iam-user",

I'm not sure why it hangs, but is the space after ../ intentional?

wutianchen commented 6 years ago

Hi @brikis98 , thanks for the reply. I have spent another several hours trying to debug ...

found out TerraformDir is not the reason. (updated my question)

If I call module it hangs !

brikis98 commented 6 years ago

Ah, I see.

If you try to use that module with just plain old terraform instead of terragrunt, what happens?

source = "git::ssh://git@ssh.git.domain/iot-infrastructure/tf-module-aws-security-group.git?ref=master"

My best guess is you don't have ssh-agent set up and you are being prompted (interactively) for an SSH key password.

wutianchen commented 6 years ago

@brikis98 ,

thanks for the reply.

If you try to use that module with just plain old terraform instead of terragrunt, what happens?

If I do not use terratest, it works.

My best guess is you don't have ssh-agent set up and you are being prompted (interactively) for an SSH key password.

ssh is set. In outputed logs, "git clone" succeeded. But "terraform apply" failed.

wutianchen commented 6 years ago

@brikis98 highly suspect there is a bug in terratest/modules/shell/command.go RunCommandAndGetOutputE function. It works to some degree if I substitute it with

func RunCommandAndGetOutputE(t *testing.T, command Command) (string, error) {
        logger.Logf(t, "Running command %s with args %s", command.Command, command.Args)

        cmd := exec.Command(command.Command, command.Args...)
        cmd.Dir = command.WorkingDir
        cmd.Stdin = os.Stdin
        cmd.Env = formatEnvVars(command)
        cmd.CombinedOutput()
        /*
        stdout, err := cmd.StdoutPipe()
        if err != nil {
                return "", err
        }

        stderr, err := cmd.StderrPipe()
        if err != nil {
                return "", err
        }

        err = cmd.Start()
        if err != nil {
                return "", err
        }

        output, err := readStdoutAndStderr(t, stdout, stderr)
        if err != nil {
                return output, err
        }

        if err := cmd.Wait(); err != nil {
                return output, err
        }
        */
        return "nil",nil
        //return output, nil
brikis98 commented 6 years ago

We've used the shell package extensively for years, and it works with many use cases, so the key is to figure out what's different about yours! Do the tests in the test folder of this repo (terratest itself) work for you?

wutianchen commented 6 years ago

@brikis98 thanks for the comment. understood. "tests in the original terratest test folder" doesn't work either

I have pinned down the exact location of my problem. It is in command.go readStdoutAndStderr func.

stdoutScanner.Scan() hangs without any output

brikis98 commented 6 years ago

What version of Go are you using? What OS? Can you hook up a debugger to figure out where it's hanging?

wutianchen commented 6 years ago

@brikis98

in Scan() function, it hangs

(dlv) s
> bufio.(*Scanner).Scan() /usr/lib/golang/src/bufio/scan.go:207 (PC: 0x51c836)
   202:                 }
   203:                 // Finally we can read some input. Make sure we don't get stuck with
   204:                 // a misbehaving Reader. Officially we don't need to do this, but let's
   205:                 // be extra careful: Scanner is for safe, simple jobs.
   206:                 for loop := 0; ; {
=> 207:                         n, err := s.r.Read(s.buf[s.end:len(s.buf)])
   208:                         s.end += n
   209:                         if err != nil {
   210:                                 s.setErr(err)
   211:                                 break
   212:                         }

more in details, it hangs when I try to stepout this

> internal/poll.(*FD).Read() /usr/lib/golang/src/internal/poll/fd_unix.go:122 (PC: 0x483cbc)
Values returned:

   117:         }
   118:         if fd.IsStream && len(p) > maxRW {
   119:                 p = p[:maxRW]
   120:         }
   121:         for {
=> 122:                 n, err := syscall.Read(fd.Sysfd, p)
   123:                 if err != nil {
   124:                         n = 0
   125:                         if err == syscall.EAGAIN && fd.pd.pollable() {
   126:                                 if err = fd.pd.waitRead(fd.isFile); err == nil {
   127:                                         continue
(dlv) stepout

go version: go1.9.4 linux/amd64 on aws ami

brikis98 commented 6 years ago

That's... really weird. I can't think of what would cause that. Are you doing anything odd with stdin/stdout? Some kind of custom shell?

wutianchen commented 6 years ago

@brikis98 I have tested lots of possibilities. The situation is that we have a company VPC.

It works outside of VPC. It hangs inside of VPC (proxy is set).

But I failed to understand why VPC has influence on stdin, Scan() function

brikis98 commented 6 years ago

Oh... Are you saying the tests are running within a VPC? If so, do you have outbound Internet access? Is there some firewall or permissions preventing Terratest from calling Terraform? Perhaps SELinux or similar?

wutianchen commented 6 years ago

@brikis98

Are you saying the tests are running within a VPC? If so, do you have outbound Internet access?

you are right. The tests are running within a VPC and it can only access internet through a proxy setting.

Perhaps SELinux or similar?

I am using "Amazon Linux 2 AMI" and SELinux is disabled

Is there some firewall or permissions preventing Terratest from calling Terraform?

I am checking that ! But why would firewall preventing Terratest from calling Terraform binary ?

error output:

TestTerraformAwsExample 2018-08-29T07:41:12Z region.go:72: Looking up all AWS regions available in this account
TestTerraformAwsExample 2018-08-29T07:41:13Z region.go:57: Using region us-west-2
TestTerraformAwsExample 2018-08-29T07:41:13Z retry.go:69: Running terraform [init -upgrade=false]
TestTerraformAwsExample 2018-08-29T07:41:13Z command.go:52: Running command terraform with args [init -upgrade=false]
TestTerraformAwsExample 2018-08-29T07:41:13Z command.go:96:
TestTerraformAwsExample 2018-08-29T07:41:13Z command.go:96: Initializing provider plugins...
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96:
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: The following providers do not have any version constraints in configuration,
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: so the latest version was installed.
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96:
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: To prevent automatic upgrades to new major versions that may contain breaking
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: changes, it is recommended to add version = "..." constraints to the
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: corresponding provider blocks in configuration, with the constraint strings
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: suggested below.
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96:
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: * provider.aws: version = "~> 1.33"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96:
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: Terraform has been successfully initialized!
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96:
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: You may now begin working with Terraform. Try running "terraform plan" to see
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: any changes that are required for your infrastructure. All Terraform commands
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: should now work.
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96:
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: If you ever set or change modules or backend configuration for Terraform,
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: rerun this command to reinitialize your working directory. If you forget, other
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:96: commands will detect it and remind you to do so if necessary.
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [INFO] Terraform version: 0.11.7  41e50bd32a8825a84535e353c3674af8ce799161
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [INFO] Go runtime version: go1.10.1
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [INFO] CLI args: []string{"/usr/local/bin/terraform", "init", "-upgrade=false"}
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] Attempting to open CLI config file: /home/ec2-user/.terraformrc
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] File doesn't exist, but doesn't need to. Ignoring.
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [INFO] CLI command args: []string{"init", "-upgrade=false"}
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] command: loading backend config file: /home/ec2-user/go/src/github.com/gruntwork-io/terratest/examples/terraform-aws-example
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [INFO] command: empty terraform config, returning nil
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] command: no data state file found for backend config
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] New state was assigned lineage "c62c2e75-5722-b77e-056c-8ad83e9b3c7a"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [INFO] command: backend initialized: <nil>
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provider in "."
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provider in "/usr/local/bin"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provider in ".terraform/plugins/linux_386"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] found provider "terraform-provider-aws_v1.33.0_x4"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] found valid plugin: "aws", "1.33.0", "/home/ec2-user/go/src/github.com/gruntwork-io/terratest/examples/terraform-aws-example/.terraform/plugins/linux_386/terraform-provider-aws_v1.33.0_x4"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provisioner in "."
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provisioner in "/usr/local/bin"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provisioner in ".terraform/plugins/linux_386"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [INFO] command: backend <nil> is not enhanced, wrapping in local
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provider in "."
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provider in "/usr/local/bin"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provider in ".terraform/plugins/linux_386"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] found provider "terraform-provider-aws_v1.33.0_x4"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] found valid plugin: "aws", "1.33.0", "/home/ec2-user/go/src/github.com/gruntwork-io/terratest/examples/terraform-aws-example/.terraform/plugins/linux_386/terraform-provider-aws_v1.33.0_x4"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] plugin requirements: "aws"=""
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provider in "."
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provider in "/usr/local/bin"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] checking for provider in ".terraform/plugins/linux_386"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] found provider "terraform-provider-aws_v1.33.0_x4"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [DEBUG] found valid plugin: "aws", "1.33.0", "/home/ec2-user/go/src/github.com/gruntwork-io/terratest/examples/terraform-aws-example/.terraform/plugins/linux_386/terraform-provider-aws_v1.33.0_x4"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:13 [ERR] Checkpoint error: Get https://checkpoint-api.hashicorp.com/v1/check/terraform?arch=386&os=linux&signature=7b4cf686-3821-e2e1-4086-092501895fd9&version=0.11.7: Forbidden
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:14 [DEBUG] checking for provider in ".terraform/plugins/linux_386"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:14 [DEBUG] found provider "terraform-provider-aws_v1.33.0_x4"
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:14 [DEBUG] plugin: waiting for all plugin processes to complete...
TestTerraformAwsExample 2018-08-29T07:41:14Z retry.go:69: Running terraform [get -update]
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:52: Running command terraform with args [get -update]
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:14 [INFO] Terraform version: 0.11.7  41e50bd32a8825a84535e353c3674af8ce799161
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:14 [INFO] Go runtime version: go1.10.1
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:14 [INFO] CLI args: []string{"/usr/local/bin/terraform", "get", "-update"}
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:14 [DEBUG] Attempting to open CLI config file: /home/ec2-user/.terraformrc
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:14 [DEBUG] File doesn't exist, but doesn't need to. Ignoring.
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:14 [INFO] CLI command args: []string{"get", "-update"}
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:100: 2018/08/29 07:41:14 [DEBUG] plugin: waiting for all plugin processes to complete...
TestTerraformAwsExample 2018-08-29T07:41:14Z retry.go:69: Running terraform [apply -input=false -lock=false -auto-approve -var instance_name="terratest-aws-example-dNvFDj"]
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:52: Running command terraform with args [apply -input=false -lock=false -auto-approve -var instance_name="terratest-aws-example-dNvFDj"]
TestTerraformAwsExample 2018-08-29T07:41:16Z command.go:96: data.aws_ami.ubuntu: Refreshing state...
panic: test timed out after 5m0s

goroutine 28 [running]:
testing.startAlarm.func1()
        /usr/lib/golang/src/testing/testing.go:1145 +0xf9
created by time.goFunc
        /usr/lib/golang/src/time/sleep.go:170 +0x44

goroutine 1 [chan receive, 4 minutes]:
testing.tRunner.func1(0xc4201ca000)
        /usr/lib/golang/src/testing/testing.go:722 +0x131
testing.tRunner(0xc4201ca000, 0xc4201bfde0)
        /usr/lib/golang/src/testing/testing.go:748 +0xda
testing.runTests(0xc4200ef5a0, 0xa59f20, 0x1, 0x1, 0xc42006d5d0)
        /usr/lib/golang/src/testing/testing.go:1002 +0x2d8
testing.(*M).Run(0xc42003ef18, 0xc4201bff70)
        /usr/lib/golang/src/testing/testing.go:921 +0x111
main.main()
        command-line-arguments/_test/_testmain.go:44 +0xdb

goroutine 21 [IO wait, 4 minutes]:
internal/poll.runtime_pollWait(0x7f46a2a14c70, 0x72, 0x1)
        /usr/lib/golang/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc42007c428, 0x72, 0xffffffffffffff01, 0xa2b500, 0xa274c0)
        /usr/lib/golang/src/internal/poll/fd_poll_runtime.go:85 +0xae
internal/poll.(*pollDesc).waitRead(0xc42007c428, 0xc420200001, 0xfcb, 0xfcb)
        /usr/lib/golang/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc42007c410, 0xc420200035, 0xfcb, 0xfcb, 0x0, 0x0, 0x0)
        /usr/lib/golang/src/internal/poll/fd_unix.go:126 +0x18a
os.(*File).read(0xc42007a218, 0xc420200035, 0xfcb, 0xfcb, 0x0, 0x71, 0xc4201940c0)
        /usr/lib/golang/src/os/file_unix.go:216 +0x4e
os.(*File).Read(0xc42007a218, 0xc420200035, 0xfcb, 0xfcb, 0x2, 0x40000000002, 0x8)
        /usr/lib/golang/src/os/file.go:103 +0x6d
bufio.(*Scanner).Scan(0xc42004d838, 0xc42010f710)
        /usr/lib/golang/src/bufio/scan.go:207 +0xaf
github.com/gruntwork-io/terratest/modules/shell.readStdoutAndStderr(0xc4201ca0f0, 0xa2d040, 0xc42007a218, 0xa2d040, 0xc42007a228, 0x83be10, 0x21, 0xc4201dde30, 0xc42020d500)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/modules/shell/command.go:94 +0x15e
github.com/gruntwork-io/terratest/modules/shell.RunCommandAndGetOutputE(0xc4201ca0f0, 0x831a4c, 0x9, 0xc4201e6300, 0x6, 0x8, 0x83be10, 0x21, 0xc4201dde30, 0x0, ...)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/modules/shell/command.go:74 +0x2d3
github.com/gruntwork-io/terratest/modules/terraform.RunTerraformCommandE.func1(0xc4201ca0f0, 0xc42010fbe0, 0x1, 0x1)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/modules/terraform/cmd.go:38 +0xf3
github.com/gruntwork-io/terratest/modules/retry.DoWithRetryE(0xc4201ca0f0, 0xc420074100, 0x72, 0x0, 0x0, 0xc42004dce0, 0x72, 0xc4201e6300, 0x2, 0xc42010fd10)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/modules/retry/retry.go:71 +0x338
github.com/gruntwork-io/terratest/modules/terraform.RunTerraformCommandE(0xc4201ca0f0, 0xc42010ff50, 0xc4201e6300, 0x6, 0x8, 0x6, 0x8, 0x0, 0x0)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/modules/terraform/cmd.go:30 +0x1ba
github.com/gruntwork-io/terratest/modules/terraform.ApplyE(0xc4201ca0f0, 0xc42010ff50, 0xc420314b40, 0x239, 0x0, 0x0)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/modules/terraform/apply.go:46 +0xc9
github.com/gruntwork-io/terratest/modules/terraform.InitAndApplyE(0xc4201ca0f0, 0xc42010ff50, 0x42bd19, 0xc42007c760, 0xc42010fe30, 0x20)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/modules/terraform/apply.go:30 +0xb1
github.com/gruntwork-io/terratest/modules/terraform.InitAndApply(0xc4201ca0f0, 0xc42010ff50, 0xc4201ca0f0, 0xc42010ff50)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/modules/terraform/apply.go:11 +0x39
command-line-arguments.TestTerraformAwsExample(0xc4201ca0f0)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/test/terraform_aws_example_test.go:43 +0x38f
testing.tRunner(0xc4201ca0f0, 0x848cd0)
        /usr/lib/golang/src/testing/testing.go:746 +0xd0
created by testing.(*T).Run
        /usr/lib/golang/src/testing/testing.go:789 +0x2de

goroutine 22 [chan receive, 4 minutes]:
testing.runTests.func1.1(0xc4201ca000)
        /usr/lib/golang/src/testing/testing.go:1009 +0x3b
created by testing.runTests.func1
        /usr/lib/golang/src/testing/testing.go:1009 +0xa2
FAIL    command-line-arguments  300.043s
brikis98 commented 6 years ago

The tests are running within a VPC and it can only access internet through a proxy setting.

And you tried running terraform apply directly from that same machine in the VPC?

But why would firewall preventing Terratest from calling Terraform binary ?

Actually, from your latest log output, it's not!

TestTerraformAwsExample 2018-08-29T07:41:14Z retry.go:69: Running terraform [apply -input=false -lock=false -auto-approve -var instance_name="terratest-aws-example-dNvFDj"]
TestTerraformAwsExample 2018-08-29T07:41:14Z command.go:52: Running command terraform with args [apply -input=false -lock=false -auto-approve -var instance_name="terratest-aws-example-dNvFDj"]
TestTerraformAwsExample 2018-08-29T07:41:16Z command.go:96: data.aws_ami.ubuntu: Refreshing state...

That last line is Terraform running!

Since there's no output afterwords, I think what's happening is that Terraform is just not getting a response to its outbound connection to AWS... It's just hanging on it indefinitely, perhaps due to the proxy settings not working.

wutianchen commented 6 years ago

@brikis98 thanks for the comment

And you tried running terraform apply directly from that same machine in the VPC?

yes. cd into terraform-aws-example and terraform apply (also terraform refresh). It works !

It's just hanging on it indefinitely, perhaps due to the proxy settings not working.

still checking on it ! But at the moment I doubt "terraform apply" is actually started because where it hangs is

(command.go) func readStdoutAndStderr which is before cmd.start()

and in error log includes

goroutine 21 [IO wait, 4 minutes]:
internal/poll.runtime_pollWait(0x7f46a2a14c70, 0x72, 0x1)
        /usr/lib/golang/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc42007c428, 0x72, 0xffffffffffffff01, 0xa2b500, 0xa274c0)
        /usr/lib/golang/src/internal/poll/fd_poll_runtime.go:85 +0xae
internal/poll.(*pollDesc).waitRead(0xc42007c428, 0xc420200001, 0xfcb, 0xfcb)
        /usr/lib/golang/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc42007c410, 0xc420200035, 0xfcb, 0xfcb, 0x0, 0x0, 0x0)
        /usr/lib/golang/src/internal/poll/fd_unix.go:126 +0x18a
os.(*File).read(0xc42007a218, 0xc420200035, 0xfcb, 0xfcb, 0x0, 0x71, 0xc4201940c0)
        /usr/lib/golang/src/os/file_unix.go:216 +0x4e
os.(*File).Read(0xc42007a218, 0xc420200035, 0xfcb, 0xfcb, 0x2, 0x40000000002, 0x8)
        /usr/lib/golang/src/os/file.go:103 +0x6d
bufio.(*Scanner).Scan(0xc42004d838, 0xc42010f710)
        /usr/lib/golang/src/bufio/scan.go:207 +0xaf
github.com/gruntwork-io/terratest/modules/shell.readStdoutAndStderr(0xc4201ca0f0, 0xa2d040, 0xc42007a218, 0xa2d040, 0xc42007a228, 0x83be10, 0x21, 0xc4201dde30, 0xc42020d500)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/modules/shell/command.go:94 +0x15e
github.com/gruntwork-io/terratest/modules/shell.RunCommandAndGetOutputE(0xc4201ca0f0, 0x831a4c, 0x9, 0xc4201e6300, 0x6, 0x8, 0x83be10, 0x21, 0xc4201dde30, 0x0, ...)
        /home/ec2-user/go/src/github.com/gruntwork-io/terratest/modules/shell/command.go:74 +0x2d3
brikis98 commented 6 years ago

But at the moment I doubt "terraform apply" is actually started because where it hangs is

It's definitely started based on your earlier log output:

TestTerraformAwsExample 2018-08-29T07:41:16Z command.go:96: data.aws_ami.ubuntu: Refreshing state...

The "Refreshing state..." is output from Terraform for sure.

wutianchen commented 6 years ago

@brikis98

The "Refreshing state..." is output from Terraform for sure.... I think what's happening is that Terraform is just not getting a response to its outbound connection to AWS...

you are right. have debugged with "tcpdump -i lo -p -s0 -w tcpdump.out" and wireshark. can not see which outbound target it is connecting to

in /home/ec2-user/go/src/github.com/gruntwork-io/terratest/test/ terraform_aws_example_test.go

If I put it like this (comment out data.aws_ami.ubuntu).

Then "terraform apply" suceeded but still "terraform destroy" doesn't execute.

resource "aws_instance" "example" {
  ami           = "ami-0f5dbc86dd9cbf7a8"
  instance_type = "t2.micro"

  tags {
    Name = "${var.instance_name}"
  }
}

/*
data "aws_ami" "ubuntu" {
  most_recent = true
  owners      = ["099720109477"] # Canonical

  filter {
    name   = "virtualization-type"
    values = ["hvm"]
  }

  filter {
    name   = "architecture"
    values = ["x86_64"]
  }

  filter {
    name   = "image-type"
    values = ["machine"]
  }

  filter {
    name   = "name"
    values = ["ubuntu/images/hvm-ssd/ubuntu-xenial-16.04-amd64-server-*"]
  }
}
*/
brikis98 commented 6 years ago

Well, 99% of what Terraform does is make outbound API calls, so if any of those are blocked by your firewall/networking settings, I don't think you're going to have much luck!

wutianchen commented 6 years ago

yep... The thing is

If I use terraform command without terratest. everything works perfectly fine all the time under my current proxy setting. pretty strange!

So a guess might be some terratest-related API calls. or terratest didn't pass env variable to terraform ? Would that be any chance I can further debug this ?

thanks a lot

brikis98 commented 6 years ago

Once Terratest has executed Terraform, Terratest itself is not making any API calls. So as we can see Terraform running, and removing data sources from the code lets it run further, it's not clear why it would be different with Terratest at all! How are your proxy settings configured? How did you install Terraform?

wutianchen commented 6 years ago

How are your proxy settings configured?

I used environment variables like following

http_proxy=http://domain:8080
https_proxy=http://domain:8080
no_proxy=169.254.169.254, amazonaws.com, eu-central-1.amazonaws.com

and tried to set it redundantly in _test.go like

terraformOptions := &terraform.Options{
                // The path to where our Terraform code is located
                TerraformDir: "../examples/terraform-aws-example",

                // Variables to pass to our Terraform code using -var options
                Vars: map[string]interface{}{
                        "instance_name": expectedName,
                },

                // Environment variables to set when running Terraform
                EnvVars: map[string]string{
                        "AWS_DEFAULT_REGION": awsRegion,
                        "http_proxy": "http://domain:8080",
                        "https_proxy": "http://domain:8080",
                        "HTTP_PROXY": "http://domain:8080",
                        "HTTPS_PROXY": "http://domain:8080",
                        "no_proxy": "169.254.169.254, amazonaws.com, eu-central-1.amazonaws.com",
                },
        }

How did you install Terraform?

I installed it with the following code

install_terraform(){
  wget https://releases.hashicorp.com/terraform/$1/terraform_$1_$2.zip
  sudo mv terraform_$1_$2.zip /usr/local/src/terraform_$1_$2.zip
  cd /usr/local/src
  sudo unzip terraform_$1_$2.zip
  sudo mv terraform /usr/local/bin/
  # export path
  export PATH=/usr/local/bin/:$PATH
}

install_terraform 0.11.7 linux_386

#verification
echo "--------------Verification---------------"
terraform version
joshpurvis commented 6 years ago

This is just a hunch, but I'd double check the behavior of your no_proxy settings. Notice you have amazonaws.com set to no proxy -- I'd bet terraform tries to hit that domain (and/or subdomain(s) of it) at various points during the API calls. Could the issue be related to this?

Are your settings for no_proxy the same in the terratest's terraform options as they are in your environment?

wutianchen commented 6 years ago

@joshpurvis thanks for the comment

Are your settings for no_proxy the same in the terratest's terraform options as they are in your environment?

yes. they are the same.

wutianchen commented 6 years ago

@brikis98 seemingly I have found the reason:

If TF_LOG(=DEBUG/TRACE) is set and TF_LOG_PATH is not set, then https://github.com/gruntwork-io/terratest/blob/master/modules/shell/command.go readStdoutAndStderr func hangs.

Does terratest work for you when TF_LOG(=DEBUG/TRACE) is set and TF_LOG_PATH is not set in the environment ?

brikis98 commented 6 years ago

Tests fail for me with TF_LOG set because it modifies stdout and some of the code is reading it, but the tests don't hang...

wutianchen commented 6 years ago

@brikis98 thanks for the answer and hope. trying also to contribute to terratest by the time of using

connaryscott commented 5 years ago

i'm experiencing this as well. I have no proxies at all and all i get is crapload of terraform processes that I have to kill after many test iterations of trying to figure out why running terraform directly works and terratest ( i assume as it appears to simply fork/exec) does not work. 

chscott$ ps -ef |grep "terraform apply" |wc -l
      13

Example of one of them (redacted some):

terraform apply -input=false -lock=false -auto-approve -var region="us-east-1" -var application_group="cloud" -var department="Infrastructure" -var team="cloud" -var incident_email="cloudengineering@REDACTED.com" -var env_group="ecomdev" -var bucket_name="ccp-example" -var zone_name="REDACTED" -var application="ccp-infrastructure-test" -var team_email="cloudengineering@REDACTED.com" -var compliance="None"

I'm willing to admit, there is a lot I probably do not know.

connaryscott commented 5 years ago

and it was something simple...

I had a (aws) provider.tf that was not being read and simply used AWS_PROFILE environment instead

ghost commented 5 years ago

I had a similar issue to this where terraform just hung on apply. It turned out that my issue was that my session token for my AWS credentials had expired.

My terraform version:

Terraform v0.11.13
+ provider.aws v2.7.0
mohangbits commented 5 years ago

@bkimbrou - same for me. Had to update the aws session token and it worked. Thank You !

brentarias commented 5 years ago

I don't know if this is related, but terraform console hangs for me - no output at all - when I launch it from Git Bash on Windows 10. It works fine when launched from any other console (viz. PowerShell, CMD). After it hangs, I run ps --windows | grep terraform (in a seperate git bash windows) and I see one terraform process that belongs to Git Bash (cygwin?) and the other belongs to windows. If I pskill the one that belongs to windows, the other one also finally exits on its own.

I have not yet figured out a way to fix this. I'm using tfenv in Git Bash to switch TF versions, and this problem happens whether I'm using 0.11.14 or 0.12.7. I'm not using any particular 3rd party TF provider. This error is happening with just the following isolated file:

terraform {
  backend "local" {
    # path = "relative/path/to/terraform.tfstate"
  }
}

locals {
  fw_cidr = "10.136.16.0/20"
  #fw_cidr = "10.136.80.0/20"

  cidrs = [
    "${cidrsubnet("${local.fw_cidr}", 3, 0)}", #attachment
    "${cidrsubnet("${local.fw_cidr}", 3, 1)}", #management
    "${cidrsubnet("${local.fw_cidr}", 3, 2)}", #trust
    "${cidrsubnet("${local.fw_cidr}", 3, 3)}", #untrust
  ]
}

data "null_data_source" "values" {
  inputs = {
      acidrs = "${join(" ",local.cidrs)}"
  }
}

output "cidrs" {
  value="${local.cidrs}"
}
no-response[bot] commented 4 years ago

This issue has been automatically closed because there has been no response to our request for more information from the original author. With only the information that is currently in the issue, we don't have enough information to take action. Please feel free to reach out if you have or find the answers we need so that we can investigate further. Thank you!