2015-12-07 18:10:30 -06:00
|
|
|
package logging
|
2014-05-30 18:07:26 -05:00
|
|
|
|
|
|
|
import (
|
2020-10-17 08:38:18 -05:00
|
|
|
"fmt"
|
2014-05-30 18:07:26 -05:00
|
|
|
"io"
|
2015-10-01 14:45:12 -05:00
|
|
|
"log"
|
2014-05-30 18:07:26 -05:00
|
|
|
"os"
|
2015-10-01 14:45:12 -05:00
|
|
|
"strings"
|
2016-10-18 15:08:23 -05:00
|
|
|
"syscall"
|
2020-10-17 08:38:18 -05:00
|
|
|
|
2021-01-27 16:04:52 -06:00
|
|
|
// go.etcd.io/etcd imports capnslog, which calls log.SetOutput in its
|
|
|
|
// init() function, so importing it here means that our log.SetOutput
|
|
|
|
// wins. this is fixed in coreos v3.5, which is not released yet. See
|
|
|
|
// https://github.com/etcd-io/etcd/issues/12498 for more information.
|
|
|
|
_ "github.com/coreos/pkg/capnslog"
|
2020-10-17 08:38:18 -05:00
|
|
|
"github.com/hashicorp/go-hclog"
|
2014-05-30 18:07:26 -05:00
|
|
|
)
|
|
|
|
|
|
|
|
// These are the environmental variables that determine if we log, and if
|
|
|
|
// we log whether or not the log should go to a file.
|
2015-10-01 14:45:12 -05:00
|
|
|
const (
|
2020-10-22 14:32:13 -05:00
|
|
|
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"
|
2015-10-01 14:45:12 -05:00
|
|
|
)
|
2014-05-30 18:07:26 -05:00
|
|
|
|
2020-10-23 12:09:29 -05:00
|
|
|
var (
|
|
|
|
// ValidLevels are the log level names that Terraform recognizes.
|
|
|
|
ValidLevels = []string{"TRACE", "DEBUG", "INFO", "WARN", "ERROR", "OFF"}
|
2015-10-01 14:45:12 -05:00
|
|
|
|
2020-10-23 12:09:29 -05:00
|
|
|
// logger is the global hclog logger
|
|
|
|
logger hclog.Logger
|
2016-03-14 11:17:05 -05:00
|
|
|
|
2020-10-23 12:09:29 -05:00
|
|
|
// logWriter is a global writer for logs, to be used with the std log package
|
|
|
|
logWriter io.Writer
|
|
|
|
|
|
|
|
// initialize our cache of panic output from providers
|
|
|
|
panics = &panicRecorder{
|
|
|
|
panics: make(map[string][]string),
|
|
|
|
maxLines: 100,
|
|
|
|
}
|
|
|
|
)
|
2020-10-18 09:01:48 -05:00
|
|
|
|
2020-10-17 08:38:18 -05:00
|
|
|
func init() {
|
2020-10-22 14:32:13 -05:00
|
|
|
logger = newHCLogger("")
|
2020-10-18 09:01:48 -05:00
|
|
|
logWriter = logger.StandardWriter(&hclog.StandardLoggerOptions{InferLevels: true})
|
|
|
|
|
2021-01-26 13:39:11 -06:00
|
|
|
// set up the default std library logger to use our output
|
2020-10-18 09:01:48 -05:00
|
|
|
log.SetFlags(0)
|
|
|
|
log.SetPrefix("")
|
|
|
|
log.SetOutput(logWriter)
|
2020-10-17 08:57:03 -05:00
|
|
|
}
|
|
|
|
|
2020-10-21 13:57:46 -05:00
|
|
|
// 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,
|
|
|
|
}))
|
|
|
|
}
|
|
|
|
|
2020-10-18 09:01:48 -05:00
|
|
|
// LogOutput return the default global log io.Writer
|
|
|
|
func LogOutput() io.Writer {
|
|
|
|
return logWriter
|
2020-10-17 08:57:03 -05:00
|
|
|
}
|
|
|
|
|
2020-10-18 09:01:48 -05:00
|
|
|
// HCLogger returns the default global hclog logger
|
2020-10-17 08:57:03 -05:00
|
|
|
func HCLogger() hclog.Logger {
|
|
|
|
return logger
|
|
|
|
}
|
|
|
|
|
2020-10-22 14:32:13 -05:00
|
|
|
// newHCLogger returns a new hclog.Logger instance with the given name
|
|
|
|
func newHCLogger(name string) hclog.Logger {
|
2020-10-17 08:38:18 -05:00
|
|
|
logOutput := io.Writer(os.Stderr)
|
2021-03-16 16:59:15 -05:00
|
|
|
logLevel, json := globalLogLevel()
|
2015-10-01 14:45:12 -05:00
|
|
|
|
2020-10-22 14:32:13 -05:00
|
|
|
if logPath := os.Getenv(envLogFile); logPath != "" {
|
2020-10-17 08:38:18 -05:00
|
|
|
f, err := os.OpenFile(logPath, syscall.O_CREAT|syscall.O_RDWR|syscall.O_APPEND, 0666)
|
2015-10-01 14:45:12 -05:00
|
|
|
if err != nil {
|
2020-10-17 08:38:18 -05:00
|
|
|
fmt.Fprintf(os.Stderr, "Error opening log file: %v\n", err)
|
|
|
|
} else {
|
|
|
|
logOutput = f
|
2014-05-30 18:07:26 -05:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2020-10-21 13:57:46 -05:00
|
|
|
return hclog.NewInterceptLogger(&hclog.LoggerOptions{
|
2020-10-22 14:32:13 -05:00
|
|
|
Name: name,
|
|
|
|
Level: logLevel,
|
|
|
|
Output: logOutput,
|
|
|
|
IndependentLevels: true,
|
2021-03-16 16:59:15 -05:00
|
|
|
JSONFormat: json,
|
2020-10-17 08:38:18 -05:00
|
|
|
})
|
|
|
|
}
|
2019-12-05 14:19:22 -06:00
|
|
|
|
2020-10-22 14:32:13 -05:00
|
|
|
// 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")
|
|
|
|
}
|
2020-10-23 12:09:29 -05:00
|
|
|
return &logPanicWrapper{
|
|
|
|
Logger: logger.Named(name),
|
|
|
|
}
|
2020-10-22 14:32:13 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
// NewProviderLogger returns a logger for the provider plugin, possibly with a
|
|
|
|
// different log level from the global logger.
|
|
|
|
func NewProviderLogger(prefix string) hclog.Logger {
|
2020-10-23 12:09:29 -05:00
|
|
|
l := &logPanicWrapper{
|
|
|
|
Logger: logger.Named(prefix + "provider"),
|
|
|
|
}
|
2020-10-22 14:32:13 -05:00
|
|
|
|
|
|
|
level := providerLogLevel()
|
|
|
|
logger.Debug("created provider logger", "level", level)
|
|
|
|
|
|
|
|
l.SetLevel(level)
|
|
|
|
return l
|
2020-10-21 13:57:46 -05:00
|
|
|
}
|
|
|
|
|
2019-12-05 13:13:37 -06:00
|
|
|
// CurrentLogLevel returns the current log level string based the environment vars
|
|
|
|
func CurrentLogLevel() string {
|
2021-03-16 16:59:15 -05:00
|
|
|
ll, _ := globalLogLevel()
|
|
|
|
return strings.ToUpper(ll.String())
|
2020-10-22 14:32:13 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
func providerLogLevel() hclog.Level {
|
|
|
|
providerEnvLevel := strings.ToUpper(os.Getenv(envLogProvider))
|
|
|
|
if providerEnvLevel == "" {
|
|
|
|
providerEnvLevel = strings.ToUpper(os.Getenv(envLog))
|
|
|
|
}
|
|
|
|
|
|
|
|
return parseLogLevel(providerEnvLevel)
|
|
|
|
}
|
|
|
|
|
2021-03-16 16:59:15 -05:00
|
|
|
func globalLogLevel() (hclog.Level, bool) {
|
|
|
|
var json bool
|
2020-10-22 14:32:13 -05:00
|
|
|
envLevel := strings.ToUpper(os.Getenv(envLog))
|
|
|
|
if envLevel == "" {
|
|
|
|
envLevel = strings.ToUpper(os.Getenv(envLogCore))
|
|
|
|
}
|
2021-03-16 16:59:15 -05:00
|
|
|
if envLevel == "JSON" {
|
|
|
|
json = true
|
|
|
|
}
|
|
|
|
return parseLogLevel(envLevel), json
|
2020-10-22 14:32:13 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
func parseLogLevel(envLevel string) hclog.Level {
|
2016-03-14 11:17:05 -05:00
|
|
|
if envLevel == "" {
|
2020-10-22 14:32:13 -05:00
|
|
|
return hclog.Off
|
2016-03-14 11:17:05 -05:00
|
|
|
}
|
2021-03-16 16:59:15 -05:00
|
|
|
if envLevel == "JSON" {
|
|
|
|
envLevel = "TRACE"
|
|
|
|
}
|
2016-03-14 11:17:05 -05:00
|
|
|
|
2020-10-22 14:32:13 -05:00
|
|
|
logLevel := hclog.Trace
|
2015-10-01 14:45:12 -05:00
|
|
|
if isValidLogLevel(envLevel) {
|
2020-10-22 14:32:13 -05:00
|
|
|
logLevel = hclog.LevelFromString(envLevel)
|
2015-10-01 14:45:12 -05:00
|
|
|
} else {
|
2020-10-22 14:32:13 -05:00
|
|
|
fmt.Fprintf(os.Stderr, "[WARN] Invalid log level: %q. Defaulting to level: TRACE. Valid levels are: %+v",
|
|
|
|
envLevel, ValidLevels)
|
2019-12-05 13:49:11 -06:00
|
|
|
}
|
2015-10-01 14:45:12 -05:00
|
|
|
|
2016-03-14 11:17:05 -05:00
|
|
|
return logLevel
|
|
|
|
}
|
2015-10-01 14:45:12 -05:00
|
|
|
|
2016-03-14 11:17:05 -05:00
|
|
|
// IsDebugOrHigher returns whether or not the current log level is debug or trace
|
|
|
|
func IsDebugOrHigher() bool {
|
2021-03-16 16:59:15 -05:00
|
|
|
level, _ := globalLogLevel()
|
2020-10-22 14:32:13 -05:00
|
|
|
return level == hclog.Debug || level == hclog.Trace
|
2014-05-30 18:07:26 -05:00
|
|
|
}
|
2015-10-01 14:45:12 -05:00
|
|
|
|
|
|
|
func isValidLogLevel(level string) bool {
|
2017-10-14 08:35:36 -05:00
|
|
|
for _, l := range ValidLevels {
|
2020-10-17 08:38:18 -05:00
|
|
|
if level == string(l) {
|
2015-10-01 14:45:12 -05:00
|
|
|
return true
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
return false
|
|
|
|
}
|
2021-05-13 14:59:51 -05:00
|
|
|
|
|
|
|
// PluginOutputMonitor creates an io.Writer that will warn about any writes in
|
|
|
|
// the default logger. This is used to catch unexpected output from plugins,
|
|
|
|
// notifying them about the problem as well as surfacing the lost data for
|
|
|
|
// context.
|
|
|
|
func PluginOutputMonitor(source string) io.Writer {
|
|
|
|
return pluginOutputMonitor{
|
|
|
|
source: source,
|
|
|
|
log: logger,
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
// pluginOutputMonitor is an io.Writer that logs all writes as
|
|
|
|
// "unexpected data" with the source name.
|
|
|
|
type pluginOutputMonitor struct {
|
|
|
|
source string
|
|
|
|
log hclog.Logger
|
|
|
|
}
|
|
|
|
|
|
|
|
func (w pluginOutputMonitor) Write(d []byte) (int, error) {
|
|
|
|
// Limit the write size to 1024 bytes We're not expecting any data to come
|
|
|
|
// through this channel, so accidental writes will usually be stray fmt
|
|
|
|
// debugging statements and the like, but we want to provide context to the
|
|
|
|
// provider to indicate what the unexpected data might be.
|
|
|
|
n := len(d)
|
|
|
|
if n > 1024 {
|
|
|
|
d = append(d[:1024], '.', '.', '.')
|
|
|
|
}
|
|
|
|
|
|
|
|
w.log.Warn("unexpected data", w.source, strings.TrimSpace(string(d)))
|
|
|
|
return n, nil
|
|
|
|
}
|