diff --git a/rpcperms/interceptor.go b/rpcperms/interceptor.go index fc3064732..d9c9e6f0e 100644 --- a/rpcperms/interceptor.go +++ b/rpcperms/interceptor.go @@ -1,9 +1,11 @@ package rpcperms import ( + "bytes" "context" "errors" "fmt" + "runtime/debug" "sync" "sync/atomic" @@ -14,6 +16,8 @@ import ( "github.com/lightningnetwork/lnd/monitoring" "github.com/lightningnetwork/lnd/subscribe" "google.golang.org/grpc" + "google.golang.org/grpc/codes" + "google.golang.org/grpc/status" "gopkg.in/macaroon-bakery.v2/bakery" ) @@ -111,6 +115,8 @@ var ( // +---v--------------------------------+ // | InterceptorChain | // +-+----------------------------------+ +// | Panic Recovery Interceptor | +// +----------------------------------+ // | Log Interceptor | // +----------------------------------+ // | RPC State Interceptor | @@ -539,7 +545,19 @@ func (r *InterceptorChain) CreateServerOpts() []grpc.ServerOption { var unaryInterceptors []grpc.UnaryServerInterceptor var strmInterceptors []grpc.StreamServerInterceptor - // The first interceptors we'll add to the chain is our logging + // The recovery interceptors need to be the outermost interceptors so + // synchronous panics in subsequent interceptors or RPC handlers are + // converted into an RPC error instead of crashing lnd. + unaryInterceptors = append( + unaryInterceptors, + panicRecoveryUnaryServerInterceptor(r.rpcsLog), + ) + strmInterceptors = append( + strmInterceptors, + panicRecoveryStreamServerInterceptor(r.rpcsLog), + ) + + // The next interceptors we'll add to the chain are our logging // interceptors, so we can automatically log all errors that happen // during RPC calls. unaryInterceptors = append( @@ -598,6 +616,139 @@ func (r *InterceptorChain) CreateServerOpts() []grpc.ServerOption { return serverOpts } +// logRecoveredPanic logs a panic caught while handling an RPC request. The +// stack trace is included to preserve enough information to debug the faulty +// handler while allowing lnd to keep running. +func logRecoveredPanic(logger btclog.Logger, fullMethod string, + panicValue any) { + + if logger == nil { + return + } + + if fullMethod == "" { + fullMethod = "" + } + + stack := truncatePanicStack(debug.Stack()) + + logger.Errorf("[%v]: recovered panic in RPC handler: %v\n%s", + fullMethod, panicValue, stack) +} + +const ( + // maxPanicStackSize is the maximum stack size logged for recovered RPC + // panics. This follows the existing 8 KiB recovered-panic stack bound + // convention while avoiding package coupling for a single constant. + maxPanicStackSize = 8192 + + panicStackTruncatedMsg = "\n... stack trace truncated ..." +) + +// truncatePanicStack caps a panic stack trace while keeping the final logged +// line readable when possible. +func truncatePanicStack(stack []byte) []byte { + if len(stack) <= maxPanicStackSize { + return stack + } + + suffix := []byte(panicStackTruncatedMsg) + maxStackLen := maxPanicStackSize - len(suffix) + searchStack := stack[:maxStackLen+1] + newLineIndex := bytes.LastIndexByte(searchStack, '\n') + if newLineIndex > 0 { + maxStackLen = newLineIndex + } + + truncatedStack := make([]byte, 0, maxStackLen+len(suffix)) + truncatedStack = append(truncatedStack, stack[:maxStackLen]...) + truncatedStack = append(truncatedStack, suffix...) + + return truncatedStack +} + +// panicRecoveryUnaryServerInterceptor recovers panics from unary RPC handlers +// and converts them to an internal gRPC error. +func panicRecoveryUnaryServerInterceptor( + logger btclog.Logger) grpc.UnaryServerInterceptor { + + return func(ctx context.Context, req any, + info *grpc.UnaryServerInfo, + handler grpc.UnaryHandler) (any, error) { + + var ( + resp any + err error + ) + + func() { + defer func() { + panicValue := recover() + if panicValue == nil { + return + } + + fullMethod := "" + if info != nil { + fullMethod = info.FullMethod + } + + logRecoveredPanic( + logger, fullMethod, panicValue, + ) + + resp = nil + err = status.Error( + codes.Internal, "internal server error", + ) + }() + + resp, err = handler(ctx, req) + }() + + return resp, err + } +} + +// panicRecoveryStreamServerInterceptor recovers panics from streaming RPC +// handlers and converts them to an internal gRPC error. +func panicRecoveryStreamServerInterceptor( + logger btclog.Logger) grpc.StreamServerInterceptor { + + return func(srv any, ss grpc.ServerStream, + info *grpc.StreamServerInfo, + handler grpc.StreamHandler) error { + + var err error + + func() { + defer func() { + panicValue := recover() + if panicValue == nil { + return + } + + fullMethod := "" + if info != nil { + fullMethod = info.FullMethod + } + + logRecoveredPanic( + logger, fullMethod, panicValue, + ) + + err = status.Error( + codes.Internal, "internal server error", + ) + }() + + err = handler(srv, ss) + }() + + return err + } +} + // errorLogUnaryServerInterceptor is a simple UnaryServerInterceptor that will // automatically log any errors that occur when serving a client's unary // request. diff --git a/rpcperms/interceptor_test.go b/rpcperms/interceptor_test.go new file mode 100644 index 000000000..1c014f6fb --- /dev/null +++ b/rpcperms/interceptor_test.go @@ -0,0 +1,129 @@ +package rpcperms + +import ( + "bytes" + "context" + "errors" + "testing" + + "github.com/btcsuite/btclog/v2" + "github.com/stretchr/testify/require" + "google.golang.org/grpc" + "google.golang.org/grpc/codes" + "google.golang.org/grpc/status" +) + +// TestPanicRecoveryUnaryServerInterceptor asserts that unary handler panics are +// converted to internal RPC errors rather than propagating to the process. +func TestPanicRecoveryUnaryServerInterceptor(t *testing.T) { + interceptor := panicRecoveryUnaryServerInterceptor(btclog.Disabled) + info := &grpc.UnaryServerInfo{ + FullMethod: "/test.Service/Unary", + } + + resp, err := interceptor( + t.Context(), nil, info, + func(context.Context, any) (any, error) { + panic("boom") + }, + ) + require.Nil(t, resp) + require.Error(t, err) + require.Equal(t, codes.Internal, status.Code(err)) + + expectedResp := struct{}{} + expectedErr := errors.New("handler error") + resp, err = interceptor( + t.Context(), nil, info, + func(context.Context, any) (any, error) { + return expectedResp, expectedErr + }, + ) + require.Equal(t, expectedResp, resp) + require.ErrorIs(t, err, expectedErr) + + var nilLogger btclog.Logger + interceptor = panicRecoveryUnaryServerInterceptor(nilLogger) + resp, err = interceptor( + t.Context(), nil, info, + func(context.Context, any) (any, error) { + panic("boom") + }, + ) + require.Nil(t, resp) + require.Error(t, err) + require.Equal(t, codes.Internal, status.Code(err)) +} + +// TestPanicRecoveryStreamServerInterceptor asserts that stream handler panics +// are converted to internal RPC errors rather than propagating to the process. +func TestPanicRecoveryStreamServerInterceptor(t *testing.T) { + interceptor := panicRecoveryStreamServerInterceptor(btclog.Disabled) + info := &grpc.StreamServerInfo{ + FullMethod: "/test.Service/Stream", + } + + err := interceptor( + nil, nil, info, func(any, grpc.ServerStream) error { + panic("boom") + }, + ) + require.Error(t, err) + require.Equal(t, codes.Internal, status.Code(err)) + + expectedErr := errors.New("handler error") + err = interceptor( + nil, nil, info, func(any, grpc.ServerStream) error { + return expectedErr + }, + ) + require.ErrorIs(t, err, expectedErr) + + var nilLogger btclog.Logger + interceptor = panicRecoveryStreamServerInterceptor(nilLogger) + err = interceptor( + nil, nil, info, func(any, grpc.ServerStream) error { + panic("boom") + }, + ) + require.Error(t, err) + require.Equal(t, codes.Internal, status.Code(err)) + + var stream recordingServerStream + err = interceptor( + nil, &stream, info, func(_ any, ss grpc.ServerStream) error { + require.NoError(t, ss.SendMsg(struct{}{})) + panic("boom") + }, + ) + require.Error(t, err) + require.Equal(t, codes.Internal, status.Code(err)) + require.Equal(t, 1, stream.numSent) +} + +type recordingServerStream struct { + grpc.ServerStream + numSent int +} + +func (s *recordingServerStream) SendMsg(any) error { + s.numSent++ + return nil +} + +// TestTruncatePanicStack asserts that panic stack traces are capped with a +// readable truncation marker. +func TestTruncatePanicStack(t *testing.T) { + shortStack := []byte("short stack") + require.Equal(t, shortStack, truncatePanicStack(shortStack)) + + longStack := bytes.Repeat([]byte("stack frame\n"), maxPanicStackSize) + truncatedStack := truncatePanicStack(longStack) + + require.LessOrEqual(t, len(truncatedStack), maxPanicStackSize) + require.True( + t, bytes.HasSuffix( + truncatedStack, []byte(panicStackTruncatedMsg), + ), + ) +}