Separate loggers

command/meta_providers.go

@@ -335,7 +335,7 @@ func providerFactory(meta *providercache.CachedProvider) providers.Factory {
 
 		config := &plugin.ClientConfig{
 			HandshakeConfig:  tfplugin.Handshake,
-			Logger:           logging.NewProviderLogger(),
+			Logger:           logging.NewProviderLogger(""),
 			AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
 			Managed:          true,
 			Cmd:              exec.Command(execFile),
@@ -383,7 +383,7 @@ func unmanagedProviderFactory(provider addrs.Provider, reattach *plugin.Reattach
 
 		config := &plugin.ClientConfig{
 			HandshakeConfig:  tfplugin.Handshake,
-			Logger:           logging.NewHCLogger("unmanaged-plugin"),
+			Logger:           logging.NewProviderLogger("unmanaged."),
 			AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
 			Managed:          false,
 			Reattach:         reattach,

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.NewProviderLogger(),
+		Logger:           logging.NewLogger(kind),
 	}
 
 	return plugin.NewClient(cfg), nil
@@ -182,7 +182,7 @@ func provisionerFactory(meta discovery.PluginMeta) terraform.ProvisionerFactory
 			HandshakeConfig:  tfplugin.Handshake,
 			VersionedPlugins: tfplugin.VersionedPlugins,
 			Managed:          true,
-			Logger:           logging.NewHCLogger("provisioner"),
+			Logger:           logging.NewLogger("provisioner"),
 			AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
 			AutoMTLS:         enableProviderAutoMTLS,
 		}

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.2-0.20201019183805-6b377870ae4a
+	github.com/hashicorp/go-hclog v0.14.2-0.20201022192508-e59fd7e11108
 	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

go.sum

@@ -242,6 +242,10 @@ github.com/hashicorp/go-hclog v0.14.1 h1:nQcJDQwIAGnmoUWp8ubocEX40cCml/17YkF6csQ
 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-hclog v0.14.2-0.20201022165706-5774f3f2f293 h1:l/xQmH6wg6Z8nRuoMcm/bx3o3nWwy0dLKy9QNKfB2+c=
+github.com/hashicorp/go-hclog v0.14.2-0.20201022165706-5774f3f2f293/go.mod h1:whpDNt7SSdeAju8AWKIWsul05p54N/39EeqMAyrmvFQ=
+github.com/hashicorp/go-hclog v0.14.2-0.20201022192508-e59fd7e11108 h1:njjwC6QCapHoavbrnzrenpovKeHauePE1wPVdflPvRU=
+github.com/hashicorp/go-hclog v0.14.2-0.20201022192508-e59fd7e11108/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=

internal/logging/logging.go

@@ -3,7 +3,6 @@ package logging
 import (
 	"fmt"
 	"io"
-	"io/ioutil"
 	"log"
 	"os"
 	"strings"
@@ -15,12 +14,18 @@ import (
 // These are the environmental variables that determine if we log, and if
 // we log whether or not the log should go to a file.
 const (
-	EnvLog     = "TF_LOG"      // Set to True
-	EnvLogFile = "TF_LOG_PATH" // Set to a file
+	envLog     = "TF_LOG"
+	envLogFile = "TF_LOG_PATH"
+
+	// Allow logging of specific subsystems.
+	// We only separate core and providers for now, but this could be extended
+	// to other loggers, like provisioners and remote-state backends.
+	envLogCore     = "TF_LOG_CORE"
+	envLogProvider = "TF_LOG_PROVIDER"
 )
 
 // ValidLevels are the log level names that Terraform recognizes.
-var ValidLevels = []string{"TRACE", "DEBUG", "INFO", "WARN", "ERROR"}
+var ValidLevels = []string{"TRACE", "DEBUG", "INFO", "WARN", "ERROR", "OFF"}
 
 // logger is the global hclog logger
 var logger hclog.Logger
@@ -29,7 +34,7 @@ var logger hclog.Logger
 var logWriter io.Writer
 
 func init() {
-	logger = NewHCLogger("")
+	logger = newHCLogger("")
 	logWriter = logger.StandardWriter(&hclog.StandardLoggerOptions{InferLevels: true})
 
 	// setup the default std library logger to use our output
@@ -65,15 +70,12 @@ func HCLogger() hclog.Logger {
 	return logger
 }
 
-// NewHCLogger returns a new hclog.Logger instance with the given name
-func NewHCLogger(name string) hclog.Logger {
+// newHCLogger returns a new hclog.Logger instance with the given name
+func newHCLogger(name string) hclog.Logger {
 	logOutput := io.Writer(os.Stderr)
-	logLevel := CurrentLogLevel()
-	if logLevel == "" {
-		logOutput = ioutil.Discard
-	}
+	logLevel := globalLogLevel()
 
-	if logPath := os.Getenv(EnvLogFile); logPath != "" {
+	if logPath := os.Getenv(envLogFile); logPath != "" {
 		f, err := os.OpenFile(logPath, syscall.O_CREAT|syscall.O_RDWR|syscall.O_APPEND, 0666)
 		if err != nil {
 			fmt.Fprintf(os.Stderr, "Error opening log file: %v\n", err)
@@ -83,38 +85,77 @@ func NewHCLogger(name string) hclog.Logger {
 	}
 
 	return hclog.NewInterceptLogger(&hclog.LoggerOptions{
-		Name:   name,
-		Level:  hclog.LevelFromString(logLevel),
-		Output: logOutput,
+		Name:              name,
+		Level:             logLevel,
+		Output:            logOutput,
+		IndependentLevels: true,
 	})
 }
 
-func NewProviderLogger() hclog.Logger {
-	return logger.Named("plugin")
+// NewLogger returns a new logger based in the current global logger, with the
+// given name appended.
+func NewLogger(name string) hclog.Logger {
+	if name == "" {
+		panic("logger name required")
+	}
+	return logger.Named(name)
+}
+
+// NewProviderLogger returns a logger for the provider plugin, possibly with a
+// different log level from the global logger.
+func NewProviderLogger(prefix string) hclog.Logger {
+	l := logger.Named(prefix + "provider")
+
+	level := providerLogLevel()
+	logger.Debug("created provider logger", "level", level)
+
+	l.SetLevel(level)
+	return l
 }
 
 // CurrentLogLevel returns the current log level string based the environment vars
 func CurrentLogLevel() string {
-	envLevel := strings.ToUpper(os.Getenv(EnvLog))
+	return strings.ToUpper(globalLogLevel().String())
+}
+
+func providerLogLevel() hclog.Level {
+	providerEnvLevel := strings.ToUpper(os.Getenv(envLogProvider))
+	if providerEnvLevel == "" {
+		providerEnvLevel = strings.ToUpper(os.Getenv(envLog))
+	}
+
+	return parseLogLevel(providerEnvLevel)
+}
+
+func globalLogLevel() hclog.Level {
+	envLevel := strings.ToUpper(os.Getenv(envLog))
+	if envLevel == "" {
+		envLevel = strings.ToUpper(os.Getenv(envLogCore))
+
+	}
+	return parseLogLevel(envLevel)
+}
+
+func parseLogLevel(envLevel string) hclog.Level {
 	if envLevel == "" {
-		return ""
+		return hclog.Off
 	}
 
-	logLevel := "TRACE"
+	logLevel := hclog.Trace
 	if isValidLogLevel(envLevel) {
-		logLevel = envLevel
+		logLevel = hclog.LevelFromString(envLevel)
 	} else {
-		logger.Warn(fmt.Sprintf("Invalid log level: %q. Defaulting to level: TRACE. Valid levels are: %+v",
-			envLevel, ValidLevels))
+		fmt.Fprintf(os.Stderr, "[WARN] Invalid log level: %q. Defaulting to level: TRACE. Valid levels are: %+v",
+			envLevel, ValidLevels)
 	}
 
 	return logLevel
 }
 
 // IsDebugOrHigher returns whether or not the current log level is debug or trace
 func IsDebugOrHigher() bool {
-	level := string(CurrentLogLevel())
-	return level == "DEBUG" || level == "TRACE"
+	level := globalLogLevel()
+	return level == hclog.Debug || level == hclog.Trace
 }
 
 func isValidLogLevel(level string) bool {

internal/logging/panic.go

@@ -5,7 +5,6 @@ import (
 	"io"
 	"io/ioutil"
 	"os"
-	"strings"
 
 	"github.com/mitchellh/panicwrap"
 )
@@ -67,6 +66,6 @@ func PanicHandler(tmpLogPath string) panicwrap.HandlerFunc {
 		// Tell the user a crash occurred in some helpful way that
 		// they'll hopefully notice.
 		fmt.Printf("\n\n")
-		fmt.Printf(strings.TrimSpace(panicOutput), f.Name())
+		fmt.Printf(panicOutput, f.Name())
 	}
 }

main.go

@@ -95,7 +95,6 @@ func wrappedMain() int {
 	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())

website/docs/commands/environment-variables.html.md

@@ -16,16 +16,16 @@ for debugging.
 
 ## TF_LOG
 
-If set to any value, enables detailed logs to appear on stderr which is useful for debugging. For example:
+Enables detailed logs to appear on stderr which is useful for debugging. For example:
 
 ```shell
-export TF_LOG=TRACE
+export TF_LOG=trace
 ```
 
-To disable, either unset it or set it to empty. When unset, logging will default to stderr. For example:
+To disable, either unset it, or set it to `off`. For example:
 
 ```shell
-export TF_LOG=
+export TF_LOG=off
 ```
 
 For more on debugging Terraform, check out the section on [Debugging](/docs/internals/debugging.html).

website/docs/internals/debugging.html.md

@@ -10,7 +10,11 @@ description: |-
 
 Terraform has detailed logs which can be enabled by setting the `TF_LOG` environment variable to any value. This will cause detailed logs to appear on stderr.
 
-You can set `TF_LOG` to one of the log levels `TRACE`, `DEBUG`, `INFO`, `WARN` or `ERROR` to change the verbosity of the logs. `TRACE` is the most verbose and it is the default if `TF_LOG` is set to something other than a log level name.
+You can set `TF_LOG` to one of the log levels `TRACE`, `DEBUG`, `INFO`, `WARN` or `ERROR` to change the verbosity of the logs.
+
+Logging can be enabled separately for terraform itself and the provider plugins
+using the `TF_LOG_CORE` or `TF_LOG_PROVIDER` environment variables. These take
+the same level arguments as `TF_LOG`, but only activate a subset of the logs.
 
 To persist logged output you can set `TF_LOG_PATH` in order to force the log to always be appended to a specific file when logging is enabled. Note that even when `TF_LOG_PATH` is set, `TF_LOG` must be set in order for any logging to be enabled.