Search code examples
goprotocol-buffersprotobuf-gogo-zap

Correctly log protobuf messages as unescaped JSON with zap logger


I have a Go project where I'm using Zap structured logging to log the contents of structs. That's how I initialise the logger:

zapLog, err := zap.NewProductionConfig().Build()
if err != nil {
    panic(err)
}

Initially I started with my own structs with json tags and it all worked perfectly:

zapLog.Info("Event persisted", zap.Any("event", &event))

Result:

{"level":"info","ts":1626448680.69099,"caller":"persisters/log.go:56",
 "msg":"Event persisted","event":{"sourceType":4, "sourceId":"some-source-id", 
 "type":"updated", "value":"{...}", "context":{"foo":"bar"}}}

I now switched to protobuf and I'm struggling to achieve the same result. Initially I just got the "reflected map" version, when using zap.Any():

zapLog.Info("Event persisted", zap.Any("event", &event))
{"level":"info","ts":1626448680.69099,"caller":"persisters/log.go:56",
 "msg":"Event persisted","event":"sourceType:TYPE_X sourceId:\"some-source-id\", 
 type:\"updated\" value:{...}, context:<key: foo, value:bar>}

I tried marshalling the object with the jsonpb marshaller, which generated the correct output on itself, however, when I use it in zap.String(), the string is escaped, so I get an extra set of '\' in front of each quotation mark. Since there's processing of the logs at a later point, this causes problems there and hence I want to avoid it:

m := jsonpb.Marshaler{}
var buf bytes.Buffer
if err := m.Marshal(&buf, msg); err != nil {
    // handle error
}
zapLog.Info("Event persisted", zap.ByteString("event", buf.Bytes()))

Result:

{"level":"info","ts":1626448680.69099,"caller":"persisters/log.go:56",
 "msg":"Event persisted","event":"{\"sourceType\":\"TYPE_X\", \"sourceId\":\"some-source-id\", 
 \"type\":\"updated\", \"value\":\"{...}\", \"context\":{\"foo\":"bar\"}}"}

I then tried using zap.Reflect() instead of zap.Any() which was the closest thing I could get to what I need, except that enums are rendered as their numerical values (the initial solution did not have enums, so that didn't work in the pre-protobuf solution either):

zapLog.Info("Event persisted", zap.Reflect("event", &event))

Result:

{"level":"info","ts":1626448680.69099,"caller":"persisters/log.go:56",
 "msg":"Event persisted","event":{"sourceType":4, "sourceId":"some-source-id", 
 "type":"updated", "value":"{...}", "context":{"foo":"bar"}}}

The only option I see so far is to write my own MarshalLogObject() function:

type ZapEvent struct {
    event *Event
}

func (z *ZapEvent) MarshalLogObject(encoder zapcore.ObjectEncoder) error {

  encoder.AddString("sourceType", z.event.SourceType.String()
  // implement encoder for each attribute

}

func processEvent(e Event) {
   ...
   zapLog.Info("Event persisted", zap.Object("event", &ZapEvent{event: &e}))
}

But since it's a complex struct, I would rather use a less error prone and maintenance heavy solution. Ideally, I would tell zap to use the jsonpb marshaller somehow, but I don't know if that's possible.


Solution

  • Use zap.Any with a json.RawMessage. You can convert directly the byte output of jsonpb.Marshaler:

        foo := &pb.FooMsg{
            Foo: "blah", 
            Bar:  1,
        }
    
        m := jsonpb.Marshaler{}
        var buf bytes.Buffer
        if err := m.Marshal(&buf, foo); err != nil {
            // handle error
        }
    
        logger, _ := zap.NewDevelopment()
        logger.Info("Event persisted", zap.Any("event", json.RawMessage(buf.Bytes())))
    

    The bytes will be printed as:

    Event persisted {"event": {"foo":"blah","bar":"1"}}`

    I believe that's the easiest way, however I'm also aware of a package kazegusuri/go-proto-zap-marshaler (I'm not affiliated to it) that generates MarshalLogObject() implementations as a protoc plugin. You may want to take a look at that too.