New method in log package to accomodate building logging wrapper over log package

[Ugorji Nwoke]

Hi folks,

I'm not sure if this is more applicable for golang-nuts or golang-dev, so starting here.

I know that the issue of logging has been discussed many times, and there is concern about expanding the base log package. Building a light logging package on top of it is a good compromise. 

Currently, any logging wrapper will need to use the log.Output function for the following reason:

- All the log.XXX methods eventually call log.Output with a calldepth of 2. For any wrapper, that calldepth will be wrong.

However, a logging package which wants to log messages asynchronously, or outside the call stack, will run into issues. I built a simple logging package where clients send log records over a channel, and the logging package receives and records them. This scenario presents the following issues:

- timestamp on the messages is wrong (if there's some buffering on the channel) 

- PC information (file, line) is not available

Looking at the log.go source, this can easily be remedied by adding a log.Output method variant as below:

  func (l *Logger) OutputR(nanoseconds int64, file string, line int, message string) os.Error 

  func (l *Logger) Output(calldepth int, s string) os.Error 

log.go will refactor Output to call OutputR, and wrappers can call log.OutputR directly. 

Wrappers can then package the PC info (file, line) along with a timestamp (nanoseconds) in a log record (along with message format and parameters), and pass this to log.OutputR at logging time.

Is this something that the GO team is willing to do?

[Kyle Lemons]

I disagree that logging packages should necessarily wrap the standard log package.  If anything, a log package might deliberately intercept log messages generated by the standard log package by injecting its own writer, not the other way around.

~K

[Ugorji Nwoke]

I'm not sure I follow.

The log package only exposes a way to set the io.Writer passed to the Logger, thus changing the destination of the log messages. This doesn't in any way change the way the log package works, or expose any additional functionality into it. 

If you want to build logging levels and filters and various handlers (log to file, database, via IPC or RPC) or in different formats (YAML, simple line-oriented file, etc), then you have two options:

- build all this functionality and do without the log package altogether (which will be a shame)

- build the extra functionality but leverage the log package where possible (e.g. as a default handler to log messages in its standard line-oriented format to a io.Writer after doing your filtering and light routing).

I took option B and I think it's a fair one. I built something lightweight in 120 lines of GO code using a channel with support for Logging Levels, named Handlers and using a built-in handler leveraging the log package by default. It works very well. The only issue is that the timestamp might be late under load, and the file and line information is incorrect. 

The proposal to support my use-case is pretty simple ie split the log.Output method into two so I can use the second one since the first one doesn't suffice.

[Kyle Lemons]

I'm not sure I follow.

The log package only exposes a way to set the io.Writer passed to the Logger, thus changing the destination of the log messages. This doesn't in any way change the way the log package works, or expose any additional functionality into it. 

If you want to build logging levels and filters and various handlers (log to file, database, via IPC or RPC) or in different formats (YAML, simple line-oriented file, etc), then you have two options:

- build all this functionality and do without the log package altogether (which will be a shame)

When you're doing the logging yourself, the standard log package doesn't buy you much, and (as you say) can cause inaccurate timestamps or source lines.  I took this first approach with log4go, because I wanted these things and more.

- build the extra functionality but leverage the log package where possible (e.g. as a default handler to log messages in its standard line-oriented format to a io.Writer after doing your filtering and light routing).

If you redirect the log package's writer to your own internal (line-buffered) handler, you could translate it into some default log level in whatever format your logger uses.  Again, I don't see going the other way around unless you're simply doing level-based logging by providing predeclared loggers with a prefix per level (all of which are mechanisms supported directly by the standard library).

 

I took option B and I think it's a fair one. I built something lightweight in 120 lines of GO code using a channel with support for Logging Levels, named Handlers and using a built-in handler leveraging the log package by default. It works very well. The only issue is that the timestamp might be late under load, and the file and line information is incorrect.

log4go is somewhat more than 120 lines :-).

 

The proposal to support my use-case is pretty simple ie split the log.Output method into two so I can use the second one since the first one doesn't suffice.

When you're providing that many arguments to OutputR, it seems that you might as well just call fmt.Fprintf.

~K

[Ugorji Nwoke]

... When you're doing the logging yourself, the standard log package doesn't buy you much ... it seems that you might as well just call fmt.Fprintf <snip>

True words. You have a strong point here. I had to look back at the log.go code to realize this. There's no need to force the use of log package if it's not giving much. 

Regarding log4go being more than 120 lines ;), that's because it comes with batteries (pattern logger, file rotation, console logger, network socket logger, xml config file, etc). The batteries occupy space ;) Nice package.