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

@@ -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),

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

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",
+		logger.Warn(fmt.Sprintf("Invalid log level: %q. Defaulting to level: TRACE. Valid levels are: %+v",
-			envLevel, ValidLevels)
+			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  ----")
 	}
 
 	return logLevel

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
+		tmpLog, err := os.Open(tmpLogPath)
-		if _, err = logF.Seek(0, 0); err != nil {
+		if err != nil {
-			fmt.Fprintf(os.Stderr, "Failed to seek log file for crash: %s", err)
+			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
 		}

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)