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.

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

Introduce interceptor to log client errors #332

Merged
merged 3 commits into from
Dec 18, 2024
Merged

Introduce interceptor to log client errors #332

merged 3 commits into from
Dec 18, 2024

Conversation

mkysel
Copy link
Collaborator

@mkysel mkysel commented Dec 18, 2024

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

Summary by CodeRabbit

  • New Features
    • Introduced a logging interceptor for gRPC services to enhance error logging during RPC calls.
  • Bug Fixes
    • Improved error handling and logging capabilities for unary and stream RPC calls.
  • Tests
    • Added unit tests for the logging interceptor to ensure correct logging behavior during error scenarios.

@mkysel mkysel requested a review from a team as a code owner December 18, 2024 16:19
Copy link

coderabbitai bot commented Dec 18, 2024

Warning

Rate limit exceeded

@mkysel has exceeded the limit for the number of commits or files that can be reviewed per hour. Please wait 8 minutes and 32 seconds before requesting another review.

⌛ How to resolve this issue?

After the wait time has elapsed, a review can be triggered using the @coderabbitai review command as a PR comment. Alternatively, push new commits to this PR.

We recommend that you space out your commits to avoid hitting the rate limit.

🚦 How do rate limits work?

CodeRabbit enforces hourly rate limits for each developer per organization.

Our paid plans have higher rate limits than the trial, open-source and free plans. In all cases, we re-allow further reviews after a brief timeout.

Please see our FAQ for further information.

📥 Commits

Reviewing files that changed from the base of the PR and between 6133c42 and 42af601.

📒 Files selected for processing (3)
  • pkg/api/server.go (3 hunks)
  • pkg/interceptors/server/logging.go (1 hunks)
  • pkg/interceptors/server/logging_test.go (1 hunks)

Walkthrough

The pull request introduces a new logging interceptor for gRPC services in the pkg/interceptors/client package. The implementation adds a mechanism to log errors during unary and stream RPC calls using a Zap logger. Changes include creating a LoggingInterceptor struct with methods to intercept and log errors, along with corresponding unit tests to validate the logging behavior. The interceptor is integrated into the API server configuration to enhance error logging capabilities.

Changes

File Change Summary
pkg/api/server.go Added logging interceptor to gRPC server options.
pkg/interceptors/client/logging.go Introduced LoggingInterceptor with methods for unary and stream logging, improved error handling in the constructor.
pkg/interceptors/client/logging_test.go Added unit tests for logging interceptor functionality, including tests for unary and stream handlers.

Assessment against linked issues

