As outlined in https://github.com/rs/zerolog/issues/84, this patch refactors the zerolog.ConsoleWriter in two ways:

• The default formatting has been changed to be more sparse and visually attractive
• The formatting logic has been extracted to separate functions, so it can be changed from the user code

I had to change the design of the prototype in order to maintain the backwards compatibility: the prototype has defined default formatting functions (formatters) on the concrete instance of ConsoleWriter, but without using an initializer, these would be empty. Therefore, I've added a number of defensive checks into ConsoleWriter.Write(), and a ConsoleWriter.Reset() method. This is not ideal, but I agree that maintaining backwards compatibility is an important goal, and the behaviour is predictable in my testing.

I've added a benchmark test to make sure I inadverently don't harm the performance: the performance has stayed roughly the same. The tests and examples have been run with the -race parameter.

I've updated the screenshot to reflect the new look, and added a comprehensive example to the README.

Submitting the PR for #21 with two minor things in the todo items:

1. Changes to documentation (README.md) Because after code review, will write the docs.

2. When doing reflection, skip using JSON and write a binary based encoder Writing an equivalent of json.Marshal() would take more time and careful testing.

When zerolog logs an error message with an Error() finalizer, it returns a error. If the StackTrace() event has been called, the error will be a wrapped error using github.com/pkg/errors and will include the stack trace.

There are a few subtle differences introduced with this change:

1. It is possible to defeat this behavior using the Fields() method.
2. Only one error can be handled by an Event at a time.

Time was spent considering introducing an accumulator for errors that would be evaluated at finalizer-time, but this seemed unnecessary given errors should be wrapped and multiple calls to Err() seemed unlikely in practice.

The behavior of the Msg() finalizer was left in tact in order to avoid any performance penalty in non-error handling conditions. The deferral of error handling can best be observed by looking at the performance hit of an Err() Event with and without StackTrace():

BenchmarkErrorContextFields-8                  	20000000	        84.8 ns/op
BenchmarkErrorContextFields_WithStackTrace-8   	  500000	      2552 ns/op
BenchmarkLogContextFields-8                    	30000000	        47.6 ns/op
PASS
ok  	github.com/rs/zerolog	4.642s

Fixes: #9

What happened: Using Context.Stack().Logger() does not work, the stack is not added to each log entries.

What you expected to happen: The stack field should be added to each log entries

How to reproduce it (as minimally and precisely as possible):

package main

import (
	"github.com/pkg/errors"

	"github.com/rs/zerolog"
	"github.com/rs/zerolog/log"
	"github.com/rs/zerolog/pkgerrors"
)

func myFunc() {

	err := errors.New("my error")
	err = errors.WithStack(errors.Wrap(err, "something failed"))

	log.Error().Err(err).Msg("hello world")
}

func main() {
	zerolog.ErrorStackMarshaler = pkgerrors.MarshalStack

	log.Logger = log.With().Str("my", "field").Stack().Logger()
	myFunc()
}

Anything else we need to know?:

I think it comes from the fact that Context.Stack() setup an Hook which is called after the event is completely built, so Err never see that Stack() was enabled. We can see it because the following example works as expected:

package main

import (
	"github.com/pkg/errors"

	"github.com/rs/zerolog"
	"github.com/rs/zerolog/log"
	"github.com/rs/zerolog/pkgerrors"
)

func myFunc() {

	err := errors.New("my error")
	err = errors.WithStack(errors.Wrap(err, "something failed"))

	log.Error().Stack().Err(err).Msg("hello world")
}

func main() {
	zerolog.ErrorStackMarshaler = pkgerrors.MarshalStack

	log.Logger = log.With().Str("my", "field").Logger()
	myFunc()
}

I'm not sure how to fix this. One solution could be to add a stack field to Logger which would be transferred to the event in logger.newEvent.

I've got an idea to retranslate logger messages to Opentracing. It needs to add some mechanics to be able to propagate the span context from context.Context to the logger.

Proposal for #11.

@sean-: what do you think about this implementation?

I'm not super happy of the API. I'm not sure having Stack and Err separated is great design. What would you think about a new set of error-with-stack methods that would package the error message and the stack together.

For instance:

log.Log().ErrStack("error", err).Msg("")

would generate:

{"error": {"message": "error message", "stack": [{...}, {...}]}}

Hey - I've recently decided to switch to zerolog and wanted to try and help by adding some organization to the README.md file. I love the logger so far! As I'm teaching myself the library and learning the APIs, it seems like there's some room for improvement in the instructions for the layman (that would be me)... I have more edits I'd like to make as I go, but wanted to see if you considered this helpful before I spent more time on it! Thanks for the logger and your consideration!

You can see the changes fully realized at my fork, which may be easier to read than all the code merge: https://github.com/gilcrest/zerolog

Dan

