public override ExitCode Execute()
{
AutoParam.ApplyParamsAndDefaults(this, Environment.GetCommandLineArgs());
if (Verbose)
{
Gauntlet.Log.Level = Gauntlet.LogLevel.Verbose;
}
IEnumerable <string> TestList = new string[0];
// If a group was specified...
if (Group.Length > 0)
{
// if a group was specified, find those tests
TestList = Utils.TestConstructor.GetTestNamesByGroup <ITestNode>(Group, new[] { "Gauntlet.SelfTest" });
}
else if (Tests.Length > 0)
{
// list of tests?
TestList = Tests.Split(',').Select(S => S.Trim());
}
else
{
// Ok, run everything!
TestList = Utils.TestConstructor.GetTestNamesByGroup <ITestNode>(null, new[] { "Gauntlet.SelfTest" });
}
// Create the list of tests
IEnumerable <ITestNode> Nodes = Utils.TestConstructor.ConstructTests <ITestNode, string[]>(TestList, null, new[] { "Gauntlet.SelfTest" });
// Create the test executor
var Executor = new TextExecutor();
TestExecutorOptions Options = new TestExecutorOptions();
AutoParam.ApplyParamsAndDefaults(Options, this.Params);
bool AllTestsPassed = Executor.ExecuteTests(Options, Nodes);
return(AllTestsPassed ? ExitCode.Success : ExitCode.Error_TestFailure);
}
/// <summary>
/// Executes the provided tests. Currently tests are executed synchronously
/// </summary>
/// <param name="Context"></param>
public bool ExecuteTests(TestExecutorOptions InOptions, IEnumerable <ITestNode> RequiredTests)
{
Options = InOptions;
Log.Info("Preparing to start {0} automation test(s)", RequiredTests.Count());
// install a cancel handler so we can stop parallel-for gracefully
Action CancelHandler = delegate()
{
Log.Info("Cancelling Tests");
IsCancelled = true;
};
Action PostCancelHandler = delegate()
{
HaveReceivedPostAbort = true;
};
Globals.AbortHandlers.Add(CancelHandler);
Globals.PostAbortHandlers.Add(PostCancelHandler);
StartTime = DateTime.Now;
CurrentTestPass = 0;
IsRunning = true;
List <int> FailedPassList = new List <int>();
int MaxParallelTasks = 0;
int MaxStartingTasks = 0;
// sort by priority
if (Options.Parallel > 1)
{
RequiredTests = RequiredTests.OrderBy(Node => Node.Priority);
}
for (CurrentTestPass = 0; CurrentTestPass < Options.TestLoops; CurrentTestPass++)
{
// do not start a pass if cancelled
if (IsCancelled)
{
break;
}
if (CurrentTestPass > 0)
{
// if repeating tests wait a little bit. If there was a crash CR might still be
// processing things.
Thread.Sleep(10000);
}
DateTime StartPassTime = DateTime.Now;
Log.Info("Starting test pass {0} of {1}", CurrentTestPass + 1, Options.TestLoops);
// Tests that we want to run
List <TestExecutionInfo> PendingTests = RequiredTests.Select(N => new TestExecutionInfo(N)).ToList();
// Tests that are in the process of starting
List <TestExecutionInfo> StartingTests = new List <TestExecutionInfo>();
List <Thread> StartingTestThreads = new List <Thread>();
// Tests that have been started and we're ticking/checking
List <TestExecutionInfo> RunningTests = new List <TestExecutionInfo>();
// Completed tests
List <TestExecutionInfo> CompletedTests = new List <TestExecutionInfo>();
DateTime LastUpdateMsg = DateTime.MinValue;
DateTime LastReadyCheck = DateTime.MinValue;
DateTime LastStatusUpdateTime = DateTime.MinValue;
const double ReadyCheckPeriod = 30.0;
const double StatusUpdatePeriod = 60.0;
while (CompletedTests.Count() < RequiredTests.Count() && IsCancelled == false)
{
Monitor.Enter(Globals.MainLock);
int SecondsRunning = (int)(DateTime.Now - StartPassTime).TotalSeconds;
int InProgressCount = RunningTests.Count() + StartingTests.Count();
double TimeSinceLastReadyCheck = (DateTime.Now - LastReadyCheck).TotalSeconds;
// Are any tests ready to run?
if (InProgressCount < Options.Parallel &&
PendingTests.Count() > 0 &&
TimeSinceLastReadyCheck >= ReadyCheckPeriod)
{
TestExecutionInfo TestToStart = null;
List <ITestNode> TestsFailingToStart = new List <ITestNode>();
// find a node that can run, and
// find the first test that can run....
for (int i = 0; i < PendingTests.Count(); i++)
{
TestExecutionInfo NodeInfo = PendingTests[i];
ITestNode Node = NodeInfo.TestNode;
bool IsTestReady = false;
try
{
IsTestReady = Node.IsReadyToStart();
}
catch (System.Exception ex)
{
Log.Error("Test {0} threw an exception during ready check. Ex: {1}", Node, ex);
PendingTests[i] = null;
NodeInfo.PreStartTime = NodeInfo.PostStartTime = NodeInfo.EndTime = DateTime.Now;
CompletedTests.Add(NodeInfo);
}
if (IsTestReady)
{
// if ready then take it and stop looking
TestToStart = NodeInfo;
if (NodeInfo.FirstReadyCheckTime == DateTime.MinValue)
{
NodeInfo.FirstReadyCheckTime = DateTime.Now;
}
break;
}
else
{
// track the time that this test should have been able to run due to no other tests
// consuming resources (at least locally...)
// TODO - how can tests express resource requirements in a generic way?
// TODO - what about the situation where no tests can run so all FirstCheck times are set, but
// then a test starts and consumes all resources?
if (RunningTests.Count() == 0 && StartingTests.Count() == 0)
{
if (NodeInfo.FirstReadyCheckTime == DateTime.MinValue)
{
NodeInfo.FirstReadyCheckTime = DateTime.Now;
}
double TimeWaiting = (DateTime.Now - NodeInfo.FirstReadyCheckTime).TotalSeconds;
if (TimeWaiting >= Options.Wait)
{
Log.Warning("Test {0} has been waiting to run resource-free for {1:00} seconds. Removing from wait list", Node, TimeWaiting);
PendingTests[i] = null;
NodeInfo.PreStartTime = NodeInfo.PostStartTime = NodeInfo.EndTime = DateTime.Now;
NodeInfo.Result = TestExecutionInfo.ExecutionResult.TimedOut;
CompletedTests.Add(NodeInfo);
}
}
}
}
// remove anything we nulled
PendingTests = PendingTests.Where(T => T != null).ToList();
if (TestToStart != null)
{
Log.Info("Test {0} is ready to run", TestToStart);
PendingTests.Remove(TestToStart);
StartingTests.Add(TestToStart);
// StartTest is the only thing we do on a thread because it's likely to be the most time consuming
// as build are copied so will get the most benefit from happening in parallel
Thread StartThread = new Thread(() =>
{
Thread.CurrentThread.IsBackground = true;
// start the test, this also fills in the pre/post start times
bool Started = StartTest(TestToStart, CurrentTestPass, Options.TestLoops);
lock (Globals.MainLock)
{
if (Started == false)
{
TestToStart.PostStartTime = TestToStart.EndTime = DateTime.Now;
CompletedTests.Add(TestToStart);
Log.Error("Test {0} failed to start", TestToStart);
}
else
{
RunningTests.Add(TestToStart);
}
StartingTests.Remove(TestToStart);
StartingTestThreads.Remove(Thread.CurrentThread);
}
});
if (StartingTests.Count > MaxStartingTasks)
{
MaxStartingTasks = StartingTests.Count;
}
// track the thread and start it
StartingTestThreads.Add(StartThread);
StartThread.Start();
}
else
{
// don't check for a while as querying kits for availability can be expensive
LastReadyCheck = DateTime.Now;
}
}
// Tick all running tests
foreach (TestExecutionInfo TestInfo in RunningTests)
{
TestResult Result = TickTest(TestInfo);
// invalid = no result yet
if (Result == TestResult.Invalid)
{
TimeSpan RunningTime = DateTime.Now - TestInfo.PostStartTime;
if ((SecondsRunning % 60) == 0)
{
Log.Verbose("Test {0} is still running. {1:00} seconds elapsed, will timeout in {2:00} seconds",
TestInfo,
RunningTime.TotalSeconds,
TestInfo.TestNode.MaxDuration - RunningTime.TotalSeconds);
LastUpdateMsg = DateTime.Now;
}
}
else
{
TestInfo.EndTime = DateTime.Now;
TestInfo.Result = Result == TestResult.Passed ? TestExecutionInfo.ExecutionResult.Passed : TestExecutionInfo.ExecutionResult.Failed;
CompletedTests.Add(TestInfo);
}
}
// remove any tests that were completed
RunningTests = RunningTests.Where(R => CompletedTests.Contains(R) == false).ToList();
if ((DateTime.Now - LastStatusUpdateTime).TotalSeconds >= StatusUpdatePeriod)
{
LastStatusUpdateTime = DateTime.Now;
Log.Info("Status: Completed:{0}, Running:{1}, Starting: {2}, Waiting:{3}",
CompletedTests.Count(), RunningTests.Count(), StartingTests.Count(), PendingTests.Count());
}
if (InProgressCount > MaxParallelTasks)
{
MaxParallelTasks = RunningTests.Count();
}
// Release our global lock before we loop
Monitor.Exit(Globals.MainLock);
// sleep a while before we tick our running tasks again
Thread.Sleep(500);
}
if (IsCancelled)
{
DateTime StartTime = DateTime.Now;
Log.Info("Cleaning up pending and running tests.");
while (HaveReceivedPostAbort == false)
{
Thread.Sleep(500);
double Elapsed = (DateTime.Now - StartTime).TotalSeconds;
if (Elapsed >= 5)
{
Log.Error("Giving up waiting for tests after {0:00} seconds", Elapsed);
break;
}
}
// tick anything running, this will also check IsCancelled and stop them
// forcibly kill anything waiting
if (StartingTestThreads.Count > 0)
{
foreach (Thread T in StartingTestThreads)
{
Log.Info("Aborting startup thread");
T.Abort();
}
Thread.Sleep(1000);
}
foreach (TestExecutionInfo TestInfo in StartingTests)
{
Log.Info("Forcing pending test {0} to run CleanupTest", TestInfo.TestNode.Name);
TestInfo.TestNode.CleanupTest();
CompletedTests.Add(TestInfo);
}
foreach (TestExecutionInfo TestInfo in RunningTests)
{
Log.Info("Ticking test {0} to cancel", TestInfo.TestNode.Name);
TestResult Res = TickTest(TestInfo);
CompletedTests.Add(TestInfo);
if (Res != TestResult.Failed)
{
Log.Warning("Ticking of cancelled test {0} returnd {1}", TestInfo.TestNode.Name, Res);
}
}
}
else
{
TimeSpan PassDuration = DateTime.Now - StartPassTime;
int FailedCount = 0;
int TestCount = CompletedTests.Count;
CompletedTests.ForEach(T =>
{
TimeSpan TimeWaiting = T.FirstReadyCheckTime - T.PreStartTime;
TimeSpan SetupTime = T.PostStartTime - T.PreStartTime;
TimeSpan TestDuration = T.EndTime - T.PostStartTime;
// status msg, kept uniform to avoid spam on notifiers (ie. don't include timestamps, etc)
string Msg = string.Format("Test {0} {1}", T.TestNode, T.Result);
if (T.Result != TestExecutionInfo.ExecutionResult.Passed)
{
FailedCount++;
}
Log.Info(Msg);
// log test timing to info
Log.Info(string.Format("Test Time: {0:mm\\:ss} (Waited:{1:mm\\:ss}, Setup:{2:mm\\:ss})", TestDuration, TimeWaiting, SetupTime));
});
if (Options.Parallel > 1)
{
Log.Info("MaxParallelTasks: {0}", MaxParallelTasks);
Log.Info("MaxStartingTasks: {0}", MaxStartingTasks);
}
// report all tests
ReportMasterSummary(CurrentTestPass + 1, Options.TestLoops, PassDuration, CompletedTests);
if (FailedCount > 0)
{
FailedPassList.Add(CurrentTestPass);
if (Options.StopOnError)
{
break;
}
}
}
// show details for multi passes
if (Options.TestLoops > 1)
{
Log.Info("Completed all passes. {0} of {1} completed without error", CurrentTestPass + 1 - FailedPassList.Count(), Options.TestLoops);
if (FailedPassList.Count > 0)
{
string FailedList = string.Join(",", FailedPassList);
Log.Warning("Failed passes: " + FailedList);
}
}
}
IsRunning = false;
Globals.AbortHandlers.Remove(CancelHandler);
Globals.PostAbortHandlers.Remove(PostCancelHandler);
return(FailedPassList.Count == 0 && !IsCancelled);
}