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

Fix trace diffs #667

Merged
merged 1 commit into from
Feb 3, 2021
Merged

Fix trace diffs #667

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
34 changes: 26 additions & 8 deletions pkg/networkservice/core/trace/client.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,24 +27,26 @@ import (

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

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

"github.com/networkservicemesh/sdk/pkg/tools/typeutils"
)

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

type endTraceClient struct{}

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

func (t *traceClient) Request(ctx context.Context, request *networkservice.NetworkServiceRequest, opts ...grpc.CallOption) (*networkservice.Connection, error) {
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, "Request")
ctx, finish := withLog(ctx, operation)
Expand All @@ -69,7 +71,7 @@ func (t *traceClient) Request(ctx context.Context, request *networkservice.Netwo
return rv, err
}

func (t *traceClient) Close(ctx context.Context, conn *networkservice.Connection, opts ...grpc.CallOption) (*empty.Empty, error) {
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, "Close")
ctx, finish := withLog(ctx, operation)
Expand All @@ -87,5 +89,21 @@ func (t *traceClient) Close(ctx context.Context, conn *networkservice.Connection
logger.Log(ctx).Errorf("%v", err)
return nil, err
}

logResponse(ctx, conn)
return rv, err
}

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

func (t *endTraceClient) Close(ctx context.Context, conn *networkservice.Connection, opts ...grpc.CallOption) (*empty.Empty, error) {
logRequest(ctx, conn)
r, err := next.Client(ctx).Close(ctx, conn, opts...)
logResponse(ctx, conn)
return r, err
}
112 changes: 112 additions & 0 deletions pkg/networkservice/core/trace/common_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,7 @@
// Copyright (c) 2020 Cisco Systems, Inc.
//
// Copyright (c) 2021 Doc.ai and/or its affiliates.
//
// SPDX-License-Identifier: Apache-2.0
//
// Licensed under the Apache License, Version 2.0 (the "License");
Expand All @@ -18,14 +20,22 @@
package trace_test

import (
"bytes"
"context"
"encoding/json"
"testing"

"github.com/sirupsen/logrus"

"github.com/golang/protobuf/ptypes/empty"
"github.com/networkservicemesh/api/pkg/api/networkservice"
"github.com/networkservicemesh/api/pkg/api/networkservice/mechanisms/cls"
"github.com/stretchr/testify/require"

"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/logger"
)

