Skip to content
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.

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

provide an easy way to derive a logger that logs at a different level #581

Closed
rogpeppe opened this issue Apr 16, 2018 · 15 comments
Closed

Comments

@rogpeppe
Copy link

rogpeppe commented Apr 16, 2018

When logging HTTP requests, we've found it useful to be able to increase the logging threshold for some requests at particular paths (for example, the trivial endpoint that the Nagios check uses) to avoid overwhelming the logs with noise.

It's possible to do this oneself with something like the below code, but this isn't particularly obvious and probably isn't that efficient, so perhaps it might be worth adding a WithLevel method to zap.Logger.

// in the code
logger = logger.WithOptions(wrapCoreWithLevel(zap.WarnLevel))

func wrapCoreWithLevel(level zapcore.Level) zap.Option {
	return zap.WrapCore(func(core zapcore.Core) zapcore.Core {
		return &coreWithLevel{
			Core:  core,
			level: level,
		}
	})
}

type coreWithLevel struct {
	zapcore.Core
	level zapcore.Level
}

func (c *coreWithLevel) Enabled(level zapcore.Level) bool {
	return c.level.Enabled(level) && c.Core.Enabled(level)
}

func (c *coreWithLevel) Check(e zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry {
	if !c.level.Enabled(e.Level) {
		return ce
	}
	return c.Core.Check(e, ce)
}
@etsangsplk
Copy link
Contributor

@rogpeppe Would you mind explaining how your code works, because zap is not easy to customize.
Am thinking about doing something similar to you.
Child logger can change their logging level and their descendants level at will without affecting its parent.

@rogpeppe
Copy link
Author

@etsangsplk It works by creating a wrapper type (coreWithLevel) for the zapcore.Core interface that reimplements the Enabled and Check methods to choose a higher logging level. There's an existing option that allows replacing the zapcore.Core associated with a given logger, so we use that and the coreWithLevel type to provide a function that can raise the level associated with a given logger.

I'm not sure if that will help much - if in doubt, read the docs and/or browse through the code.

FWIW we're using the above technique in the WithLevel function here.

@NathanZook
Copy link

I wonder if WithOption might be what you want here. https://godoc.org/go.uber.org/zap#Logger.WithOptions

@rogpeppe
Copy link
Author

rogpeppe commented Feb 8, 2019

@NathanZook The code in the issue above does use WithOptions. Have you got a particular way of using WithOptions to raise the logging threshold that's simpler than that?

@NathanZook
Copy link

More digging. How about https://godoc.org/go.uber.org/zap#example-AtomicLevel ?

@rogpeppe
Copy link
Author

rogpeppe commented Feb 8, 2019

AIUI, AtomicLevel can be used to change the level of a whole tree of loggers, not just a subtree based on the logger that's currently available. Can you show how you might think this might work?

@NathanZook
Copy link

If at the entry point to your controller, you include a defer that sets the AtomicLevel logger to default, then whatever changes you make while the request is being processed are reset when the request is done. You are then free to set the level as you will for "particular paths".
If you don't mind the long-pole performance cost, you can set it at the start of the request handling.

@rogpeppe
Copy link
Author

What if there are other requests proceeding concurrently which you don't want to affect? Doesn't that approach mean that all logging is globally affected? If so, that's not a viable solution for me.

@NathanZook
Copy link

I've not explored the options when channels are involved. I see that zapcore.Core.clone is not exported. Nor is ioCore. So, if you built your own core originally, and kept the parameters around...

originalCore = zapcore.NewCore(enc, ws, originalLevelEnabler)
logger = zap.New(originalCore, variousOptions...)
// Whatever else is needed to set up the logger--might not be trivial.  And you need to
// ensure that the changes don't affect the core.

newCore = zapcore.NewCore(enc, ws, newLevelEnabler)
newLevelLoggerOption = zap.WrapCore(func(zapcore.Core) zapcore.Core {
  return newCore
})
newLevelLogger = logger.WithOptions(newLevelLoggerOption)

That seems like it would work. Perhaps more obvious or at least clear?
Yeah, wrapping the level would seem to be a natural feature for the package.

@rogpeppe
Copy link
Author

@NathanZook Some code is missing so I can't be sure, but isn't that similar to the code that I suggested when I raised the issue initially?

@tsingson
Copy link

example:

// log one for DEBUG
var w zapcore.WriteSyncer
w = zapcore.AddSync(os.Stdout)

log1 :=  newZapCore(true, zapcore.DebugLevel, w)    // this log level is debug and output is STDOUT

// log two for Error 
w := zapcore.AddSync(&lumberjack.Logger{
  Filename:   "/var/log/myapp/foo.log",
  MaxSize:    500, // megabytes
  MaxBackups: 3,
  MaxAge:     28, // days
})
core := zapcore.NewCore(
  zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()),
  w,
  zap.ErrorLevel,
)
log2 := zap.New(core)

//

	opts := []zap.Option{}
      opts = append(opts, zap.AddCaller())


zlog :=    zap.New(zapcore.NewTee(log1, log2), opts...)  

//   just use this, log will send out to file and stdout with define log level 
zlog.Info("info")
zlog.Error("error.....")

@NathanZook
Copy link

@rogpeppe Similar, to be sure. Zap's design is such that if you want to dynamically manage levels, you're going to have to keep ahold of the LevelEnabler yourself, one way or another.

@hypnoglow
Copy link

FYI: Note that with the code from the first post you will not be able to decrease logging level threshold (e.g. from INFO to DEBUG), only increase. To allow level decreasing, you need to eliminate checks on original core:

type coreWithLevel struct {
	zapcore.Core
	level zapcore.Level
}

func (c *coreWithLevel) Enabled(level zapcore.Level) bool {
	return c.level.Enabled(level)
}

func (c *coreWithLevel) Check(e zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry {
	if !c.level.Enabled(e.Level) {
		return ce
	}
	return ce.AddCore(e, c.Core)
}

@maoueh
Copy link

maoueh commented Mar 18, 2020

Note that #581 (comment) does not work with all underlying wrapped cores.

For example, this code does not print the log, whatever the level (the WithLevel in subLog implements logic mentioned above):

func main() {
    log, _ := zap.NewDevelopment(zap.Hooks(func(e zapcore.Entry) error {
        fmt.Println("Hooked core 'swallow' entries!")
        return nil
    }))

    subLog := log.WithOptions(WithLevel(zap.DebugLevel))
    subLog.Error("Testing WithLevel wrapping a Hooked core")
}

This prints only:

Hooked core 'swallow' entries!

And removing the zap.Hooks options make it work again. This is because the zapcore.hooked core, on Write call, only perform the hook callback. The actual entry is added to downstream core in the Check method of the zapcore.hooked struct, which is not called.

This means that it's not possible in current implementation to decrease log level of a logger in all circumstances.

@prashantv
Copy link
Collaborator

+1 That's exactly right, it's not possible to decrease the log level in all cases, but it is possible to increase the log level, so we added an explicit API to increase the level.

It's not safe to call Write on a core without calling Check, as documented in the interface:

// Callers must use Check before calling Write.

Since we have an API to increase the level, and there's no decrease the level in a supported way for all use-cases, I'm going to close this issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

No branches or pull requests

7 participants