/// <summary>
/// Prune out all log text if test is passing.
/// If any failure data is present, strip out problematic characters.
/// </summary>
public void Cleanup()
{
ExecutionEventLog.RecordStatus("Post-processing logs.");
foreach (TestRecord test in Tests)
{
if (test.Variations.All(variation => variation.Result == Result.Pass))
{
test.Log = String.Empty;
foreach (VariationRecord variation in test.Variations)
{
variation.Log = String.Empty;
}
}
else
{
test.Log = StripInvalidXmlCharacters(test.Log);
foreach (VariationRecord variation in test.Variations)
{
variation.Log = StripInvalidXmlCharacters(variation.Log);
}
// In the case where a test had failing variations, we want
// to also include references to execution group log files
// that can provide context for the environment in which
// the test was run.
foreach (FileInfo file in mediator.ExecutionLogFiles)
{
test.ExecutionLogFiles.Add(file);
}
}
}
}
internal GatherTestCodeCoverageCommand(TestRecord test, DirectoryInfo logDirectory)
{
this.logDirectory = logDirectory;
this.test = test;
ExecutionEventLog.RecordStatus("Beginning Code Coverage session.");
CodeCoverageUtilities.BeginTrace();
}
internal static void UninstallKeyboardLayouts(ArrayList keyboardLayoutExclusionList)
{
uint flags;
bool result = false;
if (Environment.OSVersion.Version.Major >= 6)
{
for (int count = 0; count < vistaTipString.Length; count++)
{
if (QueryLayoutOrTipString(vistaTipString[count], 0) == IntPtr.Zero)
{
// Uninstall keyboard layouts which are not previously enabled
if (!keyboardLayoutExclusionList.Contains(vistaTipString[count]))
{
flags = ILOT_UNINSTALL;
result = InstallLayoutOrTip(vistaTipString[count], flags);
}
}
else
{
ExecutionEventLog.RecordStatus("Invalid Tip String.");
}
}
}
}
/// <summary>
/// Merges Code coverage results for a machine into a single set of results
/// </summary>
/// <param name="executionLogPath"></param>
internal static void MergeSingleMachineResults(DirectoryInfo executionLogPath)
{
FileInfo[] covDatas = executionLogPath.GetFiles("*.covdata", SearchOption.AllDirectories);
string coverageMergePath = Path.Combine(executionLogPath.FullName, "CodeCoverage");
if (Directory.Exists(coverageMergePath))
{
Directory.Delete(coverageMergePath, true);
}
Directory.CreateDirectory(coverageMergePath);
//Specify inputs to merge
StringBuilder mergeInput = new StringBuilder();
foreach (FileInfo covData in covDatas)
{
mergeInput.AppendLine(covData.FullName);
}
string inputsPath = Path.Combine(executionLogPath.FullName, "CoverageInputs.txt");
File.WriteAllText(inputsPath, mergeInput.ToString());
string command = "/I @" + inputsPath + " /O " + coverageMergePath;
ExecutionEventLog.RecordStatus("Merging Coverage results: " + coverageDataToolPath + " " + command);
if (ProcessUtilities.Run(coverageDataToolPath, command) != 0)
{
throw new ApplicationException("Code Coverage Merging failed");
}
ExecutionEventLog.RecordStatus("Clearing Redundant inputs coverage data.");
DeleteCoverageData(covDatas);
}
private static bool IsLayoutOrTipEnabled(string layoutOrTip)
{
int colon = layoutOrTip.IndexOf(":");
ushort lcid = ushort.Parse(layoutOrTip.Substring(0, colon), NumberStyles.HexNumber);
string[] layoutOrGuid = layoutOrTip.Substring(colon + 1).Replace("}", "").Split('{');
bool enabled = false;
Guid clsid = new Guid(layoutOrGuid[1]);
Guid profile = new Guid(layoutOrGuid[2]);
string key = String.Format(@"SOFTWARE\Microsoft\CTF\TIP\{0}\LanguageProfile\0x{1:x8}\{2}",
clsid.ToString("B"), lcid, profile.ToString("B"));
using (RegistryKey regKey = Registry.CurrentUser.OpenSubKey(key))
{
if (regKey != null)
{
object enable = regKey.GetValue("Enable");
int en = (int)enable;
ExecutionEventLog.RecordStatus("enabled." + en.ToString());
enabled = (enable == null) ? false : (0 != (int)enable);
}
}
return(enabled);
}
private static void PushStateImplementation(StatePool pool, StateModule stateModule)
{
ExecutionEventLog.RecordStatus("Recording Previous State: " + stateModule);
stateModule.StateImplementation.RecordPreviousState(stateModule);
ExecutionEventLog.RecordStatus("Applying State: " + stateModule);
stateModule.StateImplementation.ApplyState(stateModule);
StatePools[(int)pool].Push(stateModule);
}
public static ExecutionStateCommand Apply(TestRecord test, DirectoryInfo testBinariesDirectory)
{
ExecutionStateCommand command = new ExecutionStateCommand();
ExecutionEventLog.RecordStatus("Applying Execution State.");
StateCollection.ApplyDeployments(test.TestInfo.Deployments, testBinariesDirectory);
return(command);
}
public static SupportFileCommand Apply(List <TestRecord> tests, DirectoryInfo testBinariesDirectory, DirectoryInfo executionDirectory)
{
ExecutionEventLog.RecordStatus("STARTED : -------------- Copiying Support Files --------------- |");
CopySupportFiles(tests, testBinariesDirectory, executionDirectory);
ExecutionEventLog.RecordStatus("COMPLETED: -------------- Copiying Support Files --------------- |");
return(new SupportFileCommand());
}
/// <summary>
/// Cleans up process state after test has ended.
/// </summary>
internal void TestEnded(DateTime startTime)
{
pids.Clear();
ExecutionEventLog.RecordStatus("Now cleaning up processes.");
TerminateProcesses(IdentifyUnwantedProcesses(startTime));
ReportRogueProcesses(IdentifyUnwantedProcesses(startTime));
executionDirectory = null;
}
public static RunStateCommand Apply(DirectoryInfo testBinariesDirectory)
{
ExecutionEventLog.RecordStatus("STARTED : ------------- Gac Test Infra Assemblies ------------- |");
StateCollection infraLibraries = StateCollection.LoadStateCollection(@"Infra\GacTestLibraries.deployment", testBinariesDirectory);
infraLibraries.Push(StatePool.Run);
ExecutionEventLog.RecordStatus("COMPLETED: ------------- Gac Test Infra Assemblies ------------- |");
return(new RunStateCommand());
}
public void Cleanup()
{
if (!preserveDirectory)
{
ExecutionEventLog.RecordStatus("STARTED : ----------- Deleting Execution Directory ------------ |");
DirectoryInfo.Delete(true);
ExecutionEventLog.RecordStatus("COMPLETED: ----------- Deleting Execution Directory ------------ |");
}
}
/// <summary>
/// Adds process to list of process under test
/// </summary>
internal void OnProcessRegister(int processId)
{
//Only register processes when the test has started.
if (isTestRunning)
{
pids.Add(processId);
ExecutionEventLog.RecordStatus("Process: " + processId + " now marked for tracking.");
}
}
public override void BeginTest(string testName)
{
logBuilder.Length = 0;
if (!String.Equals(this.currentTest.TestInfo.Name, testName))
{
ExecutionEventLog.RecordStatus(string.Format(CultureInfo.InvariantCulture, "BeginTest specified '{0}' but test name registered was '{1}'.", testName, this.currentTest.TestInfo.Name));
throw new Exception("This is super serious now that we have execution groups, we cannot recover safely");
}
}
private static void PopAllStatesFromPoolImplementation(int poolId)
{
int height = StatePools[poolId].Count;
for (int i = 0; i < height; i++)
{
StateModule stateModule = StatePools[poolId].Pop();
ExecutionEventLog.RecordStatus("Rolling Back State: " + stateModule);
stateModule.StateImplementation.RollbackState(stateModule);
}
}
internal static void ApplyDeployments(Collection <string> deployments, DirectoryInfo testBinariesDirectory)
{
if (deployments != null)
{
foreach (string deployment in deployments)
{
ExecutionEventLog.RecordStatus("Applying Deployment: " + deployment);
StateCollection stateCollection = LoadStateCollection(deployment, testBinariesDirectory);
stateCollection.Push(StatePool.Execution);
}
}
}
public static ListenToTestsCommand Apply(List <TestRecord> tests, LoggingMediator loggingMediator, DirectoryInfo testLogDirectory, bool debugTest)
{
ListenToTestsCommand command = new ListenToTestsCommand();
command.Mediator = loggingMediator;
command.Tests = tests;
command.DebugTest = debugTest;
ExecutionEventLog.RecordStatus("Starting Test Logging Transaction.");
command.Mediator.StartTests(tests, testLogDirectory);
return(command);
}
internal void StartService(DebuggingEngineCommand debuggingEngine, int testCount)
{
ExecutionEventLog.RecordStatus("Starting up LoggingMediator.");
server = new LoggingServer(debuggingEngine, debugTests);
server.Start();
consoleLogger = new ConsoleLogger();
recordingLogger = new RecordingLogger();
windowProgressLogger = new ProgressWindowLogger(testCount);
server.RegisterLogger(recordingLogger);
server.RegisterLogger(consoleLogger);
server.RegisterLogger(windowProgressLogger);
}
// If preserveExistingDirectory is true, don't delete on revert if the directory already existed.
public static TemporaryDirectoryCommand Apply(DirectoryInfo directoryInfo, bool preserveExistingDirectory)
{
TemporaryDirectoryCommand directory = new TemporaryDirectoryCommand();
directory.preserveDirectory = preserveExistingDirectory && directoryInfo.Exists;
directory.DirectoryInfo = directoryInfo;
ExecutionEventLog.RecordStatus("STARTED : ----------- Creating Execution Directory ------------ |");
ExecutionEventLog.RecordStatus("Execution Dir: " + directory.DirectoryInfo.FullName);
directory.DirectoryInfo.Create();
ExecutionEventLog.RecordStatus("COMPLETED: ----------- Creating Execution Directory ------------ |");
return(directory);
}
/// <summary>
/// Gather debug information if the process was being monitored, otherwise just terminate.
/// </summary>
internal void OnProcessCrash(int processId)
{
ExecutionEventLog.RecordStatus("Process " + processId + " crash notification recieved.");
try
{
if (Process.GetCurrentProcess().Id == processId)
{
//It may be possible that some strange unhandled exception is arising in a background thread, leading to a debugger being launched
//and the infra Terminating itself. Somehow, it seems unlikely for this code to be reachable, but this case is a hypothetical possibility to account for.
ExecutionEventLog.RecordStatus("Catastrophic Situation: Infra has recieved notification that it's own process has crashed. ");
}
else if (isTestRunning && pids.Contains(processId) && accumulatedDumpCost < maxDumpCost)
{
ExecutionEventLog.RecordStatus("Debugging Process: " + processId);
FileInfo debugLogFilePath = new FileInfo(Path.Combine(executionDirectory.FullName, "TestInfraDebuggingLog_" + processId + ".log"));
FileInfo debugDumpFilePath = new FileInfo(Path.Combine(executionDirectory.FullName, "TestInfraDebuggingDump_" + processId + ".dmp"));
CdbUtilities.DebugProcess(processId.ToString(CultureInfo.InvariantCulture), debugLogFilePath, debugDumpFilePath);
accumulatedDumpCost += debugDumpFilePath.Length;
//
LoggingMediator.LogFile(debugLogFilePath.FullName);
LoggingMediator.LogFile(debugDumpFilePath.FullName);
//Dan: Is the Recording Logger guaranteed to be explicitly aware that the given test has failed if this point is reached?
//Getting here means a process the tester cares about has crashed.
}
else
{
if (accumulatedDumpCost < maxDumpCost)
{
ExecutionEventLog.RecordStatus("Terminating non-monitored Process:" + processId);
}
else
{
ExecutionEventLog.RecordStatus("Dump limit exceeded - Terminating process without analysis:" + processId);
}
Process process = Process.GetProcessById(processId);
if (process != null && !process.HasExited)
{
process.Kill();
process.WaitForExit();
}
}
}
//Uncaught exceptions in this event handler will ---- up the logging stack... Which would be bad.
catch (Exception exception)
{
ExecutionEventLog.RecordException(exception);
}
}
/// <summary>
/// Sets up a controller of the elevation service
/// Contains policy about where the exe lives... This and CleanupCommand need to be refactored to push policy up
/// </summary>
public static ElevationServiceCommand Apply(DirectoryInfo infraBinariesPath)
{
ElevationServiceCommand command = new ElevationServiceCommand();
ExecutionEventLog.RecordStatus("Starting Elevation Service.");
command.rootPath = Path.Combine(infraBinariesPath.FullName, @"ElevationService.exe");
//Obliterate previous ES
CallElevationService(command.rootPath, "forceUninstall");
//Engage the Elevation Service
CallElevationService(command.rootPath, "install");
CallElevationService(command.rootPath, "start");
return(command);
}
private void ReportRogueProcesses(List <Process> list)
{
foreach (Process p in list)
{
try
{
ExecutionEventLog.RecordStatus("ALERT- Possible rogue process! Unsuccessfully terminated:" + p.ProcessName + " " + p.Id);
}
catch (Exception e)
{
ExecutionEventLog.RecordException(e);
}
}
}
public void Cleanup()
{
try
{
bool retainResults = (ReportingUtilities.InterpretTestOutcome(test) == Result.Pass || (test.TestInfo.Bugs != null && test.TestInfo.Bugs.Count != 0));
string traceName = MakeTraceName(test);
ExecutionEventLog.RecordStatus("Ending Code Coverage session - Saving Code Coverage Trace Results.");
CodeCoverageUtilities.EndTrace(logDirectory, retainResults, traceName);
}
//Hitting a null-ref somewhere in the cleanup logic - need to understand source.
catch (Exception e)
{
ExecutionEventLog.RecordException(e);
}
}
public static LogDirectoryCommand Apply(DirectoryInfo directoryInfo, bool skipDxDiag)
{
ExecutionEventLog.RecordStatus("Creating Log Directory: " + directoryInfo.FullName);
if (!directoryInfo.Exists)
{
directoryInfo.Create();
}
//Produce the DxDiag File
if (!skipDxDiag)
{
MakeDiagnosticRecord(directoryInfo);
}
return(new LogDirectoryCommand());
}
/// <summary>
/// Registers Jit Debugger rooted from supplied infra binaries Path and returns cleanup command.
/// </summary>
public static DebuggingEngineCommand Apply(DirectoryInfo infraPath, string customJitDebuggerCommand)
{
ExecutionEventLog.RecordStatus("Starting up DebuggingEngine.");
DebuggingEngineCommand command = new DebuggingEngineCommand();
CdbUtilities.InstallCdb();
if (!String.IsNullOrEmpty(customJitDebuggerCommand))
{
JitRegistrationUtilities.Register(customJitDebuggerCommand);
}
else
{
JitRegistrationUtilities.Register(GenerateJitDebuggerCommand(infraPath));
}
return(command);
}
public void BeginTest(string testName)
{
if (LoggingState == LoggingState.IsConnected)
{
BeginVariation("Two variations created.");
LogMessage("Log consumer has attempted to call Begin Test Twice.");
LogResult(Result.Fail);
EndVariation("Two variations created.");
}
else if (LoggingState == LoggingState.HasVariation)
{
LogMessage("Log consumer has attempted to call Begin Test Twice.");
LogResult(Result.Fail);
EndVariation(currentVariationName);
}
else
{
hasConnection = true;
// If BeginTest specifies a different test name we will record
// a warning in the execution event log. We could be even more
// aggressive and create a dead test for the registered test.
if (!String.Equals(this.currentTestName, testName))
{
// If we're in debugging mode and the test name matches the first
// registered test, then what happened is the driver was rerun.
// In this case we can recover by reseting the loggers.
if (isDebugging && String.Equals(testName, registeredTests[0].TestInfo.Name))
{
Reset();
Loggers.Reset();
}
else
{
ExecutionEventLog.RecordStatus(string.Format(CultureInfo.InvariantCulture, "BeginTest specified '{0}' but test name registered was '{1}'.", testName, this.currentTestName));
throw new Exception("This is super serious now that we have execution groups, we cannot recover safely");
}
}
Loggers.BeginTest(testName);
hasReceivedBeginTest = true;
}
}
public void RegisterTests(List <TestRecord> tests, DirectoryInfo testLogDirectory)
{
// If the LoggingState is not offline it means there is another
// test which hasn't been unregistered yet. We'll unregister that
// test, and log to the execution event log that badness happened.
if (LoggingState != LoggingState.Offline)
{
ExecutionEventLog.RecordStatus("RegisterTest was called when there was already a registered test.");
UnregisterTests();
}
registeredTests = tests;
currentTestIndex = 0;
currentVariationName = null;
currentVariationIndex = -1;
IsListening = true;
hasConnection = false;
hasReceivedBeginTest = false;
hasReceivedBeginVariation = false;
this.testLogDirectory = testLogDirectory;
}
/// <summary>
/// End Tracing.
/// Assembly specific trace files will be generated.
/// </summary>
internal static void EndTrace(DirectoryInfo coverageLogDirectory, bool retainResult, string traceName)
{
if (retainResult)
{
ExecutionEventLog.RecordStatus("Retaining Coverage data for passing test as trace: " + traceName);
if (!coverageLogDirectory.Exists)
{
coverageLogDirectory.Create();
}
// List harvested components and then save to disk
ProcessUtilities.Run(coverageToolPath, "/List /session ALL");
ProcessUtilities.Run(coverageToolPath, "/SetPath \"" + coverageLogDirectory.FullName + "\"");
ProcessUtilities.Run(coverageToolPath, "/session ALL /Save /As " + traceName);
}
else
{
ExecutionEventLog.RecordStatus("Clearing Coverage data for non-passing test.");
ProcessUtilities.Run(coverageToolPath, "/Reset /session ALL");
}
ProcessUtilities.Run(coverageToolPath, "/Close /session ALL");
}
public void Cleanup()
{
try
{
if (numShots < maxShots) //Stop captures once we've hit 50 image
{
WaitForRender();
Snapshot current = Capture();
if (previous == null)
{
LogImage(current, logDirectory, "Baseline_Post_Execution_Snapshot.png");
}
else
{
Snapshot diff = previous.CompareTo(current);
SnapshotVerifier verifier = new SnapshotColorVerifier();
if (verifier.Verify(diff) == VerificationResult.Fail) // Give test benefit of doubt, and re-capture. GDI is known to be glitchy on propagating first snap.
{
WaitForRender();
current = Capture();
diff = previous.CompareTo(current);
if (verifier.Verify(diff) == VerificationResult.Fail)
{
LogImage(current, logDirectory, "Current_Post_Execution_Snapshot.png");
LogImage(diff.Resize(downsampleSize), logDirectory, "Delta_Post_Execution_Snapshot.png");
Logging.LoggingMediator.LogEvent("Desktop snapshot appears to be different from state of previously capture.");
numShots++;
}
}
}
previous = current; //Now, the current image becomes the new previous.
}
}
catch (Exception)
{
ExecutionEventLog.RecordStatus("Error on attempting Desktop Snapshot Command - Was the desktop locked or the context otherwise unavailable?");
}
}
/// <summary>
/// Encapsulates termination of processes.
/// Debug processes are not a problem, as they execute synchronously.
/// </summary>
/// <param name="processes"></param>
private void TerminateProcesses(List <Process> processes)
{
foreach (Process process in processes)
{
if (!process.HasExited)
{
try
{
ExecutionEventLog.RecordStatus("Process Name: " + process.ProcessName + " ID:" + process.Id + " is being terminated.");
process.Kill();
process.WaitForExit();
ExecutionEventLog.RecordStatus("Process termination completed.");
}
catch (InvalidOperationException e)
{
ExecutionEventLog.RecordException(e);
//The process has already exited
}
catch (Win32Exception e)
{
ExecutionEventLog.RecordException(e);
//The process has already exited or access is denied (Probably a Whidbey
}
catch (Exception e)
{
ExecutionEventLog.RecordException(e);
}
finally
{
if (!process.HasExited)
{
ExecutionEventLog.RecordStatus("Could not kill process " + process.ProcessName + " ID:" + process.Id);
ExecutionEventLog.RecordStatus("Launching external taskkill process to retry killing...");
KillWithMoreForce(process);
}
}
}
}
}
/// <summary>
/// Encapsulates discovering processes which emerged during the test run
/// </summary>
/// <returns></returns>
private List <Process> IdentifyUnwantedProcesses(DateTime startTime)
{
string userSid = WindowsIdentity.GetCurrent().User.Value;
List <Process> newProcesses = new List <Process>();
foreach (Process process in Process.GetProcesses())
{
try
{
if (IsUnwantedProcess(startTime, userSid, process))
{
newProcesses.Add(process);
}
}
catch (Exception e)
{
//With filtering, we shouldn't be hitting this. -
ExecutionEventLog.RecordException(e);
}
}
return(newProcesses);
}
