Skip to content

Commit 2d27adb

Browse files
committed
fix: finalize PagingLogger disposal path
1 parent b06c585 commit 2d27adb

5 files changed

Lines changed: 406 additions & 4 deletions

File tree

src/Runner.Common/Logging.cs

Lines changed: 53 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,7 @@
44
namespace GitHub.Runner.Common
55
{
66
[ServiceLocator(Default = typeof(PagingLogger))]
7-
public interface IPagingLogger : IRunnerService
7+
public interface IPagingLogger : IRunnerService, IDisposable
88
{
99
long TotalLines { get; }
1010
void Setup(Guid timelineId, Guid timelineRecordId);
@@ -45,6 +45,8 @@ public class PagingLogger : RunnerService, IPagingLogger
4545
private int _blockByteCount;
4646
private int _blockCount;
4747

48+
private bool _disposed;
49+
4850
public long TotalLines => _totalLines;
4951

5052
public override void Initialize(IHostContext hostContext)
@@ -164,5 +166,55 @@ private void EndBlock(bool finalize)
164166
_jobServerQueue.QueueResultsUpload(_timelineRecordId, "ResultsLog", _resultsDataFileName, "Results.Core.Log", deleteSource: true, finalize, firstBlock: _resultsDataFileName.EndsWith(".1"), totalLines: _totalLines);
165167
}
166168
}
169+
170+
// Best-effort cleanup for fault paths where End() was not reached.
171+
public void Dispose()
172+
{
173+
Dispose(true);
174+
GC.SuppressFinalize(this);
175+
}
176+
177+
protected virtual void Dispose(bool disposing)
178+
{
179+
if (_disposed)
180+
{
181+
return;
182+
}
183+
184+
if (disposing)
185+
{
186+
// Try normal flush+queue paths first.
187+
try { EndPage(); } catch { }
188+
189+
// Safety net for partially initialized page writer/stream.
190+
if (_pageWriter != null)
191+
{
192+
try { _pageWriter.Dispose(); } catch { }
193+
_pageWriter = null;
194+
_pageData = null;
195+
}
196+
else if (_pageData != null)
197+
{
198+
try { _pageData.Dispose(); } catch { }
199+
_pageData = null;
200+
}
201+
202+
try { EndBlock(finalize: true); } catch { }
203+
204+
if (_resultsBlockWriter != null)
205+
{
206+
try { _resultsBlockWriter.Dispose(); } catch { }
207+
_resultsBlockWriter = null;
208+
_resultsBlockData = null;
209+
}
210+
else if (_resultsBlockData != null)
211+
{
212+
try { _resultsBlockData.Dispose(); } catch { }
213+
_resultsBlockData = null;
214+
}
215+
}
216+
217+
_disposed = true;
218+
}
167219
}
168220
}

src/Runner.Worker/ExecutionContext.cs

Lines changed: 22 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -143,6 +143,7 @@ public sealed class ExecutionContext : RunnerService, IExecutionContext
143143
private IssueMatcherConfig[] _matchers;
144144

145145
private IPagingLogger _logger;
146+
private bool _ownsLogger;
146147
private IJobServerQueue _jobServerQueue;
147148

