Skip to content

Commit

Permalink
Add concise tracing (#1513)
Browse files Browse the repository at this point in the history 
* Log rotated after 5 minutes in NSMgr / Registry (-draft implementation for networkservise)

Signed-off-by: Alexander Peretyatko <[email protected]>

Log rotated after 5 minutes in NSMgr / Registry (-forwarder implementation)

Signed-off-by: Alexander Peretyatko <[email protected]>

Log rotated after 5 minutes in NSMgr / Registry (-skip the same errors)

Signed-off-by: Alexander Peretyatko <[email protected]>

Log rotated after 5 minutes in NSMgr / Registry (-clean up)

Signed-off-by: Alexander Peretyatko <[email protected]>

Log rotated after 5 minutes in NSMgr / Registry (-handle errors)

Signed-off-by: Alexander Peretyatko <[email protected]>

Log rotated after 5 minutes in NSMgr / Registry (-handle registry logs)

Signed-off-by: Alexander Peretyatko <[email protected]>

Log rotated after 5 minutes in NSMgr / Registry (-clean up)

Signed-off-by: Alexander Peretyatko <[email protected]>

Log rotated after 5 minutes in NSMgr / Registry (-clean up)

Signed-off-by: Alexander Peretyatko <[email protected]>

Log rotated after 5 minutes in NSMgr / Registry (-clean up)

Signed-off-by: Alexander Peretyatko <[email protected]>

* improvements

Signed-off-by: Artem Glazychev <[email protected]>

* fix datarace

Signed-off-by: Artem Glazychev <[email protected]>

* fix unstable tests

Signed-off-by: Artem Glazychev <[email protected]>

* fix registry span

Signed-off-by: Artem Glazychev <[email protected]>

* show concise logs in all cases except TraceLevel

Signed-off-by: Artem Glazychev <[email protected]>

* take into account grpcmetadata

Signed-off-by: Artem Glazychev <[email protected]>

---------

Signed-off-by: Alexander Peretyatko <[email protected]>
Signed-off-by: Artem Glazychev <[email protected]>
Co-authored-by: Alexander Peretyatko <[email protected]>
  • Loading branch information
@glazychev-art
glazychev-art and Alexander Peretyatko authored Sep 28, 2023
1 parent 97bacd7 commit 256d2cc
Show file tree
Hide file tree
Showing 32 changed files with 2,999 additions and 565 deletions.
5 changes: 5 additions & 0 deletions pkg/networkservice/chains/nsmgr/select_forwarder_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -376,12 +376,17 @@ func Test_DiscoverForwarder_Should_KeepSelectedForwarderWhileConnectionIsFine(t
conn, err = nsc.Request(ctx, request.Clone())
require.NoError(t, err)
require.Equal(t, 1, counter.UniqueRequests())
require.Equal(t, 3, counter.Requests())
require.Equal(t, 0, counter.Closes())
require.Equal(t, selectedForwarder, conn.GetPath().GetPathSegments()[2].Name)

// datapath is down
livenessValue.Store(false)
domain.Nodes[0].Forwarders[selectedForwarder].Cancel()
// waiting for healing
require.Eventually(t, func() bool {
return counter.Requests() >= 4
}, timeout, tick)

request.Connection = conn
conn, err = nsc.Request(ctx, request.Clone())
Expand Down
74 changes: 21 additions & 53 deletions pkg/networkservice/core/trace/client.go
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,4 @@
// Copyright (c) 2020-2023 Cisco Systems, Inc.
//
// Copyright (c) 2021-2023 Doc.ai and/or its affiliates.
// Copyright (c) 2023 Cisco and/or its affiliates.
//
// SPDX-License-Identifier: Apache-2.0
//
Expand All @@ -16,76 +14,46 @@
// See the License for the specific language governing permissions and
// limitations under the License.

// Package trace provides wrappers for tracing around a networkservice.NetworkServiceClient
package trace

import (
"context"

"github.com/sirupsen/logrus"

"github.com/golang/protobuf/ptypes/empty"
"google.golang.org/grpc"

"github.com/networkservicemesh/api/pkg/api/networkservice"

"github.com/networkservicemesh/sdk/pkg/networkservice/core/next"
"github.com/networkservicemesh/sdk/pkg/tools/typeutils"
"github.com/networkservicemesh/sdk/pkg/networkservice/core/trace/traceconcise"
"github.com/networkservicemesh/sdk/pkg/networkservice/core/trace/traceverbose"
)

type beginTraceClient struct {
traced networkservice.NetworkServiceClient
type traceClient struct {
verbose networkservice.NetworkServiceClient
concise networkservice.NetworkServiceClient
}

type endTraceClient struct{}

// NewNetworkServiceClient - wraps tracing around the supplied networkservice.NetworkServiceClient
func NewNetworkServiceClient(traced networkservice.NetworkServiceClient) networkservice.NetworkServiceClient {
return next.NewNetworkServiceClient(
&beginTraceClient{traced: traced},
&endTraceClient{},
)
}

func (t *beginTraceClient) Request(ctx context.Context, request *networkservice.NetworkServiceRequest, opts ...grpc.CallOption) (*networkservice.Connection, error) {
// Create a new logger
operation := typeutils.GetFuncName(t.traced, methodNameRequest)
ctx, finish := withLog(ctx, operation, methodNameRequest, request.GetConnection().GetId())
defer finish()

logRequest(ctx, request, "request")
// Actually call the next
rv, err := t.traced.Request(ctx, request, opts...)
if err != nil {
return nil, logError(ctx, err, operation)
return &traceClient{
verbose: traceverbose.NewNetworkServiceClient(traced),
concise: traceconcise.NewNetworkServiceClient(traced),
}
logResponse(ctx, rv, "request")
return rv, err
}

func (t *beginTraceClient) Close(ctx context.Context, conn *networkservice.Connection, opts ...grpc.CallOption) (*empty.Empty, error) {
// Create a new logger
operation := typeutils.GetFuncName(t.traced, methodNameClose)
ctx, finish := withLog(ctx, operation, methodNameClose, conn.GetId())
defer finish()

logRequest(ctx, conn, "close")
rv, err := t.traced.Close(ctx, conn, opts...)
if err != nil {
return nil, logError(ctx, err, operation)
func (t *traceClient) Request(ctx context.Context, request *networkservice.NetworkServiceRequest, opts ...grpc.CallOption) (*networkservice.Connection, error) {
if logrus.GetLevel() == logrus.TraceLevel {
return t.verbose.Request(ctx, request, opts...)
}
logResponse(ctx, conn, "close")

return rv, err
return t.concise.Request(ctx, request, opts...)
}

func (t *endTraceClient) Request(ctx context.Context, request *networkservice.NetworkServiceRequest, opts ...grpc.CallOption) (*networkservice.Connection, error) {
logRequest(ctx, request, "request")
conn, err := next.Client(ctx).Request(ctx, request, opts...)
logResponse(ctx, conn, "request")
return conn, err
}

func (t *endTraceClient) Close(ctx context.Context, conn *networkservice.Connection, opts ...grpc.CallOption) (*empty.Empty, error) {
logRequest(ctx, conn, "close")
r, err := next.Client(ctx).Close(ctx, conn, opts...)
logResponse(ctx, conn, "close")
return r, err
func (t *traceClient) Close(ctx context.Context, conn *networkservice.Connection, opts ...grpc.CallOption) (*empty.Empty, error) {
if logrus.GetLevel() == logrus.TraceLevel {
return t.verbose.Close(ctx, conn, opts...)
}
return t.concise.Close(ctx, conn, opts...)
}
74 changes: 21 additions & 53 deletions pkg/networkservice/core/trace/server.go
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,4 @@
// Copyright (c) 2020-2023 Cisco Systems, Inc.
//
// Copyright (c) 2021-2023 Doc.ai and/or its affiliates.
// Copyright (c) 2023 Cisco and/or its affiliates.
//
// SPDX-License-Identifier: Apache-2.0
//
Expand All @@ -21,69 +19,39 @@ package trace
import (
"context"

"github.com/sirupsen/logrus"

"github.com/networkservicemesh/sdk/pkg/networkservice/core/trace/traceconcise"
"github.com/networkservicemesh/sdk/pkg/networkservice/core/trace/traceverbose"

"github.com/golang/protobuf/ptypes/empty"

"github.com/networkservicemesh/api/pkg/api/networkservice"

"github.com/networkservicemesh/sdk/pkg/networkservice/core/next"
"github.com/networkservicemesh/sdk/pkg/tools/typeutils"
)

type beginTraceServer struct {
traced networkservice.NetworkServiceServer
type traceServer struct {
verbose networkservice.NetworkServiceServer
concise networkservice.NetworkServiceServer
}

type endTraceServer struct{}

// NewNetworkServiceServer - wraps tracing around the supplied traced
func NewNetworkServiceServer(traced networkservice.NetworkServiceServer) networkservice.NetworkServiceServer {
return next.NewNetworkServiceServer(
&beginTraceServer{traced: traced},
&endTraceServer{},
)
}

func (t *beginTraceServer) Request(ctx context.Context, request *networkservice.NetworkServiceRequest) (*networkservice.Connection, error) {
// Create a new logger
operation := typeutils.GetFuncName(t.traced, methodNameRequest)
ctx, finish := withLog(ctx, operation, methodNameRequest, request.GetConnection().GetId())
defer finish()

logRequest(ctx, request, "request")
// Actually call the next
rv, err := t.traced.Request(ctx, request)
if err != nil {
return nil, logError(ctx, err, operation)
return &traceServer{
verbose: traceverbose.NewNetworkServiceServer(traced),
concise: traceconcise.NewNetworkServiceServer(traced),
}
logResponse(ctx, rv, "request")
return rv, err
}

func (t *beginTraceServer) Close(ctx context.Context, conn *networkservice.Connection) (*empty.Empty, error) {
// Create a new logger
operation := typeutils.GetFuncName(t.traced, methodNameClose)
ctx, finish := withLog(ctx, operation, methodNameClose, conn.GetId())
defer finish()

logRequest(ctx, conn, "close")
rv, err := t.traced.Close(ctx, conn)
if err != nil {
return nil, logError(ctx, err, operation)
func (t *traceServer) Request(ctx context.Context, request *networkservice.NetworkServiceRequest) (*networkservice.Connection, error) {
if logrus.GetLevel() == logrus.TraceLevel {
return t.verbose.Request(ctx, request)
}
logResponse(ctx, conn, "close")
return rv, err
return t.concise.Request(ctx, request)
}

func (t *endTraceServer) Request(ctx context.Context, request *networkservice.NetworkServiceRequest) (*networkservice.Connection, error) {
logRequest(ctx, request, "request")
conn, err := next.Server(ctx).Request(ctx, request)
logResponse(ctx, conn, "request")
return conn, err
}

func (t *endTraceServer) Close(ctx context.Context, conn *networkservice.Connection) (*empty.Empty, error) {
logRequest(ctx, conn, "close")
r, err := next.Server(ctx).Close(ctx, conn)
logResponse(ctx, conn, "close")
return r, err
func (t *traceServer) Close(ctx context.Context, conn *networkservice.Connection) (*empty.Empty, error) {
if logrus.GetLevel() == logrus.TraceLevel {
return t.verbose.Close(ctx, conn)
}
return t.concise.Close(ctx, conn)
}
Loading

0 comments on commit 256d2cc

Please sign in to comment.