From d7ce6681e0d17aa81405cc384ca07e729dbc7190 Mon Sep 17 00:00:00 2001 From: Dave Date: Sat, 6 Feb 2021 17:27:03 -0700 Subject: [PATCH] wire up Zap Development handler to Docker-Compose handler In the Docker-Compose handler/matcher - if you working on a JSON handler and the body (after the Docker-Compose prefix) is a Zap body, then handle it appropriately by calling back into the Zap Handler setup to handle the slightly different Docker-Compose logs. --- docker_compose_handler.go | 12 ++- zap_development_handler.go | 22 ++++++ zap_development_handler_test.go | 127 ++++++++++++++++++++++++++++---- 3 files changed, 147 insertions(+), 14 deletions(-) diff --git a/docker_compose_handler.go b/docker_compose_handler.go index 1025f4c..f88d8d3 100644 --- a/docker_compose_handler.go +++ b/docker_compose_handler.go @@ -19,11 +19,21 @@ type handler interface { } func tryDockerComposePrefix(d []byte, nextHandler handler) bool { - if matches := dcLogsPrefixRe.FindSubmatch(d); matches != nil { + matches := dcLogsPrefixRe.FindSubmatch(d) + if matches != nil { if nextHandler.TryHandle(matches[2]) { nextHandler.setField([]byte(`service`), matches[1]) return true } + // The Zap Development handler is only built for `JSONHandler`s so + // short-circuit calls for LogFmtHandlers + switch h := nextHandler.(type) { + case *JSONHandler: + if tryZapDevDCPrefix(matches[2], h) { + h.setField([]byte(`service`), matches[1]) + return true + } + } } return false } diff --git a/zap_development_handler.go b/zap_development_handler.go index 8d51d96..4823bf0 100644 --- a/zap_development_handler.go +++ b/zap_development_handler.go @@ -43,3 +43,25 @@ func tryZapDevPrefix(d []byte, handler *JSONHandler) bool { } return false } + +// This is not obviously an RFC-compliant format and is not a constant in the +// time package which is worrisome but this pattern does work. +const someOtherRFC = "2006-01-02T15:04:05.000Z" + +func tryZapDevDCPrefix(d []byte, handler *JSONHandler) bool { + if matches := zapDevDCLogsPrefixRe.FindSubmatch(d); matches != nil { + if handler.TryHandle(matches[5]) { + t, err := time.Parse(someOtherRFC, string(matches[1])) + if err != nil { + return false + } + handler.Time = t + + handler.Level = strings.ToLower(string(matches[2])) + handler.setField([]byte("caller"), matches[3]) + handler.Message = string(matches[4]) + return true + } + } + return false +} diff --git a/zap_development_handler_test.go b/zap_development_handler_test.go index a654cb8..9b5bdba 100644 --- a/zap_development_handler_test.go +++ b/zap_development_handler_test.go @@ -117,6 +117,108 @@ func Test_zapDevLogsPrefixRe(t *testing.T) { } } +func Test_tryZapDevPrefix(t *testing.T) { + tests := []struct { + name string + logLine []byte + wantMatch bool + + wantLevel string + wantLocation string + wantMessage string + + wantExtraContext string + }{ + { + name: "no match", + + logLine: []byte("that's no good"), + + wantMatch: false, + }, + { + name: "debug message", + + logLine: logLinesByLevel["DEBUG"], + + wantMatch: true, + wantLevel: "debug", + wantLocation: "zapper/zapper.go:18", + wantMessage: "some message 1", + }, + { + name: "error message with caller info", + + logLine: logLinesByLevel["ERROR"], + + wantMatch: true, + wantLevel: "error", + wantLocation: "zapper/zapper.go:18", + wantMessage: "some message 2", + }, + { + name: "fatal message with caller info and exit status", + + logLine: logLinesByLevel["FATAL"], + + wantMatch: true, + + wantLevel: "fatal", + wantLocation: "zapper/zapper.go:18", + wantMessage: "some message 5", + }, + { + name: "info message", + + logLine: logLinesByLevel["INFO"], + + wantMatch: true, + wantLevel: "info", + wantLocation: "zapper/zapper.go:18", + wantMessage: "some message 3", + }, + { + + name: "warning message with caller info", + + logLine: logLinesByLevel["WARN"], + + wantMatch: true, + wantLevel: "warn", + wantLocation: "zapper/zapper.go:18", + wantMessage: "some message 4", + }, + } + + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + h := &JSONHandler{} + m := tryZapDevPrefix(test.logLine, h) + + if m != test.wantMatch { + t.Error("expected the prefix to match, it did not") + } + // Short circuit - if we want failure don't assert against the handler + if !test.wantMatch { + return + } + + if reflect.DeepEqual(time.Time{}, h.Time) { + t.Errorf("want a parsed time, got empty time; want != got") + } + if h.Level != test.wantLevel { + t.Errorf("want %q, got %q; want != got", test.wantLevel, h.Level) + } + if h.Message != test.wantMessage { + t.Errorf("want %q, got %q; want != got", test.wantMessage, h.Message) + } + if h.Fields["caller"] != test.wantLocation { + t.Errorf("want %q, got %q; want != got", test.wantLocation, h.Fields["caller"]) + } + }) + } +} + var dcLogLinesByLevel = map[string][]byte{ "DEBUG": []byte("2021-02-06T22:55:22.004Z\tDEBUG\tzapper/zapper.go:17\tsome message 1\t{\"rand_index\": 1}"), "ERROR": []byte("2021-02-06T22:55:22.008Z\tERROR\tzapper/zapper.go:17\tsome message 2\t{\"rand_index\": 2}"), @@ -229,7 +331,7 @@ func Test_zapDCDevLogsPrefixRe(t *testing.T) { } } -func Test_tryZapDevPrefix(t *testing.T) { +func Test_tryZapDevDCPrefix(t *testing.T) { tests := []struct { name string logLine []byte @@ -251,53 +353,53 @@ func Test_tryZapDevPrefix(t *testing.T) { { name: "debug message", - logLine: logLinesByLevel["DEBUG"], + logLine: dcLogLinesByLevel["DEBUG"], wantMatch: true, wantLevel: "debug", - wantLocation: "zapper/zapper.go:18", + wantLocation: "zapper/zapper.go:17", wantMessage: "some message 1", }, { name: "error message with caller info", - logLine: logLinesByLevel["ERROR"], + logLine: dcLogLinesByLevel["ERROR"], wantMatch: true, wantLevel: "error", - wantLocation: "zapper/zapper.go:18", + wantLocation: "zapper/zapper.go:17", wantMessage: "some message 2", }, { name: "fatal message with caller info and exit status", - logLine: logLinesByLevel["FATAL"], + logLine: dcLogLinesByLevel["FATAL"], wantMatch: true, wantLevel: "fatal", - wantLocation: "zapper/zapper.go:18", + wantLocation: "zapper/zapper.go:17", wantMessage: "some message 5", }, { name: "info message", - logLine: logLinesByLevel["INFO"], + logLine: dcLogLinesByLevel["INFO"], wantMatch: true, wantLevel: "info", - wantLocation: "zapper/zapper.go:18", + wantLocation: "zapper/zapper.go:17", wantMessage: "some message 3", }, { name: "warning message with caller info", - logLine: logLinesByLevel["WARN"], + logLine: dcLogLinesByLevel["WARN"], wantMatch: true, wantLevel: "warn", - wantLocation: "zapper/zapper.go:18", + wantLocation: "zapper/zapper.go:17", wantMessage: "some message 4", }, } @@ -305,7 +407,7 @@ func Test_tryZapDevPrefix(t *testing.T) { for _, test := range tests { t.Run(test.name, func(t *testing.T) { h := &JSONHandler{} - m := tryZapDevPrefix(test.logLine, h) + m := tryZapDevDCPrefix(test.logLine, h) if m != test.wantMatch { t.Error("expected the prefix to match, it did not") @@ -329,5 +431,4 @@ func Test_tryZapDevPrefix(t *testing.T) { } }) } - }