Skip to content

Commit 00f6936

Browse files
Fix race in AsyncProcessOutputReader (#2180)
The process.WaitForExit call doesn't guarantee that the last calls of ProcessOnOutputDataReceived and ProcessOnErrorDataReceived are processed. The subsequent call of reader.StopRead detaches the *DataReceived events, which leaves the output/error queues incomplete. This race leads to flakiness of various tests (e.g., AllSetupAndCleanupMethodRunsForSpecificBenchmark).
1 parent 681a638 commit 00f6936

File tree

1 file changed

+37
-15
lines changed

1 file changed

+37
-15
lines changed

src/BenchmarkDotNet/Loggers/AsyncProcessOutputReader.cs

Lines changed: 37 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -10,9 +10,12 @@ namespace BenchmarkDotNet.Loggers
1010
internal class AsyncProcessOutputReader : IDisposable
1111
{
1212
private readonly Process process;
13-
private readonly ConcurrentQueue<string> output, error;
14-
private readonly bool logOutput, readStandardError;
1513
private readonly ILogger logger;
14+
private readonly bool logOutput, readStandardError;
15+
16+
private static readonly TimeSpan FinishEventTimeout = TimeSpan.FromMilliseconds(500);
17+
private readonly AutoResetEvent outputFinishEvent, errorFinishEvent;
18+
private readonly ConcurrentQueue<string> output, error;
1619

1720
private long status;
1821

@@ -28,6 +31,8 @@ internal AsyncProcessOutputReader(Process process, bool logOutput = false, ILogg
2831
this.process = process;
2932
output = new ConcurrentQueue<string>();
3033
error = new ConcurrentQueue<string>();
34+
outputFinishEvent = new AutoResetEvent(false);
35+
errorFinishEvent = new AutoResetEvent(false);
3136
status = (long)Status.Created;
3237
this.logOutput = logOutput;
3338
this.logger = logger;
@@ -39,6 +44,9 @@ public void Dispose()
3944
Interlocked.Exchange(ref status, (long)Status.Disposed);
4045

4146
Detach();
47+
48+
outputFinishEvent.Dispose();
49+
errorFinishEvent.Dispose();
4250
}
4351

4452
internal void BeginRead()
@@ -72,6 +80,10 @@ internal void StopRead()
7280
if (Interlocked.CompareExchange(ref status, (long)Status.Stopped, (long)Status.Started) != (long)Status.Started)
7381
throw new InvalidOperationException("Only a started reader can be stopped");
7482

83+
outputFinishEvent.WaitOne(FinishEventTimeout);
84+
if (readStandardError)
85+
errorFinishEvent.WaitOne(FinishEventTimeout);
86+
7587
Detach();
7688
}
7789

@@ -103,34 +115,44 @@ private void Detach()
103115

104116
private void ProcessOnOutputDataReceived(object sender, DataReceivedEventArgs e)
105117
{
106-
if (!string.IsNullOrEmpty(e.Data))
118+
if (e.Data != null)
107119
{
108-
output.Enqueue(e.Data);
109-
110-
if (logOutput)
120+
if (!string.IsNullOrEmpty(e.Data))
111121
{
112-
lock (this) // #2125
122+
output.Enqueue(e.Data);
123+
124+
if (logOutput)
113125
{
114-
logger.WriteLine(e.Data);
126+
lock (this) // #2125
127+
{
128+
logger.WriteLine(e.Data);
129+
}
115130
}
116131
}
117132
}
133+
else // 'e.Data == null' means EOF
134+
outputFinishEvent.Set();
118135
}
119136

120137
private void ProcessOnErrorDataReceived(object sender, DataReceivedEventArgs e)
121138
{
122-
if (!string.IsNullOrEmpty(e.Data))
139+
if (e.Data != null)
123140
{
124-
error.Enqueue(e.Data);
125-
126-
if (logOutput)
141+
if (!string.IsNullOrEmpty(e.Data))
127142
{
128-
lock (this) // #2125
143+
error.Enqueue(e.Data);
144+
145+
if (logOutput)
129146
{
130-
logger.WriteLineError(e.Data);
147+
lock (this) // #2125
148+
{
149+
logger.WriteLineError(e.Data);
150+
}
131151
}
132152
}
133153
}
154+
else // 'e.Data == null' means EOF
155+
errorFinishEvent.Set();
134156
}
135157

136158
private T ReturnIfStopped<T>(Func<T> getter)
@@ -146,4 +168,4 @@ private enum Status : long
146168
Disposed
147169
}
148170
}
149-
}
171+
}

0 commit comments

Comments
 (0)