feature(trace): add context to Logger API #20

1046102779 · 2022-09-06T08:04:40Z

Signed-off-by: 1046102779 [email protected]

Description

At present, our servers need to correlate logs and traces.

This is a very urgent matter, I hope everyone can review these code at quickly. Thanks.

Checklist

Please make sure you've completed the relevant tasks for this PR, out of the following list:

Logger API with context.
Support Opentelemetry.
Unit tests.

/cc @pkedy @yaron2 @artursouza @daixiang0 @berndverst @ItalyPaleAle

Signed-off-by: 1046102779 <[email protected]>

1046102779 · 2022-09-06T08:24:39Z

Add package trace to associate micrologic and dapr runtime. as follows:

service type: client && server,
protocol type: http && gRPC

gRPC client(go-sdk):

// NewClientWithAddress instantiates Dapr using specific address (including port).
func NewClientWithAddress(address string) (client cc.Client, err error) {
	if address == "" {
		return nil, errors.New("nil address")
	}
	logger.Printf("dapr client initializing for: %s", address)

	ctx, ctxCancel := context.WithTimeout(context.Background(), 1*time.Second)
	conn, err := grpc.DialContext(
		ctx,
		address,
		grpc.WithTransportCredentials(insecure.NewCredentials()),
		grpc.WithBlock(),
		grpc.WithUnaryInterceptor(trace.GRPCClientUnaryInterceptor),
		grpc.WithStreamInterceptor(trace.GRPCClientStreamInterceptor),
	)
	if err != nil {
		ctxCancel()
		return nil, errors.Wrapf(err, "error creating connection to '%s': %v", address, err)
	}
	if hasToken := os.Getenv(apiTokenEnvVarName); hasToken != "" {
		logger.Println("client uses API token")
	}

	return newClientWithConnectionAndCancelFunc(conn, ctxCancel), nil
}

gRPC server(go-sdk):

// Start registers the server and starts it.
func (s *Server) Start() error {
	gs := grpc.NewServer(
		grpc.UnaryInterceptor(trace.GRPCServerUnaryInterceptor),
		grpc.StreamInterceptor(trace.GRPCServerStreamInterceptor),
	)
	runtimepbv1.RegisterAppCallbackServer(gs, s)
	s.grpcServer = gs
	return gs.Serve(s.listener)
}

Signed-off-by: 1046102779 <[email protected]>

1046102779 · 2022-09-07T01:54:52Z

/cc @yaron2

We desperately need this Logger Context API feature.

ps. It seems that this repo is not maintained anymore, can I be the maintainer of this repo? Currently feedback is slow for issues and PRs .

berndverst · 2022-09-07T02:13:03Z

/cc @yaron2

We desperately need this Logger Context API feature.

ps. It seems that this repo is not maintained anymore, can I be the maintainer of this repo? Currently feedback is slow for issues and PRs .

This repo is maintained, but it does not frequently require changes. In a way, it is controlled by Dapr runtime maintainers.

trace/trace.go

Signed-off-by: 1046102779 <[email protected]>

trace/adapter.go

codecov-commenter · 2022-09-07T02:28:04Z

Codecov Report

Merging #20 (b91bb22) into main (fcb0995) will decrease coverage by 4.29%.
The diff coverage is 63.19%.

@@            Coverage Diff             @@
##             main      #20      +/-   ##
==========================================
- Coverage   90.46%   86.17%   -4.29%     
==========================================
  Files          18       22       +4     
  Lines         891     1049     +158     
==========================================
+ Hits          806      904      +98     
- Misses         72      116      +44     
- Partials       13       29      +16

Impacted Files	Coverage Δ
logger/logger.go	`100.00% <ø> (ø)`
logger/nop_logger.go	`0.00% <0.00%> (ø)`
trace/trace.go	`50.00% <50.00%> (ø)`
trace/adapter.go	`60.52% <60.52%> (ø)`
trace/span_context.go	`61.11% <61.11%> (ø)`
trace/id_generator.go	`78.26% <78.26%> (ø)`
logger/dapr_logger.go	`96.82% <100.00%> (+0.74%)`	⬆️
logger/options.go	`82.35% <100.00%> (+1.70%)`	⬆️

Help us with your feedback. Take ten seconds to tell us how you rate us. Have a feature suggestion? Share it here.

Signed-off-by: 1046102779 <[email protected]>

