diff --git a/cmd/activator/main.go b/cmd/activator/main.go index e6ce107c9843..565db92eef43 100644 --- a/cmd/activator/main.go +++ b/cmd/activator/main.go @@ -103,7 +103,11 @@ func (a *activationHandler) handler(w http.ResponseWriter, r *http.Request) { func main() { flag.Parse() - logger := logging.NewLoggerFromDefaultConfigMap("loglevel.activator").Named("activator") + + var logger *zap.SugaredLogger + if logger, err := logging.NewDefaultConfigMapLogger(logging.DefaultLoggingConfigPath, "activator"); err != nil { + logger.Errorf("Error initializing logger: %s", err) + } defer logger.Sync() logger.Info("Starting the knative activator") diff --git a/cmd/autoscaler/main.go b/cmd/autoscaler/main.go index 98ca51587fab..58a91a8984be 100644 --- a/cmd/autoscaler/main.go +++ b/cmd/autoscaler/main.go @@ -230,7 +230,11 @@ func handler(w http.ResponseWriter, r *http.Request) { func main() { flag.Parse() - logger = logging.NewLoggerFromDefaultConfigMap("loglevel.autoscaler").Named("autoscaler") + + var logger *zap.SugaredLogger + if logger, err := logging.NewDefaultConfigMapLogger(logging.DefaultLoggingConfigPath, "autoscaler"); err != nil { + logger.Errorf("Error initializing logger: %s", err) + } defer logger.Sync() initEnv() diff --git a/cmd/controller/main.go b/cmd/controller/main.go index f8150ef0ce0c..a5cff02ae98a 100644 --- a/cmd/controller/main.go +++ b/cmd/controller/main.go @@ -22,6 +22,7 @@ import ( "github.com/knative/serving/pkg" "github.com/knative/serving/pkg/configmap" + "go.uber.org/zap" "github.com/josephburnett/k8sflag/pkg/k8sflag" "github.com/knative/serving/pkg/controller" @@ -76,7 +77,11 @@ var ( func main() { flag.Parse() - logger := logging.NewLoggerFromDefaultConfigMap("loglevel.controller").Named("controller") + + var logger *zap.SugaredLogger + if logger, err := logging.NewDefaultConfigMapLogger(logging.DefaultLoggingConfigPath, "controller"); err != nil { + logger.Errorf("Error initializing logger: %s", err) + } defer logger.Sync() if loggingEnableVarLogCollection.Get() { diff --git a/cmd/queue/main.go b/cmd/queue/main.go index fa2d88e11e89..f9ab0b2fc5a4 100644 --- a/cmd/queue/main.go +++ b/cmd/queue/main.go @@ -262,9 +262,20 @@ func setupAdminHandlers(server *http.Server) { server.ListenAndServe() } +func initializeLogging() *zap.SugaredLogger { + configJSON := os.Getenv("SERVING_LOGGING_CONFIG") + levelOverride := os.Getenv("SERVING_LOGGING_LEVEL") + genericLogger, err := logging.NewLogger(configJSON, levelOverride) + logger = genericLogger.Named("queueproxy") + if err != nil { + logger.Errorf("Error initializing logger: %s", err) + } + return logger +} + func main() { flag.Parse() - logger = logging.NewLogger(os.Getenv("SERVING_LOGGING_CONFIG"), os.Getenv("SERVING_LOGGING_LEVEL")).Named("queueproxy") + logger = initializeLogging() defer logger.Sync() initEnv() diff --git a/cmd/webhook/main.go b/cmd/webhook/main.go index 050d6f99d04c..fb90599173e3 100644 --- a/cmd/webhook/main.go +++ b/cmd/webhook/main.go @@ -31,7 +31,11 @@ import ( func main() { flag.Parse() - logger := logging.NewLoggerFromDefaultConfigMap("loglevel.webhook").Named("webhook") + + var logger *zap.SugaredLogger + if logger, err := logging.NewDefaultConfigMapLogger(logging.DefaultLoggingConfigPath, "webhook"); err != nil { + logger.Errorf("Error initializing logger: %s", err) + } defer logger.Sync() logger.Info("Starting the Configuration Webhook") diff --git a/pkg/logging/config.go b/pkg/logging/config.go index 6e2177bbee6f..d265aa820129 100644 --- a/pkg/logging/config.go +++ b/pkg/logging/config.go @@ -19,21 +19,25 @@ package logging import ( "encoding/json" "errors" + "fmt" - "github.com/knative/serving/pkg/logging/logkey" "github.com/josephburnett/k8sflag/pkg/k8sflag" "go.uber.org/zap" "go.uber.org/zap/zapcore" ) +// DefaultLoggingConfigPath is the path where the zap logging +// config will be written in a default Knative deployment. +const DefaultLoggingConfigPath = "/etc/config-logging" + // NewLogger creates a logger with the supplied configuration. // If configuration is empty, a fallback configuration is used. // If configuration cannot be used to instantiate a logger, // the same fallback configuration is used. -func NewLogger(configJSON string, levelOverride string) *zap.SugaredLogger { +func NewLogger(configJSON string, levelOverride string) (*zap.SugaredLogger, error) { logger, err := newLoggerFromConfig(configJSON, levelOverride) if err == nil { - return logger.Sugar() + return logger.Sugar(), nil } logger, err2 := zap.NewProduction() @@ -41,16 +45,23 @@ func NewLogger(configJSON string, levelOverride string) *zap.SugaredLogger { panic(err2) } - logger.Error("Failed to parse the logging config. Falling back to default logger.", zap.Error(err), zap.String(logkey.JSONConfig, configJSON)) - return logger.Sugar() + return logger.Sugar(), fmt.Errorf("Failed to parse the logging config. Falling back to default logger. Error: %s. Config: %s", err, configJSON) } -// NewLoggerFromDefaultConfigMap creates a logger using the configuration within /etc/config-logging file. -func NewLoggerFromDefaultConfigMap(logLevelKey string) *zap.SugaredLogger { - loggingFlagSet := k8sflag.NewFlagSet("/etc/config-logging") +// NewDefaultConfigMapLogger creates a logging object for the +// for the logLevelKey within configPath corresponding +// to the provided componentKey. +func NewDefaultConfigMapLogger(configPath string, componentKey string) (*zap.SugaredLogger, error) { + logLevelKey := "loglevel." + componentKey + + loggingFlagSet := k8sflag.NewFlagSet(configPath) + fmt.Println(loggingFlagSet) zapCfg := loggingFlagSet.String("zap-logger-config", "") zapLevelOverride := loggingFlagSet.String(logLevelKey, "") - return NewLogger(zapCfg.Get(), zapLevelOverride.Get()) + + genericLogger, err := NewLogger(zapCfg.Get(), zapLevelOverride.Get()) + logger := genericLogger.Named(componentKey) + return logger, err } func newLoggerFromConfig(configJSON string, levelOverride string) (*zap.Logger, error) { @@ -65,6 +76,7 @@ func newLoggerFromConfig(configJSON string, levelOverride string) (*zap.Logger, if len(levelOverride) > 0 { var level zapcore.Level + // If the levelOverride can't be parsed, we just ignore it and continue. if err := level.Set(levelOverride); err == nil { loggingCfg.Level = zap.NewAtomicLevelAt(level) } @@ -75,7 +87,5 @@ func newLoggerFromConfig(configJSON string, levelOverride string) (*zap.Logger, return nil, err } - logger.Info("Successfully created the logger.", zap.String(logkey.JSONConfig, configJSON)) - logger.Sugar().Infof("Logging level set to %v", loggingCfg.Level) - return logger, nil + return logger, err } diff --git a/pkg/logging/config_test.go b/pkg/logging/config_test.go index fe39e7b518e8..a2e340c2cca3 100644 --- a/pkg/logging/config_test.go +++ b/pkg/logging/config_test.go @@ -17,25 +17,74 @@ limitations under the License. package logging import ( + "fmt" + "io/ioutil" + "os" + "path/filepath" "testing" "go.uber.org/zap" ) -func TestNewLogger(t *testing.T) { - logger := NewLogger("", "") +const completeConfig = `{ + "level": "info", + "development": false, + "sampling": { + "initial": 100, + "thereafter": 100 + }, + "outputPaths": ["stdout"], + "errorOutputPaths": ["stderr"], + "encoding": "json", + "encoderConfig": { + "timeKey": "", + "levelKey": "level", + "nameKey": "logger", + "callerKey": "caller", + "messageKey": "msg", + "stacktraceKey": "stacktrace", + "lineEnding": "", + "levelEncoder": "", + "timeEncoder": "", + "durationEncoder": "", + "callerEncoder": "" + } +}` +const minimalConfigTemplate = `{ + "level": "%s", + "outputPaths": ["stdout"], + "errorOutputPaths": ["stderr"], + "encoding": "json" +}` + +func TestNewLoggerEmptyConfig(t *testing.T) { + logger, err := NewLogger("", "") + if err == nil { + t.Error("expected error when providing empty config") + } if logger == nil { t.Error("expected a non-nil logger") } +} - logger = NewLogger("some invalid JSON here", "") +func TestNewLoggerInvalidJson(t *testing.T) { + logger, err := NewLogger("some invalid JSON here", "") + if err == nil { + t.Error("expected error when providing invalid config") + } if logger == nil { t.Error("expected a non-nil logger") } +} +func TestNewLoggerValidErrorConfig(t *testing.T) { // No good way to test if all the config is applied, // but at the minimum, we can check and see if level is getting applied. - logger = NewLogger("{\"level\": \"error\", \"outputPaths\": [\"stdout\"],\"errorOutputPaths\": [\"stderr\"],\"encoding\": \"json\"}", "") + jsonConfig := fmt.Sprintf(minimalConfigTemplate, "error") + logger, err := NewLogger(jsonConfig, "") + if err != nil { + t.Errorf("did not expect error when providing valid config with error log level: %s", err) + } if logger == nil { t.Error("expected a non-nil logger") } @@ -45,8 +94,14 @@ func TestNewLogger(t *testing.T) { if ce := logger.Desugar().Check(zap.ErrorLevel, "test"); ce == nil { t.Error("expected to get error logs from the logger configured with error as min threshold") } +} - logger = NewLogger("{\"level\": \"info\", \"outputPaths\": [\"stdout\"],\"errorOutputPaths\": [\"stderr\"],\"encoding\": \"json\"}", "") +func TestNewLoggerValidInfoConfig(t *testing.T) { + jsonConfig := fmt.Sprintf(minimalConfigTemplate, "info") + logger, err := NewLogger(jsonConfig, "") + if err != nil { + t.Errorf("did not expect error when providing valid config with info log level: %s", err) + } if logger == nil { t.Error("expected a non-nil logger") } @@ -56,9 +111,14 @@ func TestNewLogger(t *testing.T) { if ce := logger.Desugar().Check(zap.InfoLevel, "test"); ce == nil { t.Error("expected to get info logs from the logger configured with info as min threshold") } +} - // Test logging override - logger = NewLogger("{\"level\": \"error\", \"outputPaths\": [\"stdout\"],\"errorOutputPaths\": [\"stderr\"],\"encoding\": \"json\"}", "info") +func TestNewLoggerOverrideInfo(t *testing.T) { + jsonConfig := fmt.Sprintf(minimalConfigTemplate, "error") + logger, err := NewLogger(jsonConfig, "info") + if err != nil { + t.Errorf("did not expect error when providing valid config with overridden info log level: %s", err) + } if logger == nil { t.Error("expected a non-nil logger") } @@ -68,9 +128,14 @@ func TestNewLogger(t *testing.T) { if ce := logger.Desugar().Check(zap.InfoLevel, "test"); ce == nil { t.Error("expected to get info logs from the logger configured with info as min threshold") } +} - // Invalid logging override - logger = NewLogger("{\"level\": \"error\", \"outputPaths\": [\"stdout\"],\"errorOutputPaths\": [\"stderr\"],\"encoding\": \"json\"}", "randomstring") +func TestNewLoggerInvalidOverride(t *testing.T) { + jsonConfig := fmt.Sprintf(minimalConfigTemplate, "error") + logger, err := NewLogger(jsonConfig, "randomstring") + if err != nil { + t.Errorf("did not expect error when providing invalid log level override, it should just be ignored: %s", err) + } if logger == nil { t.Error("expected a non-nil logger") } @@ -81,3 +146,48 @@ func TestNewLogger(t *testing.T) { t.Error("expected to get error logs from the logger configured with error as min threshold") } } + +func TestNewDefaultConfigMapLogger(t *testing.T) { + dir, err := ioutil.TempDir("", "") + if err != nil { + t.Fatalf("Could not create temporary directory for test config: %s", err) + } + defer os.RemoveAll(dir) + if err := writeConfig(dir, "loglevel.myfoo", "info"); err != nil { + t.Fatalf("Failed to write example config to temporary dir %s: %s", dir, err) + } + if err := writeConfig(dir, "zap-logger-config", completeConfig); err != nil { + t.Fatalf("Failed to write example config to temporary dir %s: %s", dir, err) + } + + logger, err := NewDefaultConfigMapLogger(dir, "myfoo") + if err != nil { + t.Errorf("did not expect error when creating logger from config file: %s", err) + } + if logger == nil { + t.Error("expected logger to be created successfully") + } +} +func TestNewDefaultConfigMapLoggerInvalidUsesDefault(t *testing.T) { + dir, err := ioutil.TempDir("", "") + if err != nil { + t.Fatalf("Could not create temporary directory for test config: %s", err) + } + defer os.RemoveAll(dir) + if err := writeConfig(dir, "zap-logger-config", "catbus"); err != nil { + t.Fatalf("Failed to write example config to temporary dir %s: %s", dir, err) + } + + logger, err := NewDefaultConfigMapLogger(dir, "myfoo") + if err == nil { + t.Error("expected error when creating logger from invalid config file") + } + if logger == nil { + t.Error("expected default logger to be created successfully") + } +} + +func writeConfig(dir, key, value string) error { + filename := filepath.Join(dir, key) + return ioutil.WriteFile(filename, []byte(value), 0666) +} diff --git a/test/logging.go b/test/logging.go index ab8d68e85715..e2fa487b5ede 100644 --- a/test/logging.go +++ b/test/logging.go @@ -85,7 +85,11 @@ func newLogger(logLevel string) *zap.SugaredLogger { } }` configJSON := fmt.Sprintf(configJSONTemplate, logLevel) - return logging.NewLogger(string(configJSON), logLevel) + logger, err := logging.NewLogger(configJSON, logLevel) + if err != nil { + logger.Errorf("Error initializing logger: %s", err) + } + return logger } func initializeMetricExporter() {