public void OnTraceTimer(string additional)
{
if (!isDetailedTraces)
{
return;
}
detailedLatestTraceTimer++;
Trace(OnTraceGetMessage($"timer{detailedLatestTraceTimer} hit", additional));
DetailedTraceTimer.Restart();
}
public void OnTraceTested(string additional)
{
if (!isDetailedTraces)
{
return;
}
isDetailedOnTraceTestedHit = true;
isDetailedOnTraceTestedHitSinceLast = true;
Trace(OnTraceGetMessage("succeeded test", additional));
detailedAssertFailedIfSet = false;
DetailedTraceTimer.Restart();
}
public void OnTraceGenerated(string additional)
{
if (!isDetailedTraces)
{
return;
}
isDetailedOnTraceGeneratedHit = true;
isDetailedOnTraceGeneratedHitSinceLast = true;
// Atomic swap of detailedLatestSeenActivity
BoxedDateTimeOffset initialValue;
BoxedDateTimeOffset computedValue;
do
{
initialValue = detailedLatestSeenActivity;
computedValue = new BoxedDateTimeOffset(DateTimeOffset.Now);
} while (initialValue != Interlocked.CompareExchange(
ref detailedLatestSeenActivity, computedValue, initialValue
));
if (detailedAssertFailedIfSet)
{
Trace(
string.Concat(OnTraceGetMessage("failed test", additional), $" ---> shrinking{Environment.NewLine}")
);
detailedCurrentStageIsShrinking = true;
detailedLatestNumExecutions = 0;
detailedLatestNumShrinks++;
}
detailedAssertFailedIfSet = true;
detailedLatestTraceTimer = 0;
detailedLatestNumExecutions++;
Trace(OnTraceGetMessage("generated", additional));
DetailedTraceTimer.Restart();
}
public void AttachToTest()
{
// Check if we want detailed traces enabled
if (FsCheckRunnerConfig.TraceDiagnosticsEnabled)
{
isDetailedTraces = true;
FsCheckRunnerConfig.Events.TraceGenerated += OnTraceGenerated;
FsCheckRunnerConfig.Events.TraceTested += OnTraceTested;
FsCheckRunnerConfig.Events.TraceTimer += OnTraceTimer;
detailedBackgroundCancel = new CancellationTokenSource();
var ct = detailedBackgroundCancel.Token;
if (isDetailedTraces || FsCheckRunnerConfig.TraceNumberOfRuns)
{
backgroundTask = Task.Run(() => TimeReporterTask(ct), CancellationToken.None);
}
DetailedTraceTimer.Start();
DetailedTraceTotalTimer.Start();
}
async Task TimeReporterTask(CancellationToken cancellationToken)
{
var firstRun = true;
var hasWarnedAboutMissingTraces = false;
var i = 0;
var startTime = DateTimeOffset.Now;
while (!cancellationToken.IsCancellationRequested)
{
i++;
var now = DateTimeOffset.Now;
var desiredEnd = startTime.AddSeconds(i);
var wait = Math.Max(1, (int)(desiredEnd - now).TotalMilliseconds);
try
{
await Task.Delay(wait, cancellationToken);
}
catch (TaskCanceledException)
{
}
if (!cancellationToken.IsCancellationRequested)
{
Trace(
string.Concat(
"time passed in total is now ",
FormattableString.Invariant($"{DetailedTraceTotalTimer.ElapsedMilliseconds:n0}ms")
)
);
}
// Give the test a few seconds to start, then report missing trace
if (!firstRun && isDetailedTraces && !cancellationToken.IsCancellationRequested)
{
WarnAboutMissingTraces();
if (!isDetailedOnTraceTestedHitSinceLast || !isDetailedOnTraceGeneratedHitSinceLast)
{
var secondsPassed = DateTimeOffset.Now - detailedLatestSeenActivity.InnerDateTimeOffset;
Trace(
FormattableString.Invariant(
$"--- {secondsPassed.TotalSeconds:n0} seconds have passed since any activity"
)
);
}
isDetailedOnTraceTestedHitSinceLast = false;
isDetailedOnTraceGeneratedHitSinceLast = false;
}
firstRun = false;
if (cancellationToken.IsCancellationRequested)
{
WarnAboutMissingTraces();
}
}
void WarnAboutMissingTraces()
{
if (hasWarnedAboutMissingTraces || isDetailedOnTraceTestedHit || isDetailedOnTraceGeneratedHit)
{
return;
}
hasWarnedAboutMissingTraces = true;
Trace(
"--- No calls to trace call functions, make sure your code is instrumented with the functions from FsCheckRunnerConfig.TraceDiagnostics.Events"
);
}
}
}