rs/zerolog

Zero Allocation JSON Logger

zerolog's Issues

Close() logger method

It would be nice to have Close() error method defined on zerolog.Logger. When it's called it checks if writer implements io.Closer interface and if yes: return l.w.Close().

This is not something required when we use os.Stdout/os.Stderr as writer. But is very helpful for buffered log writers to file, to make sure that every byte buffered in will be written to file before program exists.
Currently it's possible with treating such log writer separately from logger, which isn't comfortable as makes us to deal with one more dependency across the code.

However, os.Stdout/os.Stderr also implement io.Closer, so somebody can accidentally close them, which is not good 😕

Feature proposal: optional debug log sections

A pattern for logging I found handy in the NodeJS world is the util.debuglog() method.

Basically you have named sections of the debug log that you can enable the output for individually instead of turning on a firehose of debugging output from every part of the application at once.

So it could work something like

log.Section("foo").Debug().Int("magic", n).Msg("Made some magic")

and the output would be enabled by an environment variable:

$ DEBUG_SECTION=foo ./app

or alternatively through a setting on the logger in Go. Basically bypassing the Level check for events that have an explicitly enabled section.

To make it even more powerful it could allow specifying any output level for a given section rather than only being for Debug level events, and/or support wildcards for sections that have a hierarchy of name prefixes.

$ LOG_SECTIONS="foo=debug,bar*=info" ./app

log rotate Q

@rs - do you know what methods do users use for log rotation ?? From my analysis there are two methods:
i. rename the current log file (say log.txt) to say log.txt.1, and signal the process to close and re-open log.txt and start writing to the new log.txt file.
ii. copy the current log file (log.txt to log.txt.1) and then truncate the log.txt to null file...

If users (especially binary log) use method ii, then the writer may have written partial log message into log.txt just as it is copied over to log.txt.1. So, a single log message bytes could be split into two pieces and first half is in the old file and second half in the new file. If this happens, binary logger will not be able to detect this.

OTOH, if users use method i, then the file is closed and re-opened and there is almost no chance of this single log msg split across two log files.

I ask - so that we can first document this, while i look for a way to handle (if needed).

Thx

Could zerolog be faster with fewer pointer values?

I see that zerolog uses a lot of pointer values, for e.g. *Event and *Array.

My take-away from reading https://segment.com/blog/allocation-efficiency-in-high-performance-go-services/?utm_source=golangweekly&utm_medium=email, is something like:

• Copying in Go is quite fast, e.g. due to the use of a Duffs-device implementation within the runtime.
• It's relatively expensive when variables escape to the heap, also because the GC would need to care about it.
• By using pointers, slices with pointers, interfaces and slices where the size can not be determined at compile time, generally escape to the heap.

It would be interesting to know if there would be possible to prevent logger or event instances from escaping to the heap with less pointer usage for the cases where Array and Event are used, and if that's visible on the benchmarks.

The ConsoleWriter doesn't work well on windows10

The Code:

The messy output in Windows 10 (git bash & powershell & cmd):

And it‘s normal in Linux。

It seems like the spaces are not displayed properly...

Provide equivalent to std library log SetFlags

It would be nice to be able to show line output with log messages similar to how the standard library does this:

log.SetFlags(log.LstdFlags | log.Lshortfile)

Is this async safe?

I am working on a project involving many concurrent services that all require some manner of logging on their own. So far I have been using Zerolog since I love the API it provides and the performance seems to be very good. I have however been noticing that oftentimes I will not see logs from goroutines etc. Is this package safe for concurrent use? Right now I use a single logger instance with is passed to other services using logger.With().Str("service", "example").Logger() and a pointer...

Accessing errors and fields in hooks

I'd like to send whatever is logged on Error level to Sentry, but the hooks API only gives me a write only event that doesn't allow me to access log fields.
Is there a way to do so?

does zerolog support call depth when logging?

As the subtitle, is there someway to add log invoke func as a default field

[Feature Request] Allow log level to be outputted as multiple fields with different names

Currently the default field name for the log level is level as respected by most logging systems. Unfortunately Stackdriver Logging doesn't recognize this; it only respects field name severity instead.

