[RSDK-9149] Use RDK Logger Across Interceptors #400
Conversation
| @@ -327,10 +324,6 @@ func NewServer(logger utils.ZapCompatibleLogger, opts ...ServerOption) (Server, | |||
| logger: logger, | |||
| } | |||
|
|
|||
| grpcLogger := logger.Desugar() | |||
| if !(sOpts.debug || utils.Debug) { | |||
| grpcLogger = grpcLogger.WithOptions(zap.IncreaseLevel(zap.LevelEnablerFunc(zapcore.ErrorLevel.Enabled))) | |||
There was a problem hiding this comment.
[qu] is removing this safe? Not sure if we lose out on key functionality here by not setting these options. I'm assuming that these options are replaced by the cases outlined in LogFinalLine().
There was a problem hiding this comment.
the idea here is that if debug mode is not on, we only want to see error level logs and up. We should port that functionality to the interceptor themselves (see if you're seeing info level logs with this set of changes)
rpc/server_interceptors.go
Outdated
| @@ -119,3 +126,117 @@ func remoteSpanContextFromContext(ctx context.Context) (trace.SpanContext, error | |||
|
|
|||
| return trace.SpanContext{TraceID: traceID, SpanID: spanID, TraceOptions: traceOptions, Tracestate: nil}, nil | |||
| } | |||
|
|
|||
| func grpcUnaryServerInterceptor(logger utils.ZapCompatibleLogger, opts ...grpcZapOption) grpc.UnaryServerInterceptor { | |||
There was a problem hiding this comment.
we don't pass in any grpcZapOption, so happy to just remove all of this private stuff
rpc/server_interceptors.go
Outdated
| } | ||
| } | ||
|
|
||
| func grpcStreamServerInterceptor(logger utils.ZapCompatibleLogger, opts ...grpcZapOption) grpc.StreamServerInterceptor { |
rpc/server_interceptors.go
Outdated
| } | ||
| } | ||
|
|
||
| type grpcZapOption func(*GrpcZapOptions) |
rpc/server_interceptors.go
Outdated
|
|
||
| type grpcZapOption func(*GrpcZapOptions) | ||
|
|
||
| type GrpcZapOptions struct { |
rpc/server_interceptors.go
Outdated
| messageFunc grpc_zap.MessageProducer | ||
| } | ||
|
|
||
| func evaluateServerOpt(opts []grpcZapOption) *GrpcZapOptions { |
rpc/server_interceptors.go
Outdated
| return optCopy | ||
| } | ||
|
|
||
| var ( |
logger.go
Outdated
There was a problem hiding this comment.
The changes in this file are just part of a refactor. LogFinalLine() used to live in rpc/wrtc_client_channel.go.
rpc/wrtc_client_channel.go
Outdated
There was a problem hiding this comment.
Just refactoring. See this comment.
rpc/server_interceptors.go
Outdated
| @@ -119,3 +126,117 @@ func remoteSpanContextFromContext(ctx context.Context) (trace.SpanContext, error | |||
|
|
|||
| return trace.SpanContext{TraceID: traceID, SpanID: spanID, TraceOptions: traceOptions, Tracestate: nil}, nil | |||
| } | |||
|
|
|||
| func grpcUnaryServerInterceptor(logger utils.ZapCompatibleLogger, opts ...grpcZapOption) grpc.UnaryServerInterceptor { | |||
There was a problem hiding this comment.
we don't pass in any grpcZapOption, so happy to just remove all of this private stuff
| @@ -327,10 +324,6 @@ func NewServer(logger utils.ZapCompatibleLogger, opts ...ServerOption) (Server, | |||
| logger: logger, | |||
| } | |||
|
|
|||
| grpcLogger := logger.Desugar() | |||
| if !(sOpts.debug || utils.Debug) { | |||
| grpcLogger = grpcLogger.WithOptions(zap.IncreaseLevel(zap.LevelEnablerFunc(zapcore.ErrorLevel.Enabled))) | |||
There was a problem hiding this comment.
the idea here is that if debug mode is not on, we only want to see error level logs and up. We should port that functionality to the interceptor themselves (see if you're seeing info level logs with this set of changes)
rpc/server_interceptors.go
Outdated
| @@ -38,7 +45,7 @@ func UnaryServerTracingInterceptor(logger *zap.Logger) grpc.UnaryServerIntercept | |||
| } | |||
|
|
|||
| // StreamServerTracingInterceptor starts a new Span if Span metadata exists in the context. | |||
| func StreamServerTracingInterceptor(logger *zap.Logger) grpc.StreamServerInterceptor { | |||
| func StreamServerTracingInterceptor(logger utils.ZapCompatibleLogger) grpc.StreamServerInterceptor { | |||
There was a problem hiding this comment.
we don't even use the logger here, do we?
There was a problem hiding this comment.
Nope lol you're right good catch
rpc/server_interceptors.go
Outdated
| newCtx := newLoggerForCall(ctx, logger, info.FullMethod, startTime) | ||
|
|
||
| resp, err := handler(newCtx, req) | ||
| if !o.shouldLog(info.FullMethod, err) { |
There was a problem hiding this comment.
check the current path, I think we just always log (DefaultDecider)
rpc/server_interceptors.go
Outdated
| newCtx := newLoggerForCall(stream.Context(), logger, info.FullMethod, startTime) | ||
| wrapped := grpc_middleware.WrapServerStream(stream) | ||
|
|
||
| wrapped.WrappedContext = newCtx |
There was a problem hiding this comment.
should be fine to get rid of, we don't have a convention of passing loggers through the context. (can also check rdk for usages)
There was a problem hiding this comment.
I think I understand what you mean here. I went ahead and took out lines 155 and 158 as visible in the code block above (the lines wrapped.WrappedContext = newCtx and newCtx := newLoggerForCall(stream.Context(), logger, info.FullMethod, startTime)) from grpcStreamServerInterceptor(). grpcUnaryServerInterceptor() also uses newLoggerForCall() to wrap a Logger with a Context, but the result is directly passed to the handler function, so I don't think I can remove anything in that case.
|
For security reasons, this PR must be labeled with |
Stop converting the logger into a zap logger and instead use the native zap compatible logger. See pics below for visible change (the error log in between the highlighted lines is the same as what's referenced in the ticket).
Note
re: all the 'from here' comments..
To no longer use an ordinary zap logger, I replaced calls to grpc interceptor methods with calls to copies of those methods that I modify to use an RDK logger instead. An effect of this change was the additional copying over of all private types employed by these functions in the grpc library we use,, is there a better way about this? It seems like this PR used a similar tactic to get client interceptors to use the preferred logger.
Before:
After: notice here that the logger (from goutils/logger.go)is outputting logs that are not ERROR level or higher. This is not desired behavior. This has since been fixed; the original behavior has been restored.After:
Testing
Modify the the module.go RDK file in the simple module example custom resource so that the DoCommand() implementation always returns an error. Then, follow the instructions provided in the custom resources README.md file to see the logs output by the robot server.