#+TITLE: plog (pico log) - golang logging library
#+PROPERTY: header-args :eval never-export
[[https://pkg.go.dev/github.com/j-keck/plog][file:https://godoc.org/github.com/j-keck/plog?status.svg]]
[[https://github.com/j-keck/plog/actions][file:https://github.com/j-keck/plog/workflows/test/badge.svg]]
* Intro
pico log - because it's so small and has zero dependencies.
** Why?
I want a logging library with
- zero dependencies
- easy to use
- can emit log messages per go channel
** Non Goals
- blazing fast
- a lot of features
** Features
- console logging
- log over go channel
- optional global logger instance
(see [[#create-a-global-logger-instance][Create a global logger instance]])
- log output format configurable \\
(see [[#custom-log-format][Custom log format]], [[#log-output-format-per-program-arguments][Log output format per program arguments]] for examples)
- helper functions to set log level per command line arguments \\
(see [[#set-loglevel-per-program-arguments][Set LogLevel per program arguments]] for examples)
* Usage
/After each code block you will see an output example./
** Create a console logger instance
You create a console logger per ~plog.NewDefaultConsoleLogger~ or ~plog.NewConsoleLogger~.
*** ~plog.NewDefaultConsoleLogger()~
This function creates a console logger where each log column are separated with " | "
and three log columns: the timestamp of the log event, the log level for the message
and the log message.
#+BEGIN_SRC go -r :tangle examples/console.go :exports both
package main
import "github.com/j-keck/plog"
func main() {
log := plog.NewDefaultConsoleLogger()
log.Info("startup")
log.Debug("change to debug level")
log.SetLevel(plog.Debug)
log.Debug("level changed")
log.Infof("2 + 2 = %d", 2 + 2)
}
#+END_SRC
#+RESULTS:
: Wed Feb 19 09:34:16 CET 2020 | INFO | startup
: Wed Feb 19 09:34:16 CET 2020 | DEBUG | level changed
: Wed Feb 19 09:34:16 CET 2020 | INFO | 2 + 2 = 4
*** ~plog.NewConsoleLogger(separator string, formatters ...plog.Formatter)~
This function creates a logger with a custom log output format.
The first argument is a separator with separates each log column,
the rest are "column formatters". These describes which columns
and how this columns are formatted (see [[#formatters][Formatters]] for more information).
#+BEGIN_SRC go -r :tangle examples/console-custom-format.go :exports both
package main
import "github.com/j-keck/plog"
func main() {
log := plog.NewConsoleLogger(
" - ",
plog.Level,
plog.TimestampMillis,
plog.Message,
)
// set log prefix and suffix
log.SetLogPrefix("[").SetLogSuffix("]")
log.Info("startup")
log.Debug("change to debug level")
log.SetLevel(plog.Debug)
log.Debug("level changed")
log.Infof("2 + 2 = %d", 2 + 2)
}
#+END_SRC
#+RESULTS:
: [ INFO - Feb 19 09:34:17.009 - startup]
: [DEBUG - Feb 19 09:34:17.010 - level changed]
: [ INFO - Feb 19 09:34:17.010 - 2 + 2 = 4]
** Create a global logger instance
You create a singleton global logger instance per ~plog.GlobalLogger~.
So you can configure the log output only once, and every other ~plog.GlobalLogger~
instance have the same logging configuration.
When you create a global logger, you *must* attach a console or stream logger to it.
If not, a warning is logged (this can be disabled with ~plog.DropUnhandledMessages~).
~plog.GlobalLogger~ is a broadcast logger, so you can add many consumer.
#+BEGIN_SRC go :tangle examples/global-logger.go :eval no
package main
import "github.com/j-keck/plog"
func main() {
// initialize the logger
log := plog.GlobalLogger().Add(plog.NewDefaultConsoleLogger())
log.Info("in 'main'")
other()
}
func other() {
log := plog.GlobalLogger()
log.Info("in 'other'")
}
#+END_SRC
#+BEGIN_SRC shell :results output :exports both
go run examples/global-logger.go
#+END_SRC
#+RESULTS:
: Wed Feb 19 09:34:17 CET 2020 | INFO | in 'main'
: Wed Feb 19 09:34:17 CET 2020 | INFO | in 'other'
* API
Each logger instance have the following functions:
| ~SetLevel(LogLevel)~ | Set the log level. From ~plog.Trace~ to ~plog.Error~ |
| ~IsTraceEnabled()~ | Checks if the Trace level is enabled |
| ~IsDebugEnabled()~ | Checks if the Debug level is enabled |
| ~IsInfoEnabled()~ | Checks if the Info level is enabled |
| ~IsNoteEnabled()~ | Checks if the Note level is enabled |
| ~IsWarnEnabled()~ | Checks if the Warn level is enabled |
| ~IsErrorEnabled()~ | Checks if the Error level is enabled |
| ~Trace(string)~ / ~Tracef(string, ...{}interface)~ | Trace logging |
| ~Debug(string)~ / ~Debugf(string, ...{}interface)~ | Debug logging |
| ~Info(string)~ / ~Infof(string, ...{}interface)~ | Info logging |
| ~Note(string)~ / ~Notef(string, ...{}interface)~ | Note (Notifications) logging |
| ~Warn(string)~ / ~Warnf(string, ...{}interface)~ | Warn logging |
| ~Error(string)~ / ~Errorf(string, ...{}interface)~ | Error logging |
| ~Fatal(string)~ / ~Fatalf(string, ...{}interface)~ | Fatal logging |
Where the log functions act like ~fmt.Print(string)~ and ~fmt.Printf(string, ...{}interface)~.
*** Console logger API
The ~consoleLogger~ has the following additional functions:
| ~SetStdout(io.Writer)~ | Redirect stdout |
| ~SetStderr(io.Writer)~ | Redirect stderr |
| ~SetLogPrefix(string)~ | Prepend the given string on each log message |
| ~SetLogSuffix(string)~ | Append the given string on each log message |
| ~AddLogFormatter(Formatter)~ | Add an log formatter to format the log message |
*** Stream logger API
The ~streamLogger~ has the following additional functions:
| ~SetStderr(io.Writer)~ | Redirect stderr |
| ~Subscribe(bufferSize int) <-chan LogMessage~ | Get a go channel where the log messages are emitted |
| ~WaitForSubscribers(timeout time.Duration)~ | Blocks till all subscribers have received all messages |
*** Broadcast logger API
The ~broadcastLogger~ has the following additional functions:
| ~Add(Logger)~ | Add a logger which receives the log messages |
| ~Reset()~ | Reset removes all attached logger instances |
** Set the log level per programm arguments
*plog* provides two helper functions to configure the LogLevel per program arguments:
- ~plog.FlagDebugVar(p *LogLevel, name string, usage string)~
- ~plog.FlagTraceVar(p *LogLevel, name string, usage string)~
see [[#set-loglevel-per-program-arguments][Set LogLevel per program arguments]] for a example.
** Formatters
Formatters describes which and how each log column are logged.
To define the format of the log message, you can use predefined formatters
or construct your own.
***** Predefined formatter
#+BEGIN_SRC go :imports '("github.com/j-keck/plog" "time" "fmt" "strings") :exports results
msg := plog.LogMessage{plog.Info, time.Now(), "go_srcfile", 33, "Test"}
show := func(name string, formatter plog.Formatter) {
fmt.Printf("%-46s | '%s'\n", name, formatter.Format(&msg))
}
fmt.Printf("%-46s | example output\n%s\n", "formatter", strings.Repeat("-", 80))
show("plog.Level", plog.Level)
show("plog.Timestamp", plog.Timestamp)
show("plog.TimestampMillis", plog.TimestampMillis)
show("plog.TimestampUnixDate", plog.TimestampUnixDate)
show("plog.Location", plog.Location)
show("plog.File", plog.File)
show("plog.Line", plog.Line)
show("plog.Message", plog.Message)
#+END_SRC
#+RESULTS:
#+begin_example
formatter | example output
--------------------------------------------------------------------------------
plog.Level | ' INFO'
plog.Timestamp | 'Feb 19 09:34:17'
plog.TimestampMillis | 'Feb 19 09:34:17.855'
plog.TimestampUnixDate | 'Wed Feb 19 09:34:17 CET 2020'
plog.Location | ' go_srcfile:33 '
plog.File | ' go_srcfile'
plog.Line | '33 '
plog.Message | 'Test'
#+end_example
***** Custom Columns
A custom formatter expects a format string, which describes how each log column are formatted.
The ~TimestampFmt~ formatter used ~time.Format(format string)~ to format the
timestamp column. See the [[https://golang.org/pkg/time/#Time.Format][time.Format]] api for a description.
The ~LineFmt~ formatter expects a ~%d~ in his format where the line number
should be inserted.
All other formatters expects a ~%s~ where the value should be inserted.
#+BEGIN_SRC go :imports '("github.com/j-keck/plog" "time" "fmt" "strings") :exports results
msg := plog.LogMessage{plog.Info, time.Now(), "go_srcfile", 33, "Test"}
show := func(name string, formatter plog.Formatter) {
fmt.Printf("%-46s | '%s'\n", name, formatter.Format(&msg))
}
fmt.Printf("%-46s | example output\n%s\n", "formatter examples", strings.Repeat("-", 80))
show("plog.LevelFmt(\"%10s\")", plog.LevelFmt("(%10s)"))
show("plog.TimestampFmt(\"15:04:05.000\")", plog.TimestampFmt("15:04:05.000"))
show("plog.TimestampFmt(\"2006-01-02T15:04:05Z07:00\")", plog.TimestampFmt("2006-01-02T15:04:05Z07:00"))
show("plog.LocationFmt(\"[file: %s, line: %d]\")", plog.LocationFmt("[file: %s, line: %d]"))
show("plog.FileFmt(\"<%s>\")", plog.FileFmt("<%s>"))
show("plog.LineFmt(\"[%d]\")", plog.LineFmt("[%d]"))
#+END_SRC
#+RESULTS:
: formatter examples | example output
: --------------------------------------------------------------------------------
: plog.LevelFmt("%10s") | '( INFO)'
: plog.TimestampFmt("15:04:05.000") | '09:34:18.269'
: plog.TimestampFmt("2006-01-02T15:04:05Z07:00") | '2020-02-19T09:34:18+01:00'
: plog.LocationFmt("[file: %s, line: %d]") | '[file: go_srcfile, line: 33]'
: plog.FileFmt("<%s>") | '<go_srcfile>'
: plog.LineFmt("[%d]") | '[33]'
* Examples
** Custom log format
#+BEGIN_SRC go :tangle examples/logformat.go :eval no
package main
import "github.com/j-keck/plog"
func main() {
log := plog.NewConsoleLogger(" - ",
plog.LevelFmt("(%-5s)"),
plog.TimestampFmt("2006-01-02T15:04:05Z07:00"),
plog.MessageFmt("%-20s"),
plog.LocationFmt("%s[%d]"),
)
log.SetLogPrefix("[").SetLogSuffix("]")
log.Info("startup")
log.Debug("change to debug level")
log.SetLevel(plog.Debug)
log.Debug("level changed")
log.Infof("2 + 2 = %d", 2 + 2)
}
#+END_SRC
#+BEGIN_SRC shell :results output :exports both
go run examples/logformat.go
#+END_SRC
#+RESULTS:
: [(INFO ) - 2020-02-19T09:34:18+01:00 - startup - logformat[16]]
: [(DEBUG) - 2020-02-19T09:34:18+01:00 - level changed - logformat[19]]
: [(INFO ) - 2020-02-19T09:34:18+01:00 - 2 + 2 = 4 - logformat[20]]
** Log output format per program arguments
#+BEGIN_SRC go :tangle examples/log-output-format-per-args.go :eval no
package main
import "github.com/j-keck/plog"
import "flag"
func main() {
//
// flags
//
logTs := flag.Bool("log-timestamps", false, "log messages with timestamps")
logLocation := flag.Bool("log-location", false, "log messages with caller location")
flag.Parse()
//
// initialize / configure the logger
//
log := plog.NewConsoleLogger(" | ")
// timestamp only when '-log-timestamps' flag is given
if *logTs {
log.AddLogFormatter(plog.TimestampUnixDate)
}
// log level
log.AddLogFormatter(plog.Level)
// location only when '-log-location' flag is given
if *logLocation {
log.AddLogFormatter(plog.Location)
}
// log message
log.AddLogFormatter(plog.Message)
//
// action
//
log.Info("startup")
log.Debug("change to debug level")
log.SetLevel(plog.Debug)
log.Debug("level changed")
log.Infof("2 + 2 = %d", 2 + 2)
}
#+END_SRC
#+BEGIN_SRC shell :results output :exports results
run() { echo $(printf "=%.0s" {1..80}); echo "j@main:~ ⟩ $@"; $@; echo;}
run go run examples/log-output-format-per-args.go
run go run examples/log-output-format-per-args.go -log-timestamps
run go run examples/log-output-format-per-args.go -log-location
run go run examples/log-output-format-per-args.go -log-timestamps -log-location
#+END_SRC
#+RESULTS:
#+begin_example
================================================================================
j@main:~ ⟩ go run examples/log-output-format-per-args.go
INFO | startup
DEBUG | level changed
INFO | 2 + 2 = 4
================================================================================
j@main:~ ⟩ go run examples/log-output-format-per-args.go -log-timestamps
Wed Feb 19 09:34:19 CET 2020 | INFO | startup
Wed Feb 19 09:34:19 CET 2020 | DEBUG | level changed
Wed Feb 19 09:34:19 CET 2020 | INFO | 2 + 2 = 4
================================================================================
j@main:~ ⟩ go run examples/log-output-format-per-args.go -log-location
INFO | log-output-format-per-args:40 | startup
DEBUG | log-output-format-per-args:43 | level changed
INFO | log-output-format-per-args:44 | 2 + 2 = 4
================================================================================
j@main:~ ⟩ go run examples/log-output-format-per-args.go -log-timestamps -log-location
Wed Feb 19 09:34:20 CET 2020 | INFO | log-output-format-per-args:40 | startup
Wed Feb 19 09:34:20 CET 2020 | DEBUG | log-output-format-per-args:43 | level changed
Wed Feb 19 09:34:20 CET 2020 | INFO | log-output-format-per-args:44 | 2 + 2 = 4
#+end_example
** Set LogLevel per program arguments
#+BEGIN_SRC go :tangle examples/loglevel-per-args.go :eval no
package main
import "github.com/j-keck/plog"
import "flag"
func main() {
log := plog.NewDefaultConsoleLogger()
logLevel := plog.Info
plog.FlagDebugVar(&logLevel, "v", "debug")
plog.FlagTraceVar(&logLevel, "vv", "trace")
flag.Parse()
log.SetLevel(logLevel)
log.Info("info")
log.Debug("debug")
log.Trace("trace")
}
#+END_SRC
#+BEGIN_SRC shell :results output :exports results
run() { echo $(printf "=%.0s" {1..80}); echo "j@main:~ ⟩ $@"; $@; echo;}
run go run examples/loglevel-per-args.go
run go run examples/loglevel-per-args.go -v
run go run examples/loglevel-per-args.go -vv
#+END_SRC
#+RESULTS:
#+begin_example
================================================================================
j@main:~ ⟩ go run examples/loglevel-per-args.go
Wed Feb 19 09:34:20 CET 2020 | INFO | info
================================================================================
j@main:~ ⟩ go run examples/loglevel-per-args.go -v
Wed Feb 19 09:34:20 CET 2020 | INFO | info
Wed Feb 19 09:34:20 CET 2020 | DEBUG | debug
================================================================================
j@main:~ ⟩ go run examples/loglevel-per-args.go -vv
Wed Feb 19 09:34:21 CET 2020 | INFO | info
Wed Feb 19 09:34:21 CET 2020 | DEBUG | debug
Wed Feb 19 09:34:21 CET 2020 | TRACE | trace
#+end_example
** Log over a go channel
~plog.NewStreamLogger()~ creates a new streaming logger.
With ~Subscribe(bufferSize int) <-chan LogMessage~ you get a go channel where
the log messages are emitted.
#+BEGIN_SRC go :tangle examples/stream.go :eval no
package main
import "github.com/j-keck/plog"
import "fmt"
import "time"
func main() {
log := plog.NewStreamLogger()
logC := log.Subscribe(10)
log.Info("startup")
log.Debug("change to debug level")
log.SetLevel(plog.Debug)
log.Debug("level changed")
log.Infof("2 + 2 = %d", 2 + 2)
go func() {
for msg := range logC {
fmt.Printf("%s: %s\n", msg.Level, msg.Message)
}
}()
log.WaitForSubscribers(100 * time.Millisecond)
}
#+END_SRC
#+BEGIN_SRC shell :results output :exports both
go run examples/stream.go
#+END_SRC
#+RESULTS:
: INFO: startup
: DEBUG: level changed
: INFO: 2 + 2 = 4
** Broadcast log messages to multiple receivers.
To simplify the example, only console loggers are used,
but you can also use stream loggers.
#+BEGIN_SRC go :tangle examples/broadcast.go :eval no
package main
import "github.com/j-keck/plog"
func main() {
log := plog.NewBroadcastLogger(
plog.NewDefaultConsoleLogger(),
plog.NewDefaultConsoleLogger(),
plog.NewDefaultConsoleLogger(),
)
log.Info("startup")
log.Debug("change to debug level")
log.SetLevel(plog.Debug)
log.Debug("level changed")
log.Infof("2 + 2 = %d", 2 + 2)
}
#+END_SRC
#+BEGIN_SRC shell :results output :exports both
go run examples/broadcast.go
#+END_SRC
#+RESULTS:
: Wed Feb 19 09:34:22 CET 2020 | INFO | startup
: Wed Feb 19 09:34:22 CET 2020 | INFO | startup
: Wed Feb 19 09:34:22 CET 2020 | INFO | startup
: Wed Feb 19 09:34:22 CET 2020 | DEBUG | level changed
: Wed Feb 19 09:34:22 CET 2020 | DEBUG | level changed
: Wed Feb 19 09:34:22 CET 2020 | DEBUG | level changed
: Wed Feb 19 09:34:22 CET 2020 | INFO | 2 + 2 = 4
: Wed Feb 19 09:34:22 CET 2020 | INFO | 2 + 2 = 4
: Wed Feb 19 09:34:22 CET 2020 | INFO | 2 + 2 = 4