search

romana / rlog

A simple Golang logger without external dependencies
Apache License 2.0
39 stars 13 forks source link

readme

rlog - A simple Golang logger with lots of features and no external dependencies

Rlog is a simple logging package, rich in features. It is configurable 'from the outside' via environment variables and/or config file and has no dependencies other than the standard Golang library.

It is called "rlog", because it was originally written for the Romana project.

Features

Defaults

Rlog comes with reasonable defaults, so you can just start using it without any configuration at all. By default:

All those defaults can easily be changed through environment variables or the config file.

Controlling rlog through environment or config file variables

Rlog is configured via the following settings, which may either be defined as environment variables or via a config file.

There are two more settings, related to the configuration file, which can only be set via environment variables.

Please note! If these environment variables have incorrect or misspelled values then they will be silently ignored and a default value will be used.

Using the config file

A config file for rlog is entirely optional, since rlog works just fine even without it. However, it does provide you with a very neat feature: You can change the logging configuration of a running program from the outside and without having to restart it!

When rlog is imported it starts out with the defaults described above. It then takes an initial configuration from environment variables, which may override the default values. Next, it looks for the rlog config file. If it cannot find the config file it will quietly continue without error. If the config file is found then the configuration from environment variables is combined with the configuration from the config file. More about how this combination works, and what takes precedence, in a moment.

Config file location

The path for the config file can be set via the RLOG_CONF_FILE environment variable. Absent that, rlog looks for a config file in /etc/rlog/<your-executable-name>.conf. This means that you can easily provide different logging configurations for each of your processes.

A new config file location can also be specified at any time via the SetConfFile() function. An absolute or relative path may be specfied with that function.

Config file format

The format of the config file is simple. Each setting is referred to by the same name as the environment variable. So, your config file may look like this:

# Comment lines start with a '#'
RLOG_LOG_LEVEL  = WARN
RLOG_LOG_STREAM = stdout
RLOG_TIME_FORMAT= UnixDate
RLOG_LOG_FILE   = /var/log/myapp.log

A few notes about config file formatting:

Combining configuration from environment variables and config file

Generally, environment variables take precedence. Assume you have set a log level of INFO via the RLOG_LOG_LEVEL variable. This value will be used, even if you specified DEBUG in the config file, since an explicitly set environment variable takes precedence.

There are only two cases when a config file value takes precedence:

  1. If you do not have an explicit value set in the environment variable. For example, if you do not have the RLOG_LOG_LEVEL environment variable defined at all, or if it is set to the empty string.
  2. If you apply a '!' as prefix in the config file. That marks this value as higher priority than the environment variable. Consider the following config file as example. Here RLOG_LOG_LEVEL and RLOG_TIME_FORMAT will take precedence over whatever was defined in the environment variables.

An example of using '!' in the config file:

!RLOG_LOG_LEVEL=WARN
RLOG_LOG_STREAM=stdout
!RLOG_TIME_FORMAT=UnixDate
RLOG_LOG_FILE=/var/log/myapp.log

Updating the logging config of a running program

From the outside: By modifying the config file

Every time you log a message and at least RLOG_CONF_CHECK_INTERVAL seconds have elapsed since the last reading of the config file, rlog will automatically re-read the content of the conf file and re-apply the configuration it finds there over the initial configuration, which was based on the environment variables.

You can always just delete the config file to go back to the configuration based solely on environment variables.

From the inside: By modifying your own environment variables

A running program may also change its rlog configuration on its own: The process can use the os.Setenv() function to modify its own environment variables and then call rlog.UpdatEnv() to reapply the settings from the environment variables. The examples/example.go file shows how this is done. But in short:

// Programmatically change an rlog setting from within the program
os.Setenv("RLOG_LOG_LEVEL", "DEBUG")
rlog.UpdateEnv()

Note that this will not change rlog behaviour if the value for this config setting was specified with a '!' in the config file.

Per file level log and trace levels

In most cases you might want to set just a single log or trace level, which is then applied to all log messages in your program. With environment variables, you would set it like this:

export RLOG_LOG_LEVEL=INFO
export RLOG_TRACE_LEVEL=3

However, with rlog the log and trace levels can not only be configured 'globally' with a single value, but can also independently be set for the individual module files that were compiled into your executable. This is useful if enabling high trace levels or DEBUG logging for the entire executable would fill up logs or consume too many resources.

For example, if your executable is compiled out of several files and one of those files is called 'example.go' then you could set log levels like this:

export RLOG_LOG_LEVEL=INFO,example.go=DEBUG

This sets the global log level to INFO, but for the messages originating from the module file 'example.go' it is DEBUG.

Similarly, you can set trace levels for individual module files:

export RLOG_TRACE_LEVEL=example.go=5,2

This sets a trace level of 5 for example.go and 2 for everyone else.

More examples:

# DEBUG level for all files whose name starts with 'ex', WARNING level for
# everyone else.
export RLOG_LOG_LEVEL=WARN,ex*=DEBUG

# DEBUG level for example.go, INFO for everyone else, since INFO is the
# default level if nothing is specified.
export RLOG_LOG_LEVEL=example.go=DEBUG

# DEBUG level for example.go, no logging for anyone else.
export RLOG_LOG_LEVEL=NONE,example.go=DEBUG

# Multiple files' levels can be specified at once.
export RLOG_LOG_LEVEL=NONE,example.go=DEBUG,foo.go=INFO

