refactor: structured logging across server

Create server/src/lib/logger.ts with info/warn/error methods that add
[botfights:tag] timestamps. Replace bare console.log/warn/error calls
in index.ts, seed.ts, routes/fights.ts, engine/queue.ts, engine/mock.ts.

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
This commit is contained in:
Dorian
2026-03-08 20:41:23 +00:00
co-authored by Claude Opus 4.6
parent 7bd110684d
commit f62323c59f
6 changed files with 42 additions and 18 deletions
+5 -4
View File
@@ -1,4 +1,5 @@
import { nanoid } from 'nanoid' import { nanoid } from 'nanoid'
import { logger } from '../lib/logger.js'
import { createHash, randomBytes } from 'crypto' import { createHash, randomBytes } from 'crypto'
import { db, schema, sqlite } from '../db/index.js' import { db, schema, sqlite } from '../db/index.js'
import { randomArena } from './arenas.js' import { randomArena } from './arenas.js'
@@ -335,7 +336,7 @@ export async function seedClassicBots(): Promise<void> {
}) })
} }
console.log(`[botfights] seeded ${CLASSIC_BOTS.length} classic bots`) logger.info('mock', `seeded ${CLASSIC_BOTS.length} classic bots`)
} }
export function isClassicBot(webhookUrl: string): boolean { export function isClassicBot(webhookUrl: string): boolean {
@@ -400,7 +401,7 @@ export async function seedMockBots(): Promise<void> {
inserted++ inserted++
} }
console.log(`[botfights] mock bots: ${inserted} inserted, ${updated} updated`) logger.info('mock', `mock bots: ${inserted} inserted, ${updated} updated`)
} }
export async function runMockFight(botAId: string, botBId: string): Promise<string> { export async function runMockFight(botAId: string, botBId: string): Promise<string> {
@@ -558,7 +559,7 @@ export function generateMockBotResponse(
export async function seedMockFights(count: number = 12): Promise<void> { export async function seedMockFights(count: number = 12): Promise<void> {
const allBots = await db.select({ id: schema.bots.id, eloRating: schema.bots.eloRating }).from(schema.bots) const allBots = await db.select({ id: schema.bots.id, eloRating: schema.bots.eloRating }).from(schema.bots)
if (allBots.length < 2) { if (allBots.length < 2) {
console.log('[botfights] need at least 2 bots to seed fights') logger.info('mock', 'need at least 2 bots to seed fights')
return return
} }
@@ -584,5 +585,5 @@ export async function seedMockFights(count: number = 12): Promise<void> {
} }
} }
console.log(`[botfights] seeded ${count} mock fights`) logger.info('mock', `seeded ${count} mock fights`)
} }
+5 -4
View File
@@ -1,4 +1,5 @@
import { db, schema } from '../db/index.js' import { db, schema } from '../db/index.js'
import { logger } from '../lib/logger.js'
import { eq } from 'drizzle-orm' import { eq } from 'drizzle-orm'
import { runFightAsync, isInFight } from './orchestrator.js' import { runFightAsync, isInFight } from './orchestrator.js'
import { seedMockBots } from './mock.js' import { seedMockBots } from './mock.js'
@@ -69,7 +70,7 @@ export async function joinQueue(botId: string): Promise<string> {
throw new Error('Bot is deactivated due to webhook errors. Re-test your webhook to reactivate.') throw new Error('Bot is deactivated due to webhook errors. Re-test your webhook to reactivate.')
} }
console.log(`[queue] joinQueue botId=${botId} name=${bot.name} webhook=${bot.webhookUrl}`) logger.info('queue', `joinQueue botId=${botId} name=${bot.name} webhook=${bot.webhookUrl}`)
// Don't allow same bot twice in queue // Don't allow same bot twice in queue
const existing = waitingQueue.findIndex(e => e.botId === botId) const existing = waitingQueue.findIndex(e => e.botId === botId)
@@ -145,7 +146,7 @@ async function startFight(botAId: string, botBId: string): Promise<string> {
} }
async function matchAgainstMock(botId: string, webhookUrl: string): Promise<string> { async function matchAgainstMock(botId: string, webhookUrl: string): Promise<string> {
console.log(`[queue] matchAgainstMock botId=${botId} webhook=${webhookUrl}`) logger.info('queue', `matchAgainstMock botId=${botId} webhook=${webhookUrl}`)
const allBots = await db.select({ const allBots = await db.select({
id: schema.bots.id, id: schema.bots.id,
webhookUrl: schema.bots.webhookUrl, webhookUrl: schema.bots.webhookUrl,
@@ -155,7 +156,7 @@ async function matchAgainstMock(botId: string, webhookUrl: string): Promise<stri
const mockBots = allBots.filter(b => b.id !== botId && b.webhookUrl.startsWith('http://mock.local')) const mockBots = allBots.filter(b => b.id !== botId && b.webhookUrl.startsWith('http://mock.local'))
if (mockBots.length === 0) { if (mockBots.length === 0) {
console.log('[queue] No mock bots found, seeding...') logger.info('queue', 'No mock bots found, seeding...')
await seedMockBots() await seedMockBots()
return matchAgainstMock(botId, webhookUrl) return matchAgainstMock(botId, webhookUrl)
} }
@@ -166,6 +167,6 @@ async function matchAgainstMock(botId: string, webhookUrl: string): Promise<stri
mockBots.sort((a, b) => Math.abs(a.eloRating - botElo) - Math.abs(b.eloRating - botElo)) mockBots.sort((a, b) => Math.abs(a.eloRating - botElo) - Math.abs(b.eloRating - botElo))
const opponent = mockBots[0] const opponent = mockBots[0]
console.log(`[queue] starting fight: ${botId} vs mock ${opponent.id}`) logger.info('queue', `starting fight: ${botId} vs mock ${opponent.id}`)
return runFightAsync(botId, opponent.id) return runFightAsync(botId, opponent.id)
} }
+7 -6
View File
@@ -1,4 +1,5 @@
import { serve } from '@hono/node-server' import { serve } from '@hono/node-server'
import { logger } from './lib/logger.js'
import { app } from './app.js' import { app } from './app.js'
import { runMigrations } from './db/startup.js' import { runMigrations } from './db/startup.js'
import { seedMockBots, seedClassicBots } from './engine/mock.js' import { seedMockBots, seedClassicBots } from './engine/mock.js'
@@ -11,10 +12,10 @@ if (process.env.NODE_ENV === 'production') {
const walletVars = ['BOTFIGHTS_NWC_URL', 'BOTFIGHTS_WALLET_ENCRYPTION_KEY'] const walletVars = ['BOTFIGHTS_NWC_URL', 'BOTFIGHTS_WALLET_ENCRYPTION_KEY']
const missing = walletVars.filter(k => !process.env[k]) const missing = walletVars.filter(k => !process.env[k])
if (missing.length > 0) { if (missing.length > 0) {
console.warn(`[botfights] WARNING: Missing env vars: ${missing.join(', ')} — wallet/payment features disabled`) logger.warn('env', `Missing env vars: ${missing.join(', ')} — wallet/payment features disabled`)
} }
if (!process.env.CORS_ORIGIN || process.env.CORS_ORIGIN === '*') { if (!process.env.CORS_ORIGIN || process.env.CORS_ORIGIN === '*') {
console.warn('[botfights] WARNING: CORS_ORIGIN not set — allowing all origins') logger.warn('env', 'CORS_ORIGIN not set — allowing all origins')
} }
} }
@@ -26,7 +27,7 @@ await seedClassicBots()
const port = Number(process.env.PORT) || 9100 const port = Number(process.env.PORT) || 9100
serve({ fetch: app.fetch, port }, () => { serve({ fetch: app.fetch, port }, () => {
console.log(`[botfights] server listening on http://localhost:${port}`) logger.info('server', `listening on http://localhost:${port}`)
// Start background fight loop so the site always has fresh activity // Start background fight loop so the site always has fresh activity
startBackgroundFights() startBackgroundFights()
@@ -34,14 +35,14 @@ serve({ fetch: app.fetch, port }, () => {
// Graceful shutdown — drain in-flight fights before exiting // Graceful shutdown — drain in-flight fights before exiting
const shutdown = async (signal: string) => { const shutdown = async (signal: string) => {
console.log(`[botfights] ${signal} received, shutting down...`) logger.info('server', `${signal} received, shutting down...`)
const active = getActiveFighterCount() const active = getActiveFighterCount()
if (active > 0) { if (active > 0) {
console.log(`[botfights] ${active} fighters still active, waiting 10s...`) logger.info('server', `${active} fighters still active, waiting 10s...`)
} }
await new Promise(r => setTimeout(r, active > 0 ? 10_000 : 500)) await new Promise(r => setTimeout(r, active > 0 ? 10_000 : 500))
clearAllPending() clearAllPending()
console.log('[botfights] shutdown complete') logger.info('server', 'shutdown complete')
process.exit(0) process.exit(0)
} }
process.on('SIGTERM', () => shutdown('SIGTERM')) process.on('SIGTERM', () => shutdown('SIGTERM'))
+19
View File
@@ -0,0 +1,19 @@
function ts(): string {
return new Date().toISOString()
}
export const logger = {
info(tag: string, message: string) {
console.log(`[botfights:${tag}] ${ts()} ${message}`)
},
warn(tag: string, message: string) {
console.warn(`[botfights:${tag}] ${ts()} ${message}`)
},
error(tag: string, message: string, err?: unknown) {
if (err) {
console.error(`[botfights:${tag}] ${ts()} ${message}`, err)
} else {
console.error(`[botfights:${tag}] ${ts()} ${message}`)
}
},
}
+3 -2
View File
@@ -1,4 +1,5 @@
import { Hono } from 'hono' import { Hono } from 'hono'
import { logger } from '../lib/logger.js'
import { streamSSE } from 'hono/streaming' import { streamSSE } from 'hono/streaming'
import { db, schema } from '../db/index.js' import { db, schema } from '../db/index.js'
import { eq, desc } from 'drizzle-orm' import { eq, desc } from 'drizzle-orm'
@@ -175,8 +176,8 @@ fightsRouter.post('/mock/batch/:count', async (c) => {
const capped = Math.min(count, 500) const capped = Math.min(count, 500)
startFightLoop({ maxFights: capped, intervalMs: 500, matchmakingStyle: 'mixed' }) startFightLoop({ maxFights: capped, intervalMs: 500, matchmakingStyle: 'mixed' })
.then(() => console.log(`[botfights] batch of ${capped} fights completed`)) .then(() => logger.info('fights', `batch of ${capped} fights completed`))
.catch(err => console.error('[botfights] batch error:', err)) .catch(err => logger.error('fights', 'batch error', err))
return c.json({ message: `Started batch of ${capped} fights in background.` }) return c.json({ message: `Started batch of ${capped} fights in background.` })
}) })
+3 -2
View File
@@ -1,4 +1,5 @@
import '../src/db/index.js' import '../src/db/index.js'
import { logger } from './lib/logger.js'
import { seedMockBots, seedMockFights } from './engine/mock.js' import { seedMockBots, seedMockFights } from './engine/mock.js'
async function main() { async function main() {
@@ -8,8 +9,8 @@ async function main() {
await seedMockBots() await seedMockBots()
await seedMockFights(15) await seedMockFights(15)
console.log('[botfights] seed complete!') logger.info('seed', 'seed complete!')
process.exit(0) process.exit(0)
} }
main().catch(console.error) main().catch((err) => logger.error('seed', 'seed failed', err))