How to add new columns/fields to a ZAP log entry?

Question

I have the following logging structure:

[STDERR] 2018-07-09 11:06:16.003    INFO    some_pkg/main.go:232    Logging message 1   {"pid": 8842, "process": "some_process"}
[STDERR] 2018-07-09 11:06:16.006    DEBUG   some_pkg/main.go:291    Logging message 2   {"pid": 8842, "process": "other_process"}
[STDERR] 2018-07-09 11:06:16.009    INFO    some_pkg/main.go:345    Logging message 3   {"pid": 8842, "process": "some_process"}

You can see there are five types of information in this logging snippet. There are date/time, log-level, occurrence, message and a JSON fields (except [STDERR] field). Which means I have five columns in my logging structure. I would like to add a new columns with key pid and process (from the JSON). How should I do this with ZAP encoders and configs? I didn't find a solution for that in the ZAP documentation.

I use the following code to add fields to the logging:

logger = logger.With(zap.Field{Key: "pid", Type: zapcore.Int64Type, Integer: int64(os.Getpid())})

But the pid field's value goes to a JSON (what you can see above) and I would like to see it in a new column. There is an easy way in ZAP to do this?

My desired structure would be the following with the previous example:

[STDERR] 2018-07-09 11:06:16.003    INFO    some_pkg/main.go:232    Logging message 1   8842    some_process
[STDERR] 2018-07-09 11:06:16.006    DEBUG   some_pkg/main.go:291    Logging message 2   8836    other_process
[STDERR] 2018-07-09 11:06:16.009    INFO    some_pkg/main.go:345    Logging message 3   8842    some_process

Vigue

Answer 1

There isn't a very good way to do this. This answer provides an explanation, a non-solution and a hack.

Explanation

First of all let me clarify the terminology: the log "columns" you are talking about are the fields of zapcore.Entry, i.e. the log entry. The spacing between the columns is given by the field ConsoleSeparator of zapcore.EncoderConfig, which defaults to \t.

The formatting of the log entry happens in the EncodeEntry method of the consoleEncoder type, but you can't customize its behavior: zapcore.Entry is a struct and there are no hooks in that implementation that you can exploit to change what and when the fields are logged. It might be worth to request this to the zap team.

The non-solution

The first option you are left with is to implement your own encoder and use it to construct a zapcore.Core:

enc := &customEncoder{} 
logger := zap.New(zapcore.NewCore(enc, os.Stderr, zap.NewAtomicLevelAt(zap.DebugLevel)))

The custom encoder must implement zapcore.Encoder. This comes with a number of problems, e.g. the order of the log entry fields, the possible presence of a stack trace, the encoder's configuration options, code reuse, etc. It's not worth it to go into all the details; I'll just say that it will be very awkward to implement zapcore.Encoder for this use case, and likely not worth the maintenance burden.

The hack

The last field of zapcore.Entry that the default console encoder prints is the Message. So what you can do is to pre-format the message:

pid := 8842
procname := "some_process"

msg := fmt.Sprintf("Logging message 1\t%d\t%s", pid, procname)
logger.Info(msg)

Will print:

[STDERR] 2018-07-09 11:06:16.003 INFO some_pkg/main.go:232 Logging message 1 8842 some_process

Lundy

Answer 2

The requested logging style would result in a mix of structured logging (json) and unstructured logging (all other fields in the console).

blackgreen's answer should make it possible, and it's a good hack, but the bigger problem here I think is that you are working against what zap has to offer (Blazing fast, structured, leveled logging in Go.).

The recommended approach would be to put everything in json and parse json keys in whatever log viewer you are using. The resulting log structure looks something like this:

{"timeStamp": "2018-07-09 11:06:16.003", "level": "INFO", "source": "some_pkg/main.go:232", "msg": "Logging message 1", "pid": 8842, "process": "some_process"}

Dogwood