normalized wallet logs (#1826)

* Add invoiceId, withdrawalId to wallet logs

* Truncate wallet logs

* Fix extra db dips per log line

* Fix leak of invoice for sender

Author: ekzyis

api/resolvers/wallet.js

@@ -430,6 +430,10 @@ const resolvers = {
               lte: to ? new Date(Number(to)) : undefined
             }
           },
+          include: {
+            invoice: true,
+            withdrawal: true
+          },
           orderBy: [
             { createdAt: 'desc' },
             { id: 'desc' }
@@ -445,6 +449,10 @@ const resolvers = {
               lte: decodedCursor.time
             }
           },
+          include: {
+            invoice: true,
+            withdrawal: true
+          },
           orderBy: [
             { createdAt: 'desc' },
             { id: 'desc' }
@@ -745,11 +753,42 @@ const resolvers = {
       return item
     },
     sats: fact => msatsToSatsDecimal(fact.msats)
+  },
+
+  WalletLogEntry: {
+    context: async ({ level, context, invoice, withdrawal }, args, { models }) => {
+      const isError = ['error', 'warn'].includes(level.toLowerCase())
+
+      if (withdrawal) {
+        return {
+          ...await logContextFromBolt11(withdrawal.bolt11),
+          ...(withdrawal.preimage ? { preimage: withdrawal.preimage } : {}),
+          ...(isError ? { max_fee: formatMsats(withdrawal.msatsFeePaying) } : {})
+        }
+      }
+
+      // XXX never return invoice as context because it might leak sensitive sender details
+      // if (invoice) { ... }
+
+      return context
+    }
   }
 }
 
 export default injectResolvers(resolvers)
 
