rpc: add unary+streaming interceptors to log all errors

Not all errors that occur when serving client requests in the gRPC
server are logged. As a result, at times, we can be lacking critic
information that can be used to debug issues that pop up. With this PR,
we create a basic streaming+unary interceptor that will log all errors
that occur when servicing calls.

The current format looks something like this in the logs when an error
occurs:

```
[ERR] RPCS: [/lnrpc.Lightning/SendCoins]: decoded address is of unknown format
```
This commit is contained in:
Olaoluwa Osuntokun 2019-08-06 17:57:02 -07:00
parent e44445e952
commit ed954785b2
No known key found for this signature in database
GPG Key ID: CE58F7F8E20FD9A2
2 changed files with 44 additions and 0 deletions

35
log.go

@ -1,6 +1,7 @@
package lnd package lnd
import ( import (
"context"
"fmt" "fmt"
"io" "io"
"os" "os"
@ -37,6 +38,7 @@ import (
"github.com/lightningnetwork/lnd/sweep" "github.com/lightningnetwork/lnd/sweep"
"github.com/lightningnetwork/lnd/watchtower" "github.com/lightningnetwork/lnd/watchtower"
"github.com/lightningnetwork/lnd/watchtower/wtclient" "github.com/lightningnetwork/lnd/watchtower/wtclient"
"google.golang.org/grpc"
) )
// Loggers per subsystem. A single backend logger is created and all subsystem // Loggers per subsystem. A single backend logger is created and all subsystem
@ -235,3 +237,36 @@ func (c logClosure) String() string {
func newLogClosure(c func() string) logClosure { func newLogClosure(c func() string) logClosure {
return logClosure(c) return logClosure(c)
} }
// errorLogUnaryServerInterceptor is a simple UnaryServerInterceptor that will
// automatically log any errors that occur when serving a client's unary
// request.
func errorLogUnaryServerInterceptor(logger btclog.Logger) grpc.UnaryServerInterceptor {
return func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo,
handler grpc.UnaryHandler) (interface{}, error) {
resp, err := handler(ctx, req)
if err != nil {
// TODO(roasbeef): also log request details?
logger.Errorf("[%v]: %v", info.FullMethod, err)
}
return resp, err
}
}
// errorLogStreamServerInterceptor is a simple StreamServerInterceptor that
// will log any errors that occur while processing a client or server streaming
// RPC.
func errorLogStreamServerInterceptor(logger btclog.Logger) grpc.StreamServerInterceptor {
return func(srv interface{}, ss grpc.ServerStream,
info *grpc.StreamServerInfo, handler grpc.StreamHandler) error {
err := handler(srv, ss)
if err != nil {
logger.Errorf("[%v]: %v", info.FullMethod, err)
}
return err
}
}

@ -560,6 +560,15 @@ func newRPCServer(s *server, macService *macaroons.Service,
unaryInterceptors := append(macUnaryInterceptors, promUnaryInterceptors...) unaryInterceptors := append(macUnaryInterceptors, promUnaryInterceptors...)
strmInterceptors := append(macStrmInterceptors, promStrmInterceptors...) strmInterceptors := append(macStrmInterceptors, promStrmInterceptors...)
// We'll also add our logging interceptors as well, so we can
// automatically log all errors that happen during RPC calls.
unaryInterceptors = append(
unaryInterceptors, errorLogUnaryServerInterceptor(rpcsLog),
)
strmInterceptors = append(
strmInterceptors, errorLogStreamServerInterceptor(rpcsLog),
)
// If any interceptors have been set up, add them to the server options. // If any interceptors have been set up, add them to the server options.
if len(unaryInterceptors) != 0 && len(strmInterceptors) != 0 { if len(unaryInterceptors) != 0 && len(strmInterceptors) != 0 {
chainedUnary := grpc_middleware.WithUnaryServerChain( chainedUnary := grpc_middleware.WithUnaryServerChain(