Compare commits

...
Author SHA1 Message Date
adminandClaude Opus 4.5 cbd0bd8e31 Add Console.WriteLine for timer callbacks and make Logger thread-safe
The timers stopped logging entirely during the 28-second gap. To determine
if the timers are firing but the Logger is blocked vs timers not firing:

1. Add Console.WriteLine in timer Elapsed handlers BEFORE the callback
   - These bypass our Logger and write directly to stdout
   - Will show if timers are firing even if Logger is blocked

2. Make Logger thread-safe with locks
   - LogLine now uses lock(_lock) to prevent concurrent access issues
   - GetLogger now uses lock(_loggersLock) for thread-safe singleton access

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
2025-12-26 21:04:39 -08:00
adminandClaude Opus 4.5 a884d373c7 Add diagnostic logging for heartbeat and idle timer issues
Add logging to diagnose why heartbeat/idle timers stop firing on Windows:
- Log when heartbeat timer fires (before any checks)
- Log when heartbeat is skipped and why (cancellation, not connected)
- Log when heartbeat send fails (stream unavailable)
- Log idle check when idle > 5s with cancellation status

This will help diagnose the 90-second gap where no heartbeat or idle
logs appear before PROTOCOL_ERROR on Windows client.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
2025-12-26 20:36:18 -08:00
2 changed files with 41 additions and 10 deletions
@@ -982,7 +982,11 @@ namespace eagle {
AutoReset = true,
Interval = 5000 // Check every 5 seconds
};
_idleCheckTimer.Elapsed += (sender, args) => CheckForIdleTimeout();
_idleCheckTimer.Elapsed += (sender, args) => {
// Log BEFORE callback to confirm timer is firing
Console.WriteLine($"[IDLE_TIMER] Elapsed at {DateTime.UtcNow:HH:mm:ss.fff}");
CheckForIdleTimeout();
};
_idleCheckTimer.Enabled = true;
}
@@ -995,10 +999,16 @@ namespace eagle {
}
private void CheckForIdleTimeout() {
if (_cancellationToken.IsCancellationRequested) { return; }
var idleTime = (DateTime.UtcNow - _lastResponseReceived).TotalSeconds;
// Log every check when idle > 5s to diagnose timer issues
if (idleTime > 5.0) {
_remoteEagleClientLogger.LogLine(
$"[IDLE_CHECK] idle_time={idleTime:F1}s, cancelled={_cancellationToken.IsCancellationRequested}");
}
if (_cancellationToken.IsCancellationRequested) { return; }
// Early warnings at 10s and 20s to help diagnose slow connections
if (idleTime > 20.0 && _lastIdleWarningLevel < 2) {
_lastIdleWarningLevel = 2;
@@ -1030,7 +1040,11 @@ namespace eagle {
StopHeartbeatTimer();
_heartbeatTimer =
new Timer { AutoReset = true, Interval = HeartbeatIntervalSeconds * 1000 };
_heartbeatTimer.Elapsed += (sender, args) => Task.Run(() => SendHeartbeat());
_heartbeatTimer.Elapsed += (sender, args) => {
// Log BEFORE Task.Run to confirm timer is firing
Console.WriteLine($"[HEARTBEAT_TIMER] Elapsed at {DateTime.UtcNow:HH:mm:ss.fff}");
Task.Run(() => SendHeartbeat());
};
_heartbeatTimer.Enabled = true;
}
@@ -1043,8 +1057,17 @@ namespace eagle {
}
private async Task SendHeartbeat() {
if (_cancellationToken.IsCancellationRequested) { return; }
if (_currentState != ConnectionState.Connected) { return; }
_remoteEagleClientLogger.LogLine($"[HEARTBEAT] Timer fired, state={_currentState}");
if (_cancellationToken.IsCancellationRequested) {
_remoteEagleClientLogger.LogLine("[HEARTBEAT] Skipped - cancellation requested");
return;
}
if (_currentState != ConnectionState.Connected) {
_remoteEagleClientLogger.LogLine(
$"[HEARTBEAT] Skipped - not connected (state={_currentState})");
return;
}
// Build sync status for all subscribed games
var heartbeatRequest = new HeartbeatRequest {
@@ -1080,6 +1103,8 @@ namespace eagle {
g => $"{g.GameId}:{g.UnfilteredResultCount}"));
_remoteEagleClientLogger.LogLine(
$"[HEARTBEAT] Sent heartbeat with {heartbeatRequest.GameSyncStatuses.Count} games ({gameInfo})");
} else {
_remoteEagleClientLogger.LogLine("[HEARTBEAT] Failed to send - stream unavailable");
}
}
@@ -6,12 +6,16 @@ using UnityEngine;
namespace common {
public sealed class Logger : IDisposable {
private readonly StreamWriter _sw;
private readonly object _lock = new object();
private static Dictionary<String, Logger> _loggers = new Dictionary<String, Logger>();
private static readonly object _loggersLock = new object();
public static Logger GetLogger(string name) {
if (!_loggers.ContainsKey(name)) { _loggers[name] = new Logger(name); }
return _loggers[name];
lock (_loggersLock) {
if (!_loggers.ContainsKey(name)) { _loggers[name] = new Logger(name); }
return _loggers[name];
}
}
private string CurrentTimeString() {
@@ -29,8 +33,10 @@ namespace common {
}
public void LogLine(string line) {
_sw.WriteLine(CurrentTimeString() + " " + line);
_sw.Flush();
lock (_lock) {
_sw.WriteLine(CurrentTimeString() + " " + line);
_sw.Flush();
}
}
public void Close() { _sw.Close(); }