From 1d9d82973b56f792d8427908b8d979150311de11 Mon Sep 17 00:00:00 2001 From: James Bardin Date: Wed, 21 Oct 2020 09:45:00 -0400 Subject: [PATCH 1/6] move panicwrap handler to logging package --- panic.go => internal/logging/panic.go | 17 +++++++---------- main.go | 4 ++-- 2 files changed, 9 insertions(+), 12 deletions(-) rename panic.go => internal/logging/panic.go (80%) diff --git a/panic.go b/internal/logging/panic.go similarity index 80% rename from panic.go rename to internal/logging/panic.go index 6690a93e9..a7205ce7d 100644 --- a/panic.go +++ b/internal/logging/panic.go @@ -1,8 +1,9 @@ -package main +package logging import ( "fmt" "io" + "io/ioutil" "os" "strings" @@ -15,7 +16,7 @@ const panicOutput = ` !!!!!!!!!!!!!!!!!!!!!!!!!!! TERRAFORM CRASH !!!!!!!!!!!!!!!!!!!!!!!!!!!! Terraform crashed! This is always indicative of a bug within Terraform. -A crash log has been placed at "crash.log" relative to your current +A crash log has been placed at %[1]q relative to your current working directory. It would be immensely helpful if you could please report the crash with Terraform[1] so that we can fix this. @@ -23,7 +24,7 @@ When reporting bugs, please include your terraform version. That information is available on the first line of crash.log. You can also get it by running 'terraform --version' on the command line. -SECURITY WARNING: the "crash.log" file that was created may contain +SECURITY WARNING: the %[1]q file that was created may contain sensitive information that must be redacted before it is safe to share on the issue tracker. @@ -36,14 +37,10 @@ on the issue tracker. // within Terraform. It is guaranteed to run after the resulting process has // exited so we can take the log file, add in the panic, and store it // somewhere locally. -func panicHandler(logF *os.File) panicwrap.HandlerFunc { +func PanicHandler(logF *os.File) panicwrap.HandlerFunc { return func(m string) { - // Right away just output this thing on stderr so that it gets - // shown in case anything below fails. - fmt.Fprintf(os.Stderr, fmt.Sprintf("%s\n", m)) - // Create the crash log file where we'll write the logs - f, err := os.Create("crash.log") + f, err := ioutil.TempFile(".", "crash.*.log") if err != nil { fmt.Fprintf(os.Stderr, "Failed to create crash log file: %s", err) return @@ -66,6 +63,6 @@ func panicHandler(logF *os.File) panicwrap.HandlerFunc { // Tell the user a crash occurred in some helpful way that // they'll hopefully notice. fmt.Printf("\n\n") - fmt.Println(strings.TrimSpace(panicOutput)) + fmt.Printf(strings.TrimSpace(panicOutput), f.Name()) } } diff --git a/main.go b/main.go index e87a90231..33d39e323 100644 --- a/main.go +++ b/main.go @@ -19,6 +19,7 @@ import ( "github.com/hashicorp/terraform/command/cliconfig" "github.com/hashicorp/terraform/command/format" "github.com/hashicorp/terraform/httpclient" + "github.com/hashicorp/terraform/internal/logging" "github.com/hashicorp/terraform/version" "github.com/mattn/go-colorable" "github.com/mattn/go-shellwords" @@ -65,8 +66,7 @@ func realMain() int { go copyOutput(outR, doneCh) // Create the configuration for panicwrap and wrap our executable - wrapConfig.Handler = panicHandler(logTempFile) - wrapConfig.Writer = os.Stderr + wrapConfig.Handler = logging.PanicHandler(logTempFile) wrapConfig.Stdout = outW wrapConfig.IgnoreSignals = ignoreSignals wrapConfig.ForwardSignals = forwardSignals From fd4f7eb0b935e5a838810564fd549afe710ae19a Mon Sep 17 00:00:00 2001 From: James Bardin Date: Wed, 21 Oct 2020 13:06:23 -0400 Subject: [PATCH 2/6] remove prefixed io The main process is now handling what output to print, so it doesn't do any good to try and run it through prefixedio, which is only adding extra coordination to echo the same data. --- go.mod | 3 +- go.sum | 4 --- main.go | 98 +++------------------------------------------------------ 3 files changed, 6 insertions(+), 99 deletions(-) diff --git a/go.mod b/go.mod index 96db292b5..630e77a47 100644 --- a/go.mod +++ b/go.mod @@ -84,7 +84,7 @@ require ( github.com/lusis/go-artifactory v0.0.0-20160115162124-7e4ce345df82 github.com/masterzen/simplexml v0.0.0-20190410153822-31eea3082786 // indirect github.com/masterzen/winrm v0.0.0-20200615185753-c42b5136ff88 - github.com/mattn/go-colorable v0.1.8 + github.com/mattn/go-colorable v0.1.8 // indirect github.com/mattn/go-isatty v0.0.12 github.com/mattn/go-shellwords v1.0.4 github.com/miekg/dns v1.0.8 // indirect @@ -97,7 +97,6 @@ require ( github.com/mitchellh/gox v1.0.1 github.com/mitchellh/mapstructure v1.1.2 github.com/mitchellh/panicwrap v1.0.0 - github.com/mitchellh/prefixedio v0.0.0-20190213213902-5733675afd51 github.com/mitchellh/reflectwalk v1.0.1 github.com/nu7hatch/gouuid v0.0.0-20131221200532-179d4d0c4d8d // indirect github.com/packer-community/winrmcp v0.0.0-20180921211025-c76d91c1e7db diff --git a/go.sum b/go.sum index 4866cfeb7..7eb70d228 100644 --- a/go.sum +++ b/go.sum @@ -246,8 +246,6 @@ github.com/hashicorp/go-msgpack v0.5.4 h1:SFT72YqIkOcLdWJUYcriVX7hbrZpwc/f7h8aW2 github.com/hashicorp/go-msgpack v0.5.4/go.mod h1:ahLV/dePpqEmjfWmKiqvPkv/twdG7iPBM1vqhUKIvfM= github.com/hashicorp/go-multierror v1.0.0 h1:iVjPR7a6H0tWELX5NxNe7bYopibicUzc7uPribsnS6o= github.com/hashicorp/go-multierror v1.0.0/go.mod h1:dHtQlpGsu+cZNNAkkCN/P3hoUDHhCYQXV3UM06sGGrk= -github.com/hashicorp/go-plugin v1.3.0 h1:4d/wJojzvHV1I4i/rrjVaeuyxWrLzDE1mDCyDy8fXS8= -github.com/hashicorp/go-plugin v1.3.0/go.mod h1:F9eH4LrE/ZsRdbwhfjs9k9HoDUwAHnYtXdgmf1AVNs0= github.com/hashicorp/go-retryablehttp v0.5.2 h1:AoISa4P4IsW0/m4T6St8Yw38gTl5GtBAgfkhYh1xAz4= github.com/hashicorp/go-retryablehttp v0.5.2/go.mod h1:9B5zBasrRhHXnJnui7y6sL7es7NDiJgTc6Er0maI1Xs= github.com/hashicorp/go-rootcerts v1.0.0 h1:Rqb66Oo1X/eSV1x66xbDccZjhJigjg0+e82kpwzSwCI= @@ -384,8 +382,6 @@ github.com/mitchellh/mapstructure v1.1.2 h1:fmNYVwqnSfB9mZU6OS2O6GsXM+wcskZDuKQz github.com/mitchellh/mapstructure v1.1.2/go.mod h1:FVVH3fgwuzCH5S8UJGiWEs2h04kUh9fWfEaFds41c1Y= github.com/mitchellh/panicwrap v1.0.0 h1:67zIyVakCIvcs69A0FGfZjBdPleaonSgGlXRSRlb6fE= github.com/mitchellh/panicwrap v1.0.0/go.mod h1:pKvZHwWrZowLUzftuFq7coarnxbBXU4aQh3N0BJOeeA= -github.com/mitchellh/prefixedio v0.0.0-20190213213902-5733675afd51 h1:eD92Am0Qf3rqhsOeA1zwBHSfRkoHrt4o6uORamdmJP8= -github.com/mitchellh/prefixedio v0.0.0-20190213213902-5733675afd51/go.mod h1:kB1naBgV9ORnkiTVeyJOI1DavaJkG4oNIq0Af6ZVKUo= github.com/mitchellh/reflectwalk v1.0.0 h1:9D+8oIskB4VJBN5SFlmc27fSlIBZaov1Wpk/IfikLNY= github.com/mitchellh/reflectwalk v1.0.0/go.mod h1:mSTlrgnPZtwu0c4WaC2kGObEpuNDbx0jmZXqmk4esnw= github.com/mitchellh/reflectwalk v1.0.1 h1:FVzMWA5RllMAKIdUSC8mdWo3XtwoecrH79BY70sEEpE= diff --git a/main.go b/main.go index 33d39e323..f56be6f3f 100644 --- a/main.go +++ b/main.go @@ -3,7 +3,6 @@ package main import ( "encoding/json" "fmt" - "io" "io/ioutil" "log" "net" @@ -11,7 +10,6 @@ import ( "path/filepath" "runtime" "strings" - "sync" "github.com/hashicorp/go-plugin" "github.com/hashicorp/terraform-svchost/disco" @@ -21,12 +19,10 @@ import ( "github.com/hashicorp/terraform/httpclient" "github.com/hashicorp/terraform/internal/logging" "github.com/hashicorp/terraform/version" - "github.com/mattn/go-colorable" "github.com/mattn/go-shellwords" "github.com/mitchellh/cli" "github.com/mitchellh/colorstring" "github.com/mitchellh/panicwrap" - "github.com/mitchellh/prefixedio" backendInit "github.com/hashicorp/terraform/backend/init" ) @@ -59,15 +55,8 @@ func realMain() int { defer os.Remove(logTempFile.Name()) defer logTempFile.Close() - // Setup the prefixed readers that send data properly to - // stdout/stderr. - doneCh := make(chan struct{}) - outR, outW := io.Pipe() - go copyOutput(outR, doneCh) - // Create the configuration for panicwrap and wrap our executable wrapConfig.Handler = logging.PanicHandler(logTempFile) - wrapConfig.Stdout = outW wrapConfig.IgnoreSignals = ignoreSignals wrapConfig.ForwardSignals = forwardSignals exitStatus, err := panicwrap.Wrap(&wrapConfig) @@ -76,20 +65,7 @@ func realMain() int { return 1 } - // If >= 0, we're the parent, so just exit - if exitStatus >= 0 { - // Close the stdout writer so that our copy process can finish - outW.Close() - - // Wait for the output copying to finish - <-doneCh - - return exitStatus - } - - // We're the child, so just close the tempfile we made in order to - // save file handles since the tempfile is only used by the parent. - logTempFile.Close() + return exitStatus } // Call the real main @@ -97,15 +73,10 @@ func realMain() int { } func init() { - Ui = &cli.PrefixedUi{ - AskPrefix: OutputPrefix, - OutputPrefix: OutputPrefix, - InfoPrefix: OutputPrefix, - ErrorPrefix: ErrorPrefix, - Ui: &cli.BasicUi{ - Writer: os.Stdout, - Reader: os.Stdin, - }, + Ui = &cli.BasicUi{ + Writer: os.Stdout, + ErrorWriter: os.Stderr, + Reader: os.Stdin, } } @@ -299,65 +270,6 @@ func wrappedMain() int { return exitCode } -// copyOutput uses output prefixes to determine whether data on stdout -// should go to stdout or stderr. This is due to panicwrap using stderr -// as the log and error channel. -func copyOutput(r io.Reader, doneCh chan<- struct{}) { - defer close(doneCh) - - pr, err := prefixedio.NewReader(r) - if err != nil { - panic(err) - } - - stderrR, err := pr.Prefix(ErrorPrefix) - if err != nil { - panic(err) - } - stdoutR, err := pr.Prefix(OutputPrefix) - if err != nil { - panic(err) - } - defaultR, err := pr.Prefix("") - if err != nil { - panic(err) - } - - var stdout io.Writer = os.Stdout - var stderr io.Writer = os.Stderr - - if runtime.GOOS == "windows" { - stdout = colorable.NewColorableStdout() - stderr = colorable.NewColorableStderr() - - // colorable is not concurrency-safe when stdout and stderr are the - // same console, so we need to add some synchronization to ensure that - // we can't be concurrently writing to both stderr and stdout at - // once, or else we get intermingled writes that create gibberish - // in the console. - wrapped := synchronizedWriters(stdout, stderr) - stdout = wrapped[0] - stderr = wrapped[1] - } - - var wg sync.WaitGroup - wg.Add(3) - go func() { - defer wg.Done() - io.Copy(stderr, stderrR) - }() - go func() { - defer wg.Done() - io.Copy(stdout, stdoutR) - }() - go func() { - defer wg.Done() - io.Copy(stdout, defaultR) - }() - - wg.Wait() -} - func mergeEnvArgs(envName string, cmd string, args []string) ([]string, error) { v := os.Getenv(envName) if v == "" { From a2dee91eba439ffc4581536eb2f402fde73909e1 Mon Sep 17 00:00:00 2001 From: James Bardin Date: Wed, 21 Oct 2020 14:47:37 -0400 Subject: [PATCH 3/6] update hclog-go We need some fixes from master. --- go.mod | 2 +- go.sum | 4 ++++ 2 files changed, 5 insertions(+), 1 deletion(-) diff --git a/go.mod b/go.mod index 630e77a47..d870e58ce 100644 --- a/go.mod +++ b/go.mod @@ -55,7 +55,7 @@ require ( github.com/hashicorp/go-checkpoint v0.5.0 github.com/hashicorp/go-cleanhttp v0.5.1 github.com/hashicorp/go-getter v1.4.2-0.20200106182914-9813cbd4eb02 - github.com/hashicorp/go-hclog v0.14.1 + github.com/hashicorp/go-hclog v0.14.2-0.20201019183805-6b377870ae4a github.com/hashicorp/go-immutable-radix v0.0.0-20180129170900-7f3cd4390caa // indirect github.com/hashicorp/go-msgpack v0.5.4 // indirect github.com/hashicorp/go-multierror v1.0.0 diff --git a/go.sum b/go.sum index 7eb70d228..8c84fe4db 100644 --- a/go.sum +++ b/go.sum @@ -240,12 +240,16 @@ github.com/hashicorp/go-getter v1.4.2-0.20200106182914-9813cbd4eb02/go.mod h1:7q github.com/hashicorp/go-hclog v0.0.0-20180709165350-ff2cf002a8dd/go.mod h1:9bjs9uLqI8l75knNv3lV1kA55veR+WUPSiKIWcQHudI= github.com/hashicorp/go-hclog v0.14.1 h1:nQcJDQwIAGnmoUWp8ubocEX40cCml/17YkF6csQLReU= github.com/hashicorp/go-hclog v0.14.1/go.mod h1:whpDNt7SSdeAju8AWKIWsul05p54N/39EeqMAyrmvFQ= +github.com/hashicorp/go-hclog v0.14.2-0.20201019183805-6b377870ae4a h1:jMdSTm5U2cMM2Z0y+tiSTsMAinefoMZyXGj3Gap+JmE= +github.com/hashicorp/go-hclog v0.14.2-0.20201019183805-6b377870ae4a/go.mod h1:whpDNt7SSdeAju8AWKIWsul05p54N/39EeqMAyrmvFQ= github.com/hashicorp/go-immutable-radix v0.0.0-20180129170900-7f3cd4390caa h1:0nA8i+6Rwqaq9xlpmVxxTwk6rxiEhX+E6Wh4vPNHiS8= github.com/hashicorp/go-immutable-radix v0.0.0-20180129170900-7f3cd4390caa/go.mod h1:6ij3Z20p+OhOkCSrA0gImAWoHYQRGbnlcuk6XYTiaRw= github.com/hashicorp/go-msgpack v0.5.4 h1:SFT72YqIkOcLdWJUYcriVX7hbrZpwc/f7h8aW2NUqrA= github.com/hashicorp/go-msgpack v0.5.4/go.mod h1:ahLV/dePpqEmjfWmKiqvPkv/twdG7iPBM1vqhUKIvfM= github.com/hashicorp/go-multierror v1.0.0 h1:iVjPR7a6H0tWELX5NxNe7bYopibicUzc7uPribsnS6o= github.com/hashicorp/go-multierror v1.0.0/go.mod h1:dHtQlpGsu+cZNNAkkCN/P3hoUDHhCYQXV3UM06sGGrk= +github.com/hashicorp/go-plugin v1.3.0 h1:4d/wJojzvHV1I4i/rrjVaeuyxWrLzDE1mDCyDy8fXS8= +github.com/hashicorp/go-plugin v1.3.0/go.mod h1:F9eH4LrE/ZsRdbwhfjs9k9HoDUwAHnYtXdgmf1AVNs0= github.com/hashicorp/go-retryablehttp v0.5.2 h1:AoISa4P4IsW0/m4T6St8Yw38gTl5GtBAgfkhYh1xAz4= github.com/hashicorp/go-retryablehttp v0.5.2/go.mod h1:9B5zBasrRhHXnJnui7y6sL7es7NDiJgTc6Er0maI1Xs= github.com/hashicorp/go-rootcerts v1.0.0 h1:Rqb66Oo1X/eSV1x66xbDccZjhJigjg0+e82kpwzSwCI= From b61488a8ba3b018eeb78cb1a7e473602a5b0a83c Mon Sep 17 00:00:00 2001 From: James Bardin Date: Wed, 21 Oct 2020 14:57:25 -0400 Subject: [PATCH 4/6] write traceback to log crash log --- internal/logging/panic.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/internal/logging/panic.go b/internal/logging/panic.go index a7205ce7d..6a2c7869e 100644 --- a/internal/logging/panic.go +++ b/internal/logging/panic.go @@ -60,6 +60,9 @@ func PanicHandler(logF *os.File) panicwrap.HandlerFunc { return } + // add the trace back to the log + f.WriteString("\n" + m) + // Tell the user a crash occurred in some helpful way that // they'll hopefully notice. fmt.Printf("\n\n") From c2af5333e8b79969c886584c86042fc211ce27d8 Mon Sep 17 00:00:00 2001 From: James Bardin Date: Wed, 21 Oct 2020 14:57:46 -0400 Subject: [PATCH 5/6] use a log sink to capture logs for panicwrap Use a separate log sink to always capture trace logs for the panicwrap handler to write out in a crash log. This requires creating a log file in the outer process and passing that path to the child process to log to. --- command/meta_providers.go | 2 +- command/plugins.go | 2 +- internal/logging/logging.go | 30 ++++++++++++++++++++++++------ internal/logging/panic.go | 11 ++++++----- main.go | 26 ++++++++++++++++++++++++-- 5 files changed, 56 insertions(+), 15 deletions(-) diff --git a/command/meta_providers.go b/command/meta_providers.go index 8cc111fb0..fb964e374 100644 --- a/command/meta_providers.go +++ b/command/meta_providers.go @@ -335,7 +335,7 @@ func providerFactory(meta *providercache.CachedProvider) providers.Factory { config := &plugin.ClientConfig{ HandshakeConfig: tfplugin.Handshake, - Logger: logging.NewHCLogger("plugin"), + Logger: logging.NewProviderLogger(), AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC}, Managed: true, Cmd: exec.Command(execFile), diff --git a/command/plugins.go b/command/plugins.go index 032e00cee..a9aa0fbc7 100644 --- a/command/plugins.go +++ b/command/plugins.go @@ -169,7 +169,7 @@ func internalPluginClient(kind, name string) (*plugin.Client, error) { VersionedPlugins: tfplugin.VersionedPlugins, AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC}, AutoMTLS: enableProviderAutoMTLS, - Logger: logging.NewHCLogger("plugin"), + Logger: logging.NewProviderLogger(), } return plugin.NewClient(cfg), nil diff --git a/internal/logging/logging.go b/internal/logging/logging.go index 52ac75b00..f30dbc7b1 100644 --- a/internal/logging/logging.go +++ b/internal/logging/logging.go @@ -38,6 +38,23 @@ func init() { log.SetOutput(logWriter) } +// SetupTempLog adds a new log sink which writes all logs to the given file. +func RegisterSink(f *os.File) { + l, ok := logger.(hclog.InterceptLogger) + if !ok { + panic("global logger is not an InterceptLogger") + } + + if f == nil { + return + } + + l.RegisterSink(hclog.NewSinkAdapter(&hclog.LoggerOptions{ + Level: hclog.Trace, + Output: f, + })) +} + // LogOutput return the default global log io.Writer func LogOutput() io.Writer { return logWriter @@ -65,13 +82,17 @@ func NewHCLogger(name string) hclog.Logger { } } - return hclog.New(&hclog.LoggerOptions{ + return hclog.NewInterceptLogger(&hclog.LoggerOptions{ Name: name, Level: hclog.LevelFromString(logLevel), Output: logOutput, }) } +func NewProviderLogger() hclog.Logger { + return logger.Named("plugin") +} + // CurrentLogLevel returns the current log level string based the environment vars func CurrentLogLevel() string { envLevel := strings.ToUpper(os.Getenv(EnvLog)) @@ -83,11 +104,8 @@ func CurrentLogLevel() string { if isValidLogLevel(envLevel) { logLevel = envLevel } else { - log.Printf("[WARN] Invalid log level: %q. Defaulting to level: TRACE. Valid levels are: %+v", - envLevel, ValidLevels) - } - if logLevel != "TRACE" { - log.Printf("[WARN] Log levels other than TRACE are currently unreliable, and are supported only for backward compatibility.\n Use TF_LOG=TRACE to see Terraform's internal logs.\n ----") + logger.Warn(fmt.Sprintf("Invalid log level: %q. Defaulting to level: TRACE. Valid levels are: %+v", + envLevel, ValidLevels)) } return logLevel diff --git a/internal/logging/panic.go b/internal/logging/panic.go index 6a2c7869e..02068bc52 100644 --- a/internal/logging/panic.go +++ b/internal/logging/panic.go @@ -37,7 +37,7 @@ on the issue tracker. // within Terraform. It is guaranteed to run after the resulting process has // exited so we can take the log file, add in the panic, and store it // somewhere locally. -func PanicHandler(logF *os.File) panicwrap.HandlerFunc { +func PanicHandler(tmpLogPath string) panicwrap.HandlerFunc { return func(m string) { // Create the crash log file where we'll write the logs f, err := ioutil.TempFile(".", "crash.*.log") @@ -47,15 +47,16 @@ func PanicHandler(logF *os.File) panicwrap.HandlerFunc { } defer f.Close() - // Seek the log file back to the beginning - if _, err = logF.Seek(0, 0); err != nil { - fmt.Fprintf(os.Stderr, "Failed to seek log file for crash: %s", err) + tmpLog, err := os.Open(tmpLogPath) + if err != nil { + fmt.Fprintf(os.Stderr, "Failed to open log file %q: %v\n", tmpLogPath, err) return } + defer tmpLog.Close() // Copy the contents to the crash file. This will include // the panic that just happened. - if _, err = io.Copy(f, logF); err != nil { + if _, err = io.Copy(f, tmpLog); err != nil { fmt.Fprintf(os.Stderr, "Failed to write crash log: %s", err) return } diff --git a/main.go b/main.go index f56be6f3f..19d7f9ac6 100644 --- a/main.go +++ b/main.go @@ -30,6 +30,9 @@ import ( const ( // EnvCLI is the environment variable name to set additional CLI args. EnvCLI = "TF_CLI_ARGS" + + // The parent process will create a file to collect crash logs + envTmpLogPath = "TF_TEMP_LOG_PATH" ) func main() { @@ -52,11 +55,16 @@ func realMain() int { fmt.Fprintf(os.Stderr, "Couldn't setup logging tempfile: %s", err) return 1 } + // Now that we have the file, close it and leave it for the wrapped + // process to write to. + logTempFile.Close() defer os.Remove(logTempFile.Name()) - defer logTempFile.Close() + + // store the path in the environment for the wrapped executable + os.Setenv(envTmpLogPath, logTempFile.Name()) // Create the configuration for panicwrap and wrap our executable - wrapConfig.Handler = logging.PanicHandler(logTempFile) + wrapConfig.Handler = logging.PanicHandler(logTempFile.Name()) wrapConfig.IgnoreSignals = ignoreSignals wrapConfig.ForwardSignals = forwardSignals exitStatus, err := panicwrap.Wrap(&wrapConfig) @@ -83,6 +91,20 @@ func init() { func wrappedMain() int { var err error + tmpLogPath := os.Getenv(envTmpLogPath) + if tmpLogPath != "" { + f, err := os.OpenFile(tmpLogPath, os.O_RDWR|os.O_APPEND, 0666) + if err == nil { + defer os.Remove(f.Name()) + defer f.Close() + + log.Printf("[DEBUG] Adding temp file log sink: %s", f.Name()) + logging.RegisterSink(f) + } else { + log.Printf("[ERROR] Could not open temp log file: %v", err) + } + } + log.Printf( "[INFO] Terraform version: %s %s %s", Version, VersionPrerelease, GitCommit) From ef4fee5acbf65b9dd4c57f79b32df4bc9be4ad47 Mon Sep 17 00:00:00 2001 From: James Bardin Date: Wed, 21 Oct 2020 18:24:09 -0400 Subject: [PATCH 6/6] warnings are now on stderr --- command/e2etest/init_test.go | 14 +++----------- command/e2etest/provider_dev_test.go | 2 +- 2 files changed, 4 insertions(+), 12 deletions(-) diff --git a/command/e2etest/init_test.go b/command/e2etest/init_test.go index f59ce0b05..197671398 100644 --- a/command/e2etest/init_test.go +++ b/command/e2etest/init_test.go @@ -250,19 +250,11 @@ func TestInitProviders_pluginCache(t *testing.T) { // convert the slashes if building for windows. p := filepath.FromSlash("./cache") cmd.Env = append(cmd.Env, "TF_PLUGIN_CACHE_DIR="+p) - cmd.Stdin = nil - cmd.Stderr = &bytes.Buffer{} - err = cmd.Run() if err != nil { t.Errorf("unexpected error: %s", err) } - stderr := cmd.Stderr.(*bytes.Buffer).String() - if stderr != "" { - t.Errorf("unexpected stderr output:\n%s\n", stderr) - } - path := filepath.FromSlash(fmt.Sprintf(".terraform/providers/registry.terraform.io/hashicorp/template/2.1.0/%s_%s/terraform-provider-template_v2.1.0_x4", runtime.GOOS, runtime.GOARCH)) content, err := tf.ReadFile(path) if err != nil { @@ -375,13 +367,13 @@ func TestInitProviderWarnings(t *testing.T) { tf := e2e.NewBinary(terraformBin, fixturePath) defer tf.Close() - stdout, _, err := tf.Run("init") + _, stderr, err := tf.Run("init") if err == nil { t.Fatal("expected error, got success") } - if !strings.Contains(stdout, "This provider is archived and no longer needed. The terraform_remote_state\ndata source is built into the latest Terraform release.") { - t.Errorf("expected warning message is missing from output:\n%s", stdout) + if !strings.Contains(stderr, "This provider is archived and no longer needed. The terraform_remote_state\ndata source is built into the latest Terraform release.") { + t.Errorf("expected warning message is missing from output:\n%s", stderr) } } diff --git a/command/e2etest/provider_dev_test.go b/command/e2etest/provider_dev_test.go index 723591dbe..3c779c5a3 100644 --- a/command/e2etest/provider_dev_test.go +++ b/command/e2etest/provider_dev_test.go @@ -70,7 +70,7 @@ func TestProviderDevOverrides(t *testing.T) { if got, want := stdout, `The configuration is valid, but`; !strings.Contains(got, want) { t.Errorf("stdout doesn't include the success message\nwant: %s\n%s", want, got) } - if got, want := stdout, `Provider development overrides are in effect`; !strings.Contains(got, want) { + if got, want := stderr, `Provider development overrides are in effect`; !strings.Contains(got, want) { t.Errorf("stdout doesn't include the warning about development overrides\nwant: %s\n%s", want, got) } }