Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Simplify NSM logging system #1308

Open
wants to merge 6 commits into
base: main
Choose a base branch
from
Open

Simplify NSM logging system #1308

Show file tree
Hide file tree
Changes from 4 commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
ebf273b
Remove EnableTracing and udpate condition to enable tracing by Log level
anastasia-malysheva Jun 3, 2022
5e6914a
Lint fix
anastasia-malysheva Jun 3, 2022
897fa47
Add check for registry trace
anastasia-malysheva Jun 7, 2022
067d2a0
fix lint error
anastasia-malysheva Jun 7, 2022
510ee8f
simplify registry traceInfo
anastasia-malysheva Jul 11, 2022
a4f482f
lint fixes
anastasia-malysheva Jul 11, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 2 additions & 5 deletions pkg/networkservice/core/trace/common_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
// Copyright (c) 2020 Cisco Systems, Inc.
// Copyright (c) 2020-2022 Cisco Systems, Inc.
//
// Copyright (c) 2021 Doc.ai and/or its affiliates.
// Copyright (c) 2021-2022 Doc.ai and/or its affiliates.
//
// SPDX-License-Identifier: Apache-2.0
//
Expand Down Expand Up @@ -37,7 +37,6 @@ import (
"github.com/networkservicemesh/sdk/pkg/networkservice/core/chain"
"github.com/networkservicemesh/sdk/pkg/networkservice/core/next"
"github.com/networkservicemesh/sdk/pkg/networkservice/core/trace"
"github.com/networkservicemesh/sdk/pkg/tools/log"
)

func TestDiffMechanism(t *testing.T) {
Expand Down Expand Up @@ -113,7 +112,6 @@ func TestTraceOutput(t *testing.T) {
DisableTimestamp: true,
})
logrus.SetLevel(logrus.TraceLevel)
log.EnableTracing(true)

// Create a chain with modifying elements
ch := chain.NewNetworkServiceServer(
Expand Down Expand Up @@ -168,7 +166,6 @@ func TestErrorOutput(t *testing.T) {
DisableTimestamp: true,
})
logrus.SetLevel(logrus.TraceLevel)
log.EnableTracing(true)