Luckily I can set this with the LevelFieldName:

// log as severity for stackdriver logging to recognize the level
zerolog.LevelFieldName = "severity"

However in that case I loose the level field as recognized by many other systems. Is it possible to be able to set multiple level field names and have the information outputted redundantly?

Or is it possible to do this with some kind of interceptor? Thx

Adding feature to allow zerolog to output SystemD compatible binary logs.

The current behavior of zerlog binary output is to support CBOR encoding, however, with systemD emerging and being used in almost every Linux Distribution (Debian, CentOS, RHEL, SLES which are Distributions dedicated for enterprise/server consumption mainly).

One could argue that it is beneficial to implement the journalD (logger service integrated with systemD) to allow persistent logging and even a concise way to log information across a server-stack.

The following links provide information about this feature request:

• A kind of "RFC" for journalD API
• journalD API integrated natively with golang.

Two things to point out however, journalD binary files are highly corruptible and I personally do not favor them, however this is not about opinions, but providing the right tool for the general public.

The current STD logging in zerolog works perfectly fine when using journalctl -u goservice.service however, the logs are not persistent and lose all the data on restart/reboot of the system or service, thus the need for the "journaling" integration.

Thank you, and Best of Luck!

Time for first release?

Hello and thanks for package!

It would be convenient to have a release version of this package so tool like dep can track it. Of course it can track it without version, but still it's cleaner to see actual versions instead of commit IDs :)

Thanks again.

Context.Caller report wrong file and line number with Msgf

log.Logger = log.With().Caller().Logger()
log.Debug().Msg("report blabla.go:123")
log.Debug().Msgf("%s", "report wrong file and line")

Add an optional context field to capture the filename and line number

Often it's useful to capture the filename and line number in the log, to help finding the location where this log entry is generated.

zap have this feature:

... "caller":"hello/main.go:221" ...

zerolog should support this too, may be in an optional context field like Timestamp()?

Parameters position and order

Hello.

Is it possible to configure parameters order and position in logger lines?

E.g. I need a message generated with Msg() to be in the beginning of the line, after the level, along with time, so it turns to level, time, message, the rest of the fields ...

I would also like to have an ability to place certain additional fields in custom positions. Right now all fields in json log seem to build up only alphabetically.

This is pretty basic in other loggers and would help a lot for both visual appearance and eye scanning, as well as processing by external log consumers which can read only some initial fields (e.g. metrics or service data).

Structs as embedded json (feature request)

I had a few use cases that I needed to log a struct as embedded json under a single key. I had to marshal the json and use RawJson type. It would be great if we would have a struct type.

How to add log caller info in a fixed position for pretty logging style

i'm try to output log with pretty logging style:

logger := zerolog.New(os.Stdout).With().Timestamp().Logger().Output(zerolog.ConsoleWriter{Out: os.Stdout})

logger.Info().Str("foo", "bar").Msg("Hello world")

and the output will be pretty good as:

2018-02-07T15:09:21+08:00 |INFO| Hello world foo=bar

is it possible to add caller info, such as file name, line no info at a fixed position , such as:

2018-02-07T15:09:21+08:00 |INFO|main.go|74| Hello world foo=bar

i try to add hook for logger to parse the caller info:

func (h CallerHook) Run(e *zerolog.Event, level zerolog.Level, msg string) {
	if _, file, line, ok := runtime.Caller(3); ok {
		e.Str("file", path.Base(file)).Int("line", line)
	}
}

logger := zerolog.New(os.Stdout).With().Timestamp().Logger().Hook(CallerHook{}).Output(zerolog.ConsoleWriter{Out: os.Stdout})

obviously, the file/line info are output as normal fields, such as:

2018-02-07T15:16:35+08:00 |INFO| Hello world file=man.go foo=bar func=main line=74

Document the best strategy to send logs to external services

Hi,

Is it possible to add documentation for the best strategies to ship log to external services ? (like loggly...)

In logrus it's done using hooks but zerolog seems to use the io.Writer interface.

So what is the best practice to implement a writer that write to stdout and ship logs to an external service (eg: logz.io...) ?

