audit-bot-run.ts

/**
 * Deep audit of bot run - analyze why spam didn't trigger
 */

import 'dotenv/config'
import { readFileSync, readdirSync, statSync } from 'fs'
import { join } from 'path'

interface LogEntry {
  timestamp: string
  level: string
  category: string
  message: string
  data?: any
}

function parseLogLine(line: string): LogEntry | null {
  // Format: [2025-11-12T08:20:37.031Z] [INFO] [GAS] message | DATA: {...}
  const match = line.match(/\[([^\]]+)\]\s+\[([^\]]+)\]\s+\[([^\]]+)\]\s+(.+?)(?:\s+\|\s+DATA:\s+(.+))?$/)
  if (!match) return null
  
  const [, timestamp, level, category, message, dataStr] = match
  let data: any = undefined
  if (dataStr) {
    try {
      data = JSON.parse(dataStr)
    } catch (e) {
      // Ignore parse errors
    }
  }
  
  return { timestamp, level, category, message, data }
}

async function auditBotRun() {
  console.log('🔍 DEEP AUDIT OF BOT RUN\n')
  console.log('='.repeat(80))
  
  // Find latest log file
  const logsDir = join(process.cwd(), 'logs')
  const logFiles = readdirSync(logsDir)
    .filter(f => f.endsWith('.log'))
    .map(f => ({
      name: f,
      path: join(logsDir, f),
      mtime: statSync(join(logsDir, f)).mtime
    }))
    .sort((a, b) => b.mtime.getTime() - a.mtime.getTime())
  
  if (logFiles.length === 0) {
    console.log('❌ No log files found')
    return
  }
  
  const latestLog = logFiles[0]
  console.log(`📄 Analyzing: ${latestLog.name}\n`)
  
  const logContent = readFileSync(latestLog.path, 'utf8')
  const lines = logContent.split('\n').filter(l => l.trim())
  
  // Parse all log entries
  const entries: LogEntry[] = []
  for (const line of lines) {
    const entry = parseLogLine(line)
    if (entry) entries.push(entry)
  }
  
  console.log(`📊 Total log entries: ${entries.length}\n`)
  
  // Find initialization
  const initEntries = entries.filter(e => 
    e.message.includes('Time-based spam') || 
    e.message.includes('Expected unlock') ||
    e.message.includes('Spam starts') ||
    e.message.includes('Spam ends') ||
    e.message.includes('Adjusted unlock')
  )
  
  console.log('🔧 INITIALIZATION:\n')
  if (initEntries.length > 0) {
    initEntries.forEach(e => {
      console.log(`  [${e.timestamp}] ${e.message}`)
      if (e.data) console.log(`    Data: ${JSON.stringify(e.data, null, 2)}`)
    })
  } else {
    console.log('  ❌ No initialization entries found!')
  }
  
  // Find spam attempts
  const spamEntries = entries.filter(e => 
    e.category === 'SPAM' && 
    (e.message.includes('Spam sent') || 
     e.message.includes('Spam transaction') ||
     e.message.includes('Broadcast'))
  )
  
  console.log(`\n📤 SPAM TRANSACTIONS:\n`)
  console.log(`  Total spam entries: ${spamEntries.length}`)
  if (spamEntries.length > 0) {
    spamEntries.slice(0, 10).forEach(e => {
      console.log(`  [${e.timestamp}] ${e.message}`)
      if (e.data) {
        console.log(`    Successful RPCs: ${e.data.successfulRPCs || 'N/A'}`)
        console.log(`    Gas multiplier: ${e.data.gasMultiplier || 'N/A'}`)
      }
    })
    if (spamEntries.length > 10) {
      console.log(`  ... and ${spamEntries.length - 10} more`)
    }
  } else {
    console.log('  ❌ NO SPAM TRANSACTIONS FOUND!')
  }
  
  // Find window checks
  const windowChecks = entries.filter(e => 
    e.message.includes('Periodic window check') ||
    e.message.includes('unlockTime')
  )
  
  console.log(`\n⏰ WINDOW CHECKS:\n`)
  console.log(`  Total window checks: ${windowChecks.length}`)
  if (windowChecks.length > 0) {
    const recentChecks = windowChecks.slice(-10)
    recentChecks.forEach(e => {
      console.log(`  [${e.timestamp}] unlockTime: ${e.data?.unlockTime || 'N/A'}s, paused: ${e.data?.paused}, available: ${e.data?.available}`)
    })
  }
  
  // Find errors
  const errors = entries.filter(e => 
    e.level === 'ERROR' || 
    e.level === 'WARN' ||
    e.message.includes('failed') ||
    e.message.includes('error') ||
    e.message.includes('Error')
  )
  
  console.log(`\n⚠️ ERRORS/WARNINGS:\n`)
  console.log(`  Total: ${errors.length}`)
  if (errors.length > 0) {
    errors.slice(0, 10).forEach(e => {
      console.log(`  [${e.timestamp}] ${e.message}`)
      if (e.data?.error) console.log(`    Error: ${e.data.error}`)
    })
  }
  
  // Check for inSpamWindow logic
  const spamWindowEntries = entries.filter(e =>
    e.message.includes('inSpamWindow') ||
    e.message.includes('Time-based spam starts in') ||
    e.message.includes('Spam window ended')
  )
  
  console.log(`\n🪟 SPAM WINDOW STATUS:\n`)
  if (spamWindowEntries.length > 0) {
    spamWindowEntries.forEach(e => {
      console.log(`  [${e.timestamp}] ${e.message}`)
    })
  } else {
    console.log('  ❌ No spam window status entries found!')
  }
  
  // Check nonce initialization
  const nonceEntries = entries.filter(e =>
    e.message.includes('nonce') ||
    e.data?.nonce !== undefined
  )
  
  console.log(`\n🔢 NONCE STATUS:\n`)
  if (nonceEntries.length > 0) {
    const nonceInfo = nonceEntries
      .filter(e => e.data?.nonce !== undefined)
      .map(e => ({ time: e.timestamp, nonce: e.data.nonce }))
      .slice(-5)
    nonceInfo.forEach(n => {
      console.log(`  [${n.time}] nonce: ${n.nonce}`)
    })
  } else {
    console.log('  ⚠️ No nonce information found')
  }
  
  // Summary
  console.log(`\n${'='.repeat(80)}`)
  console.log('📋 SUMMARY:\n')
  console.log(`  Initialization entries: ${initEntries.length}`)
  console.log(`  Spam transaction attempts: ${spamEntries.length}`)
  console.log(`  Window checks: ${windowChecks.length}`)
  console.log(`  Errors/warnings: ${errors.length}`)
  console.log(`  Spam window status entries: ${spamWindowEntries.length}`)
  
  if (spamEntries.length === 0) {
    console.log(`\n❌ CRITICAL: No spam transactions were sent!`)
    console.log(`   Possible causes:`)
    console.log(`   1. spamStartTimestamp was never set or was null`)
    console.log(`   2. inSpamWindow was never true`)
    console.log(`   3. spamTransactionByTime() returned early`)
    console.log(`   4. currentNonce was null and couldn't be fetched`)
  }
}

auditBotRun().catch(console.error)