// Create a chain with modifying elements
ch := chain.NewNetworkServiceServer(
Expand Down
4 changes: 3 additions & 1 deletion pkg/networkservice/core/trace/context.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,8 @@ import (

"google.golang.org/protobuf/proto"

"github.com/sirupsen/logrus"

"github.com/networkservicemesh/sdk/pkg/tools/grpcutils"
"github.com/networkservicemesh/sdk/pkg/tools/log"
"github.com/networkservicemesh/sdk/pkg/tools/log/logruslogger"
Expand Down Expand Up @@ -55,7 +57,7 @@ func withLog(parent context.Context, operation, connectionID string) (c context.
parent = grpcutils.PassTraceToOutgoing(parent)

if grpcTraceState := grpcutils.TraceFromContext(parent); (grpcTraceState == grpcutils.TraceOn) ||
(grpcTraceState == grpcutils.TraceUndefined && log.IsTracingEnabled()) {
(grpcTraceState == grpcutils.TraceUndefined && logrus.GetLevel() == logrus.TraceLevel) {
ctx, sLogger, span, sFinish := spanlogger.FromContext(parent, operation, map[string]interface{}{"type": loggedType, "id": connectionID})
ctx, lLogger, lFinish := logruslogger.FromSpan(ctx, span, operation, map[string]interface{}{"type": loggedType, "id": connectionID})
return withTrace(log.WithLog(ctx, sLogger, lLogger)), func() {
Expand Down
21 changes: 12 additions & 9 deletions pkg/registry/core/trace/common.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
// Copyright (c) 2021 Doc.ai and/or its affiliates.
// Copyright (c) 2021-2022 Doc.ai and/or its affiliates.
//
// SPDX-License-Identifier: Apache-2.0
//
Expand Down Expand Up @@ -44,13 +44,16 @@ func logError(ctx context.Context, err error, operation string) error {
}

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)
registryInfo, ok := trace(ctx)
if ok && registryInfo.Request != nil {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This condition is always false

We don't need to check Request and Response, because these fields are used only for networkservice (not for registry)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@glazychev-art , fixes for both comments were made

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)
}
s.Tracef("%v=%s", k, msg)
}
38 changes: 35 additions & 3 deletions pkg/registry/core/trace/context.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,16 +21,30 @@ package trace
import (
"context"

"github.com/sirupsen/logrus"
"google.golang.org/protobuf/proto"

"github.com/networkservicemesh/sdk/pkg/tools/grpcutils"
"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 (
loggedType = "registry"
traceInfoKey contextKeyType = "RegistryInfo"
loggedType string = "registry"
)

// traceInfo - struct, containing string representations of request and response, used for tracing.
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
// traceInfo - struct, containing string representations of request and response, used for tracing.
type traceInfo struct {}

type traceInfo struct {
// Request is last Registry action of NetworkService{Client, Server}
Request proto.Message
// Response is last Registry action-response of NetworkService{Client, Server}
Response proto.Message
}

// withLog - provides corresponding logger in context
func withLog(parent context.Context, operation string) (c context.Context, f func()) {
if parent == nil {
Expand All @@ -41,13 +55,31 @@ func withLog(parent context.Context, operation string) (c context.Context, f fun
parent = grpcutils.PassTraceToOutgoing(parent)

if grpcTraceState := grpcutils.TraceFromContext(parent); (grpcTraceState == grpcutils.TraceOn) ||
(grpcTraceState == grpcutils.TraceUndefined && log.IsTracingEnabled()) {
(grpcTraceState == grpcutils.TraceUndefined && logrus.GetLevel() == logrus.TraceLevel) {
ctx, sLogger, span, sFinish := spanlogger.FromContext(parent, operation, map[string]interface{}{"type": loggedType})
ctx, lLogger, lFinish := logruslogger.FromSpan(ctx, span, operation, map[string]interface{}{"type": loggedType})
return log.WithLog(ctx, sLogger, lLogger), func() {
return withTrace(log.WithLog(ctx, sLogger, lLogger)), func() {
sFinish()
lFinish()
}
}
return log.WithLog(parent), func() {}
}

// withTrace - Provides a traceInfo in context
func withTrace(parent context.Context) context.Context {
if parent == nil {
panic("cannot create context from nil parent")
}
if _, ok := trace(parent); ok {
// We already had registry info
return parent
}

return context.WithValue(parent, traceInfoKey, &traceInfo{})
}

func trace(ctx context.Context) (*traceInfo, bool) {
val, ok := ctx.Value(traceInfoKey).(*traceInfo)
return val, ok
}
23 changes: 0 additions & 23 deletions pkg/tools/log/logger.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,9 +19,6 @@ package log

import (
"context"
"sync/atomic"

"github.com/sirupsen/logrus"
)

type contextKeyType string
Expand All @@ -30,10 +27,6 @@ const (
logKey contextKeyType = "Logger"
)

var (
isTracingEnabled int32 = 0
)

// Logger - unified interface for logging
type Logger interface {
Info(v ...interface{})
Expand Down Expand Up @@ -76,19 +69,3 @@ func Join(ctx context.Context, log Logger) context.Context {
func WithLog(ctx context.Context, log ...Logger) context.Context {
return context.WithValue(ctx, logKey, Combine(log...))
}

// IsTracingEnabled - checks if it is allowed to use traces
func IsTracingEnabled() bool {
// TODO: Rework this within https://github.com/networkservicemesh/sdk/issues/1272
return atomic.LoadInt32(&isTracingEnabled) != 0 && logrus.GetLevel() == logrus.TraceLevel
}

// EnableTracing - enable/disable traces
func EnableTracing(enable bool) {
if enable {
atomic.StoreInt32(&isTracingEnabled, 1)
return
}

atomic.StoreInt32(&isTracingEnabled, 0)
}
3 changes: 1 addition & 2 deletions pkg/tools/opentelemetry/README.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,8 +25,7 @@ The example exposes the following backends:
## Using spans and metrics in tests
After running docker-compose you can enable spans and metrics inside any test using the following code:
```Go
log.EnableTracing(true)
os.Setenv("TELEMETRY", "opentelemetry")
os.Setenv("TELEMETRY", "true")
spanExporter := opentelemetry.InitSpanExporter(ctx, "0.0.0.0:4317")
metricExporter := opentelemetry.InitMetricExporter(ctx, "0.0.0.0:4317")
o := opentelemetry.Init(ctx, spanExporter, metricExporter, "NSM")
Expand Down