I understand best practices recommend to print to stdout (https://12factor.net/logs) and let your process manager ship logs, but sometime it's not possible.

Best regards,
Sylvain

Understanding benchmarks

Hi - I'm trying to compare zerolog to zap, and the benchmarks as reported in the two readmes are very different. (There's obviously a lot more to things than just benchmarks, but the results are very different).

Looking at uber-go/zap#483 it looks like the zap project added benchmarks which might have been different from the ones that were used for the readme in this project. Are the zerolog readme's benchmarks available?

Example to show setting decendent logger to independently from parent logging level?

Uber zap is very unfriendly for this, would like to see yours.
Would like to see one that people will just integrate and not thinking too much, but focus on the real requirement of their project.

[ANN] New grpc-zerolog adapter...

This issue can be closed, but for the archives and people digging around, we created a gRPC LogginV2 adapter for zerolog:

https://github.com/cheapRoc/grpc-zerolog

CC @cheapRoc

Why do you need levelWriterAdapter?

Hello,

I wanted to ask, why do you need levelWriterAdapter, that implements LevelWriter, if it WriteLevel just calls the Write io.Writer method with no level usage?

And the second question, don't you think, that in MultiLevelWriter() function it is better to create lwriters with initial length == len(writers)), just like this:
lwriters := make([]LevelWriter, len(writers)) and then add elements by index?

Thank you for your package, it is really nice

With().Str(...).Logger() fails while With().Timestamp().Str(...).Logger() works

