// Copyright 1998-2019 Epic Games, Inc. All Rights Reserved. using System; using System.Collections.Generic; using System.Linq; using System.Text; using System.IO; using System.Threading; using System.Diagnostics; using System.Management; using System.Runtime.InteropServices; using System.Runtime.CompilerServices; using Tools.DotNETCommon; namespace AutomationTool { public enum CtrlTypes { CTRL_C_EVENT = 0, CTRL_BREAK_EVENT, CTRL_CLOSE_EVENT, CTRL_LOGOFF_EVENT = 5, CTRL_SHUTDOWN_EVENT } public interface IProcess { void StopProcess(bool KillDescendants = true); bool HasExited { get; } string GetProcessName(); } /// /// Tracks all active processes. /// public sealed class ProcessManager { public delegate bool CtrlHandlerDelegate(CtrlTypes EventType); // @todo: Add mono support [DllImport("Kernel32")] public static extern bool SetConsoleCtrlHandler(CtrlHandlerDelegate Handler, bool Add); /// /// List of active (running) processes. /// private static List ActiveProcesses = new List(); /// /// Synchronization object /// private static object SyncObject = new object(); /// /// Creates a new process and adds it to the tracking list. /// /// New Process objects public static IProcessResult CreateProcess(string AppName, bool bAllowSpew, bool bCaptureSpew, Dictionary Env = null, LogEventType SpewVerbosity = LogEventType.Console, ProcessResult.SpewFilterCallbackType SpewFilterCallback = null) { var NewProcess = HostPlatform.Current.CreateProcess(AppName); if (Env != null) { foreach (var EnvPair in Env) { if (NewProcess.StartInfo.EnvironmentVariables.ContainsKey(EnvPair.Key)) { NewProcess.StartInfo.EnvironmentVariables.Remove(EnvPair.Key); } if (!String.IsNullOrEmpty(EnvPair.Value)) { NewProcess.StartInfo.EnvironmentVariables.Add(EnvPair.Key, EnvPair.Value); } } } var Result = new ProcessResult(AppName, NewProcess, bAllowSpew, bCaptureSpew, SpewVerbosity: SpewVerbosity, InSpewFilterCallback: SpewFilterCallback); AddProcess(Result); return Result; } public static void AddProcess(IProcess Proc) { lock (SyncObject) { ActiveProcesses.Add(Proc); } } public static void RemoveProcess(IProcess Proc) { lock (SyncObject) { ActiveProcesses.Remove(Proc); } } public static bool CanBeKilled(string ProcessName) { return !HostPlatform.Current.DontKillProcessList.Contains(ProcessName, StringComparer.InvariantCultureIgnoreCase); } /// /// Kills all running processes. /// public static void KillAll() { List ProcessesToKill = new List(); lock (SyncObject) { foreach (var ProcResult in ActiveProcesses) { if (!ProcResult.HasExited) { ProcessesToKill.Add(ProcResult); } } ActiveProcesses.Clear(); } // Remove processes that can't be killed for (int ProcessIndex = ProcessesToKill.Count - 1; ProcessIndex >= 0; --ProcessIndex ) { var ProcessName = ProcessesToKill[ProcessIndex].GetProcessName(); if (!String.IsNullOrEmpty(ProcessName) && !CanBeKilled(ProcessName)) { CommandUtils.LogLog("Ignoring process \"{0}\" because it can't be killed.", ProcessName); ProcessesToKill.RemoveAt(ProcessIndex); } } if(ProcessesToKill.Count > 0) { CommandUtils.LogLog("Trying to kill {0} spawned processes.", ProcessesToKill.Count); foreach (var Proc in ProcessesToKill) { CommandUtils.LogLog(" {0}", Proc.GetProcessName()); } if (CommandUtils.IsBuildMachine) { for (int Cnt = 0; Cnt < 9; Cnt++) { bool AllDone = true; foreach (var Proc in ProcessesToKill) { try { if (!Proc.HasExited) { AllDone = false; CommandUtils.LogLog("Waiting for process: {0}", Proc.GetProcessName()); } } catch (Exception) { CommandUtils.LogWarning("Exception Waiting for process"); AllDone = false; } } try { if (ProcessResult.HasAnyDescendants(Process.GetCurrentProcess())) { AllDone = false; CommandUtils.LogInformation("Waiting for descendants of main process..."); } } catch (Exception Ex) { CommandUtils.LogWarning("Exception Waiting for descendants of main process. " + Ex); AllDone = false; } if (AllDone) { break; } Thread.Sleep(10000); } } foreach (var Proc in ProcessesToKill) { var ProcName = Proc.GetProcessName(); try { if (!Proc.HasExited) { CommandUtils.LogLog("Killing process: {0}", ProcName); Proc.StopProcess(false); } } catch (Exception Ex) { CommandUtils.LogWarning("Exception while trying to kill process {0}:", ProcName); CommandUtils.LogWarning(LogUtils.FormatException(Ex)); } } try { if (CommandUtils.IsBuildMachine && ProcessResult.HasAnyDescendants(Process.GetCurrentProcess())) { CommandUtils.LogLog("current process still has descendants, trying to kill them..."); ProcessResult.KillAllDescendants(Process.GetCurrentProcess()); } } catch (Exception) { CommandUtils.LogWarning("Exception killing descendants of main process"); } } } } #region ProcessResult Helper Class public interface IProcessResult : IProcess { void OnProcessExited(); void DisposeProcess(); void StdOut(object sender, DataReceivedEventArgs e); void StdErr(object sender, DataReceivedEventArgs e); int ExitCode{ get;set; } string Output {get;} Process ProcessObject {get;} string ToString(); void WaitForExit(); } /// /// Class containing the result of process execution. /// public class ProcessResult : IProcessResult { public delegate string SpewFilterCallbackType(string Message); private int ProcessExitCode = -1; private StringBuilder ProcessOutput; private bool AllowSpew = true; private LogEventType SpewVerbosity = LogEventType.Console; private SpewFilterCallbackType SpewFilterCallback = null; private string AppName = String.Empty; private Process Proc = null; private AutoResetEvent OutputWaitHandle = new AutoResetEvent(false); private AutoResetEvent ErrorWaitHandle = new AutoResetEvent(false); private object ProcSyncObject; public ProcessResult(string InAppName, Process InProc, bool bAllowSpew, bool bCaptureSpew = true, LogEventType SpewVerbosity = LogEventType.Console, SpewFilterCallbackType InSpewFilterCallback = null) { AppName = InAppName; ProcSyncObject = new object(); Proc = InProc; AllowSpew = bAllowSpew; if(bCaptureSpew) { ProcessOutput = new StringBuilder(); } else { OutputWaitHandle.Set(); ErrorWaitHandle.Set(); } this.SpewVerbosity = SpewVerbosity; SpewFilterCallback = InSpewFilterCallback; if (Proc != null) { Proc.EnableRaisingEvents = false; } } ~ProcessResult() { if(Proc != null) { Proc.Dispose(); } } /// /// Removes a process from the list of tracked processes. /// public void OnProcessExited() { ProcessManager.RemoveProcess(this); } /// /// Log output of a remote process at a given severity. /// To pretty up the output, we use a custom source so it will say the source of the process instead of this method name. /// /// /// [MethodImplAttribute(MethodImplOptions.NoInlining)] private void LogOutput(LogEventType Verbosity, string Message) { Log.WriteLine(1, Verbosity, Message); } /// /// Manually dispose of Proc and set it to null. /// public void DisposeProcess() { if(Proc != null) { Proc.Dispose(); Proc = null; } } /// /// Process.OutputDataReceived event handler. /// /// Sender /// Event args public void StdOut(object sender, DataReceivedEventArgs e) { if (e.Data != null) { if (AllowSpew) { if (SpewFilterCallback != null) { string FilteredSpew = SpewFilterCallback(e.Data); if (FilteredSpew != null) { LogOutput(SpewVerbosity, FilteredSpew); } } else { LogOutput(SpewVerbosity, e.Data); } } if(ProcessOutput != null) { lock (ProcSyncObject) { ProcessOutput.Append(e.Data); ProcessOutput.Append(Environment.NewLine); } } } else { OutputWaitHandle.Set(); } } /// /// Process.ErrorDataReceived event handler. /// /// Sender /// Event args public void StdErr(object sender, DataReceivedEventArgs e) { if (e.Data != null) { if (SpewFilterCallback != null) { string FilteredSpew = SpewFilterCallback(e.Data); if (FilteredSpew != null) { LogOutput(SpewVerbosity, FilteredSpew); } } else { LogOutput(SpewVerbosity, e.Data); } if(ProcessOutput != null) { lock (ProcSyncObject) { ProcessOutput.Append(e.Data); ProcessOutput.Append(Environment.NewLine); } } } else { ErrorWaitHandle.Set(); } } /// /// Convenience operator for getting the exit code value. /// /// /// Process exit code. [Obsolete] public static implicit operator int(ProcessResult Result) { return Result.ExitCode; } /// /// Gets or sets the process exit code. /// public int ExitCode { get { return ProcessExitCode; } set { ProcessExitCode = value; } } /// /// Gets all std output the process generated. /// public string Output { get { if (ProcessOutput == null) { return null; } lock (ProcSyncObject) { return ProcessOutput.ToString(); } } } public bool HasExited { get { bool bHasExited = true; lock (ProcSyncObject) { if (Proc != null) { bHasExited = Proc.HasExited; if (bHasExited) { ExitCode = Proc.ExitCode; } } } return bHasExited; } } public Process ProcessObject { get { return Proc; } } /// /// Thread-safe way of getting the process name /// /// Name of the process this object represents public string GetProcessName() { string Name = null; lock (ProcSyncObject) { try { if (Proc != null && !Proc.HasExited) { Name = Proc.ProcessName; } } catch { // Ignore all exceptions } } if (String.IsNullOrEmpty(Name)) { Name = "[EXITED] " + AppName; } return Name; } /// /// Object iterface. /// /// String representation of this object. public override string ToString() { return ExitCode.ToString(); } public void WaitForExit() { bool bProcTerminated = false; bool bStdOutSignalReceived = false; bool bStdErrSignalReceived = false; // Make sure the process objeect is valid. lock (ProcSyncObject) { bProcTerminated = (Proc == null); } // Keep checking if we got all output messages until the process terminates. if (!bProcTerminated) { // Check messages int MaxWaitUntilMessagesReceived = 120; while (MaxWaitUntilMessagesReceived > 0 && !(bStdOutSignalReceived && bStdErrSignalReceived)) { if (!bStdOutSignalReceived) { bStdOutSignalReceived = OutputWaitHandle.WaitOne(500); } if (!bStdErrSignalReceived) { bStdErrSignalReceived = ErrorWaitHandle.WaitOne(500); } // Check if the process terminated lock (ProcSyncObject) { bProcTerminated = (Proc == null) || Proc.HasExited; } if (bProcTerminated) { // Process terminated but make sure we got all messages, don't wait forever though MaxWaitUntilMessagesReceived--; } } if (!(bStdOutSignalReceived && bStdErrSignalReceived)) { CommandUtils.LogLog("Waited for a long time for output of {0}, some output may be missing; we gave up.", AppName); } // Double-check if the process terminated lock (ProcSyncObject) { bProcTerminated = (Proc == null) || Proc.HasExited; if (Proc != null) { if (!bProcTerminated) { // The process did not terminate yet but we've read all output messages, wait until the process terminates Proc.WaitForExit(); } ExitCode = Proc.ExitCode; } } } } /// /// Finds child processes of the current process. /// /// /// /// /// private static bool IsOurDescendant(Process ProcessToKill, int PossiblyRelatedId, HashSet VisitedPids) { // check if we're the parent of it or its parent is our descendant try { VisitedPids.Add(PossiblyRelatedId); Process Parent = null; using (ManagementObject ManObj = new ManagementObject(string.Format("win32_process.handle='{0}'", PossiblyRelatedId))) { ManObj.Get(); int ParentId = Convert.ToInt32(ManObj["ParentProcessId"]); if (ParentId == 0 || VisitedPids.Contains(ParentId)) { return false; } Parent = Process.GetProcessById(ParentId); // will throw an exception if not spawned by us or not running } if (Parent != null) { return Parent.Id == ProcessToKill.Id || IsOurDescendant(ProcessToKill, Parent.Id, VisitedPids); // could use ParentId, but left it to make the above var used } else { return false; } } catch (Exception) { // This can happen if the pid is no longer valid which is ok. return false; } } /// /// Kills all child processes of the specified process. /// /// Process id public static void KillAllDescendants(Process ProcessToKill) { bool bKilledAChild; do { bKilledAChild = false; // For some reason Process.GetProcesses() sometimes returns the same process twice // So keep track of all processes we already tried to kill var KilledPids = new HashSet(); var AllProcs = Process.GetProcesses(); foreach (Process KillCandidate in AllProcs) { var VisitedPids = new HashSet(); if (ProcessManager.CanBeKilled(KillCandidate.ProcessName) && !KilledPids.Contains(KillCandidate.Id) && IsOurDescendant(ProcessToKill, KillCandidate.Id, VisitedPids)) { KilledPids.Add(KillCandidate.Id); CommandUtils.LogLog("Trying to kill descendant pid={0}, name={1}", KillCandidate.Id, KillCandidate.ProcessName); try { KillCandidate.Kill(); bKilledAChild = true; } catch (Exception Ex) { if(!KillCandidate.HasExited) { CommandUtils.LogWarning("Failed to kill descendant:"); CommandUtils.LogWarning(LogUtils.FormatException(Ex)); } } break; // exit the loop as who knows what else died, so let's get processes anew } } } while (bKilledAChild); } /// /// returns true if this process has any descendants /// /// Process to check public static bool HasAnyDescendants(Process ProcessToCheck) { Process[] AllProcs = Process.GetProcesses(); foreach (Process KillCandidate in AllProcs) { // Silently skip InvalidOperationExceptions here, because it depends on the process still running. It may have terminated. string ProcessName; try { ProcessName = KillCandidate.ProcessName; } catch(InvalidOperationException) { continue; } // Check if it's still running HashSet VisitedPids = new HashSet(); if (ProcessManager.CanBeKilled(ProcessName) && IsOurDescendant(ProcessToCheck, KillCandidate.Id, VisitedPids)) { CommandUtils.LogLog("Descendant pid={0}, name={1}", KillCandidate.Id, ProcessName); return true; } } return false; } public void StopProcess(bool KillDescendants = true) { if (Proc != null) { Process ProcToKill = null; // At this point any call to Proc memebers will result in an exception // so null the object. var ProcToKillName = GetProcessName(); lock (ProcSyncObject) { ProcToKill = Proc; Proc = null; } // Now actually kill the process and all its descendants if requested if (KillDescendants) { KillAllDescendants(ProcToKill); } try { ProcToKill.Kill(); ProcToKill.WaitForExit(60000); if (!ProcToKill.HasExited) { CommandUtils.LogLog("Process {0} failed to exit.", ProcToKillName); } else { CommandUtils.LogLog("Process {0} successfully exited.", ProcToKillName); OnProcessExited(); } ProcToKill.Close(); } catch (Exception Ex) { CommandUtils.LogWarning("Exception while trying to kill process {0}:", ProcToKillName); CommandUtils.LogWarning(LogUtils.FormatException(Ex)); } } } } #endregion public partial class CommandUtils { #region Statistics private static Dictionary ExeToTimeInMs = new Dictionary(); public static void AddRunTime(string Exe, int TimeInMs) { lock(ExeToTimeInMs) { string Base = Path.GetFileName(Exe); if (!ExeToTimeInMs.ContainsKey(Base)) { ExeToTimeInMs.Add(Base, TimeInMs); } else { ExeToTimeInMs[Base] += TimeInMs; } } } public static void PrintRunTime() { lock(ExeToTimeInMs) { foreach (var Item in ExeToTimeInMs) { LogVerbose("Total {0}s to run " + Item.Key, Item.Value / 1000); } ExeToTimeInMs.Clear(); } } #endregion [Flags] public enum ERunOptions { None = 0, AllowSpew = 1 << 0, AppMustExist = 1 << 1, NoWaitForExit = 1 << 2, NoStdOutRedirect = 1 << 3, NoLoggingOfRunCommand = 1 << 4, UTF8Output = 1 << 5, /// When specified with AllowSpew, the output will be TraceEventType.Verbose instead of TraceEventType.Information SpewIsVerbose = 1 << 6, /// /// If NoLoggingOfRunCommand is set, it normally suppresses the run duration output. This turns it back on. /// LoggingOfRunDuration = 1 << 7, /// /// If set, a window is allowed to be created /// NoHideWindow = 1 << 8, /// /// Do not capture stdout in the process result /// NoStdOutCapture = 1 << 8, Default = AllowSpew | AppMustExist, } /// /// Resolves the passed in name using the path environment /// /// /// public static string WhichApp(string App, bool Quiet=true) { if (FileExists(Quiet, App)) { return App; } string ResolvedPath = null; if (!App.Contains(Path.DirectorySeparatorChar) && !App.Contains(Path.AltDirectorySeparatorChar)) { string[] PathDirectories = Environment.GetEnvironmentVariable("PATH").Split(Path.PathSeparator); foreach (string PathDirectory in PathDirectories) { string TryApp = Path.Combine(PathDirectory, App); if (FileExists(Quiet, TryApp)) { ResolvedPath = TryApp; break; } } } if (ResolvedPath != null) { Log.TraceVeryVerbose("Resolved {0} to {1}", App, ResolvedPath); } else { Log.TraceVerbose("Could not resolve app {0}", App); } return ResolvedPath; } /// /// Runs external program. /// /// Program filename. /// Commandline /// Optional Input for the program (will be provided as stdin) /// Defines the options how to run. See ERunOptions. /// Environment to pass to program. /// Callback to filter log spew before output. /// Object containing the exit code of the program as well as it's stdout output. public static IProcessResult Run(string App, string CommandLine = null, string Input = null, ERunOptions Options = ERunOptions.Default, Dictionary Env = null, ProcessResult.SpewFilterCallbackType SpewFilterCallback = null, string Identifier = null) { App = ConvertSeparators(PathSeparator.Default, App); HostPlatform.Current.SetupOptionsForRun(ref App, ref Options, ref CommandLine); if (App == "ectool" || App == "zip" || App == "xcodebuild") { Options &= ~ERunOptions.AppMustExist; } // Check if the application exists, including the PATH directories. if (Options.HasFlag(ERunOptions.AppMustExist) && !FileExists(Options.HasFlag(ERunOptions.NoLoggingOfRunCommand) ? true : false, App)) { string ResolvedPath = WhichApp(App); if(string.IsNullOrEmpty(ResolvedPath)) { throw new AutomationException("BUILD FAILED: Couldn't find the executable to run: {0}", App); } App = ResolvedPath; } var StartTime = DateTime.UtcNow; LogEventType SpewVerbosity = Options.HasFlag(ERunOptions.SpewIsVerbose) ? LogEventType.Verbose : LogEventType.Console; if (!Options.HasFlag(ERunOptions.NoLoggingOfRunCommand)) { LogWithVerbosity(SpewVerbosity,"Running: " + App + " " + (String.IsNullOrEmpty(CommandLine) ? "" : CommandLine)); } string PrevIndent = null; if(Options.HasFlag(ERunOptions.AllowSpew)) { PrevIndent = Tools.DotNETCommon.Log.Indent; Tools.DotNETCommon.Log.Indent += " "; } IProcessResult Result = ProcessManager.CreateProcess(App, Options.HasFlag(ERunOptions.AllowSpew), !Options.HasFlag(ERunOptions.NoStdOutCapture), Env, SpewVerbosity: SpewVerbosity, SpewFilterCallback: SpewFilterCallback); try { Process Proc = Result.ProcessObject; bool bRedirectStdOut = (Options & ERunOptions.NoStdOutRedirect) != ERunOptions.NoStdOutRedirect; Proc.StartInfo.FileName = App; Proc.StartInfo.Arguments = String.IsNullOrEmpty(CommandLine) ? "" : CommandLine; Proc.StartInfo.UseShellExecute = false; if (bRedirectStdOut) { Proc.StartInfo.RedirectStandardOutput = true; Proc.StartInfo.RedirectStandardError = true; Proc.OutputDataReceived += Result.StdOut; Proc.ErrorDataReceived += Result.StdErr; } Proc.StartInfo.RedirectStandardInput = Input != null; Proc.StartInfo.CreateNoWindow = (Options & ERunOptions.NoHideWindow) == 0; if ((Options & ERunOptions.UTF8Output) == ERunOptions.UTF8Output) { Proc.StartInfo.StandardOutputEncoding = new System.Text.UTF8Encoding(false, false); } Proc.Start(); if (bRedirectStdOut) { Proc.BeginOutputReadLine(); Proc.BeginErrorReadLine(); } if (String.IsNullOrEmpty(Input) == false) { Proc.StandardInput.WriteLine(Input); Proc.StandardInput.Close(); } if (!Options.HasFlag(ERunOptions.NoWaitForExit)) { Result.WaitForExit(); } else { Result.ExitCode = -1; } } finally { if(PrevIndent != null) { Tools.DotNETCommon.Log.Indent = PrevIndent; } } if (!Options.HasFlag(ERunOptions.NoWaitForExit)) { var BuildDuration = (DateTime.UtcNow - StartTime).TotalMilliseconds; //AddRunTime(App, (int)(BuildDuration)); Result.ExitCode = Result.ProcessObject.ExitCode; if (!Options.HasFlag(ERunOptions.NoLoggingOfRunCommand) || Options.HasFlag(ERunOptions.LoggingOfRunDuration)) { LogWithVerbosity(SpewVerbosity, "Took {0}s to run {1}, ExitCode={2}", BuildDuration / 1000, Path.GetFileName(App), Result.ExitCode); } Result.OnProcessExited(); Result.DisposeProcess(); } return Result; } /// /// Gets a logfile name for a RunAndLog call /// /// Environment to use. /// Executable to run /// Name of the logfile ( if null, executable name is used ) /// The log file name. public static string GetRunAndLogOnlyName(CommandEnvironment Env, string App, string LogName = null) { if (LogName == null) { LogName = Path.GetFileNameWithoutExtension(App); } return LogUtils.GetUniqueLogName(CombinePaths(Env.LogFolder, LogName)); } /// /// Runs external program and writes the output to a logfile. /// /// Environment to use. /// Executable to run /// Commandline to pass on to the executable /// Name of the logfile ( if null, executable name is used ) /// Optional Input for the program (will be provided as stdin) /// Defines the options how to run. See ERunOptions. /// Callback to filter log spew before output. public static void RunAndLog(CommandEnvironment Env, string App, string CommandLine, string LogName = null, int MaxSuccessCode = 0, string Input = null, ERunOptions Options = ERunOptions.Default, Dictionary EnvVars = null, ProcessResult.SpewFilterCallbackType SpewFilterCallback = null) { RunAndLog(App, CommandLine, GetRunAndLogOnlyName(Env, App, LogName), MaxSuccessCode, Input, Options, EnvVars, SpewFilterCallback); } /// /// Exception class for child process commands failing /// public class CommandFailedException : AutomationException { public CommandFailedException(string Message) : base(Message) { } public CommandFailedException(ExitCode ExitCode, string Message) : base(ExitCode, Message) { } } /// /// Runs external program and writes the output to a logfile. /// /// Executable to run /// Commandline to pass on to the executable /// Full path to the logfile, where the application output should be written to. /// Optional Input for the program (will be provided as stdin) /// Defines the options how to run. See ERunOptions. /// Callback to filter log spew before output. public static string RunAndLog(string App, string CommandLine, string Logfile = null, int MaxSuccessCode = 0, string Input = null, ERunOptions Options = ERunOptions.Default, Dictionary EnvVars = null, ProcessResult.SpewFilterCallbackType SpewFilterCallback = null) { IProcessResult Result = Run(App, CommandLine, Input, Options, EnvVars, SpewFilterCallback); if (!String.IsNullOrEmpty(Result.Output) && Logfile != null) { WriteToFile(Logfile, Result.Output); } else if (Logfile == null) { Logfile = "[No logfile specified]"; } else { Logfile = "[None!, no output produced]"; } if (Result.ExitCode > MaxSuccessCode || Result.ExitCode < 0) { throw new CommandFailedException((ExitCode)Result.ExitCode, String.Format("Command failed (Result:{3}): {0} {1}. See logfile for details: '{2}' ", App, CommandLine, Path.GetFileName(Logfile), Result.ExitCode)){ OutputFormat = AutomationExceptionOutputFormat.Minimal }; } if (!String.IsNullOrEmpty(Result.Output)) { return Result.Output; } return ""; } /// /// Runs external program and writes the output to a logfile. /// /// Executable to run /// Commandline to pass on to the executable /// Full path to the logfile, where the application output should be written to. /// Callback to filter log spew before output. /// Whether the program executed successfully or not. public static string RunAndLog(string App, string CommandLine, out int SuccessCode, string Logfile = null, Dictionary EnvVars = null, ProcessResult.SpewFilterCallbackType SpewFilterCallback = null) { IProcessResult Result = Run(App, CommandLine, Env: EnvVars, SpewFilterCallback: SpewFilterCallback); SuccessCode = Result.ExitCode; if (Result.Output.Length > 0 && Logfile != null) { WriteToFile(Logfile, Result.Output); } if (!String.IsNullOrEmpty(Result.Output)) { return Result.Output; } return ""; } /// /// Runs external program and writes the output to a logfile. /// /// Environment to use. /// Executable to run /// Commandline to pass on to the executable /// Name of the logfile ( if null, executable name is used ) /// Callback to filter log spew before output. /// Whether the program executed successfully or not. public static string RunAndLog(CommandEnvironment Env, string App, string CommandLine, out int SuccessCode, string LogName = null, Dictionary EnvVars = null, ProcessResult.SpewFilterCallbackType SpewFilterCallback = null) { return RunAndLog(App, CommandLine, out SuccessCode, GetRunAndLogOnlyName(Env, App, LogName), EnvVars, SpewFilterCallback); } /// /// Runs UAT recursively /// /// Environment to use. /// Commandline to pass on to the executable /// Log prefix for output public static void RunUAT(CommandEnvironment Env, string CommandLine, string Identifier) { // Check if there are already log files which start with this prefix, and try to uniquify it if until there aren't. string DirOnlyName = Identifier; string LogSubdir = CombinePaths(CmdEnv.LogFolder, DirOnlyName, ""); for(int Attempt = 1;;Attempt++) { string[] ExistingFiles = FindFiles(DirOnlyName + "*", false, CmdEnv.LogFolder); if (ExistingFiles.Length == 0) { break; } if (Attempt == 1000) { throw new AutomationException("Couldn't seem to create a log subdir {0}", LogSubdir); } DirOnlyName = String.Format("{0}_{1}", Identifier, Attempt + 1); LogSubdir = CombinePaths(CmdEnv.LogFolder, DirOnlyName, ""); } // Get the stdout log file for this run, and create the subdirectory for all the other log output CreateDirectory(LogSubdir); // Run UAT with the log folder redirected through the environment Dictionary EnvironmentVars = new Dictionary(); EnvironmentVars.Add(EnvVarNames.LogFolder, LogSubdir); EnvironmentVars.Add(EnvVarNames.FinalLogFolder, CombinePaths(CmdEnv.FinalLogFolder, DirOnlyName)); EnvironmentVars.Add(EnvVarNames.DisableStartupMutex, "1"); EnvironmentVars.Add(EnvVarNames.IsChildInstance, "1"); if (!IsBuildMachine) { EnvironmentVars.Add(AutomationTool.EnvVarNames.LocalRoot, ""); // if we don't clear this out, it will think it is a build machine; it will rederive everything } IProcessResult Result = Run(CmdEnv.UATExe, CommandLine, null, ERunOptions.Default, EnvironmentVars, Identifier: Identifier); if (Result.ExitCode != 0) { throw new CommandFailedException(String.Format("Recursive UAT command failed (exit code {0})", Result.ExitCode)){ OutputFormat = AutomationExceptionOutputFormat.Silent }; } } protected delegate bool ProcessLog(string LogText); /// /// Keeps reading a log file as it's being written to by another process until it exits. /// /// Name of the log file. /// Process that writes to the log file. /// Callback used to process the recently read log contents. protected static void LogFileReaderProcess(string LogFilename, IProcessResult LogProcess, ProcessLog OnLogRead = null) { while (!FileExists(LogFilename) && !LogProcess.HasExited) { LogInformation("Waiting for logging process to start..."); Thread.Sleep(2000); } Thread.Sleep(1000); using (FileStream ProcessLog = File.Open(LogFilename, FileMode.Open, FileAccess.Read, FileShare.ReadWrite)) { StreamReader LogReader = new StreamReader(ProcessLog); bool bKeepReading = true; // Read until the process has exited. while (!LogProcess.HasExited && bKeepReading) { while (!LogReader.EndOfStream && bKeepReading) { string Output = LogReader.ReadToEnd(); if (Output != null && OnLogRead != null) { bKeepReading = OnLogRead(Output); } } while (LogReader.EndOfStream && !LogProcess.HasExited && bKeepReading) { Thread.Sleep(250); // Tick the callback so that it can respond to external events if (OnLogRead != null) { bKeepReading = OnLogRead(null); } } } } } } }