mirror of
https://github.com/okieselbach/AutopilotMonitor.git
synced 2026-10-24 12:42:38 +00:00
fix(v2): 882fef64 PR2 — AgentLogger size-cap rotation
Daily log file used to grow without bound under verbose mode. AgentLogger now caps each segment at 50 MB (configurable per-instance) and rolls forward to agent_YYYYMMDD_002.log, _003.log, ... when the cap is reached. Existing rotation suffixes are probed on construction so process restarts mid-day continue at the highest existing segment instead of overwriting older ones. The first line of every rotated segment is an `AgentLogger: rotated` marker for forensic readability. Size check + rotation are best-effort: exceptions are swallowed so the logger never breaks the agent. Tests: V2.Core 716 (+5 new in Logging/AgentLoggerTests.cs), solution build 0/0. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
@@ -0,0 +1,114 @@
|
||||
#nullable enable
|
||||
using System;
|
||||
using System.IO;
|
||||
using System.Linq;
|
||||
using AutopilotMonitor.Agent.V2.Core.Logging;
|
||||
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
|
||||
using Xunit;
|
||||
|
||||
namespace AutopilotMonitor.Agent.V2.Core.Tests.Logging
|
||||
{
|
||||
/// <summary>
|
||||
/// PR2: file-size cap rotation. Long-running verbose sessions used to grow the daily log
|
||||
/// into hundreds of MB; the logger now rolls over to a numeric suffix once a segment
|
||||
/// reaches the cap, keeping every byte but in manageable files.
|
||||
/// </summary>
|
||||
public sealed class AgentLoggerTests
|
||||
{
|
||||
private static string TodayBaseName => $"agent_{DateTime.Now:yyyyMMdd}";
|
||||
|
||||
[Fact]
|
||||
public void Log_writes_to_unsuffixed_base_file_when_dir_is_empty()
|
||||
{
|
||||
using var tmp = new TempDirectory();
|
||||
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info, maxFileSizeBytes: 1024L * 1024);
|
||||
|
||||
logger.Info("hello");
|
||||
|
||||
var basePath = Path.Combine(tmp.Path, TodayBaseName + ".log");
|
||||
Assert.True(File.Exists(basePath), $"expected base file at {basePath}");
|
||||
Assert.Contains("hello", File.ReadAllText(basePath));
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void Log_rotates_when_active_segment_crosses_cap()
|
||||
{
|
||||
using var tmp = new TempDirectory();
|
||||
// 1 KB cap so rotation triggers after a few writes.
|
||||
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info, maxFileSizeBytes: 1024);
|
||||
|
||||
// Each line ~80 bytes after timestamp/severity envelope; 30 lines clears 1 KB
|
||||
// even at the smallest payload. The first lines fill the base file; once the
|
||||
// FileInfo.Length read sees >= 1024 the next call rotates to _002.
|
||||
for (int i = 0; i < 60; i++)
|
||||
{
|
||||
logger.Info($"line-{i:D4}-padded-with-some-extra-context-to-cross-1KB-quickly");
|
||||
}
|
||||
|
||||
var files = Directory.GetFiles(tmp.Path, TodayBaseName + "*.log").OrderBy(s => s).ToArray();
|
||||
Assert.True(files.Length >= 2, $"expected at least 2 segments, got: {string.Join(",", files.Select(Path.GetFileName))}");
|
||||
|
||||
// The unsuffixed file is the first segment; rotated segments use _002 onward.
|
||||
var rotated = files.FirstOrDefault(p => Path.GetFileNameWithoutExtension(p).EndsWith("_002"));
|
||||
Assert.NotNull(rotated);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void Log_writes_rotation_marker_as_first_line_of_new_segment()
|
||||
{
|
||||
using var tmp = new TempDirectory();
|
||||
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info, maxFileSizeBytes: 1024);
|
||||
|
||||
for (int i = 0; i < 60; i++)
|
||||
{
|
||||
logger.Info($"pad-{i:D4}-content-content-content-content-content-content");
|
||||
}
|
||||
|
||||
var rotatedPath = Path.Combine(tmp.Path, TodayBaseName + "_002.log");
|
||||
Assert.True(File.Exists(rotatedPath), "expected agent_YYYYMMDD_002.log to exist");
|
||||
var first = File.ReadAllLines(rotatedPath).FirstOrDefault();
|
||||
Assert.NotNull(first);
|
||||
Assert.Contains("AgentLogger: rotated", first);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void Log_continues_existing_rotation_on_restart_without_overwriting()
|
||||
{
|
||||
using var tmp = new TempDirectory();
|
||||
// Pre-seed: looks like an earlier process already rotated up to _003.
|
||||
File.WriteAllText(Path.Combine(tmp.Path, TodayBaseName + ".log"), "older-base\n");
|
||||
File.WriteAllText(Path.Combine(tmp.Path, TodayBaseName + "_002.log"), "older-002\n");
|
||||
File.WriteAllText(Path.Combine(tmp.Path, TodayBaseName + "_003.log"), "older-003\n");
|
||||
|
||||
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info, maxFileSizeBytes: 1024L * 1024);
|
||||
logger.Info("after-restart");
|
||||
|
||||
// New entries must land in the highest existing segment (_003), not in a fresh
|
||||
// base file. Older content in _003 must be preserved.
|
||||
var resumed = File.ReadAllText(Path.Combine(tmp.Path, TodayBaseName + "_003.log"));
|
||||
Assert.Contains("older-003", resumed);
|
||||
Assert.Contains("after-restart", resumed);
|
||||
|
||||
// Older segments are left alone.
|
||||
Assert.Equal("older-base\n", File.ReadAllText(Path.Combine(tmp.Path, TodayBaseName + ".log")));
|
||||
Assert.Equal("older-002\n", File.ReadAllText(Path.Combine(tmp.Path, TodayBaseName + "_002.log")));
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void Log_swallows_io_errors_silently()
|
||||
{
|
||||
using var tmp = new TempDirectory();
|
||||
var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info, maxFileSizeBytes: 1024L * 1024);
|
||||
|
||||
// Hold an exclusive lock on today's file to force AppendAllText to throw.
|
||||
var lockedPath = Path.Combine(tmp.Path, TodayBaseName + ".log");
|
||||
File.WriteAllText(lockedPath, ""); // ensure exists
|
||||
using var holder = new FileStream(lockedPath, FileMode.Open, FileAccess.ReadWrite, FileShare.None);
|
||||
|
||||
// Must NOT throw — logger swallows IO errors to keep the agent running.
|
||||
logger.Info("dropped");
|
||||
// No assertion needed beyond "did not throw"; the regression we guard against is
|
||||
// the original swallow-all behaviour, which the rotation refactor must preserve.
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -23,27 +23,82 @@ namespace AutopilotMonitor.Agent.V2.Core.Logging
|
||||
/// </summary>
|
||||
public class AgentLogger
|
||||
{
|
||||
private readonly string _logFilePath;
|
||||
// Rotation cap. With per-enrollment lifecycle (30 min – 4 h) and verbose mode the
|
||||
// active log can grow into the hundreds of MB territory; 50 MB keeps individual
|
||||
// files manageable for forensics tooling without hiding any data — rotated files
|
||||
// are kept alongside the active one with a numeric suffix.
|
||||
private const long DefaultMaxFileSizeBytes = 50L * 1024 * 1024;
|
||||
|
||||
private AgentLogLevel _logLevel;
|
||||
private readonly object _lockObject = new object();
|
||||
|
||||
private readonly long _maxFileSizeBytes;
|
||||
private readonly string _logDirectory;
|
||||
private readonly string _logFileBaseName; // "agent_20260425"
|
||||
private string _logFilePath; // mutable — rotates to "_002", "_003" ...
|
||||
private int _rotationSuffix; // 0 = base file, 2+ = "_002" etc.
|
||||
|
||||
/// <summary>
|
||||
/// When true, log entries are also written to Console.Out (same format as the log file).
|
||||
/// Set via --console flag or programmatically.
|
||||
/// </summary>
|
||||
public bool EnableConsoleOutput { get; set; }
|
||||
|
||||
public AgentLogger(string logDirectory, AgentLogLevel logLevel = AgentLogLevel.Info)
|
||||
public AgentLogger(string logDirectory, AgentLogLevel logLevel = AgentLogLevel.Info, long maxFileSizeBytes = DefaultMaxFileSizeBytes)
|
||||
{
|
||||
_logLevel = logLevel;
|
||||
_maxFileSizeBytes = maxFileSizeBytes > 0 ? maxFileSizeBytes : DefaultMaxFileSizeBytes;
|
||||
_logDirectory = logDirectory;
|
||||
|
||||
if (!Directory.Exists(logDirectory))
|
||||
{
|
||||
Directory.CreateDirectory(logDirectory);
|
||||
}
|
||||
|
||||
var logFileName = $"agent_{DateTime.Now:yyyyMMdd}.log";
|
||||
_logFilePath = Path.Combine(logDirectory, logFileName);
|
||||
_logFileBaseName = $"agent_{DateTime.Now:yyyyMMdd}";
|
||||
_rotationSuffix = ProbeNextRotationSuffix(logDirectory, _logFileBaseName);
|
||||
_logFilePath = BuildLogFilePath();
|
||||
}
|
||||
|
||||
// Picks up the highest existing rotation suffix on the same day so a process restart
|
||||
// doesn't overwrite previous segments. Returns 0 when no log file exists yet — the
|
||||
// first segment uses the unsuffixed name `agent_YYYYMMDD.log`.
|
||||
private static int ProbeNextRotationSuffix(string dir, string baseName)
|
||||
{
|
||||
if (!Directory.Exists(dir)) return 0;
|
||||
string[] existing;
|
||||
try { existing = Directory.GetFiles(dir, baseName + "*.log"); }
|
||||
catch { return 0; }
|
||||
|
||||
int max = 0;
|
||||
foreach (var path in existing)
|
||||
{
|
||||
var name = Path.GetFileNameWithoutExtension(path);
|
||||
if (string.Equals(name, baseName, StringComparison.OrdinalIgnoreCase))
|
||||
{
|
||||
if (max < 1) max = 1;
|
||||
continue;
|
||||
}
|
||||
if (name.Length > baseName.Length + 1 &&
|
||||
name.StartsWith(baseName + "_", StringComparison.OrdinalIgnoreCase) &&
|
||||
int.TryParse(name.Substring(baseName.Length + 1), out var suffix) &&
|
||||
suffix > max)
|
||||
{
|
||||
max = suffix;
|
||||
}
|
||||
}
|
||||
// 0 means "no file yet" → use the unsuffixed base; otherwise continue at the
|
||||
// highest existing suffix so the active writer appends to the most recent file
|
||||
// (rotation kicks in once it crosses the cap).
|
||||
return max;
|
||||
}
|
||||
|
||||
private string BuildLogFilePath()
|
||||
{
|
||||
var name = _rotationSuffix < 2
|
||||
? $"{_logFileBaseName}.log"
|
||||
: $"{_logFileBaseName}_{_rotationSuffix:D3}.log";
|
||||
return Path.Combine(_logDirectory, name);
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
@@ -99,6 +154,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Logging
|
||||
var timestamp = DateTime.UtcNow.ToString("yyyy-MM-dd HH:mm:ss.fff");
|
||||
var logEntry = $"[{timestamp}] [{level}] {SanitizeLogMessage(message)}";
|
||||
|
||||
RotateIfOverCap(timestamp);
|
||||
|
||||
File.AppendAllText(_logFilePath, logEntry + Environment.NewLine);
|
||||
|
||||
if (EnableConsoleOutput)
|
||||
@@ -113,6 +170,30 @@ namespace AutopilotMonitor.Agent.V2.Core.Logging
|
||||
}
|
||||
}
|
||||
|
||||
// Best-effort size check. FileInfo.Length is briefly cached, so under bursty writes
|
||||
// the active file can drift slightly past the cap before rotation kicks in — that's
|
||||
// acceptable. Rotation is non-fatal: any failure here is silently ignored so the
|
||||
// logger never breaks the agent.
|
||||
private void RotateIfOverCap(string timestamp)
|
||||
{
|
||||
try
|
||||
{
|
||||
var fi = new FileInfo(_logFilePath);
|
||||
if (!fi.Exists || fi.Length < _maxFileSizeBytes) return;
|
||||
|
||||
_rotationSuffix = _rotationSuffix < 2 ? 2 : _rotationSuffix + 1;
|
||||
_logFilePath = BuildLogFilePath();
|
||||
|
||||
var capMb = _maxFileSizeBytes / (1024 * 1024);
|
||||
var rotateMsg = $"[{timestamp}] [INFO] AgentLogger: rotated from previous segment ({capMb}MB cap reached).";
|
||||
File.AppendAllText(_logFilePath, rotateMsg + Environment.NewLine);
|
||||
}
|
||||
catch
|
||||
{
|
||||
// Best-effort: never break logging on a rotation glitch.
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Sanitizes log messages to prevent log injection attacks.
|
||||
/// Escapes control characters that could forge log entries.
|
||||
|
||||
@@ -1 +1 @@
|
||||
331
|
||||
333
|
||||
|
||||
@@ -1 +1 @@
|
||||
1161
|
||||
1162
|
||||
|
||||
Reference in New Issue
Block a user