If I try to bind some parameters to a context without calling Timestamp() on it then it will fail at print time (I'm logging to Stdout with zerolog.New(os.Stderr).Output(zerolog.ConsoleWriter{Out: os.Stderr})).

The error is:

zerolog: could not write event: invalid character 'f' looking for beginning of object key string

f is the first character of the first bound parameter (the key). If I change the parameter the "invalid character" also changes.

`RawJSON` panic when `Event` is nil.

zerolog/event.go

Line 236 in be4b7c1

e.buf = append(json.AppendKey(e.buf, key), b...)

Most of the other methods check whether Event is nil but not this.

long integer/int64 displayed as float

I'm receiving the following log lines for a long integer/int64. It appears to be turned into a float.

2018-03-22T23:03:04-04:00 |DEBU| test log line thing_id=332962181439815681
2018-03-22T23:03:04-04:00 |DEBU| Query args=[3.332574358090875e+17] module=pgx rowCount=1 sql="\nSELECT id, name, created_at, updated_at\nFROM testtable\nWHERE id = $1 AND archived = false;\n"

The fields thing_id and args contain the same value int64(332962181439815681). The first line formats the int64 properly by using fmt.Sprintf("%d", thingID) however just using the Int64 field function in zerolog does not.

I've read somewhere that this is common due to the JSON parser/marshaling but I've yet to be able to reproduce a test case myself (except through zerolog).

Any thoughts would be great, unsure if this is a bug or what I'm doing wrong.

Thanks.

Changing output of level to int?

Hello,

My fluentd cluster is having issues indexing via level due to most other services using integer for level rather than string.

What is the recommended way to override the type that level outputs?

Document default behaviour of logging to stderr

The default behaviour of the logger is to log to stderr rather than stdout. This may not be expected (I didn't realise for a long time) and should be made clear in the documentation to avoid confusion.

[Question] Single Timestamp() without duplication

Currently, if logger is configured with timestamps

logger := zerolog.New(os.Stdout).With().Timestamp().Logger()

It will create a hook which fires on Msg() (an actual time field is generated and appended when Msg() is called).

logger.Info().Str("body", "some").Msg("end")
// {"lvl":"info","body":"some","time":"2018-03-07T13:10:22.383313411Z","msg":"end"}

Sometimes we want to create a log message in one goroutine, but write in another. In this case we want to have timestamp when log entry is created, not when it's actually written. So we do something like:

log := logger.Info().Timestamp().Str("body", "some")
go func() {
    // ...
    log.Msg("start")
}()

But zerolog duplicates timestamps in this case:

// {"lvl":"info","time":"2018-03-07T13:17:11.177163291Z","body":"some","time":"2018-03-07T13:17:11.177194077Z","msg":"start"}

Question

Is there a way to capture log entry timestamp early without timestamps duplication?

Hex output for bytes

Currently, the bytes are returned as ASCII / code points. That's not very useful; in most cases, it would be better to have a hex encoding such as provided by the hex package of the standard library.

Confusing behavior with context.Context integration

First, thanks for this library; the API is easy to use and the hlog package is a nice bonus.

We recently started using zerolog.Ctx and (Logger) WithContext and were surprised to find that WithContext modified the context instead of creating a copy of the context with the modified logger. This means that when we set fields in functions that should only be visible to the functions they call, those fields are instead included on all future log message.

This program demonstrates the issue (it happens more naturally in HTTP handlers):

package main

import (
	"context"
	"github.com/rs/zerolog"
	"os"
)

func process(ctx context.Context, id int) {
	log := zerolog.Ctx(ctx).With().Int("id", id).Logger()
	child(log.WithContext(ctx))
}

func child(ctx context.Context) {
	zerolog.Ctx(ctx).Info().Msg("hello from child")
}

func main() {
	ctx := zerolog.New(os.Stdout).WithContext(context.Background())

	zerolog.Ctx(ctx).Info().Msg("processing 1")
	process(ctx, 1)

	zerolog.Ctx(ctx).Info().Msg("processing 2")
	process(ctx, 2)

	zerolog.Ctx(ctx).Info().Msg("done")
}

# expected output
{"level":"info","message":"processing 1"}
{"level":"info","id":1,"message":"hello from child"}
{"level":"info","message":"processing 2"}
{"level":"info","id":2,"message":"hello from child"}
{"level":"info","message":"done"}

# actual output
{"level":"info","message":"processing 1"}
{"level":"info","id":1,"message":"hello from child"}
{"level":"info","id":1,"message":"processing 2"}
{"level":"info","id":1,"id":2,"message":"hello from child"}
{"level":"info","id":1,"id":2,"message":"done"}

I did some digging in the history and it seems like this was added in 6a6144a to support the hlog functions, which are more efficient when they can modify the existing logger and can reasonably expect to exist at the top of the middleware stack.

However, at some later point, all those functions switched to use (*Logger) UpdateContext, which achieves the same thing. It seems like (Logger) WithContext is now only used to set the initial logger.

I think this behavior goes against the expectations of context.Context (modifications are not visible to functions that were not passed the modified context) and makes it difficult to add new logging fields only for sections of a request handler.

Is it possible that (Logger) WithContext could be reverted to always return a copy of the context if the logger is updated?

If not, do you have recommendations on how to work around this behavior? We're currently going to write our own functions to interact with the context, but it would be great if we could stick with the library functions.

Question about Error and os.Stderr

Question here that may come down to more practice then technical but I'm curious. In my applications I still expect errors to go out to Stderr, but we create a logger with one FD. That FD is usually standout. Are you guys sending >= Error to Stderr when logging (I'm using containers to it is the correct thing in my arch to send logs directly to these FDs). If you guys are, do you create two loggers one with Stderr and one with Stdout?

Thanks.

add depth/skip for Caller()

we need to set caller skip manually instead of setting the global CallerSkipFrameCount.

something like this:

func (c Context) Caller(skip int32) Context

Please provide documentation for writing to rsyslog and embedding filename and line number

Console writer prints large ints incorrectly

Using the following test case case:

import (
	"github.com/rs/zerolog/log"
	"github.com/rs/zerolog"
	"os"
)

func main() {
	log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr})
	log.Info().Uint64("foo", 1152921504606846976).Msg("test")
}

the output it produces:

$ go log.go
2018-04-19T12:51:32-07:00 |INFO| test foo=1.152921504606847e+18

setting a .Str() key to "level" can cause panic

The line below causes a panic in cosole.go (line 58). This is due to the usage of the "level" key and a value of less than 4. When the value is 4 chars or longer no panic, however the str value is then mistakenly displayed in the |LEVEL| format field.
log.Info().Str("level", "0").Msg("exception")

Collaboration with Onelog?

