diff --git a/README.md b/README.md index 6fac775..b387c5a 100644 --- a/README.md +++ b/README.md @@ -6,7 +6,7 @@ The zerolog package provides a fast and simple logger dedicated to JSON output. Zerolog's API is designed to provide both a great developer experience and stunning [performance](#benchmarks). Its unique chaining API allows zerolog to write JSON log events by avoiding allocations and reflection. -The uber's [zap](https://godoc.org/go.uber.org/zap) library pioneered this approach. Zerolog is taking this concept to the next level with simpler to use API and even better performance. +Uber's [zap](https://godoc.org/go.uber.org/zap) library pioneered this approach. Zerolog is taking this concept to the next level with a simpler to use API and even better performance. To keep the code base and the API simple, zerolog focuses on JSON logging only. Pretty logging on the console is made possible using the provided (but inefficient) `zerolog.ConsoleWriter`. @@ -24,43 +24,144 @@ To keep the code base and the API simple, zerolog focuses on JSON logging only. * `net/http` helpers * Pretty logging for development -## Usage +## Installation +```go +go get -u github.com/rs/zerolog/log +``` +## Getting Started +### Simple Logging Example +For simple logging, import the global logger package **github.com/rs/zerolog/log** +```go +package main + +import ( + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" +) + +func main() { + // UNIX Time is faster and smaller than most timestamps + // If you set zerolog.TimeFieldFormat to an empty string, + // logs will write with UNIX time + zerolog.TimeFieldFormat = "" + + log.Print("hello world") +} + +// Output: {"time":1516134303,"level":"debug","message":"hello world"} +``` +> Note: The default log level for `log.Print` is *debug* +---- +### Leveled Logging + +#### Simple Leveled Logging Example ```go -import "github.com/rs/zerolog/log" +package main + +import ( + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" +) + +func main() { + zerolog.TimeFieldFormat = "" + + log.Info().Msg("hello world") +} + +// Output: {"time":1516134303,"level":"info","message":"hello world"} ``` -### A global logger can be use for simple logging +**zerolog** allows for logging at the following levels (from highest to lowest): +- panic (`zerolog.PanicLevel`, 5) +- fatal (`zerolog.FatalLevel`, 4) +- error (`zerolog.ErrorLevel`, 3) +- warn (`zerolog.WarnLevel`, 2) +- info (`zerolog.InfoLevel`, 1) +- debug (`zerolog.DebugLevel`, 0) +You can set the Global logging level to any of these options using the `SetGlobalLevel` function in the zerolog package, passing in one of the given constants above, e.g. `zerolog.InfoLevel` would be the "info" level. Whichever level is chosen, all logs with a level greater than or equal to that level will be written. To turn off logging entirely, pass the `zerolog.Disabled` constant. + +#### Setting Global Log Level +This example uses command-line flags to demonstrate various outputs depending on the chosen log level. ```go -log.Print("hello world") +package main -// Output: {"level":"debug","time":1494567715,"message":"hello world"} +import ( + "flag" + + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" +) + +func main() { + zerolog.TimeFieldFormat = "" + debug := flag.Bool("debug", false, "sets log level to debug") + + flag.Parse() + + // Default level for this example is info, unless debug flag is present + zerolog.SetGlobalLevel(zerolog.InfoLevel) + if *debug { + zerolog.SetGlobalLevel(zerolog.DebugLevel) + } + + log.Debug().Msg("This message appears only when log level set to Debug") + log.Info().Msg("This message appears when log level set to Debug or Info") + + if e := log.Debug(); e.Enabled() { + // Compute log output only if enabled. + value := "bar" + e.Str("foo", value).Msg("some debug message") + } +} +``` +Info Output (no flag) +```bash +$ ./logLevelExample +{"time":1516387492,"level":"info","message":"This message appears when log level set to Debug or Info"} ``` +Debug Output (debug flag set) +```bash +$ ./logLevelExample -debug +{"time":1516387573,"level":"debug","message":"This message appears only when log level set to Debug"} +{"time":1516387573,"level":"info","message":"This message appears when log level set to Debug or Info"} +{"time":1516387573,"level":"debug","foo":"bar","message":"some debug message"} +``` +#### Logging Fatal Messages ```go -log.Info().Msg("hello world") +package main -// Output: {"level":"info","time":1494567715,"message":"hello world"} +import ( + "errors" + + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" +) + +func main() { + err := errors.New("A repo man spends his life getting into tense situations") + service := "myservice" + + zerolog.TimeFieldFormat = "" + + log.Fatal(). + Err(err). + Str("service", service). + Msgf("Cannot start %s", service) +} + +// Output: {"time":1516133263,"level":"fatal","error":"A repo man spends his life getting into tense situations","service":"myservice","message":"Cannot start myservice"} +// exit status 1 ``` +> NOTE: Using `Msgf` generates one allocation even when the logger is disabled. +---------------- +### Contextual Logging -NOTE: To import the global logger, import the `log` subpackage `github.com/rs/zerolog/log`. - -```go -log.Fatal(). - Err(err). - Str("service", service). - Msgf("Cannot start %s", service) - -// Output: {"level":"fatal","time":1494567715,"message":"Cannot start myservice","error":"some error","service":"myservice"} -// Exit 1 -``` - -NOTE: Using `Msgf` generates one allocation even when the logger is disabled. - -### Fields can be added to log messages - +#### Fields can be added to log messages ```go log.Info(). Str("foo", "bar"). @@ -91,22 +192,7 @@ sublogger.Info().Msg("hello world") // Output: {"level":"info","time":1494567715,"message":"hello world","component":"foo"} ``` -### Level logging -```go -zerolog.SetGlobalLevel(zerolog.InfoLevel) - -log.Debug().Msg("filtered out message") -log.Info().Msg("routed message") - -if e := log.Debug(); e.Enabled() { - // Compute log output only if enabled. - value := compute() - e.Str("foo": value).Msg("some debug message") -} - -// Output: {"level":"info","time":1494567715,"message":"routed message"} -``` ### Pretty logging @@ -375,4 +461,3 @@ Log a static string, without any context or `printf`-style templating: | logrus | 1244 ns/op | 1505 B/op | 27 allocs/op | | apex/log | 2751 ns/op | 584 B/op | 11 allocs/op | | log15 | 5181 ns/op | 1592 B/op | 26 allocs/op | - diff --git a/log/log_example_test.go b/log/log_example_test.go new file mode 100644 index 0000000..b52cb78 --- /dev/null +++ b/log/log_example_test.go @@ -0,0 +1,141 @@ +package log_test + +import ( + "errors" + "flag" + "os" + "time" + + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" +) + +// setup would normally be an init() function, however, there seems +// to be something awry with the testing framework when we set the +// global Logger from an init() +func setup() { + // UNIX Time is faster and smaller than most timestamps + // If you set zerolog.TimeFieldFormat to an empty string, + // logs will write with UNIX time + zerolog.TimeFieldFormat = "" + // In order to always output a static time to stdout for these + // examples to pass, we need to override zerolog.TimestampFunc + // and log.Logger globals -- you would not normally need to do this + zerolog.TimestampFunc = func() time.Time { + return time.Date(2008, 1, 8, 17, 5, 05, 0, time.UTC) + } + log.Logger = zerolog.New(os.Stdout).With().Timestamp().Logger() +} + +// Simple logging example using the Print function in the log package +// Note that both Print and Printf are at the debug log level by default +func ExamplePrint() { + setup() + + log.Print("hello world") + // Output: {"time":1199811905,"level":"debug","message":"hello world"} +} + +// Simple logging example using the Printf function in the log package +func ExamplePrintf() { + setup() + + log.Printf("hello %s", "world") + // Output: {"time":1199811905,"level":"debug","message":"hello world"} +} + +// Example of a log with no particular "level" +func ExampleLog() { + setup() + log.Log().Msg("hello world") + + // Output: {"time":1199811905,"message":"hello world"} +} + +// Example of a log at a particular "level" (in this case, "debug") +func ExampleDebug() { + setup() + log.Debug().Msg("hello world") + + // Output: {"time":1199811905,"level":"debug","message":"hello world"} +} + +// Example of a log at a particular "level" (in this case, "info") +func ExampleInfo() { + setup() + log.Info().Msg("hello world") + + // Output: {"time":1199811905,"level":"info","message":"hello world"} +} + +// Example of a log at a particular "level" (in this case, "warn") +func ExampleWarn() { + setup() + log.Warn().Msg("hello world") + + // Output: {"time":1199811905,"level":"warn","message":"hello world"} +} + +// Example of a log at a particular "level" (in this case, "error") +func ExampleError() { + setup() + log.Error().Msg("hello world") + + // Output: {"time":1199811905,"level":"error","message":"hello world"} +} + +// Example of a log at a particular "level" (in this case, "fatal") +func ExampleFatal() { + setup() + err := errors.New("A repo man spends his life getting into tense situations") + service := "myservice" + + log.Fatal(). + Err(err). + Str("service", service). + Msgf("Cannot start %s", service) + + // Outputs: {"time":1199811905,"level":"fatal","error":"A repo man spends his life getting into tense situations","service":"myservice","message":"Cannot start myservice"} +} + +// TODO: Panic + +// This example uses command-line flags to demonstrate various outputs +// depending on the chosen log level. +func ExampleLevelFlag() { + setup() + debug := flag.Bool("debug", false, "sets log level to debug") + + flag.Parse() + + // Default level for this example is info, unless debug flag is present + zerolog.SetGlobalLevel(zerolog.InfoLevel) + if *debug { + zerolog.SetGlobalLevel(zerolog.DebugLevel) + } + + log.Debug().Msg("This message appears only when log level set to Debug") + log.Info().Msg("This message appears when log level set to Debug or Info") + + if e := log.Debug(); e.Enabled() { + // Compute log output only if enabled. + value := "bar" + e.Str("foo", value).Msg("some debug message") + } + + // Output: {"time":1199811905,"level":"info","message":"This message appears when log level set to Debug or Info"} +} + +// TODO: Output + +// TODO: With + +// TODO: Level + +// TODO: Sample + +// TODO: Hook + +// TODO: WithLevel + +// TODO: Ctx