Improved logging for log package

[Alex]

I was considering making some improvements to the logging package to
provide some more advanced logging functionality (ultimately, this was
inspired by the google-glog C++ logging library at http://code.google.com/p/google-glog/).

More specifically, I would like to be able to differentiate my log
message as being one of {INFO, WARNING, ERROR, FATAL} and have a
threshold for determining which log messages appear. In addition, I
want to support the ability to provide user specified verbosity levels
with something equivalent to VLOG(n). The google-glog library supports
several other nice things, including LOG_IF, LOG_EVERY_N, LOG_FIRST_N,
and CHECK macros as well as support for logging to files, etc.

I started tinkering with some code to see what kind of effort this
would require. In trying to keep the log message short and of a
similar form to the LOG(INFO) << "message" used in the C++ package,
I've been using a design where log statements would take the form:
log.INFO().Outf("Invalid port: %d", port)

In this example, the INFO() function returns an interface with two
functions: Out and Outf. By making INFO() a function, I allow it to
return a dummy object (for which Out and Outf are both noops) in the
case where no log message would appear. The arguments themselves are
still evaluated, but I figured that this was still a reasonable trade
off (and I do not believe it is any different in the C++ library).
WARNING() and ERROR() behave in similar ways, and FATAL() additionally
terminates the program. This pattern also works for user specified
verbosity levels:
log.VLOG(3).Out(foo)

Before I get too far with this, could I perhaps get some feedback on
design? Or more importantly, some insight into why the current logging
package omits these features?

Thanks,
~Alex

[bflm]

Recently discussed.

 

[Monnand]

Hi Alex,
As I mentioned in this thread:
> Recently discussed<https://groups.google.com/d/msg/golang-nuts/YdIxEvPuweg/ApF51EUtBdIJ>
> .
I implemented a simple logging system in my code very similar as you
said. I will release the code in recent days. My code may be useful to
you (hopefully)

[Kyle Lemons]

I proposed additions to the standard logging package to add log levels, etc quite awhile ago when I developed my log4go package (then called elog) and that discussion includes many of the reasons why this was not (and probably will not) become a part of the standard library package.  As a previous poster mentioned, there was another recent discussion about this, which includes some other reasons that this is not in the standard library.

I was considering making some improvements to the logging package to
provide some more advanced logging functionality (ultimately, this was
inspired by the google-glog C++ logging library at http://code.google.com/p/google-glog/).

glog has the ability to leverage macros to remove a lot of overhead when things aren't logged.  Other C/C++ logging packages (and I think even glog to a certain extent) can even skip argument evaluation when the log message isn't logged.  This is simply not possible in Go.

 

More specifically, I would like to be able to differentiate my log
message as being one of {INFO, WARNING, ERROR, FATAL} and have a
threshold for determining which log messages appear. In addition, I
want to support the ability to provide user specified verbosity levels
with something equivalent to VLOG(n). The google-glog library supports
several other nice things, including LOG_IF, LOG_EVERY_N, LOG_FIRST_N,
and CHECK macros as well as support for logging to files, etc.

My log4go package supports nine log levels as well as file and network output in various formats.  I pondered things like LOG_IF and LOG_EVERY_N, but in my experience these are crutches to avoid assigning proper levels to your log messages, which is a fundamental requirement of using just about any such logging package if you actually want to see an improvement over what is currently present in "log".  As for CHECK and ASSERT, they've been discussed at length on other posts, so I won't go into why those aren't present in Go here.

 

I started tinkering with some code to see what kind of effort this
would require. In trying to keep the log message short and of a
similar form to the LOG(INFO) << "message" used in the C++ package,
I've been using a design where log statements would take the form:
log.INFO().Outf("Invalid port: %d", port)

The overhead of this call, whether it's logged or not, might be higher than you expect.  While for normal code it should be fine, it might be prohibitive for use in inner loops, especially when that log level (in log4go called FINEST) probably is filtered out.

 

In this example, the INFO() function returns an interface with two
functions: Out and Outf. By making INFO() a function, I allow it to
return a dummy object (for which Out and Outf are both noops) in the
case where no log message would appear. The arguments themselves are
still evaluated, but I figured that this was still a reasonable trade
off (and I do not believe it is any different in the C++ library).
WARNING() and ERROR() behave in similar ways, and FATAL() additionally
terminates the program. This pattern also works for user specified
verbosity levels:
log.VLOG(3).Out(foo)

User-defined log levels can cause more problems than they're worth, IMHO.  If you have multiple developers, multiple libraries, etc all logging their state, you really want to have consistency across log levels, and so having anything user-defined can make it very difficult to tune the logging output to be where you want it to be.

~K

[Alex]

Ah, I'll continue the discussion about whether or not logging levels
are desired there.

Thanks,
~Alex

On Sep 8, 2:46 am, bflm <befelemepesev...@gmail.com> wrote:

> Recently discussed<https://groups.google.com/d/msg/golang-nuts/YdIxEvPuweg/ApF51EUtBdIJ>
> .

[Alex]

It seems that there is a relatively common misconception that C/C++
logging packages skip argument evaluation when the log message isn't
logged (for now, I'll just refer to the google-glog package although I
acknowledge others may behave differently). This simply cannot be
true. In order for this to occur, one would have to know at compile
time what level of logging granularity is desired - in order to set
the granularity at run time, the messages would have to be logged.

For example, see this example program and the sample output:
http://pastebin.com/BAnPHXGb (if google-glog truly omitted log
messages, then the x should equal 0 in the second output).

I feel like varied log levels are worth it even if sometimes a small
amount of extra overhead is incurred - they help developers debug and
monitor programs.

~Alex

On Sep 8, 12:05 pm, Kyle Lemons <kev...@google.com> wrote:
> I proposed additions to the standard logging package to add log
> levels, etc quite

> awhile ago<https://groups.google.com/d/topic/golang-nuts/Y1JX8aNbdVM/discussion>
> when
> I developed my log4go <http://code.google.com/p/log4go/> package (then

> called elog) and that discussion includes many of the reasons why this was
> not (and probably will not) become a part of the standard library package.
>  As a previous poster mentioned, there was another recent

