Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Test for runTerraformCmd leaked go-routine #299

Merged
merged 8 commits into from May 20, 2022

Commits on May 10, 2022

  1. Update TestContext_sleepTimeoutExpired to check for canceling within …

    …timeframe
    
    Add a timeout to the test to ensure that the terraform apply cancels within
    a reasonable time of the 5s timeout.
    
    Currently, this test is not canceling the terraform apply as expected. In the
    logs you can see that the test takes 1 min rather than ~5s:
    ```
        --- PASS: TestContext_sleepTimeoutExpired/sleep-0.12.31 (62.13s)
    ```
    
    ```
    === RUN   TestContext_sleepTimeoutExpired/sleep-0.12.31
        util_test.go:113: [INFO] running Terraform command: /var/folders/6y/gy9gggt14379c_k39vwb50lc0000gn/T/terraform_1378921380/terraform apply -no-color -auto-approve -input=false -lock=true -parallelism=10 -refresh=true
        util_test.go:103: CLI Output:
    	    // truncated ...
            time_sleep.sleep: Creating...
            time_sleep.sleep: Still creating... [10s elapsed]
            time_sleep.sleep: Still creating... [20s elapsed]
            time_sleep.sleep: Still creating... [30s elapsed]
            time_sleep.sleep: Still creating... [41s elapsed]
            time_sleep.sleep: Still creating... [51s elapsed]
            time_sleep.sleep: Creation complete after 1m0s [id=2022-05-06T17:40:20Z]
    
            Apply complete! Resources: 1 added, 0 changed, 0 destroyed.
    ```
    lornasong committed May 10, 2022
    Copy the full SHA
    400f9d7 View commit details
    Browse the repository at this point in the history
  2. Remove runTerraformCmd check for cmd.ProcessState

    Processes were not being killed because cmd.ProcessState was nil. With this
    change, processes will be able to make the request to Kill().
    
    Added a temporary log to printout cmd.ProcessState to demonstrate. Will be
    removed in next commit.
    
    Note: this will cause hanging `TestContext_sleepTimeoutExpired` due to a known
    Golang issue with killing a command when Stdout or Stderr are set to anything
    besides `nil` or `*os.File`. This is because the Kill does not notify the
    stdout/stderr subprocesses to stop. `cmd.Wait` (called by `cmd.Run`) waits
    indefinitely for those subprocesses to stop.
    lornasong committed May 10, 2022
    Copy the full SHA
    b4e272e View commit details
    Browse the repository at this point in the history
  3. Read logs from Stderr/out Pipe to avoid hanging

    `TestContext_sleepTimeoutExpired` can occasionally hang when killing a command
    that has Stdout or Stderr set to anything besides `nil` or `*os.File`.
    golang/go#23019
    
    Use workaround to read from StdoutPipe and StderrPipe rather than setting
    Stdout / Stderr
    lornasong committed May 10, 2022
    Copy the full SHA
    c3ccdc3 View commit details
    Browse the repository at this point in the history
  4. Test for runTerraformCmd leaked go-routine

    Currently, when runTerraformCmd is called, it starts a go-routine to kill the
    Terraform CLI on context.Done(). However, when the Terraform CLI completes and
    runTerraformCmd() finishes, the go-routine continues running unnecessarily.
    
    If the caller cancels the context down the line, this will stop the go-routine
    and it will log the error: "error from kill: os: process already finished" because
    the Terraform CLI has already finished.
    
    Added a test for this in cmd_default.go and cmd_linux.go. Have not tried it in
    linux yet though.
    
    When running with the race detector:
    ```
    ==================
    WARNING: DATA RACE
    Read at 0x00c0002516c8 by goroutine 7:
      bytes.(*Buffer).String()
          /usr/local/go/src/bytes/buffer.go:65 +0x36a
      github.com/hashicorp/terraform-exec/tfexec.Test_runTerraformCmd_default()
          /Users/lornasong/go/src/github.com/hashicorp/terraform-exec/tfexec/cmd_default_test.go:35 +0x360
      testing.tRunner()
      // truncated ...
    
    Previous write at 0x00c0002516c8 by goroutine 8:
      bytes.(*Buffer).grow()
          /usr/local/go/src/bytes/buffer.go:147 +0x3b1
      bytes.(*Buffer).Write()
          /usr/local/go/src/bytes/buffer.go:172 +0xcd
      log.(*Logger).Output()
          /usr/local/go/src/log/log.go:184 +0x466
      log.(*Logger).Printf()
          /usr/local/go/src/log/log.go:191 +0x6e
      github.com/hashicorp/terraform-exec/tfexec.(*Terraform).runTerraformCmd.func1()
          /Users/lornasong/go/src/github.com/hashicorp/terraform-exec/tfexec/cmd_default.go:24 +0x2a5
      // truncated ...
    ==================
    lornasong committed May 10, 2022
    Copy the full SHA
    dc62a0f View commit details
    Browse the repository at this point in the history
  5. Copy the full SHA
    53bfc40 View commit details
    Browse the repository at this point in the history

Commits on May 17, 2022

  1. Fix EOF error check to use error.Is()

    This also fixes a race condition caused by using the pointer to the io.EOF
    lornasong committed May 17, 2022
    Copy the full SHA
    11f14d2 View commit details
    Browse the repository at this point in the history

Commits on May 20, 2022

  1. Update tests to use separate string.Builder-s for stdout and stderr

    string.Builder is a non-comparable type which is not safe for concurrent use
    when shared by Cmd.Stdout and Cmd.Stderr. Causes a race condition when accessing
    the the builder when Cmd is running.
    lornasong committed May 20, 2022
    Copy the full SHA
    594b411 View commit details
    Browse the repository at this point in the history
  2. Fixes to runTerraformCmd for race conditions

     - Use waitgroups for more readability
     - Improve handling errors from writeOutput
     - Finish reading from pipes before calling cmd.Wait - fixes a race condition
     that leads to an error :`read |0: file already closed`
     - Because now waiting for pipes to finish reading, need to update waitGroup to
     close buf.Read on context cancel. Otherwise buf.Read blocks until next line
     before stopping. Causes TestContext_sleepTimeoutExpired takes a little too long
     to cancel (~20s)
    lornasong committed May 20, 2022
    Copy the full SHA
    5a93b1e View commit details
    Browse the repository at this point in the history