Skip to content

Commit b2e7037

Browse files
author
BRUNER Patrick
committed
test changes
1 parent 277197c commit b2e7037

1 file changed

Lines changed: 172 additions & 0 deletions

File tree

src/tools/LogRotator/LogRotator.cs

Lines changed: 172 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -35,16 +35,31 @@
3535
Console.WriteLine($"Control characters in output: {(includeControlChars ? "ENABLED" : "disabled")}");
3636
Console.WriteLine("Press ENTER to perform a rotation (with oldest file deletion).");
3737
Console.WriteLine("Press A to append a single live line (no rotation) for tail testing.");
38+
Console.WriteLine("Press D to delete the log, wait, then recreate it AND start a 25 lines/s");
39+
Console.WriteLine(" background writer (repro for issue #568). Press D again to delete mid-stream.");
40+
Console.WriteLine("Press F to flicker: delete, wait, briefly recreate, delete again mid-reload,");
41+
Console.WriteLine(" wait, then recreate + writer. Tries to land LogExpert's new reader's");
42+
Console.WriteLine(" ReadFiles inside a deletion window.");
3843
Console.WriteLine("Press Q to quit.");
3944

4045
var rotationCount = 0;
46+
var delayedDeleteCount = 0;
47+
var flickerCount = 0;
48+
const int delayedDeleteSeconds = 5;
49+
const int liveWriterDelayMs = 40; // ~25 lines/s
50+
const int flickerInitialAbsentMs = 5000;
51+
const int flickerBriefVisibleMs = 200;
52+
const int flickerSecondAbsentMs = 2500;
53+
CancellationTokenSource? liveWriterCts = null;
54+
Task? liveWriterTask = null;
4155

4256
while (true)
4357
{
4458
var key = Console.ReadKey(true);
4559

4660
if (key.Key == ConsoleKey.Q)
4761
{
62+
StopLiveWriter();
4863
break;
4964
}
5065

@@ -54,6 +69,20 @@
5469
continue;
5570
}
5671

72+
if (key.Key == ConsoleKey.D)
73+
{
74+
delayedDeleteCount++;
75+
DelayedDelete(Path.Join(baseDir, safeBaseName), delayedDeleteCount, delayedDeleteSeconds);
76+
continue;
77+
}
78+
79+
if (key.Key == ConsoleKey.F)
80+
{
81+
flickerCount++;
82+
FlickerRepro(Path.Join(baseDir, safeBaseName), flickerCount);
83+
continue;
84+
}
85+
5786
if (key.Key != ConsoleKey.Enter)
5887
{
5988
continue;
@@ -131,6 +160,149 @@ void AppendLiveLine(string path)
131160
Console.WriteLine($" Appended live line to {name} ({new FileInfo(path).Length} bytes total)");
132161
}
133162

