Skip to content

Commit

Permalink
Fix test logging output.
Browse files Browse the repository at this point in the history
In version 1.0.0-1.6.0, our in-process non-binary test driver didn't
call go-plugin, and called log.SetOutput to control what got logged, to
avoid flooding test output with debug logs.

From version 1.6.0, the in-process non-binary test driver had the same
behavior, but we added an out-of-process binary test driver, which used
go-plugin, but had the provider in a separate process that sent its
stdout and stderr through Terraform. Terraform then, not the test
framework, was responsible for filtering the output.

With the introduction of our in-process binary test driver, however,
we're using go-plugin and Terraform isn't filtering log output for us.
In theory, the log.SetOutput call that was working for the in-process
non-binary test driver should've worked here, as well, and it sort of
did. The issue was that go-plugin calls log.SetOutput and sets it to
os.Stderr in plugin.Serve, which overrides our filter.

To get this behavior back, after every call to plugin.Serve, we override
the go-plugin log.SetOutput by calling our own again.

This also removes the helper/resource.logOutput function, replacing its
usage with helper/logging.SetOutput, which does the same thing. The only
difference should be that filtering on test name is no longer supported.
If we want to support that, we would need to plumb a testing.T through
to runProviderCommand, which involves updating a lot of code for
marginal gain; as far as I know, nobody actually uses the test name
filtering for logging, preferring instead to log everything and only run
the test they want logs for.
  • Loading branch information
paddycarver committed Jun 11, 2020
1 parent f9ebc90 commit d609e41
Show file tree
Hide file tree
Showing 2 changed files with 5 additions and 52 deletions.
4 changes: 4 additions & 0 deletions helper/resource/plugin.go
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@ import (
"strings"

"github.com/hashicorp/go-hclog"
"github.com/hashicorp/terraform-plugin-sdk/v2/helper/logging"
"github.com/hashicorp/terraform-plugin-sdk/v2/helper/schema"
grpcplugin "github.com/hashicorp/terraform-plugin-sdk/v2/internal/helper/plugin"
proto "github.com/hashicorp/terraform-plugin-sdk/v2/internal/tfplugin5"
Expand Down Expand Up @@ -57,6 +58,9 @@ func runProviderCommand(f func() error, wd *tftest.WorkingDir, opts *plugin.Serv
return err
}

// plugin.DebugServe hijacks our log output location, so let's reset it
logging.SetOutput()

reattachInfo := map[string]plugin.ReattachConfig{}
var namespaces []string
host := "registry.terraform.io"
Expand Down
53 changes: 1 addition & 52 deletions helper/resource/testing.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,17 +5,13 @@ import (
"errors"
"flag"
"fmt"
"io"
"io/ioutil"
"log"
"os"
"regexp"
"strconv"
"strings"
"syscall"

"github.com/hashicorp/go-multierror"
"github.com/hashicorp/logutils"
tftest "github.com/hashicorp/terraform-plugin-test"
testing "github.com/mitchellh/go-testing-interface"

Expand Down Expand Up @@ -451,49 +447,6 @@ type TestStep struct {
providers map[string]*schema.Provider
}

// Set to a file mask in sprintf format where %s is test name
const envLogPathMask = "TF_LOG_PATH_MASK"

func logOutput(t testing.T) (logOutput io.Writer, err error) {
logOutput = ioutil.Discard

logLevel := logging.LogLevel()
if logLevel == "" {
return
}

logOutput = os.Stderr

if logPath := os.Getenv(logging.EnvLogFile); logPath != "" {
var err error
logOutput, err = os.OpenFile(logPath, syscall.O_CREAT|syscall.O_RDWR|syscall.O_APPEND, 0666)
if err != nil {
return nil, err
}
}

if logPathMask := os.Getenv(envLogPathMask); logPathMask != "" {
// Escape special characters which may appear if we have subtests
testName := strings.Replace(t.Name(), "/", "__", -1)

logPath := fmt.Sprintf(logPathMask, testName)
var err error
logOutput, err = os.OpenFile(logPath, syscall.O_CREAT|syscall.O_RDWR|syscall.O_APPEND, 0666)
if err != nil {
return nil, err
}
}

// This was the default since the beginning
logOutput = &logutils.LevelFilter{
Levels: logging.ValidLevels,
MinLevel: logutils.LogLevel(logLevel),
Writer: logOutput,
}

return
}

// ParallelTest performs an acceptance test on a resource, allowing concurrency
// with other ParallelTest.
//
Expand Down Expand Up @@ -526,11 +479,7 @@ func Test(t testing.T, c TestCase) {
return
}

logWriter, err := logOutput(t)
if err != nil {
t.Error(fmt.Errorf("error setting up logging: %s", err))
}
log.SetOutput(logWriter)
logging.SetOutput()

// get instances of all providers, so we can use the individual
// resources to shim the state during the tests.
Expand Down

0 comments on commit d609e41

Please sign in to comment.