Objective Addressed Explanation
Log failed status codes [#329]

The changes comprehensively address the requirement to add middleware for logging client errors by implementing a robust logging interceptor that captures error details during gRPC calls.


Thank you for using CodeRabbit. We offer it for free to the OSS community and would appreciate your support in helping us grow. If you find it useful, would you consider giving us a shout-out on your favorite social media?

❤️ Share
🪧 Tips

Chat

There are 3 ways to chat with CodeRabbit:

  • Review comments: Directly reply to a review comment made by CodeRabbit. Example:
    • I pushed a fix in commit <commit_id>, please review it.
    • Generate unit testing code for this file.
    • Open a follow-up GitHub issue for this discussion.
  • Files and specific lines of code (under the "Files changed" tab): Tag @coderabbitai in a new review comment at the desired location with your query. Examples:
    • @coderabbitai generate unit testing code for this file.
    • @coderabbitai modularize this function.
  • PR comments: Tag @coderabbitai in a new PR comment to ask questions about the PR branch. For the best results, please provide a very specific query, as very limited context is provided in this mode. Examples:
    • @coderabbitai gather interesting stats about this repository and render them as a table. Additionally, render a pie chart showing the language distribution in the codebase.
    • @coderabbitai read src/utils.ts and generate unit testing code.
    • @coderabbitai read the files in the src/scheduler package and generate a class diagram using mermaid and a README in the markdown format.
    • @coderabbitai help me debug CodeRabbit configuration file.

Note: Be mindful of the bot's finite context window. It's strongly recommended to break down tasks such as reading entire modules into smaller chunks. For a focused discussion, use review comments to chat about specific files and their changes, instead of using the PR comments.

CodeRabbit Commands (Invoked using PR comments)

  • @coderabbitai pause to pause the reviews on a PR.
  • @coderabbitai resume to resume the paused reviews.
  • @coderabbitai review to trigger an incremental review. This is useful when automatic reviews are disabled for the repository.
  • @coderabbitai full review to do a full review from scratch and review all the files again.
  • @coderabbitai summary to regenerate the summary of the PR.
  • @coderabbitai generate docstrings to generate docstrings for this PR. (Beta)
  • @coderabbitai resolve resolve all the CodeRabbit review comments.
  • @coderabbitai configuration to show the current CodeRabbit configuration for the repository.
  • @coderabbitai help to get help.

Other keywords and placeholders

  • Add @coderabbitai ignore anywhere in the PR description to prevent this PR from being reviewed.
  • Add @coderabbitai summary to generate the high-level summary at a specific location in the PR description.
  • Add @coderabbitai anywhere in the PR title to generate the title automatically.

CodeRabbit Configuration File (.coderabbit.yaml)

  • You can programmatically configure CodeRabbit by adding a .coderabbit.yaml file to the root of your repository.
  • Please see the configuration documentation for more information.
  • If your editor has YAML language server enabled, you can add the path at the top of this file to enable auto-completion and validation: # yaml-language-server: $schema=https://coderabbit.ai/integrations/schema.v2.json

Documentation and Community

  • Visit our Documentation for detailed information on how to use CodeRabbit.
  • Join our Discord Community to get help, request features, and share feedback.
  • Follow us on X/Twitter for updates and announcements.

Copy link

@coderabbitai coderabbitai bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 2

🧹 Nitpick comments (4)
pkg/interceptors/client/logging.go (3)

18-26: Consider returning an error instead of panicking

While validating the logger is good practice, consider returning an error instead of panicking for better error handling in production environments.

-func NewLoggingInterceptor(logger *zap.Logger) *LoggingInterceptor {
+func NewLoggingInterceptor(logger *zap.Logger) (*LoggingInterceptor, error) {
 	if logger == nil {
-		panic("logger is required")
+		return nil, fmt.Errorf("logger is required")
 	}
 
 	return &LoggingInterceptor{
 		logger: logger,
-	}
+	}, nil
}

28-53: Consider enriching error logs with additional context

The error logging is good but could be enhanced with:

  1. Request metadata/headers (sanitized)
  2. Error details from the status
  3. Trace ID for distributed tracing
 if err != nil {
 	st, _ := status.FromError(err)
+	details := st.Details()
 	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()),
+		zap.Any("details", details),
+		zap.String("trace_id", trace.FromContext(ctx).SpanContext().TraceID.String()),
 	)
 }

55-80: Consider adding stream-specific context to logs

For stream RPCs, consider logging:

  1. Stream type (client/server/bidirectional)
  2. Stream state (active/closed)
 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()),
+		zap.Bool("client_stream", info.IsClientStream),
+		zap.Bool("server_stream", info.IsServerStream),
 	)
 }
pkg/interceptors/client/logging_test.go (1)

21-27: Consider testing Context cancellation

The mock ServerStream implementation could be enhanced to test context cancellation scenarios.

 type mockServerStream struct {
 	grpc.ServerStream
+	ctx context.Context
 }
 
 func (m *mockServerStream) Context() context.Context {
-	return context.Background()
+	if m.ctx != nil {
+		return m.ctx
+	}
+	return context.Background()
 }
📜 Review details

Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro

📥 Commits

Reviewing files that changed from the base of the PR and between 7efb028 and 3f160d3.

📒 Files selected for processing (3)
  • pkg/api/server.go (3 hunks)
  • pkg/interceptors/client/logging.go (1 hunks)
  • pkg/interceptors/client/logging_test.go (1 hunks)
🔇 Additional comments (2)
pkg/api/server.go (2)

65-66: 🛠️ Refactor suggestion

Verify interceptor initialization after constructor change

If the constructor is modified to return an error as suggested, this initialization needs to be updated:

-	loggingInterceptor := client.NewLoggingInterceptor(log)
+	loggingInterceptor, err := client.NewLoggingInterceptor(log)
+	if err != nil {
+		return nil, fmt.Errorf("failed to create logging interceptor: %w", err)
+	}