> discussion<https://groups.google.com/d/msg/golang-nuts/YdIxEvPuweg/ApF51EUtBdIJ>

[Paul Borman]

I will not speak for what is out there in the public, but one thing that can be done is more or less:

func Log(level int, fmt string, arg... string) {

    if level <= LogLevel {

        Output(fmt.Sprintf(fmt, arg...))

    }

}

(forgive me if I have the ...'s in the wrong places).  The arguments are still evaluated but at least the expensive Sprintf is not.

[Kyle Lemons]

It seems that there is a relatively common misconception that C/C++
logging packages skip argument evaluation when the log message isn't
logged (for now, I'll just refer to the google-glog package although I
acknowledge others may behave differently). This simply cannot be
true. In order for this to occur, one would have to know at compile
time what level of logging granularity is desired - in order to set
the granularity at run time, the messages would have to be logged.

I haven't used glog in some time, but I was specifically refering to log packaes that do

DEBUG(....)

and friends.  I thought glog had this too, but maybe not.  Often these do not have runtime abilities to shift log levels specifically so that they can completely omit those from the resulting code.  Obviously there are counterexamples for both.  Go doesn't even have that as an option.

[Alex]

Kyle -

I am willing to spend some effort improving the currently logging
package by add levels for semantic content and some support for
filtering by this content (in a manner similar to the google-glog
package). While I would attempt to reduce the overhead when messages
aren't logged, my goal would primarily be to offer more useful logging
to users of the package. Likewise, LOG_IF and LOG_EVERY_N type macros
would be used to filter log messages.

Please correct me if I am misunderstanding you, but are you suggesting
that Go will not consider improvements to the existing logging package
because they would lack the ability to omit LOG() statements from
release binaries? Isn't this a feature the existing package lacks?

~Alex

[Kyle Lemons]

I am willing to spend some effort improving the currently logging
package by add levels for semantic content and some support for
filtering by this content (in a manner similar to the google-glog
package). While I would attempt to reduce the overhead when messages
aren't logged, my goal would primarily be to offer more useful logging
to users of the package. Likewise, LOG_IF and LOG_EVERY_N type macros
would be used to filter log messages.

You are welcome to write your own goinstallable log package if you wish.

 

Please correct me if I am misunderstanding you, but are you suggesting
that Go will not consider improvements to the existing logging package
because they would lack the ability to omit LOG() statements from
release binaries? Isn't this a feature the existing package lacks?

Improvements to the existing log package are encouraged.  Just because the logging package lacks a "feature," however, does not mean that adding that feature improves it.  As I said, I made a similar proposal a long time ago.

~K 

[Rob 'Commander' Pike]

Remember to follow the contribution guidelines: API changes are best
discussed before sending any code out for review.

That said, I'm skeptical that the kind of thing you're after belongs
in the standard logging package.

-rob

[Paul Borman]

I alluded to the fact that Kyle and I both independently wrote more "feature rich" logging packages.  When we compared notes we realized that we were targeting different logging concerns.   It does not replace the standard log package, rather, it uses the standard log package.  I would not propose enhancing the standard log package to support logging levels (and in my case, ability to log (slightly different) message to both a logfile and stderr) as at the application/organization there are different logging requirements and an all singing all dancing solution would probably be difficult to use correctly.

Kyle has the right idea, use goinstall or make your own (and share it if you can/it is appropriate)

    -Paul