Skip to content

Commit

Permalink
feat: Optimize trace chain elements (#1706)
Browse files Browse the repository at this point in the history
* optimize trace chain elements

Signed-off-by: denis-tingaikin <denis.tingajkin@xored.com>

* fix ci issues

Signed-off-by: denis-tingaikin <denis.tingajkin@xored.com>

* apply self code review

Signed-off-by: denis-tingaikin <denis.tingajkin@xored.com>

* apply comments and fix #1707

Signed-off-by: denis-tingaikin <denis.tingajkin@xored.com>

* use the logrus logger by default to not miss useful logs.

Signed-off-by: denis-tingaikin <denis.tingajkin@xored.com>

---------

Signed-off-by: denis-tingaikin <denis.tingajkin@xored.com>
  • Loading branch information
denis-tingaikin authored Dec 19, 2024
1 parent 1e611de commit 55b1f2b
Show file tree
Hide file tree
Showing 31 changed files with 1,326 additions and 588 deletions.
2 changes: 1 addition & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ module github.com/networkservicemesh/sdk
go 1.23

require (
github.com/OneOfOne/xxhash v1.2.8
github.com/RoaringBitmap/roaring v0.9.4
github.com/antonfisher/nested-logrus-formatter v1.3.1
github.com/benbjohnson/clock v1.3.0
Expand Down Expand Up @@ -50,7 +51,6 @@ require (
require (
cloud.google.com/go/compute v1.23.1 // indirect
github.com/Microsoft/go-winio v0.6.1 // indirect
github.com/OneOfOne/xxhash v1.2.8 // indirect
github.com/agnivade/levenshtein v1.1.1 // indirect
github.com/armon/go-metrics v0.0.0-20190430140413-ec5e00d3c878 // indirect
github.com/beorn7/perks v1.0.1 // indirect
Expand Down
34 changes: 34 additions & 0 deletions pkg/networkservice/core/trace/README.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,34 @@
## Logging levels

- TRACE, DEBUG: these levels print diff, since diff is expensive operation (see diff between Trace and Info tests) it's recommended to use only for debugging.
- INFO: prints short information about requests and connections.
- FATAL, ERROR, WARN: Print only logs from chain elements that are using these levels directly in the source code e.g., `log.FromContext(ctx).Warn("todo")`

## Benchmarks

**Release v1.14.1**
```
Benchmark_ShortRequest_Info-8 3924 344671 ns/op 25641 B/op 178 allocs/op
Benchmark_LongRequest_Info-8 340 3765718 ns/op 273254 B/op 861 allocs/op
Benchmark_ShortRequest_Trace-8 79 13600986 ns/op 344445 B/op 8475 allocs/op
Benchmark_LongRequest_Trace-8 2 916385562 ns/op 20998324 B/op 694678 allocs/op
Benchmark_LongRequest_NoDiff_Trace-8 2 565520104 ns/op 12236116 B/op 585667 allocs/op
Benchmark_LongRequest_Diff_Warn-8 340 3765718 ns/op 273254 B/op 861 allocs/op
```


**Release v1.14.2**
```
Benchmark_ShortRequest_Info-8 4090 350181 ns/op 24246 B/op 177 allocs/op
Benchmark_LongRequest_Info-8 373 3064039 ns/op 253359 B/op 857 allocs/op
Benchmark_ShortRequest_Trace-8 543 2599280 ns/op 237262 B/op 1825 allocs/op
Benchmark_LongRequest_Trace-8 9 131145361 ns/op 22433480 B/op 20749 allocs/op
Benchmark_LongRequest_NoDiff_Trace-8 18 72167456 ns/op 10900859 B/op 13685 allocs/op
Benchmark_LongRequest_Diff_Warn-8 31128 36019 ns/op 9600 B/op 200 allocs/op
```
31 changes: 24 additions & 7 deletions pkg/networkservice/core/trace/client.go
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
// Copyright (c) 2023 Cisco and/or its affiliates.
// Copyright (c) 2023-2024 Cisco and/or its affiliates.
//
// SPDX-License-Identifier: Apache-2.0
//
Expand Down Expand Up @@ -29,30 +29,47 @@ import (

"github.com/networkservicemesh/sdk/pkg/networkservice/core/trace/traceconcise"
"github.com/networkservicemesh/sdk/pkg/networkservice/core/trace/traceverbose"
"github.com/networkservicemesh/sdk/pkg/tools/log"
"github.com/networkservicemesh/sdk/pkg/tools/log/logruslogger"
)

type traceClient struct {
verbose networkservice.NetworkServiceClient
concise networkservice.NetworkServiceClient
verbose networkservice.NetworkServiceClient
concise networkservice.NetworkServiceClient
original networkservice.NetworkServiceClient
}

// NewNetworkServiceClient - wraps tracing around the supplied networkservice.NetworkServiceClient
func NewNetworkServiceClient(traced networkservice.NetworkServiceClient) networkservice.NetworkServiceClient {
return &traceClient{
verbose: traceverbose.NewNetworkServiceClient(traced),
concise: traceconcise.NewNetworkServiceClient(traced),
verbose: traceverbose.NewNetworkServiceClient(traced),
concise: traceconcise.NewNetworkServiceClient(traced),
original: traced,
}
}

func (t *traceClient) Request(ctx context.Context, request *networkservice.NetworkServiceRequest, opts ...grpc.CallOption) (*networkservice.Connection, error) {
if logrus.GetLevel() == logrus.TraceLevel {
if logrus.GetLevel() <= logrus.WarnLevel {
if log.FromContext(ctx) == log.L() {
ctx = log.WithLog(ctx, logruslogger.New(ctx))
}
return t.original.Request(ctx, request)
}
if logrus.GetLevel() >= logrus.DebugLevel {
return t.verbose.Request(ctx, request, opts...)
}

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

func (t *traceClient) Close(ctx context.Context, conn *networkservice.Connection, opts ...grpc.CallOption) (*empty.Empty, error) {
if logrus.GetLevel() == logrus.TraceLevel {
if logrus.GetLevel() <= logrus.WarnLevel {
if log.FromContext(ctx) == log.L() {
ctx = log.WithLog(ctx, logruslogger.New(ctx))
}
return t.original.Close(ctx, conn)
}
if logrus.GetLevel() >= logrus.DebugLevel {
return t.verbose.Close(ctx, conn, opts...)
}
return t.concise.Close(ctx, conn, opts...)
Expand Down
29 changes: 22 additions & 7 deletions pkg/networkservice/core/trace/server.go
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
// Copyright (c) 2023 Cisco and/or its affiliates.
// Copyright (c) 2023-2024 Cisco and/or its affiliates.
//
// SPDX-License-Identifier: Apache-2.0
//
Expand All @@ -23,34 +23,49 @@ import (

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

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

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

type traceServer struct {
verbose networkservice.NetworkServiceServer
concise networkservice.NetworkServiceServer
verbose, concise, original networkservice.NetworkServiceServer
}

// NewNetworkServiceServer - wraps tracing around the supplied traced
func NewNetworkServiceServer(traced networkservice.NetworkServiceServer) networkservice.NetworkServiceServer {
return &traceServer{
verbose: traceverbose.NewNetworkServiceServer(traced),
concise: traceconcise.NewNetworkServiceServer(traced),
verbose: traceverbose.NewNetworkServiceServer(traced),
concise: traceconcise.NewNetworkServiceServer(traced),
original: traced,
}
}

func (t *traceServer) Request(ctx context.Context, request *networkservice.NetworkServiceRequest) (*networkservice.Connection, error) {
if logrus.GetLevel() == logrus.TraceLevel {
if logrus.GetLevel() <= logrus.WarnLevel {
if log.FromContext(ctx) == log.L() {
ctx = log.WithLog(ctx, logruslogger.New(ctx))
}
return t.original.Request(ctx, request)
}
if logrus.GetLevel() >= logrus.DebugLevel {
return t.verbose.Request(ctx, request)
}

return t.concise.Request(ctx, request)
}

func (t *traceServer) Close(ctx context.Context, conn *networkservice.Connection) (*empty.Empty, error) {
if logrus.GetLevel() == logrus.TraceLevel {
if logrus.GetLevel() <= logrus.WarnLevel {
if log.FromContext(ctx) == log.L() {
ctx = log.WithLog(ctx, logruslogger.New(ctx))
}
return t.original.Close(ctx, conn)
}
if logrus.GetLevel() >= logrus.DebugLevel {
return t.verbose.Close(ctx, conn)
}
return t.concise.Close(ctx, conn)
Expand Down
173 changes: 173 additions & 0 deletions pkg/networkservice/core/trace/server_bench_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,173 @@
// Copyright (c) 2024 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_test

import (
"context"
"fmt"
"io"
"testing"

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

"github.com/networkservicemesh/sdk/pkg/networkservice/common/null"
"github.com/networkservicemesh/sdk/pkg/networkservice/core/chain"
"github.com/networkservicemesh/sdk/pkg/networkservice/core/trace/testutil"
"github.com/networkservicemesh/sdk/pkg/networkservice/utils/checks/checkrequest"
"github.com/networkservicemesh/sdk/pkg/tools/log"
"github.com/networkservicemesh/sdk/pkg/tools/nanoid"

"github.com/sirupsen/logrus"
)

func newTestRequest(size int) *networkservice.NetworkServiceRequest {
res := testutil.NewConnection()

res.GetConnection().Path = &networkservice.Path{}
res.GetConnection().Labels = make(map[string]string)

for i := 0; i < size; i++ {
res.GetConnection().GetPath().PathSegments = append(res.GetConnection().GetPath().PathSegments,
&networkservice.PathSegment{
Name: nanoid.MustGenerateString(15),
Token: nanoid.MustGenerateString(25),
Id: nanoid.MustGenerateString(20),
})
}

res.GetConnection().Id = res.GetConnection().GetPath().GetPathSegments()[0].Id

return res
}

func newTestServerChain(size int) networkservice.NetworkServiceServer {
var servers []networkservice.NetworkServiceServer

for i := 0; i < size; i++ {
id := i
servers = append(servers, checkrequest.NewServer(nil, func(_ *testing.T, nsr *networkservice.NetworkServiceRequest) {
nsr.GetConnection().GetLabels()["common-label"] = fmt.Sprint(id)
}))
}

return chain.NewNetworkServiceServer(servers...)
}

func newTestStaticServerChain(size int) networkservice.NetworkServiceServer {
var servers []networkservice.NetworkServiceServer

for i := 0; i < size; i++ {
servers = append(servers, null.NewServer())
}

return chain.NewNetworkServiceServer(servers...)
}

func Benchmark_ShortRequest_Info(b *testing.B) {
var s = newTestServerChain(10)
var request = newTestRequest(5)
var ctx = context.Background()

logrus.SetLevel(logrus.InfoLevel)
logrus.SetOutput(io.Discard)
log.EnableTracing(true)

b.ResetTimer()

for range b.N {
_, _ = s.Request(ctx, request)
}
}

func Benchmark_LongRequest_Info(b *testing.B) {
var s = newTestServerChain(100)
var request = newTestRequest(100)
var ctx = context.Background()

logrus.SetLevel(logrus.InfoLevel)
logrus.SetOutput(io.Discard)
log.EnableTracing(true)

b.ResetTimer()

for range b.N {
_, _ = s.Request(ctx, request)
}
}

func Benchmark_ShortRequest_Trace(b *testing.B) {
var s = newTestServerChain(10)
var request = newTestRequest(5)
var ctx = context.Background()

logrus.SetLevel(logrus.TraceLevel)
logrus.SetOutput(io.Discard)
log.EnableTracing(true)

b.ResetTimer()

for range b.N {
_, _ = s.Request(ctx, request)
}
}
func Benchmark_LongRequest_Trace(b *testing.B) {
var s = newTestServerChain(100)
var request = newTestRequest(100)
var ctx = context.Background()

logrus.SetLevel(logrus.TraceLevel)
logrus.SetOutput(io.Discard)
log.EnableTracing(true)

b.ResetTimer()

for range b.N {
_, _ = s.Request(ctx, request)
}
}

func Benchmark_LongRequest_NoDiff_Trace(b *testing.B) {
var s = newTestStaticServerChain(100)
var request = newTestRequest(100)
var ctx = context.Background()

logrus.SetLevel(logrus.TraceLevel)
logrus.SetOutput(io.Discard)
log.EnableTracing(true)

b.ResetTimer()

for range b.N {
_, _ = s.Request(ctx, request)
}
}

func Benchmark_LongRequest_Diff_Warn(b *testing.B) {
var s = newTestStaticServerChain(100)
var request = newTestRequest(100)
var ctx = context.Background()

logrus.SetLevel(logrus.WarnLevel)
logrus.SetOutput(io.Discard)
log.EnableTracing(true)

b.ResetTimer()

for range b.N {
_, _ = s.Request(ctx, request)
}
}
Loading

0 comments on commit 55b1f2b

Please sign in to comment.