feat(minecraft): logging for perception pipeline

Author: shinohara-rin

services/minecraft/src/cognitive/perception/attention-detector.ts

@@ -26,6 +26,9 @@ export type AttentionEventPayload = PlayerAttentionEventPayload | MobAttentionEv
 export class AttentionDetector {
   private readonly buckets = new Map<string, LeakyBucket>()
 
+  private lastStatsAt = 0
+  private emittedSinceStats: Record<string, number> = {}
+
   private readonly movementState = new Map<
     string,
     {
@@ -68,6 +71,16 @@ export class AttentionDetector {
         this.movementState.delete(id)
       }
     }
+
+    if (now - this.lastStatsAt >= 2000) {
+      this.deps.logger.withFields({
+        deltaMs,
+        ...this.emittedSinceStats,
+      }).log('AttentionDetector: stats')
+
+      this.lastStatsAt = now
+      this.emittedSinceStats = {}
+    }
   }
 
   public ingest(event: RawPerceptionEvent): void {
@@ -216,6 +229,30 @@ export class AttentionDetector {
   }
 
   private emitAttention(payload: AttentionEventPayload): void {
+    const key = payload.kind === 'player'
+      ? `emit.player.${payload.playerAction}`
+      : 'emit.mob'
+    this.emittedSinceStats[key] = (this.emittedSinceStats[key] ?? 0) + 1
+
+    if (payload.kind === 'player') {
+      this.deps.logger.withFields({
+        kind: payload.kind,
+        action: payload.playerAction,
+        playerName: payload.playerName,
+        distance: payload.distance,
+        hasLineOfSight: payload.hasLineOfSight,
+      }).log('AttentionDetector: emit')
+    }
+    else {
+      this.deps.logger.withFields({
+        kind: payload.kind,
+        mobName: payload.mobName,
+        action: payload.mobAction,
+        distance: payload.distance,
+        hasLineOfSight: payload.hasLineOfSight,
+      }).log('AttentionDetector: emit')
+    }
+
     this.deps.eventManager.emit<AttentionEventPayload>({
       type: 'perception',
       payload,

services/minecraft/src/cognitive/perception/mineflayer-perception-collector.ts

@@ -23,6 +23,11 @@ export class MineflayerPerceptionCollector {
   private readonly lastSneak = new Map<string, boolean>()
   private lastSelfHealth: number | null = null
 
+  private lastStatsAt = 0
+  private stats: Record<string, number> = {}
+  private losSamples = 0
+  private losTotalMs = 0
+
   constructor(
     private readonly deps: {
       logger: Logg
@@ -35,6 +40,13 @@ export class MineflayerPerceptionCollector {
     this.bot = bot
     this.lastSelfHealth = bot.bot.health
 
+    this.lastStatsAt = Date.now()
+    this.stats = {}
+    this.losSamples = 0
+    this.losTotalMs = 0
+
+    this.deps.logger.withFields({ maxDistance: this.deps.maxDistance }).log('MineflayerPerceptionCollector: init')
+
     this.onBot('entityMoved', (entity: any) => {
       const now = Date.now()
       const dist = this.distanceTo(entity)
@@ -61,6 +73,8 @@ export class MineflayerPerceptionCollector {
       }
 
       this.deps.emitRaw(event)
+      this.bumpStat('sighted.entity_moved')
+      this.maybeLogStats()
     })
 
     this.onBot('entitySwingArm', (entity: any) => {
@@ -83,6 +97,8 @@ export class MineflayerPerceptionCollector {
       }
 
       this.deps.emitRaw(event)
+      this.bumpStat('sighted.arm_swing')
+      this.maybeLogStats()
     })
 
     this.onBot('entityUpdate', (entity: any) => {
@@ -119,6 +135,8 @@ export class MineflayerPerceptionCollector {
       }
 
       this.deps.emitRaw(event)
+      this.bumpStat('sighted.sneak_toggle')
+      this.maybeLogStats()
     })
 
     this.onBot('soundEffectHeard', (soundId: string, pos: Vec3) => {
@@ -167,6 +185,8 @@ export class MineflayerPerceptionCollector {
       }
 
       this.deps.emitRaw(event)
+      this.bumpStat('felt.damage_taken')
+      this.maybeLogStats()
     })
 
     // Felt: item collected (best-effort; depends on mineflayer version/events)
@@ -190,6 +210,8 @@ export class MineflayerPerceptionCollector {
       }
 
       this.deps.emitRaw(event)
+      this.bumpStat('felt.item_collected')
+      this.maybeLogStats()
     })
 
     this.onBot('entityCollect', (collector: any, collected: any) => {
@@ -212,17 +234,21 @@ export class MineflayerPerceptionCollector {
       }
 
       this.deps.emitRaw(event)
+      this.bumpStat('felt.item_collected')
+      this.maybeLogStats()
     })
   }
 
   public destroy(): void {
     if (!this.bot)
       return
 
+    this.deps.logger.withFields({ listeners: this.listeners.length }).log('MineflayerPerceptionCollector: destroy')
+
     for (const { event, handler } of this.listeners) {
       try {
-        (this.bot.bot as any).off?.(event, handler);
-        (this.bot.bot as any).removeListener?.(event, handler)
+        (this.bot.bot as any).off?.(event, handler)
+          (this.bot.bot as any).removeListener?.(event, handler)
       }
       catch (err) {
         this.deps.logger.withError(err as Error).error('MineflayerPerceptionCollector: failed to remove listener')
@@ -236,6 +262,29 @@ export class MineflayerPerceptionCollector {
     this.bot = null
   }
 
+  private bumpStat(key: string): void {
+    this.stats[key] = (this.stats[key] ?? 0) + 1
+  }
+
+  private maybeLogStats(): void {
+    const now = Date.now()
+    if (now - this.lastStatsAt < 2000)
+      return
+
+    const losAvgMs = this.losSamples > 0 ? this.losTotalMs / this.losSamples : 0
+
+    this.deps.logger.withFields({
+      ...this.stats,
+      losSamples: this.losSamples,
+      losAvgMs,
+    }).log('MineflayerPerceptionCollector: stats')
+
+    this.lastStatsAt = now
+    this.stats = {}
+    this.losSamples = 0
+    this.losTotalMs = 0
+  }
+
   private onBot(event: string, handler: (...args: any[]) => void): void {
     if (!this.bot)
       return
@@ -273,41 +322,52 @@ export class MineflayerPerceptionCollector {
     if (!this.bot)
       return false
 
-    try {
-      const canSee = (this.bot.bot as any).canSeeEntity
-      if (typeof canSee === 'function')
-        return !!canSee.call(this.bot.bot, entity)
-    }
-    catch { }
+    const startedAt = Date.now()
 
-    // Fallback ray-march; intentionally simple (we'll optimize later)
     try {
-      const from = this.bot.bot.entity.position.offset(0, this.bot.bot.entity.height * 0.9, 0)
-      const to = entity.position.offset(0, entity.height * 0.9, 0)
-      const dir = to.minus(from)
-      const total = dir.norm()
-      if (total <= 0)
-        return true
-
-      const stepSize = 0.25
-      const steps = Math.ceil(total / stepSize)
-      const step = dir.normalize().scaled(stepSize)
+      try {
+        const canSee = (this.bot.bot as any).canSeeEntity
+        if (typeof canSee === 'function')
+          return !!canSee.call(this.bot.bot, entity)
+      }
+      catch { }
 
-      let cur = from.clone()
-      for (let i = 0; i < steps; i++) {
-        cur = cur.plus(step)
-        const block = this.bot.bot.blockAt(cur)
-        if (!block)
-          continue
+      // Fallback ray-march; intentionally simple (we'll optimize later)
+      try {
+        const from = this.bot.bot.entity.position.offset(0, this.bot.bot.entity.height * 0.9, 0)
+        const to = entity.position.offset(0, entity.height * 0.9, 0)
+        const dir = to.minus(from)
+        const total = dir.norm()
+        if (total <= 0)
+          return true
+
+        const stepSize = 0.25
+        const steps = Math.ceil(total / stepSize)
+        const step = dir.normalize().scaled(stepSize)
+
+        let cur = from.clone()
+        for (let i = 0; i < steps; i++) {
+          cur = cur.plus(step)
+          const block = this.bot.bot.blockAt(cur)
+          if (!block)
+            continue
+
+          if (block.boundingBox === 'block' && !block.transparent)
+            return false
+        }
 
-        if (block.boundingBox === 'block' && !block.transparent)
-          return false
+        return true
+      }
+      catch {
+        return false
       }
-
-      return true
     }
-    catch {
-      return false
+    finally {
+      const costMs = Date.now() - startedAt
+      if (costMs > 0) {
+        this.losSamples++
+        this.losTotalMs += costMs
+      }
     }
   }
 }

services/minecraft/src/cognitive/perception/pipeline.ts

@@ -14,6 +14,10 @@ export class PerceptionPipeline {
   private collector: MineflayerPerceptionCollector | null = null
   private initialized = false
 
+  private lastStatsAt = 0
+  private collectedSinceStats = 0
+  private processedSinceStats = 0
+
   constructor(
     private readonly deps: {
       eventManager: EventManager
@@ -29,6 +33,12 @@ export class PerceptionPipeline {
   public init(bot: MineflayerWithAgents): void {
     this.initialized = true
 
+    this.lastStatsAt = Date.now()
+    this.collectedSinceStats = 0
+    this.processedSinceStats = 0
+
+    this.deps.logger.withFields({ maxDistance: 32 }).log('PerceptionPipeline: init')
+
     this.collector = new MineflayerPerceptionCollector({
       logger: this.deps.logger,
       emitRaw: (event) => {
@@ -40,6 +50,7 @@ export class PerceptionPipeline {
   }
 
   public destroy(): void {
+    this.deps.logger.log('PerceptionPipeline: destroy')
     this.collector?.destroy()
     this.collector = null
     this.buffer.clear()
@@ -50,15 +61,19 @@ export class PerceptionPipeline {
     if (!this.initialized)
       return
     this.buffer.push(event)
+    this.collectedSinceStats++
   }
 
   public tick(deltaMs: number): void {
     if (!this.initialized)
       return
 
+    const startedAt = Date.now()
+
     this.detector.tick(deltaMs)
 
     const events = this.buffer.drain()
+    this.processedSinceStats += events.length
     for (const event of events) {
       try {
         this.detector.ingest(event)
@@ -67,5 +82,21 @@ export class PerceptionPipeline {
         this.deps.logger.withError(err as Error).error('PerceptionPipeline: detector error')
       }
     }
+
+    const now = Date.now()
+    if (now - this.lastStatsAt >= 2000) {
+      this.deps.logger.withFields({
+        deltaMs,
+        tickCostMs: now - startedAt,
+        queueDepth: this.buffer.size(),
+        drained: events.length,
+        collected: this.collectedSinceStats,
+        processed: this.processedSinceStats,
+      }).log('PerceptionPipeline: stats')
+
+      this.lastStatsAt = now
+      this.collectedSinceStats = 0
+      this.processedSinceStats = 0
+    }
   }
 }

services/minecraft/src/cognitive/perception/raw-event-buffer.ts

@@ -7,6 +7,10 @@ export class RawEventBuffer {
     this.queue.push(event)
   }
 
+  public size(): number {
+    return this.queue.length
+  }
+
   public drain(): RawPerceptionEvent[] {
     if (this.queue.length === 0)
       return []