logger fix

This commit is contained in:
hatim boufnichel 2024-05-07 15:36:54 +02:00
parent aa8f9cf1ce
commit 6d597ecd1a
15 changed files with 85 additions and 46 deletions

View file

@ -6,6 +6,9 @@ LND_MACAROON_PATH=/root/.lnd/data/chain/bitcoin/mainnet/admin.macaroon
#DB
DATABASE_FILE=db.sqlite
METRICS_DATABASE_FILE=metrics.sqlite
LOGS_DIR=logs
LOG_LEVEL=DEBUG
#LOCAL
ADMIN_TOKEN=

View file

@ -1,11 +1,11 @@
import { ServerOptions } from "../proto/autogenerated/ts/express_server";
import { AdminContext, MetricsContext } from "../proto/autogenerated/ts/types";
import Main from './services/main'
import { getLogger } from './services/helpers/logger.js'
import { ERROR, getLogger } from './services/helpers/logger.js'
const serverOptions = (mainHandler: Main): ServerOptions => {
const log = getLogger({})
return {
logger: { log, error: err => log("ERROR", err) },
logger: { log, error: err => log(ERROR, err) },
AdminAuthGuard: adminAuth,
MetricsAuthGuard: metricsAuth,
AppAuthGuard: async (authHeader) => { return { app_id: mainHandler.applicationManager.DecodeAppToken(stripBearer(authHeader)) } },

View file

@ -3,7 +3,7 @@ import Nostr from "./services/nostr/index.js"
import { NostrSend, NostrSettings } from "./services/nostr/handler.js"
import * as Types from '../proto/autogenerated/ts/types.js'
import NewNostrTransport, { NostrRequest } from '../proto/autogenerated/ts/nostr_transport.js';
import { getLogger } from "./services/helpers/logger.js";
import { ERROR, getLogger } from "./services/helpers/logger.js";
export default (serverMethods: Types.ServerMethods, mainHandler: Main, nostrSettings: NostrSettings): { Stop: () => void, Send: NostrSend } => {
const log = getLogger({})
@ -14,7 +14,7 @@ export default (serverMethods: Types.ServerMethods, mainHandler: Main, nostrSett
return { user_id: nostrUser.user.user_id, app_user_id: nostrUser.identifier, app_id: appId || "" }
},
metricsCallback: metrics => mainHandler.settings.recordPerformance ? mainHandler.metricsManager.AddMetrics(metrics) : null,
logger: { log: console.log, error: err => log("ERROR", err) }
logger: { log: console.log, error: err => log(ERROR, err) }
})
const nostr = new Nostr(nostrSettings, event => {
let j: NostrRequest
@ -22,7 +22,7 @@ export default (serverMethods: Types.ServerMethods, mainHandler: Main, nostrSett
j = JSON.parse(event.content)
log("nostr event", j.rpcName || 'no rpc name')
} catch {
log("ERROR", "invalid json event received", event.content)
log(ERROR, "invalid json event received", event.content)
return
}
nostrTransport({ ...j, appId: event.appId }, res => {

View file

@ -7,7 +7,7 @@ export default class FunctionQueue<T> {
running: boolean = false
f: () => Promise<T>
constructor(name: string, f: () => Promise<T>) {
this.log = getLogger({ appName: name })
this.log = getLogger({ component: name })
this.f = f
}

View file

@ -1,37 +1,74 @@
import fs from 'fs'
type LoggerParams = { appName?: string, userId?: string }
export type PubLogger = (...message: (string | number | object)[]) => void
export const DEBUG = Symbol("DEBUG")
export const ERROR = Symbol("ERROR")
export const WARN = Symbol("WARN")
type LoggerParams = { appName?: string, userId?: string, component?: string }
export type PubLogger = (...message: (string | number | object | symbol)[]) => void
type Writer = (message: string) => void
const logsDir = process.env.LOGS_DIR || "logs"
const logLevel = process.env.LOG_LEVEL || "DEBUG"
try {
fs.mkdirSync("logs")
fs.mkdirSync(logsDir)
} catch { }
if (logLevel !== "DEBUG" && logLevel !== "WARN" && logLevel !== "ERROR") {
throw new Error("Invalid log level " + logLevel + " must be one of (DEBUG, WARN, ERROR)")
}
const z = (n: number) => n < 10 ? `0${n}` : `${n}`
const openWriter = (fileName: string): Writer => {
const logStream = fs.createWriteStream(`logs/${fileName}`, { flags: 'a' });
const now = new Date()
const date = `${now.getFullYear()}-${z(now.getMonth() + 1)}-${z(now.getDate())}`
const logStream = fs.createWriteStream(`${logsDir}/${fileName}_${date}.log`, { flags: 'a' });
return (message) => {
logStream.write(message + "\n")
}
}
const rootWriter = openWriter("ROOT.log")
if (!fs.existsSync("logs/apps")) {
fs.mkdirSync("logs/apps", { recursive: true });
if (!fs.existsSync(`${logsDir}/apps`)) {
fs.mkdirSync(`${logsDir}/apps`, { recursive: true });
}
if (!fs.existsSync("logs/users")) {
fs.mkdirSync("logs/users", { recursive: true });
if (!fs.existsSync(`${logsDir}/users`)) {
fs.mkdirSync(`${logsDir}/users`, { recursive: true });
}
if (!fs.existsSync(`${logsDir}/components`)) {
fs.mkdirSync(`${logsDir}/components`, { recursive: true });
}
export const getLogger = (params: LoggerParams): PubLogger => {
const writers: Writer[] = []
if (params.appName) {
writers.push(openWriter(`apps/${params.appName}.log`))
writers.push(openWriter(`apps/${params.appName}`))
}
if (params.userId) {
writers.push(openWriter(`users/${params.userId}.log`))
writers.push(openWriter(`users/${params.userId}`))
}
if (params.component) {
writers.push(openWriter(`components/${params.component}`))
}
if (writers.length === 0) {
writers.push(rootWriter)
}
return (...message) => {
switch (message[0]) {
case DEBUG:
if (logLevel !== "DEBUG") {
return
}
message[0] = "DEBUG"
break;
case WARN:
if (logLevel === "ERROR") {
return
}
message[0] = "WARN"
break;
case ERROR:
message[0] = "ERROR"
break;
default:
if (logLevel !== "DEBUG") {
return
}
}
const now = new Date()
const timestamp = `${now.getFullYear()}-${z(now.getMonth() + 1)}-${z(now.getDate())} ${z(now.getHours())}:${z(now.getMinutes())}:${z(now.getSeconds())}`
const toLog = [timestamp]

View file

@ -32,7 +32,7 @@ export default class {
invoicePaidCb: InvoicePaidCb
newBlockCb: NewBlockCb
htlcCb: HtlcCb
log = getLogger({ appName: 'lndManager' })
log = getLogger({ component: 'lndManager' })
outgoingOpsLocked = false
constructor(settings: LndSettings, addressPaidCb: AddressPaidCb, invoicePaidCb: InvoicePaidCb, newBlockCb: NewBlockCb, htlcCb: HtlcCb) {
this.settings = settings

View file

@ -7,7 +7,7 @@ import PaymentManager, { PendingTx } from './paymentManager.js'
import { MainSettings } from './settings.js'
import LND from "../lnd/lnd.js"
import { AddressPaidCb, HtlcCb, InvoicePaidCb, NewBlockCb } from "../lnd/settings.js"
import { getLogger, PubLogger } from "../helpers/logger.js"
import { ERROR, getLogger, PubLogger } from "../helpers/logger.js"
import AppUserManager from "./appUserManager.js"
import { Application } from '../storage/entity/Application.js'
import { UserReceivingInvoice } from '../storage/entity/UserReceivingInvoice.js'
@ -77,7 +77,7 @@ export default class {
await this.metricsManager.NewBlockCb(height, balanceEvents)
confirmed = await this.paymentManager.CheckNewlyConfirmedTxs(height)
} catch (err: any) {
log("failed to check transactions after new block", err.message || err)
log(ERROR, "failed to check transactions after new block", err.message || err)
return
}
await Promise.all(confirmed.map(async c => {
@ -91,7 +91,7 @@ export default class {
this.storage.StartTransaction(async tx => {
const { user_address: userAddress, paid_amount: amount, service_fee: serviceFee, serial_id: serialId, tx_hash } = c.tx
if (!userAddress.linkedApplication) {
log("ERROR", "an address was paid, that has no linked application")
log(ERROR, "an address was paid, that has no linked application")
return
}
const updateResult = await this.storage.paymentStorage.UpdateAddressReceivingTransaction(serialId, { confs: c.confs }, tx)
@ -108,7 +108,6 @@ export default class {
const op = { amount, paidAtUnix: Date.now() / 1000, inbound: true, type: Types.UserOperationType.INCOMING_TX, identifier: userAddress.address, operationId, network_fee: 0, service_fee: serviceFee, confirmed: true, tx_hash: c.tx.tx_hash, internal: c.tx.internal }
this.sendOperationToNostr(userAddress.linkedApplication!, userAddress.user.user_id, op)
})
}
}))
}
@ -120,7 +119,7 @@ export default class {
if (!userAddress) { return }
let log = getLogger({})
if (!userAddress.linkedApplication) {
log("ERROR", "an address was paid, that has no linked application")
log(ERROR, "an address was paid, that has no linked application")
return
}
log = getLogger({ appName: userAddress.linkedApplication.name })
@ -145,7 +144,7 @@ export default class {
const op = { amount, paidAtUnix: Date.now() / 1000, inbound: true, type: Types.UserOperationType.INCOMING_TX, identifier: userAddress.address, operationId, network_fee: 0, service_fee: fee, confirmed: internal, tx_hash: txOutput.hash, internal: false }
this.sendOperationToNostr(userAddress.linkedApplication, userAddress.user.user_id, op)
} catch {
log(ERROR, "cannot process address paid transaction, already registered")
}
})
}
@ -158,7 +157,7 @@ export default class {
if (userInvoice.paid_at_unix > 0 && internal) { log("cannot pay internally, invoice already paid"); return }
if (userInvoice.paid_at_unix > 0 && !internal && userInvoice.paidByLnd) { log("invoice already paid by lnd"); return }
if (!userInvoice.linkedApplication) {
log("ERROR", "an invoice was paid, that has no linked application")
log(ERROR, "an invoice was paid, that has no linked application")
return
}
log = getLogger({ appName: userInvoice.linkedApplication.name })
@ -181,7 +180,7 @@ export default class {
this.createZapReceipt(log, userInvoice)
log("paid invoice processed successfully")
} catch (err: any) {
log("ERROR", "cannot process paid invoice", err.message || "")
log(ERROR, "cannot process paid invoice", err.message || "")
}
})
}
@ -193,7 +192,7 @@ export default class {
try {
await fetch(url + "&ok=true")
} catch (err: any) {
log("error sending paid callback for invoice", err.message || "")
log(ERROR, "error sending paid callback for invoice", err.message || "")
}
}
@ -210,7 +209,7 @@ export default class {
async createZapReceipt(log: PubLogger, invoice: UserReceivingInvoice) {
const zapInfo = invoice.zap_info
if (!zapInfo || !invoice.linkedApplication || !invoice.linkedApplication.nostr_public_key) {
log("no zap info linked to payment")
log(ERROR, "no zap info linked to payment")
return
}
const tags = [["p", zapInfo.pub], ["bolt11", invoice.invoice], ["description", zapInfo.description]]

View file

@ -45,7 +45,7 @@ export default class {
lnd: LND
addressPaidCb: AddressPaidCb
invoicePaidCb: InvoicePaidCb
log = getLogger({ appName: "PaymentManager" })
log = getLogger({ component: "PaymentManager" })
watchDog: Watchdog
constructor(storage: Storage, lnd: LND, settings: MainSettings, addressPaidCb: AddressPaidCb, invoicePaidCb: InvoicePaidCb) {
this.storage = storage

View file

@ -20,7 +20,7 @@ export default class SanityChecker {
incrementSources: Record<string, boolean> = {}
decrementSources: Record<string, boolean> = {}
decrementEvents: Record<string, { userId: string, refund: number, failure: boolean }> = {}
log = getLogger({ appName: "SanityChecker" })
log = getLogger({ component: "SanityChecker" })
users: Record<string, { ts: number, updatedBalance: number }> = {}
constructor(storage: Storage, lnd: LND) {
this.storage = storage

View file

@ -23,14 +23,14 @@ export class Watchdog {
settings: WatchdogSettings;
storage: Storage;
latestCheckStart = 0
log = getLogger({ appName: "watchdog" })
log = getLogger({ component: "watchdog" })
ready = false
interval: NodeJS.Timer;
constructor(settings: WatchdogSettings, lnd: LND, storage: Storage) {
this.lnd = lnd;
this.settings = settings;
this.storage = storage;
this.queue = new FunctionQueue("watchdog::queue", () => this.StartCheck())
this.queue = new FunctionQueue("watchdog_queue", () => this.StartCheck())
}
Stop() {
@ -73,7 +73,7 @@ export class Watchdog {
const walletBalance = await this.lnd.GetWalletBalance()
this.log(Number(walletBalance.confirmedBalance), "sats in chain wallet")
const channelsBalance = await this.lnd.GetChannelBalance()
getLogger({ appName: "debugLndBalancev3" })({ w: walletBalance, c: channelsBalance, u: usersTotal, f: this.accumulatedHtlcFees })
getLogger({ component: "debugLndBalancev3" })({ w: walletBalance, c: channelsBalance, u: usersTotal, f: this.accumulatedHtlcFees })
const localChannelsBalance = Number(channelsBalance.localBalance?.sat || 0)
const unsettledLocalBalance = Number(channelsBalance.unsettledLocalBalance?.sat || 0)

View file

@ -16,9 +16,9 @@ export default class HtlcTracker {
constructor(storage: Storage) {
this.storage = storage
}
log = getLogger({ appName: 'htlcTracker' })
log = getLogger({ component: 'htlcTracker' })
onHtlcEvent = async (htlc: HtlcEvent) => {
getLogger({ appName: 'debugHtlcs' })(htlc)
getLogger({ component: 'debugHtlcs' })(htlc)
const htlcEvent = htlc.event
if (htlcEvent.oneofKind === 'subscribedEvent') {
this.log("htlc subscribed")

View file

@ -1,7 +1,7 @@
//import { SimplePool, Sub, Event, UnsignedEvent, getEventHash, signEvent } from 'nostr-tools'
import { SimplePool, Sub, Event, UnsignedEvent, getEventHash, finishEvent, relayInit } from './tools/index.js'
import { encryptData, decryptData, getSharedSecret, decodePayload, encodePayload } from './nip44.js'
import { getLogger } from '../helpers/logger.js'
import { ERROR, getLogger } from '../helpers/logger.js'
import { encodeNprofile } from '../../custom-nip19.js'
const handledEvents: string[] = [] // TODO: - big memory leak here, add TTL
type AppInfo = { appId: string, publicKey: string, privateKey: string, name: string }
@ -56,13 +56,13 @@ process.on("message", (message: ChildProcessRequest) => {
sendToNostr(message.appId, message.data, message.relays)
break
default:
getLogger({ appName: "nostrMiddleware" })("ERROR", "unknown nostr request", message)
getLogger({ component: "nostrMiddleware" })(ERROR, "unknown nostr request", message)
break
}
})
const initSubprocessHandler = (settings: NostrSettings) => {
if (subProcessHandler) {
getLogger({ appName: "nostrMiddleware" })("ERROR", "nostr settings ignored since handler already exists")
getLogger({ component: "nostrMiddleware" })(ERROR, "nostr settings ignored since handler already exists")
return
}
subProcessHandler = new Handler(settings, event => {
@ -74,7 +74,7 @@ const initSubprocessHandler = (settings: NostrSettings) => {
}
const sendToNostr: NostrSend = (appId, data, relays) => {
if (!subProcessHandler) {
getLogger({ appName: "nostrMiddleware" })("ERROR", "nostr was not initialized")
getLogger({ component: "nostrMiddleware" })(ERROR, "nostr was not initialized")
return
}
subProcessHandler.Send(appId, data, relays)
@ -87,7 +87,7 @@ export default class Handler {
subs: Sub[] = []
apps: Record<string, AppInfo> = {}
eventCallback: (event: NostrEvent) => void
log = getLogger({ appName: "nostrMiddleware" })
log = getLogger({ component: "nostrMiddleware" })
constructor(settings: NostrSettings, eventCallback: (event: NostrEvent) => void) {
this.settings = settings
this.log(

View file

@ -23,7 +23,7 @@ const columns = ["timestampMs", "userId", "appUserId", "appId", "balance", "type
type StringerWrite = (chunk: any, cb: (error: Error | null | undefined) => void) => boolean
export default class EventsLogManager {
eventLogPath: string
log = getLogger({ appName: "EventsLogManager" })
log = getLogger({ component: "EventsLogManager" })
stringerWrite: StringerWrite
constructor(eventLogPath: string) {
this.eventLogPath = eventLogPath

View file

@ -15,7 +15,7 @@ export default class {
log: PubLogger
constructor(name: string, DB: DataSource | EntityManager) {
this.DB = DB
this.log = getLogger({ appName: name })
this.log = getLogger({ component: name })
}
PushToQueue<T>(op: TxOperation<T>) {

View file

@ -94,10 +94,10 @@ export default class {
user_id: userId,
}, "balance_sats", increment)
if (!res.affected) {
getLogger({ userId: userId, appName: "balanceUpdates" })("user unaffected by increment")
getLogger({ userId: userId, component: "balanceUpdates" })("user unaffected by increment")
throw new Error("unaffected balance increment for " + userId) // TODO: fix logs doxing
}
getLogger({ userId: userId, appName: "balanceUpdates" })("incremented balance from", user.balance_sats, "sats, by", increment, "sats")
getLogger({ userId: userId, component: "balanceUpdates" })("incremented balance from", user.balance_sats, "sats, by", increment, "sats")
this.eventsLog.LogEvent({ type: 'balance_increment', userId, appId: "", appUserId: "", balance: user.balance_sats, data: reason, amount: increment })
}
async DecrementUserBalance(userId: string, decrement: number, reason: string, entityManager?: DataSource | EntityManager) {
@ -116,17 +116,17 @@ export default class {
async DecrementUserBalanceInTx(userId: string, decrement: number, reason: string, dbTx: DataSource | EntityManager) {
const user = await this.GetUser(userId, dbTx)
if (!user || user.balance_sats < decrement) {
getLogger({ userId: userId, appName: "balanceUpdates" })("not enough balance to decrement")
getLogger({ userId: userId, component: "balanceUpdates" })("not enough balance to decrement")
throw new Error("not enough balance to decrement")
}
const res = await dbTx.getRepository(User).decrement({
user_id: userId,
}, "balance_sats", decrement)
if (!res.affected) {
getLogger({ userId: userId, appName: "balanceUpdates" })("user unaffected by decrement")
getLogger({ userId: userId, component: "balanceUpdates" })("user unaffected by decrement")
throw new Error("unaffected balance decrement for " + userId) // TODO: fix logs doxing
}
getLogger({ userId: userId, appName: "balanceUpdates" })("decremented balance from", user.balance_sats, "sats, by", decrement, "sats")
getLogger({ userId: userId, component: "balanceUpdates" })("decremented balance from", user.balance_sats, "sats, by", decrement, "sats")
this.eventsLog.LogEvent({ type: 'balance_decrement', userId, appId: "", appUserId: "", balance: user.balance_sats, data: reason, amount: decrement })
}