Skip to content

Do not log in log library #1364

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
bobcatfish wants to merge 1 commit into from
Closed

Do not log in log library #1364

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 5 additions & 1 deletion cmd/activator/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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")
Expand Down
6 changes: 5 additions & 1 deletion cmd/autoscaler/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand Down
7 changes: 6 additions & 1 deletion cmd/controller/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down Expand Up @@ -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() {
Expand Down
13 changes: 12 additions & 1 deletion cmd/queue/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand Down
6 changes: 5 additions & 1 deletion cmd/webhook/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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")
Expand Down
34 changes: 22 additions & 12 deletions pkg/logging/config.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,38 +19,49 @@ 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"
Copy link
Copy Markdown
Contributor Author

@bobcatfish bobcatfish Jun 27, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@mattmoor let me know if you wanted me to do something more specific re 'not relying on /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()
if err2 != nil {
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) {
Copy link
Copy Markdown
Member

@dprotaso dprotaso Jun 28, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Given there is a default config path we can simplify the usability of this function a bit more by making configPath optional. Maybe it makes sense to name this function NewComponentLogger now?

ie.

func NewComponentLogger(componentKey string, configPath ...string) (*zap.SugaredLogger, error) {
  conf  := DefaultLoggingConfigPath
  if len(configPath) > 0 {
    conf = configPath[0]
  }

  ...
}

then the usage would simplified to

if logger, err := logging.NewComponentLogger("webhook"); err != nil {
	logger.Errorf("Error initializing logger: %s", err)
}

Copy link
Copy Markdown
Contributor Author

@bobcatfish bobcatfish Jun 28, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

thanks for letting me know about this! i didn't know about variadic functions in Go!

however after looking into it a bit, I'm not sure I like the idea of using them for this optional params and here is an example of why. The TL;DidntRun is the fact that using a variadic args means callers can start passing you incorrect arguments have you have to either check and make sure they're not doing that explicitly or allow the weird extra arguments to silently not do anything, and neither option seems great

Copy link
Copy Markdown
Member

@dprotaso dprotaso Jun 28, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yup it's dirty - would you settle on having two New* functions

ie.

func NewComponentLogger(componentKey string) (*zap.SugaredLogger, error) {
  return NewComponentLoggerFromConfig(componentKey, DefaultLoggingConfigPath)
}

func NewComponentLoggerFromConfig(componentKey, configPath 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) {
Expand All @@ -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)
}
Expand All @@ -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
}
128 changes: 119 additions & 9 deletions pkg/logging/config_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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")
}
Expand All @@ -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")
}
Expand All @@ -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")
}
Expand All @@ -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")
}
Expand All @@ -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)
}
6 changes: 5 additions & 1 deletion test/logging.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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() {
Expand Down