There have been a bunch of loggers popping up all getting down to zero allocation with minimal compute overhead. So now it comes down to an API preference. I just discovered Onelog which makes comparisons with Zerolog. I think the two APIs are nice in their own way. I like Onelog because there is less chaining since it uses functions so augment a message. That said Zerolog is more mature, has more features and integrations, and have a larger community.

Is there any desire or interest in the two projects unifying? Taking the best from both?

The wrong code example in README.md

Hi,
I read the README of zerolog, I think zerolog is cool and I want to use it in my work. I find something wrong in README, I run the code in go1.10.2 darwin/amd64

Sub dictionary
log.Info().
    Str("foo", "bar").
    Dict("dict", zerolog.Dict().
        Str("bar", "baz").
        Int("n", 1)
    ).Msg("hello world")

right code:

Sub dictionary
log.Info().
    Str("foo", "bar").
    Dict("dict", zerolog.Dict().
        Str("bar", "baz").
        Int("n", 1),  // fix here
    ).Msg("hello world")

New functions for improved composability

As of right now, zerolog's interface is not very composable. If you have an object that can be serialized and you want to log it, it can be very awkward to achieve that. Consider the following:

type Price struct {
    val uint64
    prec int
    unit Unit 
}

var price = Price{val: 6449, prec: 2, unit: currency.USD}

And suppose it can be serialized into something like $64.49. Now to achieve it right now you need something like (assuming we want to keep the number of allocations to 0):

var buf = getBuffer()
price.PrintJSONValue(buf)
log.Warn().Bytes("price", buf.Bytes()).Msg("Price is too high")
freeBuffer(buf)

this is a handful and leaks the implementation details of both price and zerolog to a degree. It also does an unnecessary copy.
Of course all of this could be avoided if price and zerolog coud somehow share the byte buffer.
One of the ways would be simply allowing the user access to the zerolog.Event's internal buffer.
Another would be an interface like (the actual names are arbitrary):

type JSONAppendable interface {
     JSONAppendTo([]byte) []byte
}
func (p *Price) JSONAppendTo(src []byte) (dst []byte) {
   // just assumes it's always dollars for demonstration purposes
    dst = append(src, `"$`...)
    dst = p.appendWholePart(dst)
    dst = append(dst, '.')
    dst = p.appendFracPart(dst)
    dst = append(dst, '"')
    return
}
//....
log.Warn().JSONVal("price", &price).Msg("Price is too high")

That interface can be reused/composed with not just zerolog but really any other custom json serializer, avoid unnecessary copies and keep the user of the logging call happily unaware about any implementation details

Enable hooks to transform Msg

Would it be possible to allow hooks to modify the message?

The use case I'm looking at is adding support for automatic redaction of potentially sensitive info (e.g. passwords, tokens) from log messages. This wouldn't address devs intentionally logging this via a structured attribute, but that's fairly visible in code review.

zero value for zerolog.Logger

package main

import (
	"github.com/rs/zerolog"
)

func main() {
	var log zerolog.Logger
	log.Info().Msg("crash")
}

$ go run zerolog-zero.go
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x28 pc=0x109832b]

goroutine 1 [running]:
github.com/rs/zerolog.(*Event).write(0xc420012240, 0x1b, 0x1f4)
	/.../go/src/github.com/rs/zerolog/event.go:61 +0x6b
github.com/rs/zerolog.(*Event).Msg(0xc420012240, 0x10ca3d8, 0x5)
	/.../go/src/github.com/rs/zerolog/event.go:86 +0x59
main.main()
	/.../go/src/exp/zerolog-zero.go:9 +0x9a
exit status 2

The best zero value would be github.com/rs/zerolog/log Logger.
Being calm is also better than panic, imho. Or at least it could panic at Info() event creation, not at writing Msg().

Error wrapping and returned error types...

First things first: thank you for the library. It's very interesting and promising. I've used it a few times in the last week with good success but noticed something in practice that I wanted to bring up.

import (
  "github.com/rs/zerolog/log"
  "github.com/pkg/errors"
)

func myFunc() error {
  if err := someMethod(); err != nil {
    log.Error().Err(err).Str("some detail", "my details").Msg("something bad")
    return errors.Wrapf(err, "something bad: some details")
  }

  return nil
}

