From dacfc9890c073f8e33baf1aa9ca21114f095ab02 Mon Sep 17 00:00:00 2001 From: anastasia-malysheva <81400483+anastasia-malysheva@users.noreply.github.com> Date: Thu, 25 Aug 2022 08:46:14 +0700 Subject: [PATCH] Add tracing and logs to dns handlers (#1343) * add logs to dns context functions Signed-off-by: Nikita Skrynnik * add tracing to dns handlers Signed-off-by: Nikita Skrynnik * resolve conflict Signed-off-by: anastasia.malysheva * use another diff package (looks better) Signed-off-by: Nikita Skrynnik * cleanup Signed-off-by: Nikita Skrynnik * add ResponseWriter wrapper Signed-off-by: Nikita Skrynnik * add ResponseWriter wrapper Signed-off-by: Nikita Skrynnik * add logResponse func Signed-off-by: Nikita Skrynnik * add wrapper on every trace chain element call (looks working) Signed-off-by: Nikita Skrynnik * cleanup Signed-off-by: Nikita Skrynnik * cleanup Signed-off-by: Nikita Skrynnik * resolve conflict Signed-off-by: anastasia.malysheva * apply review comments Signed-off-by: Nikita Skrynnik * fix after go mod tidy Signed-off-by: anastasia.malysheva Signed-off-by: Nikita Skrynnik Signed-off-by: anastasia.malysheva Co-authored-by: Nikita Skrynnik --- go.mod | 1 + go.sum | 2 + pkg/tools/clienturlctx/context.go | 1 + pkg/tools/dnsutils/chain/server.go | 31 ++++++++++ pkg/tools/dnsutils/fanout/handler.go | 2 +- pkg/tools/dnsutils/next/next.go | 22 +++++-- pkg/tools/dnsutils/searches/context.go | 3 + pkg/tools/dnsutils/trace/common.go | 80 ++++++++++++++++++++++++ pkg/tools/dnsutils/trace/context.go | 72 ++++++++++++++++++++++ pkg/tools/dnsutils/trace/handler.go | 85 ++++++++++++++++++++++++++ 10 files changed, 293 insertions(+), 6 deletions(-) create mode 100644 pkg/tools/dnsutils/chain/server.go create mode 100644 pkg/tools/dnsutils/trace/common.go create mode 100644 pkg/tools/dnsutils/trace/context.go create mode 100644 pkg/tools/dnsutils/trace/handler.go diff --git a/go.mod b/go.mod index d098c2b86..34c78090a 100644 --- a/go.mod +++ b/go.mod @@ -21,6 +21,7 @@ require ( github.com/networkservicemesh/api v1.4.1-0.20220711153918-a59689088578 github.com/open-policy-agent/opa v0.43.0 github.com/pkg/errors v0.9.1 + github.com/r3labs/diff v1.1.0 github.com/sirupsen/logrus v1.9.0 github.com/spiffe/go-spiffe/v2 v2.0.0 github.com/stretchr/testify v1.8.0 diff --git a/go.sum b/go.sum index 7ed5300f7..821c8c5ec 100644 --- a/go.sum +++ b/go.sum @@ -904,6 +904,8 @@ github.com/prometheus/procfs v0.6.0/go.mod h1:cz+aTbrPOrUb4q7XlbU9ygM+/jj0fzG6c1 github.com/prometheus/procfs v0.7.3 h1:4jVXhlkAyzOScmCkXBTOLRLTz8EeU+eyjrwB/EPq0VU= github.com/prometheus/procfs v0.7.3/go.mod h1:cz+aTbrPOrUb4q7XlbU9ygM+/jj0fzG6c1xBZuNvfVA= github.com/prometheus/tsdb v0.7.1/go.mod h1:qhTCs0VvXwvX/y3TZrWD7rabWM+ijKTux40TwIPHuXU= +github.com/r3labs/diff v1.1.0 h1:V53xhrbTHrWFWq3gI4b94AjgEJOerO1+1l0xyHOBi8M= +github.com/r3labs/diff v1.1.0/go.mod h1:7WjXasNzi0vJetRcB/RqNl5dlIsmXcTTLmF5IoH6Xig= github.com/rabbitmq/amqp091-go v1.1.0/go.mod h1:ogQDLSOACsLPsIq0NpbtiifNZi2YOz0VTJ0kHRghqbM= github.com/rcrowley/go-metrics v0.0.0-20200313005456-10cdbea86bc0/go.mod h1:bCqnVzQkZxMG4s8nGwiZ5l3QUCyqpo9Y+/ZMZ9VjZe4= github.com/rcrowley/go-metrics v0.0.0-20201227073835-cf1acfcdf475 h1:N/ElC8H3+5XpJzTSTfLsJV/mx9Q9g7kxmchpfZyxgzM= diff --git a/pkg/tools/clienturlctx/context.go b/pkg/tools/clienturlctx/context.go index 3be8c06e7..cfe11cc07 100644 --- a/pkg/tools/clienturlctx/context.go +++ b/pkg/tools/clienturlctx/context.go @@ -58,6 +58,7 @@ func WithClientURLs(parent context.Context, urls []url.URL) context.Context { if parent == nil { panic("cannot create context from nil parent") } + log.FromContext(parent).Debugf("passed clientURLs: %v", urls) return context.WithValue(parent, clientURLsKey, urls) } diff --git a/pkg/tools/dnsutils/chain/server.go b/pkg/tools/dnsutils/chain/server.go new file mode 100644 index 000000000..9e8395fbf --- /dev/null +++ b/pkg/tools/dnsutils/chain/server.go @@ -0,0 +1,31 @@ +// Copyright (c) 2022 Cisco Systems, Inc. +// +// SPDX-License-Identifier: Apache-2.0 +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at: +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +// Package chain provides a simple file for creating a dnsutils.Handler from a 'chain' of dnsutils.Handler +package chain + +import ( + "github.com/networkservicemesh/sdk/pkg/tools/dnsutils" + "github.com/networkservicemesh/sdk/pkg/tools/dnsutils/next" + "github.com/networkservicemesh/sdk/pkg/tools/dnsutils/trace" +) + +// NewDNSHandler - chains together a list of dnsutils.Handler with tracing +func NewDNSHandler(handlers ...dnsutils.Handler) dnsutils.Handler { + return next.NewDNSHandler( + next.NewWrappedDNSHandler(trace.NewDNSHandler, handlers...), + ) +} diff --git a/pkg/tools/dnsutils/fanout/handler.go b/pkg/tools/dnsutils/fanout/handler.go index 4a01be8e6..10dc550fe 100644 --- a/pkg/tools/dnsutils/fanout/handler.go +++ b/pkg/tools/dnsutils/fanout/handler.go @@ -84,7 +84,7 @@ func (h *fanoutHandler) ServeDNS(ctx context.Context, rw dns.ResponseWriter, msg return } - next.Handler(ctx).ServeDNS(ctx, rw, resp) + next.Handler(ctx).ServeDNS(ctx, rw, msg) } func (h *fanoutHandler) waitResponse(ctx context.Context, respCh <-chan *dns.Msg) *dns.Msg { diff --git a/pkg/tools/dnsutils/next/next.go b/pkg/tools/dnsutils/next/next.go index 0fff08f70..47857b0f8 100644 --- a/pkg/tools/dnsutils/next/next.go +++ b/pkg/tools/dnsutils/next/next.go @@ -25,17 +25,29 @@ import ( "github.com/networkservicemesh/sdk/pkg/tools/dnsutils" ) -// NewDNSHandler creates a new chain of dns handlers -func NewDNSHandler(handlers ...dnsutils.Handler) dnsutils.Handler { - return &nextDNSHandler{handlers: handlers} -} - type nextDNSHandler struct { handlers []dnsutils.Handler index int nextParent dnsutils.Handler } +// ServerWrapper - A function that wraps a dnsutils.Handler +type ServerWrapper func(dnsutils.Handler) dnsutils.Handler + +// NewWrappedDNSHandler - chains together the servers provides with the wrapper wrapped around each one in turn. +func NewWrappedDNSHandler(wrapper ServerWrapper, handlers ...dnsutils.Handler) dnsutils.Handler { + rv := &nextDNSHandler{handlers: make([]dnsutils.Handler, 0, len(handlers))} + for _, h := range handlers { + rv.handlers = append(rv.handlers, wrapper(h)) + } + return rv +} + +// NewDNSHandler creates a new chain of dns handlers +func NewDNSHandler(handlers ...dnsutils.Handler) dnsutils.Handler { + return &nextDNSHandler{handlers: handlers} +} + func (n *nextDNSHandler) ServeDNS(ctx context.Context, rp dns.ResponseWriter, m *dns.Msg) { nextHandler, nextCtx := n.getClientAndContext(ctx) nextHandler.ServeDNS(nextCtx, rp, m) diff --git a/pkg/tools/dnsutils/searches/context.go b/pkg/tools/dnsutils/searches/context.go index 278b7c2dc..411eab4b1 100644 --- a/pkg/tools/dnsutils/searches/context.go +++ b/pkg/tools/dnsutils/searches/context.go @@ -18,6 +18,8 @@ package searches import ( "context" + + "github.com/networkservicemesh/sdk/pkg/tools/log" ) const ( @@ -31,6 +33,7 @@ func WithSearchDomains(parent context.Context, domains []string) context.Context if parent == nil { panic("cannot create context from nil parent") } + log.FromContext(parent).Debugf("passed SearchDomains: %v", domains) return context.WithValue(parent, searchDomainsKey, domains) } diff --git a/pkg/tools/dnsutils/trace/common.go b/pkg/tools/dnsutils/trace/common.go new file mode 100644 index 000000000..7255a1802 --- /dev/null +++ b/pkg/tools/dnsutils/trace/common.go @@ -0,0 +1,80 @@ +// Copyright (c) 2022 Cisco Systems, Inc. +// +// SPDX-License-Identifier: Apache-2.0 +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at: +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package trace + +import ( + "context" + "encoding/json" + "fmt" + "strings" + + "github.com/google/go-cmp/cmp" + "github.com/miekg/dns" + "github.com/r3labs/diff" + + "github.com/networkservicemesh/sdk/pkg/tools/log" +) + +func logRequest(ctx context.Context, message *dns.Msg, prefixes ...string) { + msg := strings.Join(append(prefixes, "request"), "-") + diffMsg := strings.Join(append(prefixes, "request", "diff"), "-") + + messageInfo, ok := trace(ctx) + if ok && !cmp.Equal(messageInfo.RequestMsg, message) { + if messageInfo.RequestMsg != nil { + messageDiff, _ := diff.Diff(messageInfo.RequestMsg, message) + if len(messageDiff) > 0 { + logObjectTrace(ctx, diffMsg, messageDiff) + } + } else { + logObjectTrace(ctx, msg, message) + } + messageInfo.RequestMsg = message.Copy() + return + } +} + +func logResponse(ctx context.Context, message *dns.Msg, prefixes ...string) { + msg := strings.Join(append(prefixes, "response"), "-") + diffMsg := strings.Join(append(prefixes, "response", "diff"), "-") + + messageInfo, ok := trace(ctx) + if ok && !cmp.Equal(messageInfo.ResponseMsg, message) { + if messageInfo.ResponseMsg != nil { + messageDiff, _ := diff.Diff(messageInfo.ResponseMsg, message) + if len(messageDiff) > 0 { + logObjectTrace(ctx, diffMsg, messageDiff) + } + } else { + logObjectTrace(ctx, msg, message) + } + messageInfo.ResponseMsg = message.Copy() + return + } +} + +func logObjectTrace(ctx context.Context, k, v interface{}) { + s := log.FromContext(ctx) + msg := "" + cc, err := json.Marshal(v) + if err == nil { + msg = string(cc) + } else { + msg = fmt.Sprint(v) + } + s.Tracef("%v=%s", k, msg) +} diff --git a/pkg/tools/dnsutils/trace/context.go b/pkg/tools/dnsutils/trace/context.go new file mode 100644 index 000000000..c99c7c48b --- /dev/null +++ b/pkg/tools/dnsutils/trace/context.go @@ -0,0 +1,72 @@ +// Copyright (c) 2020-2022 Cisco Systems, Inc. +// +// SPDX-License-Identifier: Apache-2.0 +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at: +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +// Package trace provides a wrapper for tracing around a dnsutils.Handler +package trace + +import ( + "context" + + "github.com/miekg/dns" + + "github.com/networkservicemesh/sdk/pkg/tools/log" + "github.com/networkservicemesh/sdk/pkg/tools/log/logruslogger" + "github.com/networkservicemesh/sdk/pkg/tools/log/spanlogger" +) + +type contextKeyType string + +const ( + traceInfoKey contextKeyType = "MessageInfo" + loggedType string = "dnsServer" +) + +type traceInfo struct { + RequestMsg *dns.Msg + ResponseMsg *dns.Msg +} + +func withLog(parent context.Context, operation, messageID string) (c context.Context, f func()) { + if parent == nil { + panic("cannot create context from nil parent") + } + + if log.IsTracingEnabled() { + ctx, sLogger, span, sFinish := spanlogger.FromContext(parent, operation, map[string]interface{}{"type": loggedType, "id": messageID}) + ctx, lLogger, lFinish := logruslogger.FromSpan(ctx, span, operation, map[string]interface{}{"type": loggedType, "id": messageID}) + return withTrace(log.WithLog(ctx, sLogger, lLogger)), func() { + sFinish() + lFinish() + } + } + return log.WithLog(parent), func() {} +} + +func withTrace(parent context.Context) context.Context { + if parent == nil { + panic("cannot create context from nil parent") + } + if _, ok := trace(parent); ok { + return parent + } + + return context.WithValue(parent, traceInfoKey, &traceInfo{}) +} + +func trace(ctx context.Context) (*traceInfo, bool) { + val, ok := ctx.Value(traceInfoKey).(*traceInfo) + return val, ok +} diff --git a/pkg/tools/dnsutils/trace/handler.go b/pkg/tools/dnsutils/trace/handler.go new file mode 100644 index 000000000..1c11bd2c5 --- /dev/null +++ b/pkg/tools/dnsutils/trace/handler.go @@ -0,0 +1,85 @@ +// Copyright (c) 2022 Cisco Systems, Inc. +// +// SPDX-License-Identifier: Apache-2.0 +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at: +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package trace + +import ( + "context" + "strconv" + + "github.com/miekg/dns" + + "github.com/networkservicemesh/sdk/pkg/tools/dnsutils" + "github.com/networkservicemesh/sdk/pkg/tools/dnsutils/next" + "github.com/networkservicemesh/sdk/pkg/tools/typeutils" +) + +type beginTraceHandler struct { + traced dnsutils.Handler +} + +type endTraceHandler struct{} + +// NewDNSHandler - wraps tracing around the supplied traced +func NewDNSHandler(traced dnsutils.Handler) dnsutils.Handler { + return next.NewDNSHandler( + &beginTraceHandler{traced: traced}, + &endTraceHandler{}, + ) +} + +func (t *beginTraceHandler) ServeDNS(ctx context.Context, rw dns.ResponseWriter, m *dns.Msg) { + operation := typeutils.GetFuncName(t.traced, "ServeDNS") + ctx, finish := withLog(ctx, operation, strconv.Itoa(int(m.Id))) + defer finish() + + logRequest(ctx, m, "message") + + wrapper := wrapResponseWriter(rw) + t.traced.ServeDNS(ctx, wrapper, m) + + logResponse(ctx, &wrapper.responseMsg, "message") +} + +func (t *endTraceHandler) ServeDNS(ctx context.Context, rw dns.ResponseWriter, m *dns.Msg) { + logRequest(ctx, m, "message") + + wrapper := wrapResponseWriter(rw) + next.Handler(ctx).ServeDNS(ctx, wrapper, m) + + logResponse(ctx, &wrapper.responseMsg, "message") +} + +func wrapResponseWriter(rw dns.ResponseWriter) *traceResponseWriter { + wrapper, ok := rw.(*traceResponseWriter) + if !ok { + wrapper = &traceResponseWriter{ + ResponseWriter: rw, + } + } + + return wrapper +} + +type traceResponseWriter struct { + dns.ResponseWriter + responseMsg dns.Msg +} + +func (rw *traceResponseWriter) WriteMsg(m *dns.Msg) error { + rw.responseMsg = *m.Copy() + return rw.ResponseWriter.WriteMsg(m) +}