func TestDiffMechanism(t *testing.T) {
Expand Down Expand Up @@ -91,6 +101,60 @@ func TestDiffPathAdd(t *testing.T) {
require.True(t, diff)
}

func TestTraceOutput(t *testing.T) {
// Configure logging
// Set output to buffer
var buff bytes.Buffer
logrus.SetOutput(&buff)
logrus.SetFormatter(&logrus.TextFormatter{
DisableTimestamp: true,
})
logger.EnableTracing(true)

// Create a chain with modifying elements
ch := chain.NewNamedNetworkServiceServer(
"TestTraceOutput",
&labelChangerFirstServer{},
&labelChangerSecondServer{},
)

request := newConnection()

conn, err := ch.Request(context.Background(), request)
require.NoError(t, err)
require.NotNil(t, conn)

e, err := ch.Close(context.Background(), conn)
require.NoError(t, err)
require.NotNil(t, e)

expectedOutput :=
"level=trace msg=\"[INFO] (1) ⎆ sdk/pkg/networkservice/core/trace_test/labelChangerFirstServer.Request()\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (1.1) request={\\\"connection\\\":{\\\"id\\\":\\\"conn-1\\\",\\\"context\\\":" +
"{\\\"ip_context\\\":{\\\"src_ip_required\\\":true}}},\\\"mechanism_preferences\\\":[{\\\"cls\\\":\\\"LOCAL\\\"," +
"\\\"type\\\":\\\"KERNEL\\\"},{\\\"cls\\\":\\\"LOCAL\\\",\\\"type\\\":\\\"KERNEL\\\",\\\"parameters\\\":{\\\"label\\\"" +
":\\\"v2\\\"}}]}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (1.2) request-diff={\\\"connection\\\":{\\\"labels\\\":{\\\"+Label\\\":\\\"A\\\"}}}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (2) ⎆ sdk/pkg/networkservice/core/trace_test/labelChangerSecondServer.Request()\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (2.1) request-diff={\\\"connection\\\":{\\\"labels\\\":{\\\"Label\\\":\\\"B\\\"}}}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (2.2) response={\\\"id\\\":\\\"conn-1\\\",\\\"context\\\":{\\\"ip_context\\\":{\\\"src_ip_required\\\":true}}," +
"\\\"labels\\\":{\\\"Label\\\":\\\"B\\\"}}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (2.3) response-diff={\\\"labels\\\":{\\\"Label\\\":\\\"C\\\"}}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (1.3) response-diff={\\\"labels\\\":{\\\"Label\\\":\\\"D\\\"}}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (1) ⎆ sdk/pkg/networkservice/core/trace_test/labelChangerFirstServer.Close()\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (1.1) request={\\\"id\\\":\\\"conn-1\\\",\\\"context\\\":{\\\"ip_context\\\":{\\\"src_ip_required\\\":true}}," +
"\\\"labels\\\":{\\\"Label\\\":\\\"D\\\"}}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (1.2) request-diff={\\\"labels\\\":{\\\"Label\\\":\\\"W\\\"}}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (2) ⎆ sdk/pkg/networkservice/core/trace_test/labelChangerSecondServer.Close()\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (2.1) request-diff={\\\"labels\\\":{\\\"Label\\\":\\\"X\\\"}}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (2.2) response={\\\"id\\\":\\\"conn-1\\\",\\\"context\\\":{\\\"ip_context\\\":{\\\"src_ip_required\\\"" +
":true}},\\\"labels\\\":{\\\"Label\\\":\\\"X\\\"}}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (2.3) response-diff={\\\"labels\\\":{\\\"Label\\\":\\\"Y\\\"}}\" name=TestTraceOutput\n" +
"level=trace msg=\"[INFO] (1.3) response-diff={\\\"labels\\\":{\\\"Label\\\":\\\"Z\\\"}}\" name=TestTraceOutput\n"

require.Equal(t, expectedOutput, buff.String())
}

func newConnection() *networkservice.NetworkServiceRequest {
return &networkservice.NetworkServiceRequest{
Connection: &networkservice.Connection{
Expand All @@ -116,3 +180,51 @@ func newConnection() *networkservice.NetworkServiceRequest {
},
}
}

type labelChangerFirstServer struct{}

func (c *labelChangerFirstServer) Request(ctx context.Context, request *networkservice.NetworkServiceRequest) (*networkservice.Connection, error) {
request.Connection.Labels = map[string]string{
"Label": "A",
}
rv, err := next.Server(ctx).Request(ctx, request)
rv.Labels = map[string]string{
"Label": "D",
}
return rv, err
}

func (c *labelChangerFirstServer) Close(ctx context.Context, connection *networkservice.Connection) (*empty.Empty, error) {
connection.Labels = map[string]string{
"Label": "W",
}
r, err := next.Server(ctx).Close(ctx, connection)
connection.Labels = map[string]string{
"Label": "Z",
}
return r, err
}

type labelChangerSecondServer struct{}

func (c *labelChangerSecondServer) Request(ctx context.Context, request *networkservice.NetworkServiceRequest) (*networkservice.Connection, error) {
request.Connection.Labels = map[string]string{
"Label": "B",
}
rv, err := next.Server(ctx).Request(ctx, request)
rv.Labels = map[string]string{
"Label": "C",
}
return rv, err
}

func (c *labelChangerSecondServer) Close(ctx context.Context, connection *networkservice.Connection) (*empty.Empty, error) {
connection.Labels = map[string]string{
"Label": "X",
}
r, err := next.Server(ctx).Close(ctx, connection)
connection.Labels = map[string]string{
"Label": "Y",
}
return r, err
}
33 changes: 26 additions & 7 deletions pkg/networkservice/core/trace/server.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,25 +22,29 @@ import (
"context"

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

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

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

"github.com/networkservicemesh/sdk/pkg/tools/typeutils"
)

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

type endTraceServer struct{}

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

func (t *traceServer) Request(ctx context.Context, request *networkservice.NetworkServiceRequest) (*networkservice.Connection, error) {
func (t *beginTraceServer) Request(ctx context.Context, request *networkservice.NetworkServiceRequest) (*networkservice.Connection, error) {
// Create a new logger
operation := typeutils.GetFuncName(t.traced, "Request")
ctx, finish := withLog(ctx, operation)
Expand All @@ -65,7 +69,7 @@ func (t *traceServer) Request(ctx context.Context, request *networkservice.Netwo
return rv, err
}

func (t *traceServer) Close(ctx context.Context, conn *networkservice.Connection) (*empty.Empty, error) {
func (t *beginTraceServer) Close(ctx context.Context, conn *networkservice.Connection) (*empty.Empty, error) {
// Create a new logger
operation := typeutils.GetFuncName(t.traced, "Close")
ctx, finish := withLog(ctx, operation)
Expand All @@ -83,5 +87,20 @@ func (t *traceServer) Close(ctx context.Context, conn *networkservice.Connection
logger.Log(ctx).Errorf("%v", err)
return nil, err
}
logResponse(ctx, conn)
return rv, err
}

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

func (t *endTraceServer) Close(ctx context.Context, conn *networkservice.Connection) (*empty.Empty, error) {
logRequest(ctx, conn)
r, err := next.Server(ctx).Close(ctx, conn)
logResponse(ctx, conn)
return r, err
}