Sometimes you want finer-grained informational events and need to debug something that outputs way too much data to log outside of a specific build when you're targeting that particular thing and do not care about errors or other logging info (since the volume of trace info will obscure them).

I think this could encroach on loggers like journald and that's why I'm asking for your opinion on adding this new log level.

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...

While using hook capability, in my use case, I had to access buf member in zerolog.Event struct, which is currently available only using reflection, which affects the performance.

Hi,

I spent an hour or so debugging zerolog, so let's see if i'm wrong or there is a bug :-)

In the sample application code (without testing.T to keep it as simple as possible) below, the default output does not go to stderr, but stdout. When I debug, I do see initialization within zerolog to stderr, but the end result is not in stderr...

package main

import (
	"bytes"
	"fmt"
	"io"
	"os"
	"strings"

	"github.com/rs/zerolog/log"
)


func captureStderr(f func()) (string, error) {
	var errOccurred error // in case an error occurred
	old := os.Stderr      // keep backup of the real stderr
	r, w, err := os.Pipe()
	if err != nil {
		return "", err
	}
	os.Stderr = w

	outC := make(chan string)
	// copy the output in a separate goroutine so printing can't block indefinitely
	go func() {
		var buf bytes.Buffer
		_, cpErr := io.Copy(&buf, r)
		if cpErr != nil {
			errOccurred = cpErr
		}
		outC <- buf.String()
	}()

	// calling function which stderr we are going to capture:
	f()

	// back to normal state
	err = w.Close()
	if err != nil {
		_, err = old.Write([]byte("Could not close file, error: " + err.Error()))
		if err != nil {
			errOccurred = err
		}
	}
	os.Stderr = old // restoring the real stderr
	if errOccurred != nil {
		fmt.Printf("CaptureStderr, error occurred: %v\n", err)
	}
	return <-outC, nil
}


func main() {
	stdErr, err := captureStderr(func() {
		log.Error().Msg("sw")
	})
	if err != nil {
		fmt.Println("error: " + err.Error())
	}
	if !strings.Contains(stdErr, "sw") {
		fmt.Println("stderr does not contain, output: " + stdErr)
	} else {
		fmt.Println("ok, stderr contains: " + stdErr)
	}
}

module "awesomeProject"

go 1.14

require (
    github.com/rs/zerolog v1.19.0
)

Bumps actions/cache from 3.0.5 to 3.2.2.

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.

I've been using https://pkg.go.dev/github.com/rs/zerolog#Logger.Write to emit error logs from https://pkg.go.dev/net/http#Server and as the stderr for https://pkg.go.dev/os/exec#Cmd, so that output all goes to the same place.

In both of those cases the level of the log messages is always nil, which I guess makes sense because nothing is setting the level.

Is there some way to set a default level for Logger.Write? Any suggestions for how I might be able to set a level on these log lines? Thanks!

Hi,

Just a suggestion. Would it be better to replace example code here as the one below so that the callers matches in json and flat line logs? e.g. some/path/to/file.go:123 (no forward slash at the beginning which matches json version)

Thanks

From

zerolog.CallerMarshalFunc = func(pc uintptr, file string, line int) string {
    short := file
    for i := len(file) - 1; i > 0; i-- {
        if file[i] == '/' {
            short = file[i+1:]
            break
        }
    }
    file = short
    return file + ":" + strconv.Itoa(line)
}

To

zerolog.CallerMarshalFunc = func(_ uintptr, file string, line int) string {
	p, _ := os.Getwd()

	return fmt.Sprintf("%s:%d", strings.TrimPrefix(file, p+"/"), line)
}

I'm new to using zerolog. I'm using ConsoleWriter, as it's indented to be viewable to the end-user, while running the program. However, double quotes seem to be escaped.

	logger.Fatal(). // Fatal because this is the last attempt at a ping
		Err(err).
		Str("help", "Privileged pings are disabled. To enable, run \"sudo sysctl -w net.ipv4.ping_group_range=\"0 2147483647\"\" For more information, check https://github.com/prometheus-community/pro-bing#linux").
		Msg("Privileged ping failed")

Outputs the followig: 2022-11-05T03:23:29-05:00 FTL Privileged ping failed error="socket: permission denied" help="Privileged pings are disabled. To enable, run \"sudo sysctl -w net.ipv4.ping_group_range=\"0 2147483647\"\" For more information, check https://github.com/prometheus-community/pro-bing#linux"

My logger configuration is logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr, TimeFormat: time.RFC3339}).Level(zerolog.DebugLevel).With().Timestamp().Logger()

Is there an idiomatic way to access context.Context from an Event?

My goal is to support OpenTelemetry's span.AddEvent(...) seamlessly

(eg. if a span is in ctx, log.Info().Msg("foo") should invoke span.AddEvent(...))