1046102779 · 2022-09-07T02:35:20Z

id(traceid): 196d92cb7ed0571d7129a803cba99bed

➜  logger git:(feature/log0905) go test -v ./... -test.run=TestJSONLoggerFieldsWithSpanCo
ntext
=== RUN   TestJSONLoggerFieldsWithSpanContext
=== RUN   TestJSONLoggerFieldsWithSpanContext/info()
line: {"app_id":"dapr_app","instance":"dapr-pod","level":"info","msg":"King Dapr","scope":"fakeLogger","time":"2022-09-07T10:34:58.008556446+08:00","type":"log","ver":"unknown"}
=== RUN   TestJSONLoggerFieldsWithSpanContext/info()#01
line: {"app_id":"dapr_app","id":"196d92cb7ed0571d7129a803cba99bed","instance":"dapr-pod","level":"info","msg":"King Dapr","scope":"fakeLogger","time":"2022-09-07T10:34:58.008773554+08:00","type":"log","ver":"dapr_app"}
--- PASS: TestJSONLoggerFieldsWithSpanContext (0.00s)
    --- PASS: TestJSONLoggerFieldsWithSpanContext/info() (0.00s)
    --- PASS: TestJSONLoggerFieldsWithSpanContext/info()#01 (0.00s)
PASS
ok      github.com/dapr/kit/logger      0.006s

1046102779 · 2022-09-13T08:51:08Z

/cc @daixiang0 @artursouza @yaron2 @pkedy

1046102779 · 2022-09-14T01:27:57Z

/cc @daixiang0 @artursouza @yaron2 @pkedy @berndverst

1046102779 · 2022-09-16T02:28:59Z

/cc @daixiang0 @artursouza @yaron2 @pkedy @berndverst

yaron2 · 2022-09-16T03:41:03Z

@daixiang0 @berndverst can you complete the review here?

go.mod

trace/adapter.go

trace/adapter_grpc_stream_test.go

1046102779 · 2022-12-13T23:19:10Z

cc @yaron2 @artursouza @ItalyPaleAle

Signed-off-by: seachen <[email protected]>

logger/dapr_logger.go

trace/adapter.go

Signed-off-by: seachen <[email protected]>

1046102779 · 2022-12-15T02:01:26Z

cc @ItalyPaleAle

1046102779 · 2022-12-16T01:19:30Z

cc @ItalyPaleAle @yaron2 @berndverst

1046102779 · 2022-12-16T08:36:22Z

cc @daixiang0 @yaron2 @berndverst @artursouza @daixiang0

1046102779 · 2022-12-19T06:38:04Z

cc @daixiang0 @yaron2 @berndverst @artursouza @ItalyPaleAle

1046102779 · 2022-12-20T23:03:31Z

I need this pr to apply micrologic.

ItalyPaleAle · 2022-12-20T23:07:38Z

@1046102779 Please do not ping maintainers every day.

As for this PR, I still am not clear exactly what this is for. I am also concerned with importing an entire tracing package (and dependencies on things like OTEL) in dapr/kit.

Can you help me understand why this is necessary? How will this be used in Dapr?

yaron2 · 2022-12-20T23:19:54Z

@1046102779 Please do not ping maintainers every day.

As for this PR, I still am not clear exactly what this is for. I am also concerned with importing an entire tracing package (and dependencies on things like OTEL) in dapr/kit.

Can you help me understand why this is necessary? How will this be used in Dapr?

@ItalyPaleAle as discussed, this is to add a trace id if present to the log output to help in correlating service calls with logs.

1046102779 · 2022-12-20T23:52:00Z

(MicroLogic, Dapr runtime)'s trace and log can be associated, and the effect is as follows:

ItalyPaleAle · 2022-12-21T01:36:37Z

logger/dapr_logger.go