Would you be interested in an Error() or Errorf() event processor that would return an error object? I'm already in the error path at this point in time and am less concerned about performance.

I'm hoping to arrive at something like the following in order to reduce redundant code:

import (
  "github.com/rs/zerolog/log"
  "github.com/pkg/errors"
)

func myFunc() error {
  if err := someMethod(); err != nil {
    return log.Error().Err(err).Str("some detail", "my details").Stacktrace().Error("something bad")
  }

  return nil
}

The thinking being that tStacktrace() would capture the current stack trace and include it in the error object returned to the caller, and the Error() event handler would return a wrapped error similar to github.com/pkg/errors, github.com/hashicorp/errwrap, github.com/contiv/errored.

Thoughts? Thanks in advance!

List companies / projects using zerolog

To contributors and users of this lib, I have created a wiki page to list companies / project using zerolog. This might help future users decide if this library is mature enough for their use.

Cc @rasky @rcoelho @johansja @y0ssar1an @awishformore @tyranron @gilcrest @xpzouying @nogoegst @millerlogic @toravir @unixisevil @tidwall @jgeiger @WJH

zerolog.Logger methods should be on *Logger, not value type

Allow user to configure timezone

At the moment, the only way to control time format is the zerolog.TimeFieldFormat.

There should be a way to allow the user to change the timezone of the timestamp.

Example: a user wants to always log in Zulu timezone (Z without timezone), no matter where the server is running. If she sets TimeFieldFormat to 2006-01-02T15:04:05Z, then the timestamp will be wrong if the server is running anywhere other than UTC.

Proposal: A customizable ConsoleWriter output

Hello, I've recently used zerolog in a project, and I like it very much — many thanks!

One thing I wanted to change was the ConsoleWriter output: I wanted to format the output differently, I wanted to highlight field values, not field names, etc. So I wrote a custom implementation, looking like this (adapting the output from zerolog's README):

I've realized that my needs are probably not unique (see #34), and that it would be nice to expose a customizable ConsoleWriter. Therefore, I've extracted what I did in the project into a library, available at https://github.com/karmi/consolelog, since I didn't want to just blindly send code your way.

My question is: is this something you would consider interesting to have in the zerolog library itself? If so, I can move the implementation into a patch and send a pull request.

Binary format support

[Enhancement]
having a binary logging support will be useful.. meaning keeping json formatted byte array means the code does a strconv for each data type. If we add an option to have binary log support, it will reduce the cpu and memory overhead. I did this simple test:

For Int type - current test passes '0' - it takes 31.2 ns/op

instead, if i put in MaxInt64 as field value, the time is 44ns/op:
BenchmarkLogFieldType/Int-8 30000000 44.0 ns/op

I attribute it to strconv() taking longer time to generate all the digits.

The conversion of the binary log to a readable format can be done offline.

I did a small code snippet to do comparison of JSON/BSON - the eval code and results are available here: https://github.com/toravir/bson-eval

My proposal is that zerolog can be configured either to use JSON or BSON. All the BSON code will be added into internal/bson/ directory.

Please reply if you think this is useful addition to zerolog.

suggest zerolog support multiple output like log file and stderr / stdout

FYI

suggest zerolog support multiple output like log file and stderr / stdout for debug on development

Enable hooks to filter Events

It would be nice if an hook could set a flag to mark an event to be discarded maybe by setting its level to zerolog.Discard, i.e:

func (h SeverityHook) Run(e *zerolog.Event, level zerolog.Level, msg string) {
    if condition {
        e.Level = zerolog.Discard
    }
}

How to change caller point?

//Two extra frames to skip (added by hook infra).

In this we need to skip 3. Because I am having one more wrapper on top of zerolog.

Level guards

One thing that i believe is missing is the possibly to get the current level of a zerolog.Logger. This might be useful when constructing log messages might be expensive (hot path + allocating) in certain places.
Something like

func (l *Logger) Is(lvl Level) bool {
        return l.level >= lvl
}

Don't know if this is something interesting because the only logging package that i could (quickly) find that has something like this is https://github.com/mgutz/logxi.