Skip to content

568 stop following tail after file re creation #592

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
Hirogen merged 3 commits into from
Jun 1, 2026
Merged

568 stop following tail after file re creation #592

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
b2e7037
test changes
May 29, 2026
cddf257
update settings
Jun 1, 2026
edd5a66
chore: update plugin hashes [skip ci]
github-actions[bot] Jun 1, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 3 additions & 1 deletion .vscode/settings.json
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,5 +15,7 @@
"matchCommandLine": true
},
"git rev-parse": true
}
},
"dotnet.preferCSharpExtension": true,
"dotnet.defaultSolution": "src/LogExpert.sln"
}
32 changes: 16 additions & 16 deletions src/PluginRegistry/PluginHashGenerator.Generated.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,35 +10,35 @@ public static partial class PluginValidator
{
/// <summary>
/// Gets pre-calculated SHA256 hashes for built-in plugins.
/// Generated: 2026-05-28 19:52:00 UTC
/// Generated: 2026-06-01 09:31:40 UTC
/// Configuration: Release
/// Plugin count: 21
/// </summary>
public static Dictionary<string, string> GetBuiltInPluginHashes()
{
return new Dictionary<string, string>(StringComparer.OrdinalIgnoreCase)
{
["AutoColumnizer.dll"] = "EDF4B48F71CF2192A99F63B9FE493661521A2E671D9185CCEB181B513DF0C1A5",
["AutoColumnizer.dll"] = "1E5C3388943F4EB34382324E6A2C54F93C89B88CFE1D69ACF1203FB7416E672F",
["BouncyCastle.Cryptography.dll"] = "E5EEAF6D263C493619982FD3638E6135077311D08C961E1FE128F9107D29EBC6",
["BouncyCastle.Cryptography.dll (x86)"] = "E5EEAF6D263C493619982FD3638E6135077311D08C961E1FE128F9107D29EBC6",
["CsvColumnizer.dll"] = "397CCA331A6FD1687C8CBDF78DF6DF9C080B7A16860C511F2DC0E275A5257C4F",
["CsvColumnizer.dll (x86)"] = "397CCA331A6FD1687C8CBDF78DF6DF9C080B7A16860C511F2DC0E275A5257C4F",
["DefaultPlugins.dll"] = "58B2ED626556C1B0E1B02D62DF0A0658618FA05B309BFAA2C2582B180594B7E6",
["FlashIconHighlighter.dll"] = "0861244E3F7B52D44B8487732724E277658143E5940AACFF977AA74048FF1B9D",
["GlassfishColumnizer.dll"] = "B75D7808007E9CA1235E282B07431C70A16D378B647B58BAEE605075D7B8FF08",
["JsonColumnizer.dll"] = "A469FEC6C1E6F7B209D960CE7C3416CF80EFD5A2A062BCAD7B0E8AE6A3988ABF",
["JsonCompactColumnizer.dll"] = "F6735973634AE8A986BC9FD8B89F8817D36458E488B6A7BCD2320883DD4BA5BC",
["Log4jXmlColumnizer.dll"] = "D148D1FEC9A0152714AAE8CBAB0A9BDDF9ACFBFED3FF0CEB8D5966908DC24760",
["LogExpert.Resources.dll"] = "A25FDA182EECF5BCC828C0C3F145FD774530980E9C72AC17591043677FA9E201",
["CsvColumnizer.dll"] = "0DB8949CCFB20468D5C934474EEC98B3BD1AD0802D2F79F9DF9013DAF2A037C9",
["CsvColumnizer.dll (x86)"] = "0DB8949CCFB20468D5C934474EEC98B3BD1AD0802D2F79F9DF9013DAF2A037C9",
["DefaultPlugins.dll"] = "FE68CE75E429D0F29ABB2D221A4BBBC16AD6C06B77FB2B709134591F276DE9DF",
["FlashIconHighlighter.dll"] = "A8C733BBA980A364B3739EFBF866E85E166C15B79A6B704456C7F92884BECB27",
["GlassfishColumnizer.dll"] = "86D49BC1EAC7F843893134F7F5B64BE37A94C914F389DB56598DBC670D849835",
["JsonColumnizer.dll"] = "6A6B27428F647DF29D03F4F17AED89DDF1FF24636B59644FBD12FB3D92A26F18",
["JsonCompactColumnizer.dll"] = "04A7169C087181B49189AB8DD9C9FB260189EB1CF394452EA02987FFE6934794",
["Log4jXmlColumnizer.dll"] = "301E7805F9BA5BA211256119636B7A8D34848475C5B7885737FD8E61CB1B5233",
["LogExpert.Resources.dll"] = "A2AFABDCFDA0B558426706336C11FB8B02770383419BA1E0192FFFEBEB091A38",
["Microsoft.Extensions.DependencyInjection.Abstractions.dll"] = "67FA4325000DB017DC0C35829B416F024F042D24EFB868BCF17A895EE6500A93",
["Microsoft.Extensions.DependencyInjection.Abstractions.dll (x86)"] = "67FA4325000DB017DC0C35829B416F024F042D24EFB868BCF17A895EE6500A93",
["Microsoft.Extensions.Logging.Abstractions.dll"] = "BB853130F5AFAF335BE7858D661F8212EC653835100F5A4E3AA2C66A4D4F685D",
["Microsoft.Extensions.Logging.Abstractions.dll (x86)"] = "BB853130F5AFAF335BE7858D661F8212EC653835100F5A4E3AA2C66A4D4F685D",
["RegexColumnizer.dll"] = "C0DC4D43DB02C2015A490BC4C62549D7CDD1B107C6944F20DB0B4C4285371288",
["SftpFileSystem.dll"] = "AAD426FB4E53916B8B26F427374EA3E6706B940564F4CD0E059E69A613CBE02B",
["SftpFileSystem.dll (x86)"] = "6FEC9B0EC9B9241ACA09999C55AD96F33FD52A2A1A14DC513D06BC42BF2C1B86",
["SftpFileSystem.Resources.dll"] = "0F8C4D65FE7E8A79A11DF521116E36E65AC28DE732C67264A3790AD2F1E4CBB8",
["SftpFileSystem.Resources.dll (x86)"] = "0F8C4D65FE7E8A79A11DF521116E36E65AC28DE732C67264A3790AD2F1E4CBB8",
["RegexColumnizer.dll"] = "AC1E977392AD7A291174C357211480121C49898C2258E8608E06AF8DDA48DE7E",
["SftpFileSystem.dll"] = "E5B7DD9D7038F68B501BD8398141FD6E8EBE9878B205D346E3C36FCD40DA9CA8",
["SftpFileSystem.dll (x86)"] = "8B892CC370EE3E01693F282C32245B55F3D225F48D6631102EB2DC79692F762B",
["SftpFileSystem.Resources.dll"] = "20CFD22D83D1581FF63348F3F0D3E824A73887F80BCDEB04E6AAF3E5A200C036",
["SftpFileSystem.Resources.dll (x86)"] = "20CFD22D83D1581FF63348F3F0D3E824A73887F80BCDEB04E6AAF3E5A200C036",

};
}
Expand Down
172 changes: 172 additions & 0 deletions src/tools/LogRotator/LogRotator.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -35,16 +35,31 @@
Console.WriteLine($"Control characters in output: {(includeControlChars ? "ENABLED" : "disabled")}");
Console.WriteLine("Press ENTER to perform a rotation (with oldest file deletion).");
Console.WriteLine("Press A to append a single live line (no rotation) for tail testing.");
Console.WriteLine("Press D to delete the log, wait, then recreate it AND start a 25 lines/s");
Console.WriteLine(" background writer (repro for issue #568). Press D again to delete mid-stream.");
Console.WriteLine("Press F to flicker: delete, wait, briefly recreate, delete again mid-reload,");
Console.WriteLine(" wait, then recreate + writer. Tries to land LogExpert's new reader's");
Console.WriteLine(" ReadFiles inside a deletion window.");
Console.WriteLine("Press Q to quit.");

var rotationCount = 0;
var delayedDeleteCount = 0;
var flickerCount = 0;
const int delayedDeleteSeconds = 5;
const int liveWriterDelayMs = 40; // ~25 lines/s
const int flickerInitialAbsentMs = 5000;
const int flickerBriefVisibleMs = 200;
const int flickerSecondAbsentMs = 2500;
CancellationTokenSource? liveWriterCts = null;
Task? liveWriterTask = null;

while (true)
{
var key = Console.ReadKey(true);

if (key.Key == ConsoleKey.Q)
{
StopLiveWriter();
break;
}

Expand All @@ -54,6 +69,20 @@
continue;
}

if (key.Key == ConsoleKey.D)
{
delayedDeleteCount++;
DelayedDelete(Path.Join(baseDir, safeBaseName), delayedDeleteCount, delayedDeleteSeconds);
continue;
}

if (key.Key == ConsoleKey.F)
{
flickerCount++;
FlickerRepro(Path.Join(baseDir, safeBaseName), flickerCount);
continue;
}

if (key.Key != ConsoleKey.Enter)
{
continue;
Expand Down Expand Up @@ -131,6 +160,149 @@ void AppendLiveLine(string path)
Console.WriteLine($" Appended live line to {name} ({new FileInfo(path).Length} bytes total)");
}

// Repro path for issue #568: stop any background writer, delete the file and
// keep it absent long enough (> LogExpert's 1.25s OpenStream retry budget) for
// the watcher to enter FileNotFound state, then recreate it AND start a
// continuous background writer (~25 lines/s). The next D press will delete the
// file while the writer is actively appending — that mid-stream delete is the
// scenario the reporter describes.
void DelayedDelete(string path, int iteration, int delaySeconds)
{
var name = Path.GetFileName(path);
Console.WriteLine($"\n--- Delete + delay + recreate #{iteration} ---");

StopLiveWriter();

if (File.Exists(path))
{
File.Delete(path);
Console.WriteLine($" Deleted: {name}");
}
else
{
Console.WriteLine($" {name} was already missing.");
}

Console.WriteLine($" File absent. Waiting {delaySeconds}s so LogExpert enters FileNotFound state...");
for (var i = delaySeconds; i > 0; i--)
{
Console.Write($"\r Countdown: {i}s ");
Thread.Sleep(1000);
}
Console.WriteLine("\r Countdown: done.");

WriteLogFile(path, fileId: 900 + iteration);
Console.WriteLine($" Recreated {name} with {linesPerFile} lines ({new FileInfo(path).Length} bytes).");
StartLiveWriter(path, iteration);
Console.WriteLine($" Background writer started (~{1000 / liveWriterDelayMs} lines/s).");
Console.WriteLine(" Watch LogExpert: lines should keep appearing.");
Console.WriteLine(" If they do NOT, the bug is reproduced. Press D again to delete mid-stream.");
}

// Tighter race than DelayedDelete: after the file has been absent long enough
// for LogExpert to enter FileNotFound, we briefly recreate it (so the watcher
// fires OnRespawned and the LogWindow schedules a Reload), then delete it
// again before the new LogfileReader's first ReadFiles completes its
// OpenStream retries (5 x 250ms = 1.25s). If the hypothesis about issue #568
// is correct, the new reader's ReadFiles catches IOException, _isDeleted is
// set, ReportLoadingFinished is skipped, and FileSizeChanged never gets wired
// up. After we recreate the file for real and start the writer, those writes
// should fail to propagate.
void FlickerRepro(string path, int iteration)
{
var name = Path.GetFileName(path);
Console.WriteLine($"\n--- Flicker repro #{iteration} ---");

StopLiveWriter();

if (File.Exists(path))
{
File.Delete(path);
Console.WriteLine($" Deleted: {name}");
}

Console.WriteLine($" Phase 1: file absent for {flickerInitialAbsentMs / 1000.0:0.0}s (LogExpert -> FileNotFound)");
Thread.Sleep(flickerInitialAbsentMs);

WriteLogFile(path, fileId: 700 + iteration);
Console.WriteLine($" Phase 2: briefly visible ({flickerBriefVisibleMs}ms) - LogExpert schedules a Reload");
Thread.Sleep(flickerBriefVisibleMs);

File.Delete(path);
Console.WriteLine($" Phase 3: deleted again, absent {flickerSecondAbsentMs / 1000.0:0.0}s");
Console.WriteLine($" (exceeds 1.25s OpenStream retry budget - new reader's ReadFiles should fail)");
Thread.Sleep(flickerSecondAbsentMs);

WriteLogFile(path, fileId: 750 + iteration);
Console.WriteLine($" Phase 4: recreated with {linesPerFile} lines, starting writer.");
StartLiveWriter(path, iteration);
Console.WriteLine(" Watch LogExpert. If row count freezes, bug reproduced.");
}

void StartLiveWriter(string path, int iteration)
{
StopLiveWriter();
liveWriterCts = new CancellationTokenSource();
var token = liveWriterCts.Token;
var fileId = 800 + iteration;
liveWriterTask = Task.Run(() => LiveWriterLoop(path, fileId, token));
}

void StopLiveWriter()
{
if (liveWriterCts == null)
{
return;
}

liveWriterCts.Cancel();
try
{
liveWriterTask?.Wait(TimeSpan.FromSeconds(2));
}
catch (AggregateException)
{
// expected: task cancelled
}

liveWriterCts.Dispose();
liveWriterCts = null;
liveWriterTask = null;
}

void LiveWriterLoop(string path, int fileId, CancellationToken token)
{
var name = Path.GetFileName(path);
var lineIndex = 0;
while (!token.IsCancellationRequested)
{
try
{
using var fs = new FileStream(path, FileMode.Append, FileAccess.Write, FileShare.ReadWrite | FileShare.Delete);
using var writer = new StreamWriter(fs, Encoding.UTF8);
writer.WriteLine(BuildLine(fileId, ++lineIndex, name));
}
catch (IOException)
{
// file may be momentarily inaccessible during a D-press; just keep
// trying so writes resume once it reappears.
}

try
{
Task.Delay(liveWriterDelayMs, token).Wait(token);
}
catch (OperationCanceledException)
{
return;
}
catch (AggregateException)
{
return;
}
}
}

string BuildLine(int fileId, int lineIndex, string fileName)
{
var baseText = $"{DateTime.Now:yyyy-MM-dd HH:mm:ss.fff} [INFO] File#{fileId:D3} Line {lineIndex:D3} - {fileName} - Sample log message";
Expand Down