accounts: start logging useful info from payment request handlers

This commit adds a prefixed logger that is then used to log trace
information about a payment. This will make it easy to see from the logs
which account ID is making the request, what the request ID is and what
the relavant payment hash is.

Author: ellemouton

accounts/checkers.go

@@ -522,12 +522,7 @@ func checkSend(ctx context.Context, chainParams *chaincfg.Params,
 	service Service, amt, amtMsat int64, invoice string,
 	paymentHash []byte, feeLimit *lnrpc.FeeLimit) error {
 
-	acct, err := AccountFromContext(ctx)
-	if err != nil {
-		return err
-	}
-
-	reqID, err := RequestIDFromContext(ctx)
+	log, acct, reqID, err := requestScopedValuesFromCtx(ctx)
 	if err != nil {
 		return err
 	}
@@ -584,6 +579,9 @@ func checkSend(ctx context.Context, chainParams *chaincfg.Params,
 		return fmt.Errorf("a payment hash is required")
 	}
 
+	log.Tracef("Handling send request for payment with hash: %s and "+
+		"amount: %d", pHash, sendAmt)
+
 	// We also add the max fee to the amount to check. This might mean that
 	// not every single satoshi of an account can be used up. But it
 	// prevents an account from going into a negative balance if we only
@@ -642,7 +640,7 @@ func checkSendResponse(ctx context.Context, service Service,
 func checkSendToRoute(ctx context.Context, service Service, paymentHash []byte,
 	route *lnrpc.Route) error {
 
-	acct, err := AccountFromContext(ctx)
+	log, acct, reqID, err := requestScopedValuesFromCtx(ctx)
 	if err != nil {
 		return err
 	}
@@ -652,11 +650,6 @@ func checkSendToRoute(ctx context.Context, service Service, paymentHash []byte,
 		return err
 	}
 
-	reqID, err := RequestIDFromContext(ctx)
-	if err != nil {
-		return err
-	}
-
 	if route == nil {
 		return fmt.Errorf("invalid route")
 	}
@@ -666,6 +659,9 @@ func checkSendToRoute(ctx context.Context, service Service, paymentHash []byte,
 		sendAmt = lnwire.MilliSatoshi(route.TotalAmtMsat)
 	}
 
+	log.Tracef("Handling send request for payment with hash: %s and "+
+		"amount: %d", hash, sendAmt)
+
 	// We also add the max fee to the amount to check. This might mean that
 	// not every single satoshi of an account can be used up. But it
 	// prevents an account from going into a negative balance if we only

accounts/context.go

@@ -3,6 +3,9 @@ package accounts
 import (
 	"context"
 	"fmt"
+
+	"github.com/btcsuite/btclog"
+	"github.com/lightningnetwork/lnd/build"
 )
 
 // ContextKey is the type that we use to identify account specific values in the
@@ -72,3 +75,25 @@ func RequestIDFromContext(ctx context.Context) (uint64, error) {
 
 	return reqID, nil
 }
+
+// requestScopedValuesFromCtx is a helper function that can be used to extract
+// an account and requestID from the given context. It also creates a new
+// prefixed logger that can be used by account request and response handlers.
+// Each log line will be prefixed by the account ID and the request ID.
+func requestScopedValuesFromCtx(ctx context.Context) (btclog.Logger,
+	*OffChainBalanceAccount, uint64, error) {
+
+	acc, err := AccountFromContext(ctx)
+	if err != nil {
+		return nil, nil, 0, err
+	}
+
+	reqID, err := RequestIDFromContext(ctx)
+	if err != nil {
+		return nil, nil, 0, err
+	}
+
+	prefix := fmt.Sprintf("[account: %s, request: %d]", acc.ID, reqID)
+
+	return build.NewPrefixLog(prefix, log), acc, reqID, nil
+}

accounts/interface.go

@@ -53,6 +53,11 @@ func ParseAccountID(idStr string) (*AccountID, error) {
 	return &id, nil
 }
 
+// String returns the string representation of the AccountID.
+func (a AccountID) String() string {
+	return hex.EncodeToString(a[:])
+}
+
 // PaymentEntry is the data we track per payment that is associated with an
 // account. This basically includes all information required to make sure
 // in-flight payments don't exceed the total available account balance.

accounts/log.go

@@ -5,7 +5,7 @@ import (
 	"github.com/lightningnetwork/lnd/build"
 )
 
-const Subsystem = "ACCT"
+const Subsystem = "ACNT"
 
 // log is a logger that is initialized with no output filters.  This
 // means the package will not perform any logging by default until the caller