diff --git a/server.go b/server.go index 44719ac..8098602 100644 --- a/server.go +++ b/server.go @@ -14,11 +14,14 @@ import ( "github.com/roadrunner-server/grpc/v6/parser" "github.com/roadrunner-server/grpc/v6/proxy" "go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc" + "google.golang.org/genproto/googleapis/rpc/errdetails" "google.golang.org/grpc" "google.golang.org/grpc/codes" "google.golang.org/grpc/credentials" "google.golang.org/grpc/keepalive" "google.golang.org/grpc/status" + "google.golang.org/protobuf/encoding/prototext" + "google.golang.org/protobuf/proto" ) func (p *Plugin) createGRPCserver(interceptors map[string]api.Interceptor) (*grpc.Server, error) { @@ -109,7 +112,11 @@ func (p *Plugin) interceptor(ctx context.Context, req any, info *grpc.UnaryServe }() if err != nil { - p.log.Error("method call was finished with error", "error", err, "method", info.FullMethod, "start", start, "elapsed", time.Since(start).Milliseconds()) + args := []any{"error", err, "method", info.FullMethod, "start", start, "elapsed", time.Since(start).Milliseconds()} + if details := statusDetails(s); len(details) > 0 { + args = append(args, "details", details) + } + p.log.Error("method call was finished with error", args...) return nil, err } @@ -118,6 +125,39 @@ func (p *Plugin) interceptor(ctx context.Context, req any, info *grpc.UnaryServe return resp, nil } +// statusDetails renders the well-known google.rpc.* error details attached to s as +// compact, one-line strings for logging, skipping any other (and potentially large) +// handler-attached detail. It returns nil when there are no such details. +func statusDetails(s *status.Status) []string { + details := s.Details() + if len(details) == 0 { + return nil + } + + out := make([]string, 0, len(details)) + for _, d := range details { + // Only the standard google.rpc.* error details are logged; arbitrary payloads + // a handler may attach are skipped (without touching them), so a failing call + // can't dump a large custom message into the logs. + switch d.(type) { + case *errdetails.BadRequest, + *errdetails.ErrorInfo, + *errdetails.DebugInfo, + *errdetails.Help, + *errdetails.LocalizedMessage, + *errdetails.PreconditionFailure, + *errdetails.QuotaFailure, + *errdetails.RequestInfo, + *errdetails.ResourceInfo, + *errdetails.RetryInfo: + m := d.(proto.Message) + out = append(out, fmt.Sprintf("%s: %s", m.ProtoReflect().Descriptor().FullName(), prototext.MarshalOptions{}.Format(m))) + } + } + + return out +} + func (p *Plugin) serverOptions() ([]grpc.ServerOption, error) { const op = errors.Op("grpc_plugin_server_options") diff --git a/server_test.go b/server_test.go new file mode 100644 index 0000000..4088d15 --- /dev/null +++ b/server_test.go @@ -0,0 +1,75 @@ +package grpc + +import ( + "errors" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "google.golang.org/genproto/googleapis/rpc/errdetails" + "google.golang.org/grpc/codes" + "google.golang.org/grpc/status" + "google.golang.org/protobuf/types/known/wrapperspb" +) + +func TestStatusDetails_NoDetails_Nil(t *testing.T) { + s := status.New(codes.InvalidArgument, "bad arg") + assert.Nil(t, statusDetails(s)) +} + +func TestStatusDetails_NonStatusError_Nil(t *testing.T) { + s, ok := status.FromError(errors.New("boom")) + require.False(t, ok) + assert.Nil(t, statusDetails(s), "a non-status error carries no details") +} + +func TestStatusDetails_SingleDetail(t *testing.T) { + s, err := status.New(codes.InvalidArgument, "bad arg").WithDetails(&errdetails.BadRequest{ + FieldViolations: []*errdetails.BadRequest_FieldViolation{ + {Field: "email", Description: "is required"}, + }, + }) + require.NoError(t, err) + + got := statusDetails(s) + require.Len(t, got, 1) + assert.Contains(t, got[0], "google.rpc.BadRequest", "should name the detail type") + assert.Contains(t, got[0], "email", "should include the field value") + assert.Contains(t, got[0], "is required") +} + +func TestStatusDetails_MultipleDetails(t *testing.T) { + s, err := status.New(codes.FailedPrecondition, "nope").WithDetails( + &errdetails.BadRequest{FieldViolations: []*errdetails.BadRequest_FieldViolation{{Field: "x", Description: "y"}}}, + &errdetails.ErrorInfo{Reason: "QUOTA", Domain: "example.com"}, + ) + require.NoError(t, err) + + got := statusDetails(s) + require.Len(t, got, 2) + joined := got[0] + " | " + got[1] + assert.Contains(t, joined, "google.rpc.BadRequest") + assert.Contains(t, joined, "google.rpc.ErrorInfo") + assert.Contains(t, joined, "QUOTA") +} + +func TestStatusDetails_SkipsNonGoogleRpc(t *testing.T) { + // Handlers can attach arbitrary (and potentially large) details; only the + // standard google.rpc.* error details should be logged. + s, err := status.New(codes.Internal, "boom").WithDetails(&wrapperspb.StringValue{Value: "arbitrary payload"}) + require.NoError(t, err) + assert.Empty(t, statusDetails(s), "non-google.rpc details must be skipped") +} + +func TestStatusDetails_MixedKeepsOnlyGoogleRpc(t *testing.T) { + s, err := status.New(codes.InvalidArgument, "bad").WithDetails( + &wrapperspb.StringValue{Value: "arbitrary payload"}, + &errdetails.BadRequest{FieldViolations: []*errdetails.BadRequest_FieldViolation{{Field: "email", Description: "is required"}}}, + ) + require.NoError(t, err) + + got := statusDetails(s) + require.Len(t, got, 1, "only the google.rpc detail should be kept") + assert.Contains(t, got[0], "google.rpc.BadRequest") + assert.NotContains(t, got[0], "StringValue") +}