/// <summary>
/// Runs the specified test method.
/// </summary>
internal void RunTest(Delegate testMethod, string testName)
{
testName = string.IsNullOrEmpty(testName) ? string.Empty : $" '{testName}'";
this.Logger.WriteLine($"<TestLog> Running test{testName}.");
this.Assert(testMethod != null, "Unable to execute a null test method.");
this.Assert(Task.CurrentId != null, "The test must execute inside a controlled task.");
ulong operationId = this.GetNextOperationId();
var op = new TaskOperation(operationId, this.Scheduler);
this.Scheduler.RegisterOperation(op);
op.OnEnabled();
Task task = new Task(async() =>
{
try
{
// Update the current asynchronous control flow with the current runtime instance,
// allowing future retrieval in the same asynchronous call stack.
AssignAsyncControlFlowRuntime(this);
OperationScheduler.StartOperation(op);
if (testMethod is Action <IActorRuntime> actionWithRuntime)
{
actionWithRuntime(this);
}
else if (testMethod is Action action)
{
action();
}
else if (testMethod is Func <IActorRuntime, CoyoteTasks.Task> functionWithRuntime)
{
await functionWithRuntime(this);
}
else if (testMethod is Func <CoyoteTasks.Task> function)
{
await function();
}
else
{
throw new InvalidOperationException($"Unsupported test delegate of type '{testMethod.GetType()}'.");
}
IO.Debug.WriteLine("<ScheduleDebug> Completed operation {0} on task '{1}'.", op.Name, Task.CurrentId);
op.OnCompleted();
// Task has completed, schedule the next enabled operation.
this.Scheduler.ScheduleNextEnabledOperation();
}
catch (Exception ex)
{
this.ProcessUnhandledExceptionInOperation(op, ex);
}
});
this.Scheduler.ScheduleOperation(op, task.Id);
task.Start();
this.Scheduler.WaitOperationStart(op);
}
/// <summary>
/// Initializes a new instance of the <see cref="ControlledRuntime"/> class.
/// </summary>
internal ControlledRuntime(Configuration configuration, ISchedulingStrategy strategy,
IRandomValueGenerator valueGenerator)
: base(configuration, valueGenerator)
{
IsExecutionControlled = true;
this.RootTaskId = Task.CurrentId;
this.NameValueToActorId = new ConcurrentDictionary <string, ActorId>();
this.CoverageInfo = new CoverageInfo();
var scheduleTrace = new ScheduleTrace();
if (configuration.IsLivenessCheckingEnabled)
{
strategy = new TemperatureCheckingStrategy(configuration, this.Monitors, strategy);
}
this.Scheduler = new OperationScheduler(this, strategy, scheduleTrace, this.Configuration);
this.TaskController = new TaskController(this, this.Scheduler);
// Update the current asynchronous control flow with this runtime instance,
// allowing future retrieval in the same asynchronous call stack.
AssignAsyncControlFlowRuntime(this);
}
/// <summary>
/// Initializes a new instance of the <see cref="TestingEngine"/> class.
/// </summary>
private TestingEngine(Configuration configuration, TestMethodInfo testMethodInfo)
{
this.Configuration = configuration;
this.TestMethodInfo = testMethodInfo;
this.DefaultLogger = new ConsoleLogger()
{
LogLevel = configuration.LogLevel
};
this.Logger = this.DefaultLogger;
this.Profiler = new Profiler();
this.PerIterationCallbacks = new HashSet <Action <uint> >();
this.TestReport = new TestReport(configuration);
this.ReadableTrace = string.Empty;
this.ReproducibleTrace = string.Empty;
this.CancellationTokenSource = new CancellationTokenSource();
this.PrintGuard = 1;
if (configuration.IsDebugVerbosityEnabled)
{
IO.Debug.IsEnabled = true;
}
// Do some sanity checking.
string error = string.Empty;
if (configuration.IsConcurrencyFuzzingEnabled &&
(configuration.SchedulingStrategy is "replay" || configuration.ScheduleFile.Length > 0))
{
error = "Replaying a bug trace is not supported in concurrency fuzzing.";
}
if (configuration.SchedulingStrategy is "portfolio")
{
error = "Portfolio testing strategy is only available in parallel testing.";
}
if (!string.IsNullOrEmpty(error))
{
if (configuration.DisableEnvironmentExit)
{
throw new Exception(error);
}
else
{
Error.ReportAndExit(error);
}
}
this.Scheduler = OperationScheduler.Setup(configuration);
if (TelemetryClient is null)
{
TelemetryClient = new CoyoteTelemetryClient(this.Configuration);
}
}
/// <summary>
/// Initializes a new instance of the <see cref="TaskOperation"/> class.
/// </summary>
internal TaskOperation(ulong operationId, OperationScheduler scheduler)
: base()
{
this.Scheduler = scheduler;
this.Id = operationId;
this.Name = $"Task({operationId})";
this.JoinDependencies = new HashSet <Task>();
}
public CoyoteTasks.Task ScheduleAction(Action action, Task predecessor, CancellationToken cancellationToken)
{
// TODO: support cancellations during testing.
this.Assert(action != null, "The task cannot execute a null action.");
ulong operationId = this.Runtime.GetNextOperationId();
var op = new TaskOperation(operationId, this.Scheduler);
this.Scheduler.RegisterOperation(op);
op.OnEnabled();
var task = new Task(() =>
{
try
{
// Update the current asynchronous control flow with the current runtime instance,
// allowing future retrieval in the same asynchronous call stack.
CoyoteRuntime.AssignAsyncControlFlowRuntime(this.Runtime);
OperationScheduler.StartOperation(op);
if (predecessor != null)
{
op.OnWaitTask(predecessor);
}
action();
}
catch (Exception ex)
{
// Report the unhandled exception unless it is our ExecutionCanceledException which is our
// way of terminating async task operations at the end of the test iteration.
if (!(ex is ExecutionCanceledException))
{
this.ReportUnhandledExceptionInOperation(op, ex);
}
// and rethrow it
throw;
}
finally
{
IO.Debug.WriteLine("<ScheduleDebug> Completed operation '{0}' on task '{1}'.", op.Name, Task.CurrentId);
op.OnCompleted();
}
});
// Schedule a task continuation that will schedule the next enabled operation upon completion.
task.ContinueWith(t => this.Scheduler.ScheduleNextEnabledOperation(), TaskScheduler.Current);
IO.Debug.WriteLine("<CreateLog> Operation '{0}' was created to execute task '{1}'.", op.Name, task.Id);
this.Scheduler.ScheduleOperation(op, task.Id);
task.Start();
this.Scheduler.WaitOperationStart(op);
this.Scheduler.ScheduleNextEnabledOperation();
return(new CoyoteTasks.Task(this, task));
}
public CoyoteTasks.Task <TResult> ScheduleFunction <TResult>(Func <CoyoteTasks.Task <TResult> > function, Task predecessor,
CancellationToken cancellationToken)
{
// TODO: support cancellations during testing.
this.Assert(function != null, "The task cannot execute a null function.");
ulong operationId = this.Runtime.GetNextOperationId();
var op = new TaskOperation(operationId, this.Scheduler);
this.Scheduler.RegisterOperation(op);
op.OnEnabled();
var task = new Task <Task <TResult> >(() =>
{
try
{
// Update the current asynchronous control flow with the current runtime instance,
// allowing future retrieval in the same asynchronous call stack.
CoyoteRuntime.AssignAsyncControlFlowRuntime(this.Runtime);
OperationScheduler.StartOperation(op);
if (predecessor != null)
{
op.OnWaitTask(predecessor);
}
CoyoteTasks.Task <TResult> resultTask = function();
this.OnWaitTask(operationId, resultTask.UncontrolledTask);
return(resultTask.UncontrolledTask);
}
catch (Exception ex)
{
// Report the unhandled exception and rethrow it.
this.ReportUnhandledExceptionInOperation(op, ex);
throw;
}
finally
{
IO.Debug.WriteLine("<ScheduleDebug> Completed operation '{0}' on task '{1}'.", op.Name, Task.CurrentId);
op.OnCompleted();
}
});
Task <TResult> innerTask = task.Unwrap();
// Schedule a task continuation that will schedule the next enabled operation upon completion.
innerTask.ContinueWith(t => this.Scheduler.ScheduleNextEnabledOperation(), TaskScheduler.Current);
IO.Debug.WriteLine("<CreateLog> Operation '{0}' was created to execute task '{1}'.", op.Name, task.Id);
this.Scheduler.ScheduleOperation(op, task.Id);
task.Start();
this.Scheduler.WaitOperationStart(op);
this.Scheduler.ScheduleNextEnabledOperation();
return(new CoyoteTasks.Task <TResult>(this, innerTask));
}
/// <summary>
/// Returns a test report with the scheduling statistics.
/// </summary>
internal TestReport GetSchedulerReport(OperationScheduler scheduler)
{
lock (scheduler.SyncObject)
{
TestReport report = new TestReport(this.Configuration);
if (scheduler.BugFound)
{
report.NumOfFoundBugs++;
report.ThrownException = scheduler.UnhandledException;
report.BugReports.Add(scheduler.BugReport);
}
if (this.Strategy.IsFair())
{
report.NumOfExploredFairSchedules++;
report.TotalExploredFairSteps += scheduler.ScheduledSteps;
if (report.MinExploredFairSteps < 0 ||
report.MinExploredFairSteps > scheduler.ScheduledSteps)
{
report.MinExploredFairSteps = scheduler.ScheduledSteps;
}
if (report.MaxExploredFairSteps < scheduler.ScheduledSteps)
{
report.MaxExploredFairSteps = scheduler.ScheduledSteps;
}
if (scheduler.Strategy.HasReachedMaxSchedulingSteps())
{
report.MaxFairStepsHitInFairTests++;
}
if (scheduler.ScheduledSteps >= report.Configuration.MaxUnfairSchedulingSteps)
{
report.MaxUnfairStepsHitInFairTests++;
}
}
else
{
report.NumOfExploredUnfairSchedules++;
if (scheduler.Strategy.HasReachedMaxSchedulingSteps())
{
report.MaxUnfairStepsHitInUnfairTests++;
}
}
return(report);
}
}
/// <summary>
/// Runs a new asynchronous event handler for the specified actor.
/// This is a fire and forget invocation.
/// </summary>
/// <param name="actor">The actor that executes this event handler.</param>
/// <param name="initialEvent">Optional event for initializing the actor.</param>
/// <param name="isFresh">If true, then this is a new actor.</param>
/// <param name="syncCaller">Caller actor that is blocked for quiscence.</param>
private void RunActorEventHandler(Actor actor, Event initialEvent, bool isFresh, Actor syncCaller)
{
var op = this.Scheduler.GetOperationWithId <ActorOperation>(actor.Id.Value);
op.OnEnabled();
Task task = new Task(async() =>
{
try
{
// Update the current asynchronous control flow with this runtime instance,
// allowing future retrieval in the same asynchronous call stack.
AssignAsyncControlFlowRuntime(this);
OperationScheduler.StartOperation(op);
if (isFresh)
{
await actor.InitializeAsync(initialEvent);
}
await actor.RunEventHandlerAsync();
if (syncCaller != null)
{
this.EnqueueEvent(syncCaller, new QuiescentEvent(actor.Id), actor, actor.OperationGroupId, null);
}
if (!actor.IsHalted)
{
ResetProgramCounter(actor);
}
IO.Debug.WriteLine("<ScheduleDebug> Completed operation {0} on task '{1}'.", actor.Id, Task.CurrentId);
op.OnCompleted();
// The actor is inactive or halted, schedule the next enabled operation.
this.Scheduler.ScheduleNextEnabledOperation();
}
catch (Exception ex)
{
this.ProcessUnhandledExceptionInOperation(op, ex);
}
});
this.Scheduler.ScheduleOperation(op, task.Id);
task.Start();
this.Scheduler.WaitOperationStart(op);
}
public CoyoteTasks.Task <TResult> ScheduleDelegate <TResult>(Delegate work, Task predecessor, CancellationToken cancellationToken)
{
// TODO: support cancellations during testing.
this.Assert(work != null, "The task cannot execute a null delegate.");
ulong operationId = this.Runtime.GetNextOperationId();
var op = new TaskOperation(operationId, this.Scheduler);
this.Scheduler.RegisterOperation(op);
op.OnEnabled();
var task = new Task <TResult>(() =>
{
try
{
// Update the current asynchronous control flow with the current runtime instance,
// allowing future retrieval in the same asynchronous call stack.
CoyoteRuntime.AssignAsyncControlFlowRuntime(this.Runtime);
OperationScheduler.StartOperation(op);
if (predecessor != null)
{
op.OnWaitTask(predecessor);
}
if (work is Func <Task> funcWithTaskResult)
{
Task resultTask = funcWithTaskResult();
this.OnWaitTask(operationId, resultTask);
if (resultTask is TResult typedResultTask)
{
return(typedResultTask);
}
}
else if (work is Func <Task <TResult> > funcWithGenericTaskResult)
{
Task <TResult> resultTask = funcWithGenericTaskResult();
this.OnWaitTask(operationId, resultTask);
return(resultTask.Result);
}
else if (work is Func <TResult> funcWithGenericResult)
{
return(funcWithGenericResult());
}
return(default);
/// <summary>
/// Initializes a new instance of the <see cref="TestingEngine"/> class.
/// </summary>
private TestingEngine(Configuration configuration, TestMethodInfo testMethodInfo)
{
this.Configuration = configuration;
this.TestMethodInfo = testMethodInfo;
this.DefaultLogger = new ConsoleLogger()
{
LogLevel = configuration.LogLevel
};
this.Logger = this.DefaultLogger;
this.Profiler = new Profiler();
this.PerIterationCallbacks = new HashSet <Action <uint> >();
this.TestReport = new TestReport(configuration);
this.ReadableTrace = string.Empty;
this.ReproducibleTrace = string.Empty;
this.CancellationTokenSource = new CancellationTokenSource();
this.PrintGuard = 1;
if (configuration.IsDebugVerbosityEnabled)
{
IO.Debug.IsEnabled = true;
}
// Do some sanity checking.
string error = string.Empty;
if (configuration.IsSystematicFuzzingEnabled &&
(configuration.SchedulingStrategy is "replay" || configuration.ScheduleFile.Length > 0))
{
error = "Replaying a bug trace is not currently supported in systematic fuzzing.";
}
if (!string.IsNullOrEmpty(error))
{
Error.Report(error);
throw new InvalidOperationException(error);
}
this.Scheduler = OperationScheduler.Setup(configuration);
TelemetryClient = TelemetryClient.GetOrCreate(this.Configuration);
}
/// <summary>
/// Initializes a new instance of the <see cref="ControlledRuntime"/> class.
/// </summary>
internal ControlledRuntime(Configuration configuration, ISchedulingStrategy strategy,
IRandomValueGenerator valueGenerator)
: base(configuration, valueGenerator)
{
IncrementExecutionControlledUseCount();
this.RootTaskId = Task.CurrentId;
this.NameValueToActorId = new ConcurrentDictionary <string, ActorId>();
this.CoverageInfo = new CoverageInfo();
var scheduleTrace = new ScheduleTrace();
if (configuration.IsLivenessCheckingEnabled)
{
strategy = new TemperatureCheckingStrategy(configuration, this.Monitors, strategy);
}
this.Scheduler = new OperationScheduler(this, strategy, scheduleTrace, this.Configuration);
this.TaskController = new TaskController(this, this.Scheduler);
}
/// <summary>
/// Initializes a new instance of the <see cref="TaskController"/> class.
/// </summary>
internal TaskController(ControlledRuntime runtime, OperationScheduler scheduler)
{
this.Runtime = runtime;
this.Scheduler = scheduler;
}
/// <summary>
/// Initializes a new instance of the <see cref="TaskDelayOperation"/> class.
/// </summary>
internal TaskDelayOperation(ulong operationId, string name, uint delay, OperationScheduler scheduler)
: base(operationId, name, scheduler)
{
this.Timeout = delay > int.MaxValue ? int.MaxValue : (int)delay;
}
public CoyoteTasks.Task<TResult> ScheduleDelegate<TResult>(Delegate work, Task predecessor, CancellationToken cancellationToken)
{
// TODO: support cancellations during testing.
this.Assert(work != null, "The task cannot execute a null delegate.");
ulong operationId = this.Runtime.GetNextOperationId();
var op = new TaskOperation(operationId, this.Scheduler);
this.Scheduler.RegisterOperation(op);
op.OnEnabled();
var task = new Task<TResult>(() =>
{
try
{
// Update the current asynchronous control flow with the current runtime instance,
// allowing future retrieval in the same asynchronous call stack.
CoyoteRuntime.AssignAsyncControlFlowRuntime(this.Runtime);
OperationScheduler.StartOperation(op);
if (predecessor != null)
{
op.OnWaitTask(predecessor);
}
if (work is Func<Task> funcWithTaskResult)
{
Task resultTask = funcWithTaskResult();
this.OnWaitTask(operationId, resultTask);
if (resultTask is TResult typedResultTask)
{
return typedResultTask;
}
}
else if (work is Func<Task<TResult>> funcWithGenericTaskResult)
{
Task<TResult> resultTask = funcWithGenericTaskResult();
this.OnWaitTask(operationId, resultTask);
return resultTask.Result;
}
else if (work is Func<TResult> funcWithGenericResult)
{
return funcWithGenericResult();
}
return default;
}
catch (Exception ex)
{
// Report the unhandled exception and rethrow it.
ReportUnhandledExceptionInOperation(op, ex);
throw;
}
finally
{
IO.Debug.WriteLine("<ScheduleDebug> Completed operation '{0}' on task '{1}'.", op.Name, Task.CurrentId);
op.OnCompleted();
}
}, cancellationToken);
// Schedule a task continuation that will schedule the next enabled operation upon completion.
task.ContinueWith(t => this.Scheduler.ScheduleNextEnabledOperation(), TaskScheduler.Current);
IO.Debug.WriteLine("<CreateLog> Operation '{0}' was created to execute task '{1}'.", op.Name, task.Id);
this.Scheduler.ScheduleOperation(op, task.Id);
task.Start();
this.Scheduler.WaitOperationStart(op);
this.Scheduler.ScheduleNextEnabledOperation();
return new CoyoteTasks.Task<TResult>(this, task);
}
/// <summary>
/// Initializes a new instance of the <see cref="TaskOperation"/> class.
/// </summary>
internal TaskOperation(ulong operationId, string name, OperationScheduler scheduler)
: base(operationId, name)
{
this.Scheduler = scheduler;
this.JoinDependencies = new HashSet <Task>();
}
/// <summary>
/// Runs the next testing iteration for the specified test method.
/// </summary>
private bool RunNextIteration(TestMethodInfo methodInfo, uint iteration)
{
if (!this.Scheduler.InitializeNextIteration(iteration))
{
// The next iteration cannot run, so stop exploring.
return(false);
}
if (!this.Scheduler.IsReplayingSchedule && this.ShouldPrintIteration(iteration + 1))
{
this.Logger.WriteLine(LogSeverity.Important, $"..... Iteration #{iteration + 1}");
// Flush when logging to console.
if (this.Logger is ConsoleLogger)
{
Console.Out.Flush();
}
}
// Runtime used to serialize and test the program in this iteration.
CoyoteRuntime runtime = null;
// Logger used to intercept the program output if no custom logger
// is installed and if verbosity is turned off.
InMemoryLogger runtimeLogger = null;
// Gets a handle to the standard output and error streams.
var stdOut = Console.Out;
var stdErr = Console.Error;
try
{
// Creates a new instance of the controlled runtime.
runtime = new CoyoteRuntime(this.Configuration, this.Scheduler);
// If verbosity is turned off, then intercept the program log, and also redirect
// the standard output and error streams to the runtime logger.
if (!this.Configuration.IsVerbose)
{
runtimeLogger = new InMemoryLogger();
if (this.Logger != this.DefaultLogger)
{
runtimeLogger.UserLogger = this.Logger;
}
runtime.Logger = runtimeLogger;
Console.SetOut(runtimeLogger.TextWriter);
Console.SetError(runtimeLogger.TextWriter);
}
else if (this.Logger != this.DefaultLogger)
{
runtime.Logger = this.Logger;
}
this.InitializeCustomActorLogging(runtime.DefaultActorExecutionContext);
// Runs the test and waits for it to terminate.
Task task = runtime.RunTestAsync(methodInfo.Method, methodInfo.Name);
task.Wait();
// Invokes the user-specified iteration disposal method.
methodInfo.DisposeCurrentIteration();
// Invoke the per iteration callbacks, if any.
foreach (var callback in this.PerIterationCallbacks)
{
callback(iteration);
}
runtime.LogWriter.LogCompletion();
this.GatherTestingStatistics(runtime);
if (!this.Scheduler.IsReplayingSchedule && this.TestReport.NumOfFoundBugs > 0)
{
if (runtimeLogger != null)
{
this.ReadableTrace = string.Empty;
if (this.Configuration.IsTelemetryEnabled)
{
this.ReadableTrace += $"<TelemetryLog> Anonymized telemetry is enabled, see {LearnAboutTelemetryUrl}.\n";
}
this.ReadableTrace += runtimeLogger.ToString();
this.ReadableTrace += this.TestReport.GetText(this.Configuration, "<StrategyLog>");
}
if (runtime.SchedulingPolicy is SchedulingPolicy.Interleaving)
{
this.ReproducibleTrace = this.Scheduler.Trace.Serialize(
this.Configuration, this.Scheduler.IsScheduleFair);
}
}
}
finally
{
if (!this.Configuration.IsVerbose)
{
// Restores the standard output and error streams.
Console.SetOut(stdOut);
Console.SetError(stdErr);
}
if (this.Configuration.IsSystematicFuzzingFallbackEnabled &&
runtime.SchedulingPolicy is SchedulingPolicy.Interleaving &&
(runtime.ExecutionStatus is ExecutionStatus.ConcurrencyUncontrolled ||
runtime.ExecutionStatus is ExecutionStatus.Deadlocked))
{
// Detected uncontrolled concurrency or deadlock, so switch to systematic fuzzing.
this.Scheduler = OperationScheduler.Setup(this.Configuration, SchedulingPolicy.Fuzzing,
this.Scheduler.ValueGenerator);
this.Logger.WriteLine(LogSeverity.Important, $"..... Iteration #{iteration + 1} " +
$"enables systematic fuzzing due to uncontrolled concurrency");
}
else if (runtime.ExecutionStatus is ExecutionStatus.BoundReached)
{
this.Logger.WriteLine(LogSeverity.Important, $"..... Iteration #{iteration + 1} " +
$"hit bound of '{this.Scheduler.StepCount}' scheduling steps");
}
else if (runtime.ExecutionStatus is ExecutionStatus.BugFound)
{
if (!this.Scheduler.IsReplayingSchedule)
{
this.Logger.WriteLine(LogSeverity.Important, $"..... Iteration #{iteration + 1} " +
$"found bug #{this.TestReport.NumOfFoundBugs}");
}
this.Logger.WriteLine(LogSeverity.Error, runtime.BugReport);
}
else if (this.Scheduler.IsReplayingSchedule)
{
this.Logger.WriteLine(LogSeverity.Error, "Failed to reproduce the bug.");
}
// Cleans up the runtime before the next iteration starts.
runtimeLogger?.Close();
runtimeLogger?.Dispose();
runtime?.Dispose();
}
return(true);
}
