Wallet debug logs (#2307)

* Add wallet debug logs

* Add checkbox to toggle diagnostics

* Require authentication for /wallets/debug

* Update debug log messages

* Use me.privates.diagnostics as source of truth

api/resolvers/user.js

@@ -919,6 +919,14 @@ export default {
 
       await models.user.update({ where: { id: me.id }, data: { hideWalletRecvPrompt: true } })
       return true
+    },
+    setDiagnostics: async (parent, { diagnostics }, { me, models }) => {
+      if (!me) {
+        throw new GqlAuthenticationError()
+      }
+
+      await models.user.update({ where: { id: me.id }, data: { diagnostics } })
+      return diagnostics
     }
   },
 

api/typeDefs/user.js

@@ -56,6 +56,7 @@ export default gql`
     generateApiKey(id: ID!): String
     deleteApiKey(id: ID!): User
     disableFreebies: Boolean
+    setDiagnostics(diagnostics: Boolean!): Boolean
   }
 
   type User {
@@ -86,7 +87,6 @@ export default gql`
 
   input SettingsInput {
     autoDropBolt11s: Boolean!
-    diagnostics: Boolean @deprecated
     noReferralLinks: Boolean!
     fiatCurrency: String!
     satsFilter: Int!
@@ -155,12 +155,12 @@ export default gql`
     hasInvites: Boolean!
     apiKeyEnabled: Boolean!
     showPassphrase: Boolean!
+    diagnostics: Boolean!
 
     """
     mirrors SettingsInput
     """
     autoDropBolt11s: Boolean!
-    diagnostics: Boolean @deprecated
     noReferralLinks: Boolean!
     fiatCurrency: String!
     satsFilter: Int!

api/typeDefs/wallet.js

@@ -11,7 +11,7 @@ const typeDefs = gql`
     wallets: [WalletOrTemplate!]!
     wallet(id: ID, name: String): WalletOrTemplate
     walletSettings: WalletSettings!
-    walletLogs(protocolId: Int, cursor: String): WalletLogs!
+    walletLogs(protocolId: Int, cursor: String, debug: Boolean): WalletLogs!
     failedInvoices: [Invoice!]!
   }
 
@@ -21,7 +21,7 @@ const typeDefs = gql`
     cancelInvoice(hash: String!, hmac: String, userCancel: Boolean): Invoice!
     dropBolt11(hash: String!): Boolean
     removeWallet(id: ID!): Boolean
-    deleteWalletLogs(protocolId: Int): Boolean
+    deleteWalletLogs(protocolId: Int, debug: Boolean): Boolean
     setWalletPriorities(priorities: [WalletPriorityUpdate!]!): Boolean
     buyCredits(credits: Int!): BuyCreditsPaidAction!
 
@@ -44,7 +44,7 @@ const typeDefs = gql`
     resetWallets(newKeyHash: String!): Boolean
     disablePassphraseExport: Boolean
     setWalletSettings(settings: WalletSettingsInput!): Boolean
