Merge pull request #8540 from hashicorp/dnephin/logging-setup-cleanup

logging: cleanup Setup and configuration

agent/agent.go

@@ -23,7 +23,6 @@ import (
 	"github.com/hashicorp/go-memdb"
 
 	"google.golang.org/grpc"
-	"google.golang.org/grpc/grpclog"
 
 	"github.com/armon/go-metrics"
 	"github.com/hashicorp/consul/acl"
@@ -354,9 +353,6 @@ func New(bd BaseDeps) (*Agent, error) {
 		autoConf:        bd.AutoConfig,
 	}
 
-	// TODO: set globals somewhere else, not Agent.New
-	grpclog.SetLoggerV2(logging.NewGRPCLogger(bd.RuntimeConfig.LogLevel, bd.Logger))
-
 	a.serviceManager = NewServiceManager(&a)
 
 	// TODO: do this somewhere else, maybe move to newBaseDeps
@@ -3666,11 +3662,11 @@ func (a *Agent) ReloadConfig() error {
 // runtime configuration and applies it.
 func (a *Agent) reloadConfigInternal(newCfg *config.RuntimeConfig) error {
 	// Change the log level and update it
-	if logging.ValidateLogLevel(newCfg.LogLevel) {
+	if logging.ValidateLogLevel(newCfg.Logging.LogLevel) {
-		a.logger.SetLevel(logging.LevelFromString(newCfg.LogLevel))
+		a.logger.SetLevel(logging.LevelFromString(newCfg.Logging.LogLevel))
 	} else {
-		a.logger.Warn("Invalid log level in new configuration", "level", newCfg.LogLevel)
+		a.logger.Warn("Invalid log level in new configuration", "level", newCfg.Logging.LogLevel)
-		newCfg.LogLevel = a.config.LogLevel
+		newCfg.Logging.LogLevel = a.config.Logging.LogLevel
 	}
 
 	// Bulk update the services and checks

agent/config/builder.go

@@ -25,6 +25,7 @@ import (
 	"github.com/hashicorp/consul/ipaddr"
 	"github.com/hashicorp/consul/lib"
 	libtempl "github.com/hashicorp/consul/lib/template"
+	"github.com/hashicorp/consul/logging"
 	"github.com/hashicorp/consul/tlsutil"
 	"github.com/hashicorp/consul/types"
 	"github.com/hashicorp/go-bexpr"
@@ -971,7 +972,7 @@ func (b *Builder) Build() (rt RuntimeConfig, err error) {
 		EnableDebug:                            b.boolVal(c.EnableDebug),
 		EnableRemoteScriptChecks:               enableRemoteScriptChecks,
 		EnableLocalScriptChecks:                enableLocalScriptChecks,
-		EnableSyslog:                           b.boolVal(c.EnableSyslog),
+
 		EnableUI:              b.boolVal(c.UI),
 		EncryptKey:            b.stringVal(c.EncryptKey),
 		EncryptVerifyIncoming: b.boolVal(c.EncryptVerifyIncoming),
@@ -984,12 +985,16 @@ func (b *Builder) Build() (rt RuntimeConfig, err error) {
 		KVMaxValueSize:        b.uint64Val(c.Limits.KVMaxValueSize),
 		LeaveDrainTime:        b.durationVal("performance.leave_drain_time", c.Performance.LeaveDrainTime),
 		LeaveOnTerm:           leaveOnTerm,
+		Logging: logging.Config{
 			LogLevel:          b.stringVal(c.LogLevel),
 			LogJSON:           b.boolVal(c.LogJSON),
-		LogFile:                                b.stringVal(c.LogFile),
+			LogFilePath:       b.stringVal(c.LogFile),
-		LogRotateBytes:                         b.intVal(c.LogRotateBytes),
+			EnableSyslog:      b.boolVal(c.EnableSyslog),
+			SyslogFacility:    b.stringVal(c.SyslogFacility),
 			LogRotateDuration: b.durationVal("log_rotate_duration", c.LogRotateDuration),
+			LogRotateBytes:    b.intVal(c.LogRotateBytes),
 			LogRotateMaxFiles: b.intVal(c.LogRotateMaxFiles),
+		},
 		MaxQueryTime:                b.durationVal("max_query_time", c.MaxQueryTime),
 		NodeID:                      types.NodeID(b.stringVal(c.NodeID)),
 		NodeMeta:                    c.NodeMeta,
@@ -1038,7 +1043,6 @@ func (b *Builder) Build() (rt RuntimeConfig, err error) {
 		SkipLeaveOnInt:              skipLeaveOnInt,
 		StartJoinAddrsLAN:           b.expandAllOptionalAddrs("start_join", c.StartJoinAddrsLAN),
 		StartJoinAddrsWAN:           b.expandAllOptionalAddrs("start_join_wan", c.StartJoinAddrsWAN),
-		SyslogFacility:                         b.stringVal(c.SyslogFacility),
 		TLSCipherSuites:             b.tlsCipherSuites("tls_cipher_suites", c.TLSCipherSuites),
 		TLSMinVersion:               b.stringVal(c.TLSMinVersion),
 		TLSPreferServerCipherSuites: b.boolVal(c.TLSPreferServerCipherSuites),

agent/config/runtime.go

@@ -11,6 +11,7 @@ import (
 	"github.com/hashicorp/consul/agent/structs"
 	"github.com/hashicorp/consul/api"
 	"github.com/hashicorp/consul/lib"
+	"github.com/hashicorp/consul/logging"
 	"github.com/hashicorp/consul/tlsutil"
 	"github.com/hashicorp/consul/types"
 	"github.com/hashicorp/go-uuid"
@@ -724,13 +725,6 @@ type RuntimeConfig struct {
 	// flag: -enable-script-checks
 	EnableRemoteScriptChecks bool
 
-	// EnableSyslog is used to also tee all the logs over to syslog. Only supported
-	// on linux and OSX. Other platforms will generate an error.
-	//
-	// hcl: enable_syslog = (true|false)
-	// flag: -syslog
-	EnableSyslog bool
-
 	// EnableUI enables the statically-compiled assets for the Consul web UI and
 	// serves them at the default /ui/ endpoint automatically.
 	//
@@ -858,40 +852,8 @@ type RuntimeConfig struct {
 	// hcl: leave_on_terminate = (true|false)
 	LeaveOnTerm bool
 
-	// LogLevel is the level of the logs to write. Defaults to "INFO".
+	// Logging configuration used to initialize agent logging.
-	//
+	Logging logging.Config
-	// hcl: log_level = string
-	LogLevel string
-
-	// LogJSON controls whether to output logs as structured JSON. Defaults to false.
-	//
-	// hcl: log_json = (true|false)
-	// flag: -log-json
-	LogJSON bool
-
-	// LogFile is the path to the file where the logs get written to. Defaults to empty string.
-	//
-	// hcl: log_file = string
-	// flags: -log-file string
-	LogFile string
-
-	// LogRotateDuration is the time configured to rotate logs based on time
-	//
-	// hcl: log_rotate_duration = string
-	// flags: -log-rotate-duration string
-	LogRotateDuration time.Duration
-
-	// LogRotateBytes is the time configured to rotate logs based on bytes written
-	//
-	// hcl: log_rotate_bytes = int
-	// flags: -log-rotate-bytes int
-	LogRotateBytes int
-
-	// LogRotateMaxFiles is the maximum number of log file archives to keep
-	//
-	// hcl: log_rotate_max_files = int
-	// flags: -log-rotate-max-files int
-	LogRotateMaxFiles int
 
 	// MaxQueryTime is the maximum amount of time a blocking query can wait
 	// before Consul will force a response. Consul applies jitter to the wait
@@ -1422,12 +1384,6 @@ type RuntimeConfig struct {
 	// flag: -join-wan string -join-wan string
 	StartJoinAddrsWAN []string
 
-	// SyslogFacility is used to control where the syslog messages go
-	// By default, goes to LOCAL0
-	//
-	// hcl: syslog_facility = string
-	SyslogFacility string
-
 	// TLSCipherSuites is used to specify the list of supported ciphersuites.
 	//
 	// The values should be a list of the following values:

agent/config/runtime_test.go

@@ -22,6 +22,7 @@ import (
 	"github.com/hashicorp/consul/agent/checks"
 	"github.com/hashicorp/consul/agent/structs"
 	"github.com/hashicorp/consul/lib"
+	"github.com/hashicorp/consul/logging"
 	"github.com/hashicorp/consul/sdk/testutil"
 	"github.com/hashicorp/consul/types"
 	"github.com/stretchr/testify/require"
@@ -288,7 +289,7 @@ func TestBuilder_BuildAndValide_ConfigFlagsAndEdgecases(t *testing.T) {
 				rt.EnableDebug = true
 				rt.EnableUI = true
 				rt.LeaveOnTerm = false
-				rt.LogLevel = "DEBUG"
+				rt.Logging.LogLevel = "DEBUG"
 				rt.RPCAdvertiseAddr = tcpAddr("127.0.0.1:8300")
 				rt.RPCBindAddr = tcpAddr("127.0.0.1:8300")
 				rt.SerfAdvertiseAddrLAN = tcpAddr("127.0.0.1:8301")
@@ -533,7 +534,7 @@ func TestBuilder_BuildAndValide_ConfigFlagsAndEdgecases(t *testing.T) {
 				`-data-dir=` + dataDir,
 			},
 			patch: func(rt *RuntimeConfig) {
-				rt.LogLevel = "a"
+				rt.Logging.LogLevel = "a"
 				rt.DataDir = dataDir
 			},
 		},
@@ -544,7 +545,7 @@ func TestBuilder_BuildAndValide_ConfigFlagsAndEdgecases(t *testing.T) {
 				`-data-dir=` + dataDir,
 			},
 			patch: func(rt *RuntimeConfig) {
-				rt.LogJSON = true
+				rt.Logging.LogJSON = true
 				rt.DataDir = dataDir
 			},
 		},
@@ -557,7 +558,7 @@ func TestBuilder_BuildAndValide_ConfigFlagsAndEdgecases(t *testing.T) {
 			json: []string{`{ "log_rotate_max_files": 2 }`},
 			hcl:  []string{`log_rotate_max_files = 2`},
 			patch: func(rt *RuntimeConfig) {
-				rt.LogRotateMaxFiles = 2
+				rt.Logging.LogRotateMaxFiles = 2
 				rt.DataDir = dataDir
 			},
 		},
@@ -835,7 +836,7 @@ func TestBuilder_BuildAndValide_ConfigFlagsAndEdgecases(t *testing.T) {
 				`-data-dir=` + dataDir,
 			},
 			patch: func(rt *RuntimeConfig) {
-				rt.EnableSyslog = true
+				rt.Logging.EnableSyslog = true
 				rt.DataDir = dataDir
 			},
 		},
@@ -6053,7 +6054,6 @@ func TestFullConfig(t *testing.T) {
 		EnableDebug:                            true,
 		EnableRemoteScriptChecks:               true,
 		EnableLocalScriptChecks:                true,
-		EnableSyslog:                           true,
 		EnableUI:                               true,
 		EncryptKey:                             "A4wELWqH",
 		EncryptVerifyIncoming:                  true,
@@ -6074,8 +6074,12 @@ func TestFullConfig(t *testing.T) {
 		KVMaxValueSize:                         1234567800000000,
 		LeaveDrainTime:                         8265 * time.Second,
 		LeaveOnTerm:                            true,
+		Logging: logging.Config{
 			LogLevel:       "k1zo9Spt",
 			LogJSON:        true,
+			EnableSyslog:   true,
+			SyslogFacility: "hHv79Uia",
+		},
 		MaxQueryTime:            18237 * time.Second,
 		NodeID:                  types.NodeID("AsUIlw99"),
 		NodeMeta:                map[string]string{"5mgGQMBk": "mJLtVMSG", "A7ynFMJB": "0Nx6RGab"},
@@ -6411,7 +6415,6 @@ func TestFullConfig(t *testing.T) {
 		SkipLeaveOnInt:       true,
 		StartJoinAddrsLAN:    []string{"LR3hGDoG", "MwVpZ4Up"},
 		StartJoinAddrsWAN:    []string{"EbFSc3nA", "kwXTh623"},
-		SyslogFacility:       "hHv79Uia",
 		Telemetry: lib.TelemetryConfig{
 			CirconusAPIApp:                     "p4QOTe9j",
 			CirconusAPIToken:                   "E3j35V23",
@@ -6941,7 +6944,6 @@ func TestSanitize(t *testing.T) {
 		"EnableCentralServiceConfig": false,
 		"EnableLocalScriptChecks": false,
 		"EnableRemoteScriptChecks": false,
-		"EnableSyslog": false,
 		"EnableUI": false,
 		"EncryptKey": "hidden",
 		"EncryptVerifyIncoming": false,
@@ -6967,12 +6969,17 @@ func TestSanitize(t *testing.T) {
 		"KVMaxValueSize": 1234567800000000,
 		"LeaveDrainTime": "0s",
 		"LeaveOnTerm": false,
+		"Logging": {
+			"EnableSyslog": false,
 			"LogLevel": "",
 			"LogJSON": false,
-		"LogFile": "",
+			"LogFilePath": "",
 			"LogRotateBytes": 0,
 			"LogRotateDuration": "0s",
 			"LogRotateMaxFiles": 0,
+			"Name": "",
+			"SyslogFacility": ""
+		},
 		"MaxQueryTime": "0s",
 		"NodeID": "",
 		"NodeMeta": {},
@@ -7079,7 +7086,6 @@ func TestSanitize(t *testing.T) {
 		"StartJoinAddrsWAN": [],
 		"SyncCoordinateIntervalMin": "0s",
 		"SyncCoordinateRateTarget": 0,
-		"SyslogFacility": "",
 		"TLSCipherSuites": [],
 		"TLSMinVersion": "",
 		"TLSPreferServerCipherSuites": false,

agent/setup.go

@@ -20,6 +20,7 @@ import (
 	"github.com/hashicorp/consul/logging"
 	"github.com/hashicorp/consul/tlsutil"
 	"github.com/hashicorp/go-hclog"
+	"google.golang.org/grpc/grpclog"
 )
 
 // TODO: BaseDeps should be renamed in the future once more of Agent.Start
@@ -50,22 +51,13 @@ func NewBaseDeps(configLoader ConfigLoader, logOut io.Writer) (BaseDeps, error)
 		return d, err
 	}
 
-	// TODO: use logging.Config in RuntimeConfig instead of separate fields
+	logConf := cfg.Logging
-	logConf := &logging.Config{
+	logConf.Name = logging.Agent
-		LogLevel:          cfg.LogLevel,
+	d.Logger, err = logging.Setup(logConf, logOut)
-		LogJSON:           cfg.LogJSON,
-		Name:              logging.Agent,
-		EnableSyslog:      cfg.EnableSyslog,
-		SyslogFacility:    cfg.SyslogFacility,
-		LogFilePath:       cfg.LogFile,
-		LogRotateDuration: cfg.LogRotateDuration,
-		LogRotateBytes:    cfg.LogRotateBytes,
-		LogRotateMaxFiles: cfg.LogRotateMaxFiles,
-	}
-	d.Logger, err = logging.Setup(logConf, []io.Writer{logOut})
 	if err != nil {
 		return d, err
 	}
+	grpclog.SetLoggerV2(logging.NewGRPCLogger(cfg.Logging.LogLevel, d.Logger))
 
 	for _, w := range warnings {
 		d.Logger.Warn(w)

command/agent/agent.go

@@ -181,7 +181,7 @@ func (c *cmd) run(args []string) int {
 
 	// Setup gate to check if we should output CLI information
 	cli := GatedUi{
-		JSONoutput: config.LogJSON,
+		JSONoutput: config.Logging.LogJSON,
 		ui:         c.UI,
 	}
 

command/connect/proxy/proxy.go

@@ -3,7 +3,6 @@ package proxy
 import (
 	"flag"
 	"fmt"
-	"io"
 	"log"
 	"net"
 	"net/http"
@@ -132,7 +131,7 @@ func (c *cmd) Run(args []string) int {
 	}
 
 	// Setup the log outputs
-	logConfig := &logging.Config{
+	logConfig := logging.Config{
 		LogLevel: c.logLevel,
 		Name:     logging.Proxy,
 		LogJSON:  c.logJSON,
@@ -140,7 +139,7 @@ func (c *cmd) Run(args []string) int {
 
 	logGate := logging.GatedWriter{Writer: &cli.UiWriter{Ui: c.UI}}
 
-	logger, err := logging.Setup(logConfig, []io.Writer{&logGate})
+	logger, err := logging.Setup(logConfig, &logGate)
 	if err != nil {
 		c.UI.Error(err.Error())
 		return 1

logging/grpc.go

@@ -17,7 +17,7 @@ type GRPCLogger struct {
 // logger with Severity/Verbosity level appropriate for the given config.
 //
 // Note that grpclog has Info, Warning, Error, Fatal severity levels AND integer
-// verbosity levels for additional info. Verbose logs in glog are always INFO
+// verbosity levels for additional info. Verbose logs in hclog are always DEBUG
 // severity so we map Info,V0 to INFO, Info,V1 to DEBUG, and Info,V>1 to TRACE.
 func NewGRPCLogger(logLevel string, logger hclog.Logger) *GRPCLogger {
 	return &GRPCLogger{

logging/logger.go

@@ -52,34 +52,25 @@ var (
 
 type LogSetupErrorFn func(string)
 
-// Setup is used to perform setup of several logging objects:
+// Setup logging from Config, and return an hclog Logger.
 //
-// * A hclog.Logger is used to perform filtering by log level and write to io.Writer.
+// Logs may be written to out, and optionally to syslog, and a file.
-// * A GatedWriter is used to buffer logs until startup UI operations are
+func Setup(config Config, out io.Writer) (hclog.InterceptLogger, error) {
-//   complete. After this is flushed then logs flow directly to output
-//   destinations.
-// * An io.Writer is provided as the sink for all logs to flow to.
-//
-// The provided ui object will get any log messages related to setting up
-// logging itself, and will also be hooked up to the gated logger. The final bool
-// parameter indicates if logging was set up successfully.
-// TODO: accept a single io.Writer
-func Setup(config *Config, writers []io.Writer) (hclog.InterceptLogger, error) {
 	if !ValidateLogLevel(config.LogLevel) {
 		return nil, fmt.Errorf("Invalid log level: %s. Valid log levels are: %v",
 			config.LogLevel,
 			allowedLogLevels)
 	}
 
-	// Set up syslog if it's enabled.
+	writers := []io.Writer{out}
-	var syslog io.Writer
+
 	if config.EnableSyslog {
 		retries := 12
 		delay := 5 * time.Second
 		for i := 0; i <= retries; i++ {
-			l, err := gsyslog.NewLogger(gsyslog.LOG_NOTICE, config.SyslogFacility, "consul")
+			syslog, err := gsyslog.NewLogger(gsyslog.LOG_NOTICE, config.SyslogFacility, "consul")
 			if err == nil {
-				syslog = &SyslogWrapper{l}
+				writers = append(writers, syslog)
 				break
 			}
 
@@ -92,10 +83,6 @@ func Setup(config *Config, writers []io.Writer) (hclog.InterceptLogger, error) {
 		}
 	}
 
-	if syslog != nil {
-		writers = append(writers, syslog)
-	}
-
 	// Create a file logger if the user has specified the path to the log file
 	if config.LogFilePath != "" {
 		dir, fileName := filepath.Split(config.LogFilePath)

logging/logger_test.go

@@ -4,7 +4,6 @@ import (
 	"bytes"
 	"encoding/json"
 	"errors"
-	"io"
 	"os"
 	"testing"
 
@@ -15,9 +14,7 @@ import (
 func TestLogger_SetupBasic(t *testing.T) {
 	t.Parallel()
 	require := require.New(t)
-	cfg := &Config{
+	cfg := Config{LogLevel: "INFO"}
-		LogLevel: "INFO",
-	}
 
 	logger, err := Setup(cfg, nil)
 	require.NoError(err)
@@ -26,7 +23,7 @@ func TestLogger_SetupBasic(t *testing.T) {
 
 func TestLogger_SetupInvalidLogLevel(t *testing.T) {
 	t.Parallel()
-	cfg := &Config{}
+	cfg := Config{}
 
 	_, err := Setup(cfg, nil)
 	testutil.RequireErrorContains(t, err, "Invalid log level")
@@ -61,7 +58,7 @@ func TestLogger_SetupLoggerErrorLevel(t *testing.T) {
 			require := require.New(t)
 			var buf bytes.Buffer
 
-			logger, err := Setup(&cfg, []io.Writer{&buf})
+			logger, err := Setup(cfg, &buf)
 			require.NoError(err)
 			require.NotNil(logger)
 
@@ -79,12 +76,10 @@ func TestLogger_SetupLoggerErrorLevel(t *testing.T) {
 func TestLogger_SetupLoggerDebugLevel(t *testing.T) {
 	t.Parallel()
 	require := require.New(t)
-	cfg := &Config{
+	cfg := Config{LogLevel: "DEBUG"}
-		LogLevel: "DEBUG",
-	}
 	var buf bytes.Buffer
 
-	logger, err := Setup(cfg, []io.Writer{&buf})
+	logger, err := Setup(cfg, &buf)
 	require.NoError(err)
 	require.NotNil(logger)
 
@@ -100,13 +95,13 @@ func TestLogger_SetupLoggerDebugLevel(t *testing.T) {
 func TestLogger_SetupLoggerWithName(t *testing.T) {
 	t.Parallel()
 	require := require.New(t)
-	cfg := &Config{
+	cfg := Config{
 		LogLevel: "DEBUG",
 		Name:     "test-system",
 	}
 	var buf bytes.Buffer
 
-	logger, err := Setup(cfg, []io.Writer{&buf})
+	logger, err := Setup(cfg, &buf)
 	require.NoError(err)
 	require.NotNil(logger)
 
@@ -118,14 +113,14 @@ func TestLogger_SetupLoggerWithName(t *testing.T) {
 func TestLogger_SetupLoggerWithJSON(t *testing.T) {
 	t.Parallel()
 	require := require.New(t)
-	cfg := &Config{
+	cfg := Config{
 		LogLevel: "DEBUG",
 		LogJSON:  true,
 		Name:     "test-system",
 	}
 	var buf bytes.Buffer
 
-	logger, err := Setup(cfg, []io.Writer{&buf})
+	logger, err := Setup(cfg, &buf)
 	require.NoError(err)
 	require.NotNil(logger)
 
@@ -146,13 +141,13 @@ func TestLogger_SetupLoggerWithValidLogPath(t *testing.T) {
 
 	tmpDir := testutil.TempDir(t, t.Name())
 
-	cfg := &Config{
+	cfg := Config{
 		LogLevel:    "INFO",
 		LogFilePath: tmpDir + "/",
 	}
 	var buf bytes.Buffer
 
-	logger, err := Setup(cfg, []io.Writer{&buf})
+	logger, err := Setup(cfg, &buf)
 	require.NoError(err)
 	require.NotNil(logger)
 }
@@ -161,13 +156,13 @@ func TestLogger_SetupLoggerWithInValidLogPath(t *testing.T) {
 	t.Parallel()
 	require := require.New(t)
 
-	cfg := &Config{
+	cfg := Config{
 		LogLevel:    "INFO",
 		LogFilePath: "nonexistentdir/",
 	}
 	var buf bytes.Buffer
 
-	logger, err := Setup(cfg, []io.Writer{&buf})
+	logger, err := Setup(cfg, &buf)
 	require.Error(err)
 	require.True(errors.Is(err, os.ErrNotExist))
 	require.Nil(logger)
@@ -182,13 +177,13 @@ func TestLogger_SetupLoggerWithInValidLogPathPermission(t *testing.T) {
 	os.Mkdir(tmpDir, 0000)
 	defer os.RemoveAll(tmpDir)
 
-	cfg := &Config{
+	cfg := Config{
 		LogLevel:    "INFO",
 		LogFilePath: tmpDir + "/",
 	}
 	var buf bytes.Buffer
 
-	logger, err := Setup(cfg, []io.Writer{&buf})
+	logger, err := Setup(cfg, &buf)
 	require.Error(err)
 	require.True(errors.Is(err, os.ErrPermission))
 	require.Nil(logger)