/// <summary>
/// Called before starting a new test run to clear all the transient values to its initial values.
/// </summary>
public void Reset()
{
lock (this.stateLock)
{
// reset run-time objects
this.randomizer = new Helpers.SeededRandomizer(this.Meta.schedulingSeed);
this.counter = 0;
this.programState = new ProgramState();
this.SessionFinished = new TaskCompletionSource <SessionRecord>();
this.pendingRequests = new HashSet <RemoteMethodInvocation>();
this.testTrace = new List <DecisionTrace>();
this.runtimeLog = new List <string>();
this.IsFinished.Value = false;
this.timeout = new Timer(_ =>
{
string currentTask = this.programState.currentTask.ToString();
var errorInfo = $"No activity for {(Meta.timeoutMs / 1000).ToString()} seconds!\n Program State: [ {this.programState.GetCurrentStateString()} ]\n Possible reasons:\n\t- Not calling EndTask({currentTask})\n\t- Calling ContextSwitch from an undeclared Task\n\t- Some Tasks not being modelled";
this.Finish(TestResult.InactivityTimeout, errorInfo);
}, null, Meta.timeoutMs, Timeout.Infinite);
this.currentRecord = new SessionRecord(this.Id, this.Meta.schedulingSeed);
this.currentRecord.RecordBegin();
}
// create a continuation callback that will notify the client once the test is finished
this.SessionFinished.Task.ContinueWith(prev => {
//Console.WriteLine("\n[TestingSession.SessionFinished] was settled");
#if DEBUG
Console.WriteLine(Profiler.ToString());
#endif
// emit onComplete event
this.OnComplete(this, prev.Result);
});
}
/// <summary>
/// Called internally to end the test. This method asynchronously resolves the <see cref="SessionFinished"/>
/// TaskCompletionSource and returns immediately to the caller.
/// If the test run has encountered a bug (i.e., AssertionFailure is thrown), it drops all pending requests.
/// This method is idempotent with respect to a single test run -- only the first call will move the object's
/// state to IsFinished, and any subsequent calls potentially made by concurrent requests will not do anything.
/// </summary>
/// <param name="result">The result of the test run</param>
/// <param name="reason">Any description of the result</param>
private void Finish(TestResult result, string reason = "")
{
// Ensure the following is called at most once
if (!this.IsFinished.Value)
{
this.IsFinished.Value = true;
// Drop all pending tasks if finished due to error
if (result != TestResult.Pass)
{
// Console.WriteLine(" Dropping {0} tasks", this.programState.taskToTcs.Count);
lock (programState)
{
foreach (var item in this.programState.taskToTcs)
{
#if DEBUG
Console.WriteLine(" ... dropping Session {2} Task {0} ({1})", item.Key, item.Value.Task.Status.ToString(), this.Id);
#endif
item.Value.TrySetException(new TestFailedException(reason));
this.programState.taskToTcs.Remove(item.Key);
}
}
}
// The following procedure needs to be done asynchronously
// because this call to Finish must return to the caller
Task.Run(() =>
{
SessionRecord record = this.currentRecord;
// Wait for other threads to return first
// if there is some thread that is not returning, then there is something wrong with the user program.
// One last pending request is the current request: WaitForMainTask
bool userProgramFaulty = false;
string userProgramFaultyReason = "";
int wait = 2000;
while (this.pendingRequests.Count > 0)
{
#if DEBUG
lock (this.pendingRequests)
{
Console.WriteLine("Waiting for {0} requests to complete...\t({2} Tasks still in queue){1}", this.pendingRequests.Count, String.Join("", this.pendingRequests.Select(item => "\n\t... " + item.ToString())), programState.taskToTcs.Count);
}
#endif
Thread.Sleep(50);
wait -= 50;
if (wait <= 0)
{
userProgramFaulty = true;
var pendingList = String.Join("", this.pendingRequests.Select(req => "\n\t - " + req.ToString()));
userProgramFaultyReason = $"Could not resolve {this.pendingRequests.Count} pending requests!\n\t waiting on:{pendingList}.\n\nPossible reasons:\n\t- Some Tasks not being modelled\n\t- Calling ContextSwitch in a Task that is not declared";
break;
}
}
// Clear timer
this.timeout.Change(Timeout.Infinite, Timeout.Infinite);
this.timeout.Dispose();
#if DEBUG
Console.WriteLine("\n\nOnly {0} last request to complete...", this.pendingRequests.Count);
#endif
record.RecordEnd();
record.numDecisions = testTrace.Count;
if (PrintVerbosity > 1)
{
Console.WriteLine("\n===[ Decision Trace ({0} decision points) ]=====\n", testTrace.Count);
PrintTrace(testTrace);
}
// TODO: Uncomment while doing for Traces
/* if (testTrace.Count == 0)
* {
* userProgramFaulty = true;
* userProgramFaultyReason = "There seems to be no concurrency modeled in the user program - 0 scheduling decisions were made";
* } */
// if result is set, then there was something wrong with the user program so we do not record the trace
if (userProgramFaulty)
{
// var pendingList = String.Join("", this.pendingRequests.Select(req => "\n\t - " + req.ToString()));
// var errorInfo = $"Could not resolve {this.pendingRequests.Count} pending requests!\n\t waiting on:{pendingList}.\n\nPossible reasons:\n\t- Some Tasks not being modelled\n\t- Calling ContextSwitch in a Task that is not declared";
record.RecordResult(TestResult.FaultyProgram, userProgramFaultyReason);
}
else
{
bool reproducible = false;
// Write trace only if this is the first time running this session
if (!this.IsReplayMode)
{
record.RecordResult(result, reason);
this.traceFile.Write(String.Join("\n", this.testTrace.Select(step => step.ToString())));
this.traceFile.Close();
this.logFile.Write(String.Join("\n", this.runtimeLog));
this.logFile.Close();
}
// If it is in replay mode, compare with previous trace
/* else
* {
* // if the results are different, then something is wrong with the user program
* if (this.LastRecord.result != result || this.LastRecord.reason != reason)
* {
* var errorInfo = $"Could not reproduce the trace for Session {this.Id}.\nPossible reasons:\n\t- Some Tasks not being modelled";
* record.RecordResult(TestResult.FaultyProgram, errorInfo);
* Console.WriteLine("\n\n!!! Result Mismatch:\n Last: {0} {1},\n Now: {2} {3} \n", this.LastRecord.result.ToString(), this.LastRecord.reason, result.ToString(), reason);
* }
* else
* {
* var traceText = File.ReadAllText(this.traceFilePath);
* List<DecisionTrace> previousTrace = traceText.Split(new[] { '\n' }, StringSplitOptions.RemoveEmptyEntries).Select(line => DecisionTrace.FromString(line)).ToList();
*
* //PrintTrace(previousTrace);
*
* // if the traces are different, then something is wrong with the user program
* if (this.testTrace.Count != previousTrace.Count)
* {
* var errorInfo = $"Could not reproduce the trace for Session {this.Id}.\nPossible reasons:\n\t- Some Tasks not being modelled";
* record.RecordResult(TestResult.FaultyProgram, errorInfo);
*
* Console.WriteLine("\n\n!!! Trace Length Mismatch: Last = {0} vs Now = {1}\n", previousTrace.Count.ToString(), this.testTrace.Count.ToString());
* PrintTrace(previousTrace);
* Console.WriteLine("----- versus -----");
* PrintTrace(this.testTrace);
* }
* else
* {
* bool match = this.testTrace.Select((t, i) => previousTrace[i] == t).Aggregate(true, (acc, b) => acc && b);
*
* // if the traces are different, then something is wrong with the user program
* if (!match)
* {
* var errorInfo = $"Could not reproduce the trace for Session {this.Id}.\nPossible reasons:\n\t- Some Tasks not being modelled";
* record.RecordResult(TestResult.FaultyProgram, errorInfo);
*
* Console.WriteLine("\n\n!!! Trace Mismatch \n");
* PrintTrace(previousTrace);
* Console.WriteLine("----- versus -----");
* PrintTrace(this.testTrace);
* }
* else
* {
* // Console.WriteLine("\n\t... Decision trace was reproduced successfully");
* record.RecordResult(result, reason);
* reproducible = true;
* }
* }
* }
* } */
lock (this.records)
{
if (!this.IsReplayMode || reproducible)
{
this.records.Add(record);
}
}
}
#if DEBUG
//Console.WriteLine(Profiler.ToString());
#endif
Console.WriteLine("<<< Ending Session {0} : {1} >>>", this.Id, result.ToString());
// signal the end of the test, so that WaitForMainTask can return
this.SessionFinished.SetResult(record);
});
}
}