148149
private Guid _mainTimelineId;
@@ -411,6 +412,7 @@ public IExecutionContext CreateChild(
411412
else
412413
{
413414
child._logger = HostContext.CreateService<IPagingLogger>();
415+
child._ownsLogger = true;
414416
child._logger.Setup(_mainTimelineId, recordId);
415417
}
416418

@@ -552,7 +554,14 @@ public TaskResult Complete(TaskResult? result = null, string currentOperation =
552554
_cancellationTokenSource?.Dispose();
553555
}
554556

555-
_logger.End();
557+
try
558+
{
559+
_logger.End();
560+
}
561+
finally
562+
{
563+
DisposeOwnedLogger();
564+
}
556565

557566
UpdateGlobalStepsContext();
558567

@@ -961,6 +970,7 @@ public void InitializeJob(Pipelines.AgentJobRequestMessage message, Cancellation
961970

962971
// Logger (must be initialized before writing warnings).
963972
_logger = HostContext.CreateService<IPagingLogger>();
973+
_ownsLogger = true;
964974
_logger.Setup(_mainTimelineId, _record.Id);
965975

966976
// Initialize 'echo on action command success' property, default to false, unless Step_Debug is set
@@ -1277,6 +1287,17 @@ private IExecutionContext CreatePostChild(string displayName, Dictionary<string,
12771287
return CreateChild(newGuid, displayName, newGuid.ToString("N"), null, null, ActionRunStage.Post, intraActionState, _childTimelineRecordOrder - Root.PostJobSteps.Count, siblingScopeName: siblingScopeName);
12781288
}
12791289

1290+
private void DisposeOwnedLogger()
1291+
{
1292+
if (!_ownsLogger)
1293+
{
1294+
return;
1295+
}
1296+
1297+
_logger.Dispose();
1298+
_ownsLogger = false;
1299+
}
1300+
12801301
// Sets debug using vars context in case debug variables are not present.
12811302
private static void SetDebugUsingVars(IDictionary<string, VariableValue> variables, IDictionary<string, PipelineContextData> contextData)
12821303
{

src/Runner.Worker/JobRunner.cs

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -411,13 +411,16 @@ private async Task<TaskResult> CompleteJobAsync(IRunServer runServer, IExecution
411411
private async Task<TaskResult> CompleteJobAsync(IJobServer jobServer, IExecutionContext jobContext, Pipelines.AgentJobRequestMessage message, TaskResult? taskResult = null)
412412
{
413413
jobContext.Debug($"Finishing: {message.JobDisplayName}");
414-
TaskResult result = jobContext.Complete(taskResult);
415414

416415
if (_runnerSettings.DisableUpdate == true)
417416
{
418-
await WarningOutdatedRunnerAsync(jobContext, message, result);
417+
// Emit warning before Complete() closes paging logger.
418+
TaskResult warningResult = taskResult ?? jobContext.Result ?? TaskResult.Succeeded;
419+
await WarningOutdatedRunnerAsync(jobContext, message, warningResult);
419420
}
420421

422+
TaskResult result = jobContext.Complete(taskResult);
423+
421424
try
422425
{
423426
var jobQueueTelemetry = await ShutdownQueue(throwOnFailure: true);

src/Test/L0/PagingLoggerL0.cs

Lines changed: 211 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
using Moq;
22
using System;
33
using System.IO;
4+
using System.Reflection;
45
using Xunit;
56

67
namespace GitHub.Runner.Common.Tests.Listener
@@ -126,5 +127,215 @@ public void ShipEmptyLog()
126127
CleanLogFolder();
127128
}
128129
}
130+
131+
// Dispose without End() should flush/queue partial content.
132+
[Fact]
133+
[Trait("Level", "L0")]
134+
[Trait("Category", "Common")]
135+
public void Dispose_AfterPartialWrite_FlushesAndClosesFiles()
136+
{
137+
CleanLogFolder();
138+
139+
try
140+
{
141+
using (var hc = new TestHostContext(this))
142+
{
143+
var pagingLogger = new PagingLogger();
144+
hc.SetSingleton<IJobServerQueue>(_jobServerQueue.Object);
145+
pagingLogger.Initialize(hc);
146+
Guid timeLineId = Guid.NewGuid();
147+
Guid timeLineRecordId = Guid.NewGuid();
148+
149+
string queuedPagePath = null;
150+
_jobServerQueue
151+
.Setup(x => x.QueueFileUpload(timeLineId, timeLineRecordId, It.IsAny<string>(), It.IsAny<string>(), It.IsAny<string>(), true))
152+
.Callback((Guid _, Guid _, string _, string _, string path, bool _) => queuedPagePath = path);
153+
154+
string queuedBlockPath = null;
155+
_jobServerQueue
156+
.Setup(x => x.QueueResultsUpload(timeLineRecordId, It.IsAny<string>(), It.IsAny<string>(), It.IsAny<string>(), true, It.IsAny<bool>(), It.IsAny<bool>(), It.IsAny<long>()))
157+
.Callback((Guid _, string _, string path, string _, bool _, bool _, bool _, long _) => queuedBlockPath = path);
158+
159+
// Act: write once, then dispose without End().
160+
pagingLogger.Setup(timeLineId, timeLineRecordId);
161+
pagingLogger.Write(LogData);
162+
pagingLogger.Dispose();
163+
164+
Assert.False(string.IsNullOrEmpty(queuedPagePath), "Dispose should have queued the partial page for upload.");
165+
Assert.False(string.IsNullOrEmpty(queuedBlockPath), "Dispose should have queued the partial block for upload with finalize=true.");
166+
167+
// Verify flushed content reached queued files.
168+
Assert.Contains(LogData, File.ReadAllText(queuedPagePath));
169+
Assert.Contains(LogData, File.ReadAllText(queuedBlockPath));
170+
171+
// Cleanup files created outside the normal callback path.
172+
File.Delete(queuedPagePath);
173+
File.Delete(queuedBlockPath);
174+
}
175+
}
176+
finally
177+
{
178+
CleanLogFolder();
179+
}
180+
}
181+
182+
// Dispose should be idempotent.
183+
[Fact]
184+
[Trait("Level", "L0")]
185+
[Trait("Category", "Common")]
186+
public void Dispose_IsIdempotent()
187+
{
188+
CleanLogFolder();
189+
190+
try
191+
{
192+
using (var hc = new TestHostContext(this))
193+
{
194+
var pagingLogger = new PagingLogger();
195+
hc.SetSingleton<IJobServerQueue>(_jobServerQueue.Object);
196+
pagingLogger.Initialize(hc);
197+
Guid timeLineId = Guid.NewGuid();
198+
Guid timeLineRecordId = Guid.NewGuid();
199+
200+
int queueFileUploadCount = 0;
201+
int queueResultsUploadCount = 0;
202+
_jobServerQueue
203+
.Setup(x => x.QueueFileUpload(timeLineId, timeLineRecordId, It.IsAny<string>(), It.IsAny<string>(), It.IsAny<string>(), true))
204+
.Callback(() => queueFileUploadCount++);
205+
_jobServerQueue
206+
.Setup(x => x.QueueResultsUpload(timeLineRecordId, It.IsAny<string>(), It.IsAny<string>(), It.IsAny<string>(), true, It.IsAny<bool>(), It.IsAny<bool>(), It.IsAny<long>()))
207+
.Callback(() => queueResultsUploadCount++);
208+
209+
pagingLogger.Setup(timeLineId, timeLineRecordId);
210+
pagingLogger.Write(LogData);
211+
pagingLogger.Dispose();
212+
pagingLogger.Dispose();
213+
214+
Assert.Equal(1, queueFileUploadCount);
215+
Assert.Equal(1, queueResultsUploadCount);
216+
}
217+
}
218+
finally
219+
{
220+
CleanLogFolder();
221+
}
222+
}
223+
224+
// Dispose after End() should be a no-op.
225+
[Fact]
226+
[Trait("Level", "L0")]
227+
[Trait("Category", "Common")]
228+
public void Dispose_AfterEnd_IsNoOp()
229+
{
230+
CleanLogFolder();
231+
232+
try
233+
{
234+
using (var hc = new TestHostContext(this))
235+
{
236+
var pagingLogger = new PagingLogger();
237+
hc.SetSingleton<IJobServerQueue>(_jobServerQueue.Object);
238+
pagingLogger.Initialize(hc);
239+
Guid timeLineId = Guid.NewGuid();
240+
Guid timeLineRecordId = Guid.NewGuid();
241+
242+
int queueCount = 0;
243+
_jobServerQueue
244+
.Setup(x => x.QueueFileUpload(timeLineId, timeLineRecordId, It.IsAny<string>(), It.IsAny<string>(), It.IsAny<string>(), true))
245+
.Callback(() => queueCount++);
246+
247+
pagingLogger.Setup(timeLineId, timeLineRecordId);
248+
pagingLogger.Write(LogData);
249+
pagingLogger.End();
250+
int afterEnd = queueCount;
251+
252+
pagingLogger.Dispose();
253+
254+
Assert.Equal(afterEnd, queueCount);
255+
}
256+
}
257+
finally
258+
{
259+
CleanLogFolder();
260+
}
261+
}
262+
263+
// Dispose before Write() should not queue uploads.
264+
[Fact]
265+
[Trait("Level", "L0")]
266+
[Trait("Category", "Common")]
267+
public void Dispose_BeforeAnyWrite_DoesNotThrow()
268+
{
269+
CleanLogFolder();
270+
271+
try
272+
{
273+
using (var hc = new TestHostContext(this))
274+
{
275+
var pagingLogger = new PagingLogger();
276+
hc.SetSingleton<IJobServerQueue>(_jobServerQueue.Object);
277+
pagingLogger.Initialize(hc);
278+
279+
int queueCount = 0;
280+
_jobServerQueue
281+
.Setup(x => x.QueueFileUpload(It.IsAny<Guid>(), It.IsAny<Guid>(), It.IsAny<string>(), It.IsAny<string>(), It.IsAny<string>(), It.IsAny<bool>()))
282+
.Callback(() => queueCount++);
283+
284+
pagingLogger.Setup(Guid.NewGuid(), Guid.NewGuid());
285+
pagingLogger.Dispose();
286+
287+
Assert.Equal(0, queueCount);
288+
}
289+
}
290+
finally
291+
{
292+
CleanLogFolder();
293+
}
294+
}
295+
296+
// Safety net: close orphaned _pageData when _pageWriter was never assigned.
297+
[Fact]
298+
[Trait("Level", "L0")]
299+
[Trait("Category", "Common")]
300+
public void Dispose_ReleasesOrphanedFileStream_WhenWriterWasNeverAssigned()
301+
{
302+
CleanLogFolder();
303+
304+
try
305+
{
306+
using (var hc = new TestHostContext(this))
307+
{
308+
var pagingLogger = new PagingLogger();
309+
hc.SetSingleton<IJobServerQueue>(_jobServerQueue.Object);
310+
pagingLogger.Initialize(hc);
311+
pagingLogger.Setup(Guid.NewGuid(), Guid.NewGuid());
312+
313+
// Force partial-init state: _pageData set, _pageWriter null.
314+
var pagesFolder = Path.Combine(hc.GetDirectory(WellKnownDirectory.Diag), PagingLogger.PagingFolder);
315+
Directory.CreateDirectory(pagesFolder);
316+
var orphanPath = Path.Combine(pagesFolder, $"orphan-{Guid.NewGuid():N}.log");
317+
var orphanStream = new FileStream(orphanPath, FileMode.Create, FileAccess.ReadWrite, FileShare.ReadWrite);
318+
319+
typeof(PagingLogger)
320+
.GetField("_pageData", BindingFlags.NonPublic | BindingFlags.Instance)
321+
.SetValue(pagingLogger, orphanStream);
322+
323+
pagingLogger.Dispose();
324+
325+
var closedStream = (FileStream)typeof(PagingLogger)
326+
.GetField("_pageData", BindingFlags.NonPublic | BindingFlags.Instance)
327+
.GetValue(pagingLogger);
328+
Assert.Null(closedStream);
329+
330+
Assert.True(orphanStream.SafeFileHandle.IsClosed, "Dispose should have closed the orphaned FileStream's handle.");
331+
File.Delete(orphanPath);
332+
}
333+
}
334+
finally
335+
{
336+
CleanLogFolder();
337+
}
338+
}
339+
129340
}
130341
}

0 commit comments

Comments
 (0)