-
Notifications
You must be signed in to change notification settings - Fork 11
Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
Introduce interceptor to log client errors (#332)
Here is an example of the logger: ``` 2024-12-18T16:17:30.226Z ERROR replication Client Unary RPC Error {"method": "/xmtp.xmtpv4.payer_api.PayerApi/PublishClientEnvelopes", "duration": 10888708, "code": "Internal", "message": "error publishing group message: rpc error: code = Internal desc = error publishing identity update: timed out"} ``` Fixes #329
- Loading branch information
Showing
3 changed files
with
197 additions
and
0 deletions.
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,81 @@ | ||
package server | ||
|
||
import ( | ||
"context" | ||
"fmt" | ||
"go.uber.org/zap" | ||
"time" | ||
|
||
"google.golang.org/grpc" | ||
"google.golang.org/grpc/status" | ||
) | ||
|
||
// LoggingInterceptor logs errors for unary and stream RPCs. | ||
type LoggingInterceptor struct { | ||
logger *zap.Logger | ||
} | ||
|
||
// NewLoggingInterceptor creates a new instance of LoggingInterceptor. | ||
func NewLoggingInterceptor(logger *zap.Logger) (*LoggingInterceptor, error) { | ||
if logger == nil { | ||
return nil, fmt.Errorf("logger is required") | ||
} | ||
|
||
return &LoggingInterceptor{ | ||
logger: logger, | ||
}, nil | ||
} | ||
|
||
// Unary intercepts unary RPC calls to log errors. | ||
func (i *LoggingInterceptor) Unary() grpc.UnaryServerInterceptor { | ||
return func( | ||
ctx context.Context, | ||
req interface{}, | ||
info *grpc.UnaryServerInfo, | ||
handler grpc.UnaryHandler, | ||
) (interface{}, error) { | ||
start := time.Now() | ||
resp, err := handler(ctx, req) // Call the actual RPC handler | ||
duration := time.Since(start) | ||
|
||
if err != nil { | ||
st, _ := status.FromError(err) | ||
i.logger.Error( | ||
"Client Unary RPC Error", | ||
zap.String("method", info.FullMethod), | ||
zap.Duration("duration", duration), | ||
zap.Any("code", st.Code()), | ||
zap.String("message", st.Message()), | ||
) | ||
} | ||
|
||
return resp, err | ||
} | ||
} | ||
|
||
// Stream intercepts stream RPC calls to log errors. | ||
func (i *LoggingInterceptor) Stream() grpc.StreamServerInterceptor { | ||
return func( | ||
srv interface{}, | ||
ss grpc.ServerStream, | ||
info *grpc.StreamServerInfo, | ||
handler grpc.StreamHandler, | ||
) error { | ||
start := time.Now() | ||
err := handler(srv, ss) // Call the actual stream handler | ||
duration := time.Since(start) | ||
|
||
if err != nil { | ||
st, _ := status.FromError(err) | ||
i.logger.Error( | ||
"Stream Client RPC Error", | ||
zap.String("method", info.FullMethod), | ||
zap.Duration("duration", duration), | ||
zap.Any("code", st.Code()), | ||
zap.String("message", st.Message()), | ||
) | ||
} | ||
|
||
return err | ||
} | ||
} |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,107 @@ | ||
package server | ||
|
||
import ( | ||
"context" | ||
"github.com/stretchr/testify/require" | ||
"go.uber.org/zap" | ||
"go.uber.org/zap/zapcore" | ||
"go.uber.org/zap/zaptest/observer" | ||
"google.golang.org/grpc" | ||
"google.golang.org/grpc/codes" | ||
"google.golang.org/grpc/status" | ||
"testing" | ||
) | ||
|
||
func createTestLogger() (*zap.Logger, *observer.ObservedLogs) { | ||
core, observedLogs := observer.New(zapcore.DebugLevel) | ||
logger := zap.New(core) | ||
return logger, observedLogs | ||
} | ||
|
||
type mockServerStream struct { | ||
grpc.ServerStream | ||
} | ||
|
||
func (m *mockServerStream) Context() context.Context { | ||
return context.Background() | ||
} | ||
|
||
func TestUnaryLoggingInterceptor(t *testing.T) { | ||
logger, logs := createTestLogger() | ||
|
||
interceptor, err := NewLoggingInterceptor(logger) | ||
require.NoError(t, err) | ||
|
||
handler := func(ctx context.Context, req interface{}) (interface{}, error) { | ||
return nil, status.Errorf(codes.Internal, "mock internal error") | ||
} | ||
|
||
ctx := context.Background() | ||
info := &grpc.UnaryServerInfo{ | ||
FullMethod: "/test.TestService/TestMethod", | ||
} | ||
req := struct{}{} | ||
|
||
interceptorUnary := interceptor.Unary() | ||
_, err = interceptorUnary(ctx, req, info, handler) | ||
|
||
require.Error(t, err) | ||
require.Equal(t, 1, logs.Len(), "expected one log entry but got none") | ||
|
||
logEntry := logs.All()[0] | ||
|
||
require.Equal(t, zapcore.ErrorLevel, logEntry.Level, "expected log level 'Error'") | ||
require.Contains(t, logEntry.ContextMap(), "method") | ||
require.Equal( | ||
t, | ||
"/test.TestService/TestMethod", | ||
logEntry.ContextMap()["method"], | ||
"expected log to contain correct method", | ||
) | ||
require.Contains(t, logEntry.ContextMap(), "message") | ||
require.Equal( | ||
t, | ||
"mock internal error", | ||
logEntry.ContextMap()["message"], | ||
"expected log to contain correct error message", | ||
) | ||
} | ||
func TestStreamLoggingInterceptor(t *testing.T) { | ||
logger, logs := createTestLogger() | ||
interceptor, err := NewLoggingInterceptor(logger) | ||
require.NoError(t, err) | ||
|
||
handler := func(srv interface{}, ss grpc.ServerStream) error { | ||
return status.Errorf(codes.NotFound, "mock stream error") | ||
} | ||
|
||
info := &grpc.StreamServerInfo{ | ||
FullMethod: "/test.TestService/TestStream", | ||
} | ||
|
||
stream := &mockServerStream{} | ||
|
||
incerceptorStream := interceptor.Stream() | ||
err = incerceptorStream(nil, stream, info, handler) | ||
|
||
require.Error(t, err) | ||
require.Equal(t, 1, logs.Len(), "expected one log entry but got none") | ||
|
||
logEntry := logs.All()[0] | ||
|
||
require.Equal(t, zapcore.ErrorLevel, logEntry.Level, "expected log level 'Error'") | ||
require.Contains(t, logEntry.ContextMap(), "method") | ||
require.Equal( | ||
t, | ||
"/test.TestService/TestStream", | ||
logEntry.ContextMap()["method"], | ||
"expected log to contain correct method", | ||
) | ||
require.Contains(t, logEntry.ContextMap(), "message") | ||
require.Equal( | ||
t, | ||
"mock stream error", | ||
logEntry.ContextMap()["message"], | ||
"expected log to contain correct error message", | ||
) | ||
} |