+
+	if id != "" {
+		return l.WithFields(map[string]any{
+			"id": id,


Can we find a better name than id? How about traceId? Anything with the word "trace" in it

ItalyPaleAle · 2022-12-21T01:39:49Z

trace/adapter.go

+
+// SpanContextGrpc gets span context from grpc request.
+func SpanContextFromGrpc(ctx context.Context) trace.SpanContext {
+	md, ok := metadata.FromIncomingContext(ctx)


This method does a lot of re-allocations and string transformations on every call, and it's very slow. Not what we should use with a logger.... I changed it in the runtime to cache the values: https://github.com/dapr/dapr/blob/master/pkg/grpc/metadata/metadata.go

Perhaps consider moving that package (pkg/grpc/metadata) into dapr/kit, and use the FromIncomingContext method from that package.

ItalyPaleAle · 2022-12-21T01:41:32Z

trace/trace.go

@@ -0,0 +1,146 @@
+package trace


A lot of this code seems to be available here almost exactly the same: https://github.com/dapr/dapr/blob/master/pkg/diagnostics/tracing.go

Can you perhaps move that package into dapr/kit and consolidate?

ItalyPaleAle · 2022-12-21T01:42:28Z

Ok makes sense now.

My concern with code duplication remains. A lot of the code here seems to be present in dapr/dapr too, and it would cause duplications.

Can you (maybe in a separate PR first) move some of that code from dapr/dapr into dapr/kit, and then use those packages in both dapr/kit and dapr/dapr?

1046102779 · 2022-12-21T01:47:57Z

Ok makes sense now.

My concern with code duplication remains. A lot of the code here seems to be present in dapr/dapr too, and it would cause duplications.

Can you (maybe in a separate PR first) move some of that code from dapr/dapr into dapr/kit, and then use those packages in both dapr/kit and dapr/dapr?

Yes. I plan to move some trace-related packages in the dapr/dapr main repo to this dapr/kit repo, as a public component capability for dapr/dapr, dapr/go-sdk or MicroLogic.

yaron2 · 2023-01-24T19:04:06Z

@1046102779 please resolve the conflicts.

Signed-off-by: seachen <[email protected]>

1046102779 · 2023-01-29T01:24:41Z

@1046102779 please resolve the conflicts.

Done.

daixiang0 · 2023-01-30T00:36:54Z

LGTM

ItalyPaleAle · 2023-01-30T00:49:45Z

trace/id_generator.go

+	"context"
+	crand "crypto/rand"
+	"encoding/binary"
+	"math/rand"


Don't use math/rand. Please use a CSPRNG for all sources of random data

ItalyPaleAle · 2023-01-30T00:53:05Z

trace/trace.go

+// w3c reference: https://www.w3.org/TR/trace-context/#traceparent-header.
+// traceparent: 00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01.
+// SpanContextFromW3CString generates span context by traceparent.
+func SpanContextFromW3CString(traceparent string) trace.SpanContext {


Please use the method we're currently using in dapr/dapr: https://github.dev/dapr/dapr/blob/a64a8a97c59c0678bec4d754b21d837d25a38f4c/pkg/diagnostics/tracing.go#L107-L108

ItalyPaleAle · 2023-01-30T00:56:34Z

trace/adapter.go

+}
+
+// SpanContextFromHTTP get span context from http request.
+func SpanContextFromHTTP(h http.Header) trace.SpanContext {


We will also need an adapter for fasthttp if you plan to use that with Dapr?

Signed-off-by: seachen <[email protected]>

feature(trace): add context to Logger API

0dc51fe

Signed-off-by: 1046102779 <[email protected]>

1046102779 requested a review from a team as a code owner September 6, 2022 08:04

feature(trace): add context to Logger API

a32b811

Signed-off-by: 1046102779 <[email protected]>

1046102779 added 3 commits September 6, 2022 16:29

feature(trace): add context to Logger API

af9682d

Signed-off-by: 1046102779 <[email protected]>

feature(trace): add context to Logger API

f550d4a

Signed-off-by: 1046102779 <[email protected]>

feature(trace): add context to Logger API

8255ede

Signed-off-by: 1046102779 <[email protected]>

berndverst reviewed Sep 7, 2022

View reviewed changes

trace/trace.go Outdated Show resolved Hide resolved

feature(trace): add context to Logger API

8838aac

Signed-off-by: 1046102779 <[email protected]>

berndverst requested changes Sep 7, 2022

View reviewed changes

trace/adapter.go Outdated Show resolved Hide resolved

1046102779 added 2 commits September 7, 2022 10:28

feature(trace): add context to Logger API

5fe5012

Signed-off-by: 1046102779 <[email protected]>

feature(trace): add context to Logger API

59b5895

Signed-off-by: 1046102779 <[email protected]>

1046102779 mentioned this pull request Sep 13, 2022

bugfix(apphealth): app health status no change and return directly. dapr/dapr#5134

Closed

yaron2 requested review from daixiang0 and berndverst September 16, 2022 03:40