# The default log level can appear anywhere in the list.
export RLOG_LOG_LEVEL=example.go=DEBUG,INFO,foo.go=WARN

Note that as before, if in RLOG_LOG_LEVEL no global log level is specified then INFO is assumed to be the global log level. If in RLOG_TRACE_LEVEL no global trace level is specified then -1 (no trace output) is assumed as the global trace level.

Usage example

import "github.com/romana/rlog"

func main() {
   rlog.Debug("A debug message: For the developer")
   rlog.Info("An info message: Normal operation messages")
   rlog.Warn("A warning message: Intermittent issues, high load, etc.")
   rlog.Error("An error message: An error occurred, I will recover.")
   rlog.Critical("A critical message: That's it! I give up!")
   rlog.Trace(2, "A trace message")
   rlog.Trace(3, "An even deeper trace message")
}

For a more interesting example, please check out 'examples/example.go'.

Sample output

With time stamp, trace to level 2, log level WARNING, no caller info:

$ export RLOG_LOG_LEVEL=WARN
$ export RLOG_TRACE_LEVEL=2
$ go run examples/example.go

2017-11-16T08:06:56+13:00 WARN     : Warning level log message
2017-11-16T08:06:56+13:00 ERROR    : Error level log message
2017-11-16T08:06:56+13:00 CRITICAL : Critical level log message
2017-11-16T08:06:56+13:00 DEBUG    : You can see this message, because we changed level to DEBUG.
2017-11-16T08:06:56+13:00 TRACE(1) : Trace messages have their own numeric levels
2017-11-16T08:06:56+13:00 TRACE(1) : To see them set RLOG_TRACE_LEVEL to the cut-off number
2017-11-16T08:06:56+13:00 TRACE(1) : We're 1 levels down now...
2017-11-16T08:06:56+13:00 TRACE(2) : We're 2 levels down now...
2017-11-16T08:06:56+13:00 INFO     : Reached end of recursion at level 10
2017-11-16T08:06:56+13:00 INFO     : About to change log output. Check /tmp/rlog-output.log...
2017-11-16T08:06:56+13:00 INFO     : Back to stderr

With time stamp, log level WARN, no trace logging (switched off by unsetting the variable), but with caller info ('23730' in the example below is the process ID):

$ export RLOG_CALLER_INFO=yes
$ export RLOG_LOG_LEVEL=WARN
$ export RLOG_TRACE_LEVEL=
$ go run examples/example.go

2017-11-16T08:07:57+13:00 WARN     : [21233 examples/example.go:31 (main.main)] Warning level log message
2017-11-16T08:07:57+13:00 ERROR    : [21233 examples/example.go:32 (main.main)] Error level log message
2017-11-16T08:07:57+13:00 CRITICAL : [21233 examples/example.go:33 (main.main)] Critical level log message
2017-11-16T08:07:57+13:00 DEBUG    : [21233 examples/example.go:42 (main.main)] You can see this message, because we changed level to DEBUG.
2017-11-16T08:07:57+13:00 INFO     : [21233 examples/example.go:17 (main.someRecursiveFunction)] Reached end of recursion at level 10
2017-11-16T08:07:57+13:00 INFO     : [21233 examples/example.go:52 (main.main)] About to change log output. Check /tmp/rlog-output.log...
2017-11-16T08:07:57+13:00 INFO     : [21233 examples/example.go:61 (main.main)] Back to stderr

Without time stamp, no trace logging, no caller info:

$ export RLOG_LOG_NOTIME=yes
$ export RLOG_CALLER_INFO=no
$ go run examples/example.go

WARN     : Warning level log message
ERROR    : Error level log message
CRITICAL : Critical level log message
DEBUG    : You can see this message, because we changed level to DEBUG.
INFO     : Reached end of recursion at level 10
INFO     : About to change log output. Check /tmp/rlog-output.log...
INFO     : Back to stderr

With time stamp in RFC822 format.

$ export RLOG_LOG_NOTIME=no
$ export RLOG_TIME_FORMAT=RFC822
$ go run examples/example.go

2017-11-16T08:08:49+13:00 WARN     : Warning level log message
2017-11-16T08:08:49+13:00 ERROR    : Error level log message
2017-11-16T08:08:49+13:00 CRITICAL : Critical level log message
2017-11-16T08:08:49+13:00 DEBUG    : You can see this message, because we changed level to DEBUG.
2017-11-16T08:08:49+13:00 INFO     : Reached end of recursion at level 10
2017-11-16T08:08:49+13:00 INFO     : About to change log output. Check /tmp/rlog-output.log...
2017-11-16T08:08:49+13:00 INFO     : Back to stderr

With custom time stamp:

$ export RLOG_TIME_FORMAT="2006/01/06 15:04:05"
$ go run examples/example.go

2017-11-16T08:09:08+13:00 WARN     : Warning level log message
2017-11-16T08:09:08+13:00 ERROR    : Error level log message
2017-11-16T08:09:08+13:00 CRITICAL : Critical level log message
2017-11-16T08:09:08+13:00 DEBUG    : You can see this message, because we changed level to DEBUG.
2017-11-16T08:09:08+13:00 INFO     : Reached end of recursion at level 10
2017-11-16T08:09:08+13:00 INFO     : About to change log output. Check /tmp/rlog-output.log...
2017-11-16T08:09:08+13:00 INFO     : Back to stderr

Links