Also applies to: 81-82


81-82: Consider interceptor ordering impact

The logging interceptor is added after the prometheus interceptor. Consider if this ordering affects the accuracy of duration measurements.

✅ Verification successful

Let me gather more context about the interceptor setup to understand the full chain and ordering.


Let me check the implementation of the prometheus and logging interceptors to understand their functionality better.


Let me check the implementation of the prometheus interceptor to understand how it handles metrics.


Interceptor ordering is correct for accurate metrics

The current implementation has prometheus interceptors registered first, followed by logging interceptors, which is the correct order. This ensures that prometheus metrics capture the full duration of request handling, including any time spent in the logging interceptor. If the order were reversed, the metrics would not include the logging overhead.

🏁 Scripts executed

The following scripts were executed for the analysis:

Script:

#!/bin/bash
# Check for other interceptor orderings in the codebase
rg "ChainUnaryInterceptor|ChainStreamInterceptor" --type go

Length of output: 333


Script:

#!/bin/bash
# Get more context around the interceptor setup
rg "ChainUnaryInterceptor|ChainStreamInterceptor" -B 5 -A 5 --type go pkg/api/server.go

Length of output: 845


Script:

#!/bin/bash
# Look for prometheus and logging interceptor implementations
rg "type.*Interceptor struct" -B 5 -A 5 --type go
rg "func.*Unary.*Interceptor" -B 5 -A 5 --type go
rg "func.*Stream.*Interceptor" -B 5 -A 5 --type go

Length of output: 29292


Script:

#!/bin/bash
# Look for prometheus interceptor implementation
rg "prometheus.*Interceptor" -B 5 -A 10 --type go

Length of output: 949

Copy link

@coderabbitai coderabbitai bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 0

🧹 Nitpick comments (2)
pkg/interceptors/client/logging.go (2)

30-54: Consider extracting common logging logic into a helper function for maintainability.

Both unary and stream interceptors contain similar error-logging logic, which can introduce duplication. Extracting the shared logic (e.g., status extraction, time measurement, structured log fields) into a helper method can reduce code duplication and improve maintainability.

Example approach (no guarantee of perfect fit, just illustrating the idea):

 func (i *LoggingInterceptor) logError(method string, duration time.Duration, err error) {
   if err == nil {
     return
   }
   st, _ := status.FromError(err)
   i.logger.Error(
     "RPC Error",
     zap.String("method", method),
     zap.Duration("duration", duration),
     zap.Any("code", st.Code()),
     zap.String("message", st.Message()),
   )
 }

 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)
     duration := time.Since(start)
-    if err != nil {
-      st, _ := status.FromError(err)
-      i.logger.Error(...same fields...)
-    }
+    i.logError(info.FullMethod, duration, err)
     return resp, err
   }
 }

41-50: Include additional context if available.

Currently, the log statement captures method, duration, error code, and message. In certain situations, additional context (e.g., request ID, user ID, or correlation ID) might be available via metadata or context. Integrating such fields can help in debugging complex client errors or tracing user-specific issues.

📜 Review details

Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro

📥 Commits

Reviewing files that changed from the base of the PR and between 3f160d3 and 6133c42.

📒 Files selected for processing (3)
  • pkg/api/server.go (3 hunks)
  • pkg/interceptors/client/logging.go (1 hunks)
  • pkg/interceptors/client/logging_test.go (1 hunks)
🚧 Files skipped from review as they are similar to previous changes (2)
  • pkg/api/server.go
  • pkg/interceptors/client/logging_test.go
🔇 Additional comments (2)
pkg/interceptors/client/logging.go (2)

19-27: Great job checking for a nil logger!

The conditional check ensures that a valid logger is always provided, preventing potential runtime panics and enhancing robustness.


57-81: Stream interceptor implementation looks solid!

This code properly logs errors along with method name, duration, error code, and message. It mirrors the unary logic suitably and should provide consistent logs across different RPC types.

@mkysel mkysel requested a review from neekolas December 18, 2024 16:40
@mkysel mkysel merged commit e732d08 into main Dec 18, 2024
7 checks passed
@mkysel mkysel deleted the mkysel/interceptor branch December 18, 2024 16:53
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Add middleware to log client errors
2 participants