|
35 | 35 | Console.WriteLine($"Control characters in output: {(includeControlChars ? "ENABLED" : "disabled")}"); |
36 | 36 | Console.WriteLine("Press ENTER to perform a rotation (with oldest file deletion)."); |
37 | 37 | 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."); |
38 | 43 | Console.WriteLine("Press Q to quit."); |
39 | 44 |
|
40 | 45 | 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; |
41 | 55 |
|
42 | 56 | while (true) |
43 | 57 | { |
44 | 58 | var key = Console.ReadKey(true); |
45 | 59 |
|
46 | 60 | if (key.Key == ConsoleKey.Q) |
47 | 61 | { |
| 62 | + StopLiveWriter(); |
48 | 63 | break; |
49 | 64 | } |
50 | 65 |
|
|
54 | 69 | continue; |
55 | 70 | } |
56 | 71 |
|
| 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 | + |
57 | 86 | if (key.Key != ConsoleKey.Enter) |
58 | 87 | { |
59 | 88 | continue; |
@@ -131,6 +160,149 @@ void AppendLiveLine(string path) |
131 | 160 | Console.WriteLine($" Appended live line to {name} ({new FileInfo(path).Length} bytes total)"); |
132 | 161 | } |
133 | 162 |
|
| 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 | + |
134 | 306 | string BuildLine(int fileId, int lineIndex, string fileName) |
135 | 307 | { |
136 | 308 | 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