+const logContextFromBolt11 = async (bolt11) => {
+  const decoded = await parsePaymentRequest({ request: bolt11 })
+  return {
+    bolt11,
+    amount: formatMsats(decoded.mtokens),
+    payment_hash: decoded.id,
+    created_at: decoded.created_at,
+    expires_at: decoded.expires_at,
+    description: decoded.description
+  }
+}
+
 export const walletLogger = ({ wallet, models }) => {
   // no-op logger if wallet is not provided
   if (!wallet) {
@@ -762,31 +801,27 @@ export const walletLogger = ({ wallet, models }) => {
   }
 
   // server implementation of wallet logger interface on client
-  const log = (level) => async (message, context = {}) => {
+  const log = (level) => async (message, ctx = {}) => {
     try {
-      if (context?.bolt11) {
+      let { invoiceId, withdrawalId, ...context } = ctx
+
+      if (context.bolt11) {
         // automatically populate context from bolt11 to avoid duplicating this code
-        const decoded = await parsePaymentRequest({ request: context.bolt11 })
         context = {
           ...context,
-          amount: formatMsats(decoded.mtokens),
-          payment_hash: decoded.id,
-          created_at: decoded.created_at,
-          expires_at: decoded.expires_at,
-          description: decoded.description,
-          // payments should affect wallet status
-          status: true
+          ...await logContextFromBolt11(context.bolt11)
         }
       }
-      context.recv = true
 
       await models.walletLog.create({
         data: {
           userId: wallet.userId,
           wallet: wallet.type,
           level,
           message,
-          context
+          context,
+          invoiceId,
+          withdrawalId
         }
       })
     } catch (err) {

components/wallet-logger.js

@@ -239,7 +239,13 @@ export function useWalletLogs (wallet, initialPage = 1, logsPerPage = 10) {
       const newLogs = data.walletLogs.entries.map(({ createdAt, wallet: walletType, ...log }) => ({
         ts: +new Date(createdAt),
         wallet: walletTag(getWalletByType(walletType)),
-        ...log
+        ...log,
+        // required to resolve recv status
+        context: {
+          recv: true,
+          status: !!log.context?.bolt11 && ['warn', 'error', 'success'].includes(log.level.toLowerCase()),
+          ...log.context
+        }
       }))
       const combinedLogs = uniqueSort([...result.data, ...newLogs])
 

prisma/migrations/20250118192921_normalized_wallet_logs/migration.sql

@@ -0,0 +1,8 @@
+ALTER TABLE "WalletLog"
+    ADD COLUMN     "invoiceId" INTEGER,
+    ADD COLUMN     "withdrawalId" INTEGER;
+
+ALTER TABLE "WalletLog" ADD CONSTRAINT "WalletLog_invoiceId_fkey" FOREIGN KEY ("invoiceId") REFERENCES "Invoice"("id") ON DELETE SET NULL ON UPDATE CASCADE;
+ALTER TABLE "WalletLog" ADD CONSTRAINT "WalletLog_withdrawalId_fkey" FOREIGN KEY ("withdrawalId") REFERENCES "Withdrawl"("id") ON DELETE SET NULL ON UPDATE CASCADE;
+
+TRUNCATE "WalletLog" RESTRICT;

prisma/schema.prisma

@@ -264,14 +264,18 @@ model VaultEntry {
 }
 
 model WalletLog {
-  id        Int        @id @default(autoincrement())
-  createdAt DateTime   @default(now()) @map("created_at")
-  userId    Int
-  user      User       @relation(fields: [userId], references: [id], onDelete: Cascade)
-  wallet    WalletType
-  level     LogLevel
-  message   String
-  context   Json?      @db.JsonB
+  id           Int        @id @default(autoincrement())
+  createdAt    DateTime   @default(now()) @map("created_at")
+  userId       Int
+  user         User       @relation(fields: [userId], references: [id], onDelete: Cascade)
+  wallet       WalletType
+  level        LogLevel
+  message      String
+  invoiceId    Int?
+  invoice      Invoice?   @relation(fields: [invoiceId], references: [id])
+  withdrawalId Int?
+  withdrawal   Withdrawl? @relation(fields: [withdrawalId], references: [id])
+  context      Json?      @db.JsonB
 
   @@index([userId, createdAt])
 }
@@ -971,6 +975,7 @@ model Invoice {
   Upload             Upload[]
   PollVote           PollVote[]
   PollBlindVote      PollBlindVote[]
+  WalletLog          WalletLog[]
 
   @@index([createdAt], map: "Invoice.created_at_index")
   @@index([userId], map: "Invoice.userId_index")
@@ -1048,6 +1053,7 @@ model Withdrawl {
   user           User             @relation(fields: [userId], references: [id], onDelete: Cascade)
   wallet         Wallet?          @relation(fields: [walletId], references: [id], onDelete: SetNull)
   invoiceForward InvoiceForward?
+  WalletLog      WalletLog[]
 
   @@index([createdAt], map: "Withdrawl.created_at_index")
   @@index([userId], map: "Withdrawl.userId_index")

wallets/server.js

@@ -39,8 +39,7 @@ export async function * createUserInvoice (userId, { msats, description, descrip
 
     try {
       logger.info(
-        `↙ incoming payment: ${formatSats(msatsToSats(msats))}`,
-        {
+        `↙ incoming payment: ${formatSats(msatsToSats(msats))}`, {
           amount: formatMsats(msats)
         })
 

worker/paidAction.js

@@ -2,7 +2,7 @@ import { getPaymentFailureStatus, hodlInvoiceCltvDetails, getPaymentOrNotSent }
 import { paidActions } from '@/api/paidAction'
 import { walletLogger } from '@/api/resolvers/wallet'
 import { LND_PATHFINDING_TIME_PREF_PPM, LND_PATHFINDING_TIMEOUT_MS, PAID_ACTION_TERMINAL_STATES } from '@/lib/constants'
-import { formatMsats, formatSats, msatsToSats, toPositiveNumber } from '@/lib/format'
+import { formatSats, msatsToSats, toPositiveNumber } from '@/lib/format'
 import { datePivot } from '@/lib/time'
 import { Prisma } from '@prisma/client'
 import {
@@ -317,17 +317,13 @@ export async function paidActionForwarded ({ data: { invoiceId, withdrawal, ...a
   }, { models, lnd, boss })
 
   if (transitionedInvoice) {
-    const { bolt11, msatsPaid } = transitionedInvoice.invoiceForward.withdrawl
+    const withdrawal = transitionedInvoice.invoiceForward.withdrawl
 
     const logger = walletLogger({ wallet: transitionedInvoice.invoiceForward.wallet, models })
     logger.ok(
-      `↙ payment received: ${formatSats(msatsToSats(Number(msatsPaid)))}`,
-      {
-        bolt11,
-        preimage: transitionedInvoice.preimage
-        // we could show the outgoing fee that we paid from the incoming amount to the receiver
-        // but we don't since it might look like the receiver paid the fee but that's not the case.
-        // fee: formatMsats(msatsFeePaid)
+      `↙ payment received: ${formatSats(msatsToSats(Number(withdrawal.msatsPaid)))}`, {
+        invoiceId: transitionedInvoice.id,
+        withdrawalId: withdrawal.id
       })
   }
 
@@ -376,12 +372,11 @@ export async function paidActionFailedForward ({ data: { invoiceId, withdrawal:
   }, { models, lnd, boss })
 
   if (transitionedInvoice) {
-    const { bolt11, msatsFeePaying } = transitionedInvoice.invoiceForward.withdrawl
-    const logger = walletLogger({ wallet: transitionedInvoice.invoiceForward.wallet, models })
+    const fwd = transitionedInvoice.invoiceForward
+    const logger = walletLogger({ wallet: fwd.wallet, models })
     logger.warn(
       `incoming payment failed: ${message}`, {
-        bolt11,
-        max_fee: formatMsats(msatsFeePaying)
+        withdrawalId: fwd.withdrawl.id
       })
   }
 
@@ -446,7 +441,11 @@ export async function paidActionCanceling ({ data: { invoiceId, ...args }, model
       const { wallet, bolt11 } = transitionedInvoice.invoiceForward
       const logger = walletLogger({ wallet, models })
       const decoded = await parsePaymentRequest({ request: bolt11 })
-      logger.info(`invoice for ${formatSats(msatsToSats(decoded.mtokens))} canceled by payer`, { bolt11 })
+      logger.info(
+        `invoice for ${formatSats(msatsToSats(decoded.mtokens))} canceled by payer`, {
+          bolt11,
+          invoiceId: transitionedInvoice.id
+        })
     }
   }
 

worker/payingAction.js

@@ -125,11 +125,8 @@ export async function payingActionConfirmed ({ data: args, models, lnd, boss })
 
     const logger = walletLogger({ models, wallet: transitionedWithdrawal.wallet })
     logger?.ok(
-      `↙ payment received: ${formatSats(msatsToSats(transitionedWithdrawal.msatsPaid))}`,
-      {
-        bolt11: transitionedWithdrawal.bolt11,
-        preimage: transitionedWithdrawal.preimage,
-        fee: formatMsats(transitionedWithdrawal.msatsFeePaid)
+      `↙ payment received: ${formatSats(msatsToSats(transitionedWithdrawal.msatsPaid))}`, {
+        withdrawalId: transitionedWithdrawal.id
       })
   }
 }