-    addWalletLog(protocolId: Int!, level: String!, message: String!, timestamp: Date!, invoiceId: Int): Boolean
+    addWalletLog(protocolId: Int, level: String!, message: String!, timestamp: Date!, invoiceId: Int): Boolean
   }
 
   type BuyCreditsResult {

fragments/users.js

@@ -51,6 +51,7 @@ ${STREAK_FIELDS}
       vaultKeyHashUpdatedAt
       walletsUpdatedAt
       showPassphrase
+      diagnostics
     }
     optional {
       isContributor
@@ -392,3 +393,9 @@ export const MY_SUBSCRIBED_SUBS = gql`
     }
   }
 `
+
+export const SET_DIAGNOSTICS = gql`
+  mutation setDiagnostics($diagnostics: Boolean!) {
+    setDiagnostics(diagnostics: $diagnostics)
+  }
+`

pages/wallets/debug.js

@@ -1,7 +1,7 @@
 import { getGetServerSideProps } from '@/api/ssrApollo'
-import { WalletLayout, WalletLayoutHeader, WalletDebugSettings } from '@/wallets/client/components'
+import { WalletLayout, WalletLayoutHeader, WalletDebugSettings, WalletLogs } from '@/wallets/client/components'
 
-export const getServerSideProps = getGetServerSideProps({})
+export const getServerSideProps = getGetServerSideProps({ authRequired: true })
 
 export default function WalletDebug () {
   return (
@@ -9,6 +9,7 @@ export default function WalletDebug () {
       <div className='py-5 mx-auto w-100' style={{ maxWidth: '600px' }}>
         <WalletLayoutHeader>wallet debug</WalletLayoutHeader>
         <WalletDebugSettings />
+        <WalletLogs className='mt-3' debug />
       </div>
     </WalletLayout>
   )

prisma/schema.prisma

@@ -117,7 +117,7 @@ model User {
   followees                 UserSubscription[]   @relation("followee")
   hideWelcomeBanner         Boolean              @default(false)
   hideWalletRecvPrompt      Boolean              @default(false)
-  diagnostics               Boolean              @default(false) @ignore
+  diagnostics               Boolean              @default(false)
   hideIsContributor         Boolean              @default(false)
   lnAddr                    String?
   autoWithdrawMaxFeePercent Float?

wallets/client/components/debug.js

@@ -1,7 +1,7 @@
 import { formatBytes } from '@/lib/format'
 import { useEffect, useState } from 'react'
 import { useKeyHash, useKeyUpdatedAt } from '@/wallets/client/context'
-import { useRemoteKeyHash, useRemoteKeyHashUpdatedAt, useWalletsUpdatedAt } from '@/wallets/client/hooks'
+import { useDiagnostics, useRemoteKeyHash, useRemoteKeyHashUpdatedAt, useWalletsUpdatedAt } from '@/wallets/client/hooks'
 import { timeSince } from '@/lib/time'
 
 export function WalletDebugSettings () {
@@ -13,6 +13,7 @@ export function WalletDebugSettings () {
   const [persistent, setPersistent] = useState(null)
   const [quota, setQuota] = useState(null)
   const [usage, setUsage] = useState(null)
+  const [diagnostics, setDiagnostics] = useDiagnostics()
 
   useEffect(() => {
     async function init () {
@@ -59,6 +60,14 @@ export function WalletDebugSettings () {
       <div className='text-end' suppressHydrationWarning>
         {walletsUpdatedAt ? `${timeSince(new Date(walletsUpdatedAt).getTime())} ago` : 'unknown'}
       </div>
+      <div className='text-nowrap'>diagnostics:</div>
+      {/* not using Formik here because we want to submit immediately on change */}
+      <input
+        type='checkbox'
+        checked={diagnostics}
+        style={{ justifySelf: 'end', accentColor: 'var(--bs-primary)' }}
+        onChange={(e) => setDiagnostics(e.target.checked)}
+      />
     </div>
   )
 }

wallets/client/components/logger.js

@@ -10,9 +10,9 @@ import { ModalClosedError } from '@/components/modal'
 //   when we delete logs for a protocol, the cache is not updated
 //   so when we go to all wallet logs, we still see the deleted logs until the query is refetched
 
-export function WalletLogs ({ protocol, className }) {
+export function WalletLogs ({ protocol, className, debug }) {
-  const { logs, loadMore, hasMore, loading, clearLogs } = useWalletLogs(protocol)
+  const { logs, loadMore, hasMore, loading, clearLogs } = useWalletLogs(protocol, debug)
-  const deleteLogs = useDeleteWalletLogs(protocol)
+  const deleteLogs = useDeleteWalletLogs(protocol, debug)
 
   const onDelete = useCallback(async () => {
     try {
@@ -73,8 +73,11 @@ export function LogMessage ({ tag, level, message, context, ts }) {
     case 'warning':
       level = 'warn'
       className = 'text-warning'; break
+    case 'info':
+      className = 'text-info'; break
+    case 'debug':
     default:
-      className = 'text-info'
+      className = 'text-muted'; break
   }
 
   const filtered = context

wallets/client/context/hooks.js

@@ -6,7 +6,8 @@ import useInvoice from '@/components/use-invoice'
 import { useMe } from '@/components/me'
 import {
   useWalletsQuery, useWalletPayment, useGenerateRandomKey, useSetKey, useLoadKey, useLoadOldKey,
-  useWalletMigrationMutation, CryptoKeyRequiredError, useIsWrongKey
+  useWalletMigrationMutation, CryptoKeyRequiredError, useIsWrongKey,
+  useWalletLogger
 } from '@/wallets/client/hooks'
 import { WalletConfigurationError } from '@/wallets/client/errors'
 import { SET_WALLETS, WRONG_KEY, KEY_MATCH, useWalletsDispatch, WALLETS_QUERY_ERROR, KEY_STORAGE_UNAVAILABLE } from '@/wallets/client/context'
@@ -108,6 +109,8 @@ export function useKeyInit () {
   const dispatch = useWalletsDispatch()
   const wrongKey = useIsWrongKey()
 
+  const logger = useWalletLogger()
+
   useEffect(() => {
     if (typeof window.indexedDB === 'undefined') {
       dispatch({ type: KEY_STORAGE_UNAVAILABLE })
@@ -165,17 +168,20 @@ export function useKeyInit () {
           const read = tx.objectStore('vault').get('key')
 
           read.onerror = () => {
+            logger.debug('key init: error reading key: ' + read.error)
             reject(read.error)
           }
 
           read.onsuccess = () => {
             if (read.result) {
               // return key+hash found in db
+              logger.debug('key init: key found in IndexedDB')
               return resolve(read.result)
             }
 
             if (oldKeyAndHash) {
               // return key+hash found in old db
+              logger.debug('key init: key found in old IndexedDB')
               return resolve(oldKeyAndHash)
             }
 
@@ -184,11 +190,13 @@ export function useKeyInit () {
             const write = tx.objectStore('vault').put({ key: randomKey, hash: randomHash, updatedAt }, 'key')
 
             write.onerror = () => {
+              logger.debug('key init: error writing new random key: ' + write.error)
               reject(write.error)
             }
 
             write.onsuccess = (event) => {
               // return key+hash we just wrote to db
+              logger.debug('key init: saved new random key')
               resolve({ key: randomKey, hash: randomHash, updatedAt })
             }
           }
@@ -196,11 +204,12 @@ export function useKeyInit () {
 
         await setKey({ key, hash, updatedAt }, { updateDb: false })
       } catch (err) {
-        console.error('key init failed:', err)
+        logger.debug('key init: error: ' + err)
+        console.error('key init: error:', err)
       }
     }
     keyInit()
-  }, [me?.id, db, generateRandomKey, loadOldKey, setKey, loadKey])
+  }, [me?.id, db, generateRandomKey, loadOldKey, setKey, loadKey, logger])
 }
 
 // TODO(wallet-v2): remove migration code

wallets/client/fragments/wallet.js

@@ -229,14 +229,14 @@ export const SET_WALLET_SETTINGS = gql`
 `
 
 export const ADD_WALLET_LOG = gql`
-  mutation AddWalletLog($protocolId: Int!, $level: String!, $message: String!, $timestamp: Date!, $invoiceId: Int) {
+  mutation AddWalletLog($protocolId: Int, $level: String!, $message: String!, $timestamp: Date!, $invoiceId: Int) {
     addWalletLog(protocolId: $protocolId, level: $level, message: $message, timestamp: $timestamp, invoiceId: $invoiceId)
   }
 `
 
 export const WALLET_LOGS = gql`
-  query WalletLogs($protocolId: Int, $cursor: String) {
+  query WalletLogs($protocolId: Int, $cursor: String, $debug: Boolean) {
-    walletLogs(protocolId: $protocolId, cursor: $cursor) {
+    walletLogs(protocolId: $protocolId, cursor: $cursor, debug: $debug) {
       entries {
         id
         level
@@ -253,7 +253,7 @@ export const WALLET_LOGS = gql`
 `
 
 export const DELETE_WALLET_LOGS = gql`
-  mutation DeleteWalletLogs($protocolId: Int) {
+  mutation DeleteWalletLogs($protocolId: Int, $debug: Boolean) {
-    deleteWalletLogs(protocolId: $protocolId)
+    deleteWalletLogs(protocolId: $protocolId, debug: $debug)
   }
 `

wallets/client/hooks/crypto.js

@@ -9,7 +9,7 @@ import bip39Words from '@/lib/bip39-words'
 import { Form, PasswordInput, SubmitButton } from '@/components/form'
 import { object, string } from 'yup'
 import { SET_KEY, useKey, useKeyHash, useWalletsDispatch } from '@/wallets/client/context'
-import { useDisablePassphraseExport, useUpdateKeyHash, useWalletEncryptionUpdate, useWalletReset } from '@/wallets/client/hooks'
+import { useDisablePassphraseExport, useUpdateKeyHash, useWalletEncryptionUpdate, useWalletLogger, useWalletReset } from '@/wallets/client/hooks'
 import { useToast } from '@/components/toast'
 
 export class CryptoKeyRequiredError extends Error {
@@ -41,6 +41,7 @@ export function useSetKey () {
   const { set } = useIndexedDB()
   const dispatch = useWalletsDispatch()
   const updateKeyHash = useUpdateKeyHash()
+  const logger = useWalletLogger()
 
   return useCallback(async ({ key, hash, updatedAt }, { updateDb = true } = {}) => {
     if (updateDb) {
@@ -49,7 +50,8 @@ export function useSetKey () {
     }
     await updateKeyHash(hash)
     dispatch({ type: SET_KEY, key, hash, updatedAt })
-  }, [set, dispatch, updateKeyHash])
+    logger.debug(`using key ${hash}`)
+  }, [set, dispatch, updateKeyHash, logger])
 }
 
 export function useEncryption () {
@@ -159,12 +161,14 @@ export function useSavePassphrase () {
   const setKey = useSetKey()
   const salt = useKeySalt()
   const disablePassphraseExport = useDisablePassphraseExport()
+  const logger = useWalletLogger()
 
   return useCallback(async ({ passphrase }) => {
+    logger.debug('passphrase entered')
     const { key, hash } = await deriveKey(passphrase, salt)
     await setKey({ key, hash })
     await disablePassphraseExport()
-  }, [setKey, disablePassphraseExport])
+  }, [setKey, disablePassphraseExport, logger])
 }
 
 export function useResetPassphrase () {
@@ -173,19 +177,22 @@ export function useResetPassphrase () {
   const generateRandomKey = useGenerateRandomKey()
   const setKey = useSetKey()
   const toaster = useToast()
+  const logger = useWalletLogger()
 
   const resetPassphrase = useCallback((close) =>
     async () => {
       try {
+        logger.debug('passphrase reset')
         const { key: randomKey, hash } = await generateRandomKey()
         await setKey({ key: randomKey, hash })
         await walletReset({ newKeyHash: hash })
         close()
       } catch (err) {
+        logger.debug('failed to reset passphrase: ' + err)
         console.error('failed to reset passphrase:', err)
         toaster.error('failed to reset passphrase')
       }
-    }, [walletReset, generateRandomKey, setKey, toaster])
+    }, [walletReset, generateRandomKey, setKey, toaster, logger])
 
   return useCallback(async () => {
     showModal(close => (

wallets/client/hooks/diagnostics.js

@@ -0,0 +1,23 @@
+import { useMe } from '@/components/me'
+import { useToast } from '@/components/toast'
+import { SET_DIAGNOSTICS } from '@/fragments/users'
+import { useMutation } from '@apollo/client'
+import { useCallback } from 'react'
+
+export function useDiagnostics () {
+  const { me, refreshMe } = useMe()
+  const [mutate] = useMutation(SET_DIAGNOSTICS)
+  const toaster = useToast()
+
+  const setDiagnostics = useCallback(async (diagnostics) => {
+    try {
+      await mutate({ variables: { diagnostics } })
+      await refreshMe()
+    } catch (err) {
+      console.error('failed to toggle diagnostics:', err)
+      toaster.danger('failed to toggle diagnostics')
+    }
+  }, [mutate, toaster, refreshMe])
+
+  return [me?.privates?.diagnostics ?? false, setDiagnostics]
+}

wallets/client/hooks/index.js

@@ -6,3 +6,4 @@ export * from './wallet'
 export * from './crypto'
 export * from './query'
 export * from './logger'
+export * from './diagnostics'

wallets/client/hooks/logger.js

@@ -6,6 +6,7 @@ import { ModalClosedError, useShowModal } from '@/components/modal'
 import { useToast } from '@/components/toast'
 import { FAST_POLL_INTERVAL } from '@/lib/constants'
 import { isTemplate } from '@/wallets/lib/util'
+import { useDiagnostics } from '@/wallets/client/hooks/diagnostics'
 
 const TemplateLogsContext = createContext({})
 
@@ -38,17 +39,18 @@ export function TemplateLogsProvider ({ children }) {
 export function useWalletLoggerFactory () {
   const { addTemplateLog } = useContext(TemplateLogsContext)
   const [addWalletLog] = useMutation(ADD_WALLET_LOG)
+  const [diagnostics] = useDiagnostics()
 
   const log = useCallback(({ protocol, level, message, invoiceId }) => {
-    console[mapLevelToConsole(level)](`[${protocol.name}] ${message}`)
+    console[mapLevelToConsole(level)](`[${protocol ? protocol.name : 'system'}] ${message}`)
 
-    if (isTemplate(protocol)) {
+    if (protocol && isTemplate(protocol)) {
       // this is a template, so there's no protocol yet to which we could attach logs in the db
       addTemplateLog?.({ level, message })
       return
     }
 
-    return addWalletLog({ variables: { protocolId: Number(protocol.id), level, message, invoiceId, timestamp: new Date() } })
+    return addWalletLog({ variables: { protocolId: protocol ? Number(protocol.id) : null, level, message, invoiceId, timestamp: new Date() } })
       .catch(err => {
         console.error('error adding wallet log:', err)
       })
@@ -68,9 +70,13 @@ export function useWalletLoggerFactory () {
       },
       warn: (message) => {
         log({ protocol, level: 'WARN', message, invoiceId })
+      },
+      debug: (message) => {
+        if (!diagnostics) return
+        log({ protocol, level: 'DEBUG', message, invoiceId })
       }
     }
-  }, [log])
+  }, [log, diagnostics])
 }
 
 export function useWalletLogger (protocol) {
@@ -78,7 +84,7 @@ export function useWalletLogger (protocol) {
   return useMemo(() => loggerFactory(protocol), [loggerFactory, protocol])
 }
 
-export function useWalletLogs (protocol) {
+export function useWalletLogs (protocol, debug) {
   const { templateLogs, clearTemplateLogs } = useContext(TemplateLogsContext)
 
   const [cursor, setCursor] = useState(null)
@@ -90,7 +96,7 @@ export function useWalletLogs (protocol) {
   const protocolId = protocol ? Number(protocol.id) : undefined
 
   const [fetchLogs, { called, loading, error }] = useLazyQuery(WALLET_LOGS, {
-    variables: { protocolId },
+    variables: { protocolId, debug },
     skip,
     fetchPolicy: 'network-only'
   })
@@ -99,7 +105,11 @@ export function useWalletLogs (protocol) {
     if (skip) return
 
     const interval = setInterval(async () => {
-      const { data } = await fetchLogs({ variables: { protocolId } })
+      const { data, error } = await fetchLogs({ variables: { protocolId, debug } })
+      if (error) {
+        console.error('failed to fetch wallet logs:', error.message)
+        return
+      }
       const { entries: updatedLogs, cursor } = data.walletLogs
       setLogs(logs => [...updatedLogs.filter(log => !logs.some(l => l.id === log.id)), ...logs])
       if (!called) {
@@ -108,14 +118,14 @@ export function useWalletLogs (protocol) {
     }, FAST_POLL_INTERVAL)
 
     return () => clearInterval(interval)
-  }, [fetchLogs, called, skip])
+  }, [fetchLogs, called, skip, debug])
 
   const loadMore = useCallback(async () => {
-    const { data } = await fetchLogs({ variables: { protocolId, cursor } })
+    const { data } = await fetchLogs({ variables: { protocolId, cursor, debug } })
     const { entries: cursorLogs, cursor: newCursor } = data.walletLogs
     setLogs(logs => [...logs, ...cursorLogs.filter(log => !logs.some(l => l.id === log.id))])
     setCursor(newCursor)
-  }, [fetchLogs, cursor, protocolId])
+  }, [fetchLogs, cursor, protocolId, debug])
 
   const clearLogs = useCallback(() => {
     setLogs([])
@@ -149,7 +159,7 @@ function mapLevelToConsole (level) {
   }
 }
 
-export function useDeleteWalletLogs (protocol) {
+export function useDeleteWalletLogs (protocol, debug) {
   const showModal = useShowModal()
 
   return useCallback(async () => {
@@ -174,6 +184,7 @@ export function useDeleteWalletLogs (protocol) {
             protocol={protocol}
             onClose={onClose}
             onDelete={onDelete}
+            debug={debug}
           />
         )
       }, { onClose })
@@ -181,7 +192,7 @@ export function useDeleteWalletLogs (protocol) {
   }, [showModal])
 }
 
-function DeleteWalletLogsObstacle ({ protocol, onClose, onDelete }) {
+function DeleteWalletLogsObstacle ({ protocol, onClose, onDelete, debug }) {
   const toaster = useToast()
   const [deleteWalletLogs] = useMutation(DELETE_WALLET_LOGS)
 
@@ -190,9 +201,9 @@ function DeleteWalletLogsObstacle ({ protocol, onClose, onDelete }) {
     if (protocol && isTemplate(protocol)) return
 
     await deleteWalletLogs({
-      variables: { protocolId: protocol ? Number(protocol.id) : undefined }
+      variables: { protocolId: protocol ? Number(protocol.id) : undefined, debug }
     })
-  }, [protocol, deleteWalletLogs])
+  }, [protocol, deleteWalletLogs, debug])
 
   const onClick = useCallback(async () => {
     try {
@@ -206,7 +217,7 @@ function DeleteWalletLogsObstacle ({ protocol, onClose, onDelete }) {
     }
   }, [onClose, deleteLogs, toaster])
 
-  let prompt = 'Do you really want to delete all wallet logs?'
+  let prompt = debug ? 'Do you really want to delete all debug logs?' : 'Do you really want to delete all logs?'
   if (protocol) {
     prompt = 'Do you really want to delete all logs of this protocol?'
   }

wallets/server/logger.js

@@ -56,7 +56,8 @@ export function walletLogger ({
     ok: (message, context) => log('OK')(message, context),
     info: (message, context) => log('INFO')(message, context),
     error: (message, context) => log('ERROR')(message, context),
-    warn: (message, context) => log('WARNING')(message, context)
+    warn: (message, context) => log('WARNING')(message, context),
+    debug: (message, context) => log('DEBUG')(message, context)
   }
 }
 

wallets/server/resolvers/protocol.js

@@ -237,7 +237,7 @@ export async function removeWalletProtocol (parent, { id }, { me, models, tx })
   return await (tx ? transaction(tx) : models.$transaction(transaction))
 }
 
-async function walletLogs (parent, { protocolId, cursor }, { me, models }) {
+async function walletLogs (parent, { protocolId, cursor, debug }, { me, models }) {
   if (!me) throw new GqlAuthenticationError()
 
   const decodedCursor = decodeCursor(cursor)
@@ -248,7 +248,8 @@ async function walletLogs (parent, { protocolId, cursor }, { me, models }) {
       protocolId,
       createdAt: {
         lt: decodedCursor.time
-      }
+      },
+      level: debug ? 'DEBUG' : { not: 'DEBUG' }
     },
     orderBy: {
       createdAt: 'desc'
@@ -295,13 +296,14 @@ async function addWalletLog (parent, { protocolId, level, message, timestamp, in
   return true
 }
 
-async function deleteWalletLogs (parent, { protocolId }, { me, models }) {
+async function deleteWalletLogs (parent, { protocolId, debug }, { me, models }) {
   if (!me) throw new GqlAuthenticationError()
 
   await models.walletLog.deleteMany({
     where: {
       userId: me.id,
-      protocolId
+      protocolId,
+      level: debug ? 'DEBUG' : { not: 'DEBUG' }
     }
   })