163+
// Repro path for issue #568: stop any background writer, delete the file and
164+
// keep it absent long enough (> LogExpert's 1.25s OpenStream retry budget) for
165+
// the watcher to enter FileNotFound state, then recreate it AND start a
166+
// continuous background writer (~25 lines/s). The next D press will delete the
167+
// file while the writer is actively appending — that mid-stream delete is the
168+
// scenario the reporter describes.
169+
void DelayedDelete(string path, int iteration, int delaySeconds)
170+
{
171+
var name = Path.GetFileName(path);
172+
Console.WriteLine($"\n--- Delete + delay + recreate #{iteration} ---");
173+
174+
StopLiveWriter();
175+
176+
if (File.Exists(path))
177+
{
178+
File.Delete(path);
179+
Console.WriteLine($" Deleted: {name}");
180+
}
181+
else
182+
{
183+
Console.WriteLine($" {name} was already missing.");
184+
}
185+
186+
Console.WriteLine($" File absent. Waiting {delaySeconds}s so LogExpert enters FileNotFound state...");
187+
for (var i = delaySeconds; i > 0; i--)
188+
{
189+
Console.Write($"\r Countdown: {i}s ");
190+
Thread.Sleep(1000);
191+
}
192+
Console.WriteLine("\r Countdown: done.");
193+
194+
WriteLogFile(path, fileId: 900 + iteration);
195+
Console.WriteLine($" Recreated {name} with {linesPerFile} lines ({new FileInfo(path).Length} bytes).");
196+
StartLiveWriter(path, iteration);
197+
Console.WriteLine($" Background writer started (~{1000 / liveWriterDelayMs} lines/s).");
198+
Console.WriteLine(" Watch LogExpert: lines should keep appearing.");
199+
Console.WriteLine(" If they do NOT, the bug is reproduced. Press D again to delete mid-stream.");
200+
}
201+
202+
// Tighter race than DelayedDelete: after the file has been absent long enough
203+
// for LogExpert to enter FileNotFound, we briefly recreate it (so the watcher
204+
// fires OnRespawned and the LogWindow schedules a Reload), then delete it
205+
// again before the new LogfileReader's first ReadFiles completes its
206+
// OpenStream retries (5 x 250ms = 1.25s). If the hypothesis about issue #568
207+
// is correct, the new reader's ReadFiles catches IOException, _isDeleted is
208+
// set, ReportLoadingFinished is skipped, and FileSizeChanged never gets wired
209+
// up. After we recreate the file for real and start the writer, those writes
210+
// should fail to propagate.
211+
void FlickerRepro(string path, int iteration)
212+
{
213+
var name = Path.GetFileName(path);
214+
Console.WriteLine($"\n--- Flicker repro #{iteration} ---");
215+
216+
StopLiveWriter();
217+
218+
if (File.Exists(path))
219+
{
220+
File.Delete(path);
221+
Console.WriteLine($" Deleted: {name}");
222+
}
223+
224+
Console.WriteLine($" Phase 1: file absent for {flickerInitialAbsentMs / 1000.0:0.0}s (LogExpert -> FileNotFound)");
225+
Thread.Sleep(flickerInitialAbsentMs);
226+
227+
WriteLogFile(path, fileId: 700 + iteration);
228+
Console.WriteLine($" Phase 2: briefly visible ({flickerBriefVisibleMs}ms) - LogExpert schedules a Reload");
229+
Thread.Sleep(flickerBriefVisibleMs);
230+
231+
File.Delete(path);
232+
Console.WriteLine($" Phase 3: deleted again, absent {flickerSecondAbsentMs / 1000.0:0.0}s");
233+
Console.WriteLine($" (exceeds 1.25s OpenStream retry budget - new reader's ReadFiles should fail)");
234+
Thread.Sleep(flickerSecondAbsentMs);
235+
236+
WriteLogFile(path, fileId: 750 + iteration);
237+
Console.WriteLine($" Phase 4: recreated with {linesPerFile} lines, starting writer.");
238+
StartLiveWriter(path, iteration);
239+
Console.WriteLine(" Watch LogExpert. If row count freezes, bug reproduced.");
240+
}
241+
242+
void StartLiveWriter(string path, int iteration)
243+
{
244+
StopLiveWriter();
245+
liveWriterCts = new CancellationTokenSource();
246+
var token = liveWriterCts.Token;
247+
var fileId = 800 + iteration;
248+
liveWriterTask = Task.Run(() => LiveWriterLoop(path, fileId, token));
249+
}
250+
251+
void StopLiveWriter()
252+
{
253+
if (liveWriterCts == null)
254+
{
255+
return;
256+
}
257+
258+
liveWriterCts.Cancel();
259+
try
260+
{
261+
liveWriterTask?.Wait(TimeSpan.FromSeconds(2));
262+
}
263+
catch (AggregateException)
264+
{
265+
// expected: task cancelled
266+
}
267+
268+
liveWriterCts.Dispose();
269+
liveWriterCts = null;
270+
liveWriterTask = null;
271+
}
272+
273+
void LiveWriterLoop(string path, int fileId, CancellationToken token)
274+
{
275+
var name = Path.GetFileName(path);
276+
var lineIndex = 0;
277+
while (!token.IsCancellationRequested)
278+
{
279+
try
280+
{
281+
using var fs = new FileStream(path, FileMode.Append, FileAccess.Write, FileShare.ReadWrite | FileShare.Delete);
282+
using var writer = new StreamWriter(fs, Encoding.UTF8);
283+
writer.WriteLine(BuildLine(fileId, ++lineIndex, name));
284+
}
285+
catch (IOException)
286+
{
287+
// file may be momentarily inaccessible during a D-press; just keep
288+
// trying so writes resume once it reappears.
289+
}
290+
291+
try
292+
{
293+
Task.Delay(liveWriterDelayMs, token).Wait(token);
294+
}
295+
catch (OperationCanceledException)
296+
{
297+
return;
298+
}
299+
catch (AggregateException)
300+
{
301+
return;
302+
}
303+
}
304+
}
305+
134306
string BuildLine(int fileId, int lineIndex, string fileName)
135307
{
136308
var baseText = $"{DateTime.Now:yyyy-MM-dd HH:mm:ss.fff} [INFO] File#{fileId:D3} Line {lineIndex:D3} - {fileName} - Sample log message";

0 commit comments

Comments
 (0)