// Copyright 1998-2019 Epic Games, Inc. All Rights Reserved. using System; using System.Collections.Generic; using System.Diagnostics; using System.IO; using System.Linq; using System.Reflection; using System.Runtime.CompilerServices; using System.Text; namespace Tools.DotNETCommon { /// /// Log Event Type /// public enum LogEventType { /// /// The log event is a fatal error /// Fatal = 1, /// /// The log event is an error /// Error = 2, /// /// The log event is a warning /// Warning = 4, /// /// Output the log event to the console /// Console = 8, /// /// Output the event to the on-disk log /// Log = 16, /// /// The log event should only be displayed if verbose logging is enabled /// Verbose = 32, /// /// The log event should only be displayed if very verbose logging is enabled /// VeryVerbose = 64 } /// /// Options for formatting messages /// [Flags] public enum LogFormatOptions { /// /// Format normally /// None = 0, /// /// Never write a severity prefix. Useful for pre-formatted messages that need to be in a particular format for, eg. the Visual Studio output window /// NoSeverityPrefix = 1, /// /// Do not output text to the console /// NoConsoleOutput = 2, } /// /// UAT/UBT Custom log system. /// /// This lets you use any TraceListeners you want, but you should only call the static /// methods below, not call Trace.XXX directly, as the static methods /// This allows the system to enforce the formatting and filtering conventions we desire. /// /// For posterity, we cannot use the Trace or TraceSource class directly because of our special log requirements: /// 1. We possibly capture the method name of the logging event. This cannot be done as a macro, so must be done at the top level so we know how many layers of the stack to peel off to get the real function. /// 2. We have a verbose filter we would like to apply to all logs without having to have each listener filter individually, which would require our string formatting code to run every time. /// 3. We possibly want to ensure severity prefixes are logged, but Trace.WriteXXX does not allow any severity info to be passed down. /// static public class Log { /// /// Temporary status message displayed on the console. /// [DebuggerDisplay("{HeadingText}")] class StatusMessage { /// /// The heading for this status message. /// public string HeadingText; /// /// The current status text. /// public string CurrentText; /// /// Whether the heading has been written to the console. Before the first time that lines are output to the log in the midst of a status scope, the heading will be written on a line of its own first. /// public bool bHasFlushedHeadingText; } /// /// Object used for synchronization /// private static object SyncObject = new object(); /// /// When true, verbose logging is enabled. /// public static LogEventType OutputLevel { get; set; } /// /// Whether to include timestamps on each line of log output /// public static bool IncludeTimestamps { get; set; } /// /// When true, warnings and errors will have a WARNING: or ERROR: prexifx, respectively. /// public static bool IncludeSeverityPrefix { get; set; } /// /// When true, warnings and errors will have a prefix suitable for display by MSBuild (avoiding error messages showing as (EXEC : Error : ") /// public static bool IncludeProgramNameWithSeverityPrefix { get; set; } /// /// When true, logs will have the calling mehod prepended to the output as MethodName: /// public static bool IncludeCallingMethod { get; set; } /// /// When true, console output will have the calling mehod prepended to the output as MethodName: /// public static bool IncludeCallingMethodForConsole { get; set; } /// /// When true, will detect warnings and errors and set the console output color to yellow and red. /// public static bool ColorConsoleOutput { get; set; } /// /// Path to the log file being written to. May be null. /// public static FileReference OutputFile { get; private set; } /// /// Whether console output is redirected. This prevents writing status updates that rely on moving the cursor. /// private static bool AllowStatusUpdates { get { return !Console.IsOutputRedirected; } } /// /// When configured, this tracks time since initialization to prepend a timestamp to each log. /// private static Stopwatch Timer = Stopwatch.StartNew(); /// /// A collection of strings that have been already written once /// private static HashSet WriteOnceSet = new HashSet(); /// /// Stack of status scope information. /// private static Stack StatusMessageStack = new Stack(); /// /// The currently visible status text /// private static string StatusText = ""; /// /// Last time a status message was pushed to the stack /// private static Stopwatch StatusTimer = new Stopwatch(); /// /// Indent added to every output line /// public static string Indent { get; set; } /// /// Static initializer /// static Log() { Indent = ""; OutputLevel = LogEventType.Log; IncludeSeverityPrefix = true; IncludeProgramNameWithSeverityPrefix = false; IncludeCallingMethod = true; IncludeCallingMethodForConsole = false; ColorConsoleOutput = true; } /// /// Adds a trace listener that writes to a log file /// /// The file to write to /// The created trace listener public static TextWriterTraceListener AddFileWriter(string Name, FileReference OutputFile) { try { Log.OutputFile = OutputFile; DirectoryReference.CreateDirectory(OutputFile.Directory); TextWriterTraceListener LogTraceListener = new TextWriterTraceListener(new StreamWriter(OutputFile.FullName), Name); Trace.Listeners.Add(LogTraceListener); return LogTraceListener; } catch (Exception Ex) { throw new Exception(String.Format("Unable to open log file for writing ({0})", OutputFile), Ex); } } /// /// Determines if a TextWriterTraceListener has been added to the list of trace listeners /// /// True if a TextWriterTraceListener has been added public static bool HasFileWriter() { foreach(TraceListener Listener in Trace.Listeners) { if(Listener is TextWriterTraceListener) { return true; } } return false; } /// /// Gets the name of the Method N levels deep in the stack frame. Used to trap what method actually made the logging call. /// Only used when bLogSources is true. /// /// /// ClassName.MethodName [MethodImplAttribute(MethodImplOptions.NoInlining)] private static string GetSource(int StackFramesToSkip) { StackFrame Frame = new StackFrame(2 + StackFramesToSkip); System.Reflection.MethodBase Method = Frame.GetMethod(); return String.Format("{0}.{1}", Method.DeclaringType.Name, Method.Name); } /// /// Converts a LogEventType into a log prefix. Only used when bLogSeverity is true. /// /// /// private static string GetSeverityPrefix(LogEventType Severity) { switch (Severity) { case LogEventType.Fatal: return "FATAL ERROR: "; case LogEventType.Error: return "ERROR: "; case LogEventType.Warning: return "WARNING: "; case LogEventType.Console: return ""; case LogEventType.Verbose: return "VERBOSE: "; case LogEventType.VeryVerbose: return "VVERBOSE: "; default: return ""; } } /// /// Formats message for logging. Enforces the configured options. /// /// Number of frames to skip to get to the originator of the log request. /// Message verbosity level /// Options for formatting this string /// Whether the message is intended for console output /// Message text format string /// Message text parameters /// Formatted message [MethodImplAttribute(MethodImplOptions.NoInlining)] private static List FormatMessage(int StackFramesToSkip, LogEventType Verbosity, LogFormatOptions Options, bool bForConsole, string Format, params object[] Args) { string TimePrefix = IncludeTimestamps? String.Format("[{0:hh\\:mm\\:ss\\.fff}] ", Timer.Elapsed) : ""; string SourcePrefix = (bForConsole ? IncludeCallingMethodForConsole : IncludeCallingMethod) ? string.Format("{0}: ", GetSource(StackFramesToSkip)) : ""; string SeverityPrefix = (IncludeSeverityPrefix && ((Options & LogFormatOptions.NoSeverityPrefix) == 0)) ? GetSeverityPrefix(Verbosity) : ""; // Include the executable name when running inside MSBuild. If unspecified, MSBuild re-formats them with an "EXEC :" prefix. if(SeverityPrefix.Length > 0 && IncludeProgramNameWithSeverityPrefix) { SeverityPrefix = String.Format("{0}: {1}", Path.GetFileNameWithoutExtension(Assembly.GetEntryAssembly().Location), SeverityPrefix); } // If there are no extra args, don't try to format the string, in case it has any format control characters in it (our LOCTEXT strings tend to). string[] Lines = ((Args.Length > 0) ? String.Format(Format, Args) : Format).TrimEnd(' ', '\t', '\r', '\n').Split('\n'); List FormattedLines = new List(); FormattedLines.Add(String.Format("{0}{1}{2}{3}{4}", TimePrefix, SourcePrefix, Indent, SeverityPrefix, Lines[0].TrimEnd('\r'))); if (Lines.Length > 1) { int PaddingLength = 0; while(PaddingLength < Lines[0].Length && Char.IsWhiteSpace(Lines[0][PaddingLength])) { PaddingLength++; } string Padding = new string(' ', SeverityPrefix.Length) + Lines[0].Substring(0, PaddingLength); for (int Idx = 1; Idx < Lines.Length; Idx++) { FormattedLines.Add(String.Format("{0}{1}{2}{3}{4}", TimePrefix, SourcePrefix, Indent, Padding, Lines[Idx].TrimEnd('\r'))); } } return FormattedLines; } /// /// Writes a formatted message to the console. All other functions should boil down to calling this method. /// /// Number of frames to skip to get to the originator of the log request. /// If true, this message will be written only once /// Message verbosity level. We only meaningfully use values up to Verbose /// Options for formatting messages /// Message format string. /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] private static void WriteLinePrivate(int StackFramesToSkip, bool bWriteOnce, LogEventType Verbosity, LogFormatOptions FormatOptions, string Format, params object[] Args) { // if we want this message only written one time, check if it was already written out if (bWriteOnce) { string Formatted = string.Format(Format, Args); if (WriteOnceSet.Contains(Formatted)) { return; } WriteOnceSet.Add(Formatted); } if (Verbosity <= OutputLevel) { lock (SyncObject) { // Output to all the other trace listeners List Lines = FormatMessage(StackFramesToSkip + 1, Verbosity, FormatOptions, false, Format, Args); foreach (TraceListener Listener in Trace.Listeners) { foreach(string Line in Lines) { Listener.WriteLine(Line); } Listener.Flush(); } // Handle the console output separately; we format things differently if ((Verbosity != LogEventType.Log || OutputLevel >= LogEventType.Verbose) && (FormatOptions & LogFormatOptions.NoConsoleOutput) == 0) { FlushStatusHeading(); bool bResetConsoleColor = false; if (ColorConsoleOutput) { if(Verbosity == LogEventType.Warning) { Console.ForegroundColor = ConsoleColor.Yellow; bResetConsoleColor = true; } if(Verbosity <= LogEventType.Error) { Console.ForegroundColor = ConsoleColor.Red; bResetConsoleColor = true; } } try { List ConsoleLines = FormatMessage(StackFramesToSkip + 1, Verbosity, FormatOptions, true, Format, Args); foreach (string ConsoleLine in ConsoleLines) { Console.WriteLine(ConsoleLine); } } finally { // make sure we always put the console color back. if(bResetConsoleColor) { Console.ResetColor(); } } if(StatusMessageStack.Count > 0 && AllowStatusUpdates) { SetStatusText(StatusMessageStack.Peek().CurrentText); } } } } } /// /// Similar to Trace.WriteLineIf /// /// /// /// /// [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void WriteLineIf(bool Condition, LogEventType Verbosity, string Format, params object[] Args) { if (Condition) { WriteLinePrivate(1, false, Verbosity, LogFormatOptions.None, Format, Args); } } /// /// Mostly an internal function, but expose StackFramesToSkip to allow UAT to use existing wrapper functions and still get proper formatting. /// /// /// /// /// [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void WriteLine(int StackFramesToSkip, LogEventType Verbosity, string Format, params object[] Args) { WriteLinePrivate(StackFramesToSkip + 1, false, Verbosity, LogFormatOptions.None, Format, Args); } /// /// Mostly an internal function, but expose StackFramesToSkip to allow UAT to use existing wrapper functions and still get proper formatting. /// /// /// /// /// /// [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void WriteLine(int StackFramesToSkip, LogEventType Verbosity, LogFormatOptions FormatOptions, string Format, params object[] Args) { WriteLinePrivate(StackFramesToSkip + 1, false, Verbosity, FormatOptions, Format, Args); } /// /// Similar to Trace.WriteLine /// /// /// /// [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void WriteLine(LogEventType Verbosity, string Format, params object[] Args) { WriteLinePrivate(1, false, Verbosity, LogFormatOptions.None, Format, Args); } /// /// Similar to Trace.WriteLine /// /// /// /// /// [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void WriteLine(LogEventType Verbosity, LogFormatOptions FormatOptions, string Format, params object[] Args) { WriteLinePrivate(1, false, Verbosity, FormatOptions, Format, Args); } /// /// Formats an exception for display in the log. The exception message is shown as an error, and the stack trace is included in the log. /// /// The exception to display /// The log filename to display, if any public static void WriteException(Exception Ex, string LogFileName) { string LogSuffix = (LogFileName == null)? "" : String.Format("\n(see {0} for full exception trace)", LogFileName); TraceLog("=============================================================================="); TraceError("{0}{1}", ExceptionUtils.FormatException(Ex), LogSuffix); TraceLog("\n{0}", ExceptionUtils.FormatExceptionDetails(Ex)); TraceLog("=============================================================================="); } /// /// Writes an error message to the console. /// /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceError(string Format, params object[] Args) { WriteLinePrivate(1, false, LogEventType.Error, LogFormatOptions.None, Format, Args); } /// /// Writes an error message to the console, in a format suitable for Visual Studio to parse. /// /// The file containing the error /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceError(FileReference File, string Format, params object[] Args) { WriteLinePrivate(1, false, LogEventType.Error, LogFormatOptions.NoSeverityPrefix, "{0}: error: {1}", File, String.Format(Format, Args)); } /// /// Writes an error message to the console, in a format suitable for Visual Studio to parse. /// /// The file containing the error /// Line number of the error /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceError(FileReference File, int Line, string Format, params object[] Args) { WriteLinePrivate(1, false, LogEventType.Error, LogFormatOptions.NoSeverityPrefix, "{0}({1}): error: {2}", File, Line, String.Format(Format, Args)); } /// /// Writes a verbose message to the console. /// /// Message format string /// Optional arguments [Conditional("TRACE")] [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceVerbose(string Format, params object[] Args) { WriteLinePrivate(1, false, LogEventType.Verbose, LogFormatOptions.None, Format, Args); } /// /// Writes a message to the console. /// /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceInformation(string Format, params object[] Args) { WriteLinePrivate(1, false, LogEventType.Console, LogFormatOptions.None, Format, Args); } /// /// Writes a warning message to the console. /// /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceWarning(string Format, params object[] Args) { WriteLinePrivate(1, false, LogEventType.Warning, LogFormatOptions.None, Format, Args); } /// /// Writes a warning message to the console. /// /// The file containing the error /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceWarning(FileReference File, string Format, params object[] Args) { WriteLinePrivate(1, false, LogEventType.Warning, LogFormatOptions.NoSeverityPrefix, "{0}: warning: {1}", File, String.Format(Format, Args)); } /// /// Writes a warning message to the console. /// /// The file containing the error /// Line number of the error /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceWarning(FileReference File, int Line, string Format, params object[] Args) { WriteLinePrivate(1, false, LogEventType.Warning, LogFormatOptions.NoSeverityPrefix, "{0}({1}): warning: {2}", File, Line, String.Format(Format, Args)); } /// /// Writes a very verbose message to the console. /// /// Message format string /// Optional arguments [Conditional("TRACE")] [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceVeryVerbose(string Format, params object[] Args) { WriteLinePrivate(1, false, LogEventType.VeryVerbose, LogFormatOptions.None, Format, Args); } /// /// Writes a message to the log only. /// /// Message format string /// Optional arguments [Conditional("TRACE")] [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceLog(string Format, params object[] Args) { WriteLinePrivate(1, false, LogEventType.Log, LogFormatOptions.None, Format, Args); } /// /// Similar to Trace.WriteLine /// /// /// /// [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void WriteLineOnce(LogEventType Verbosity, string Format, params object[] Args) { WriteLinePrivate(1, true, Verbosity, LogFormatOptions.None, Format, Args); } /// /// Similar to Trace.WriteLine /// /// /// /// /// [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void WriteLineOnce(LogEventType Verbosity, LogFormatOptions Options, string Format, params object[] Args) { WriteLinePrivate(1, true, Verbosity, Options, Format, Args); } /// /// Writes an error message to the console. /// /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceErrorOnce(string Format, params object[] Args) { WriteLinePrivate(1, true, LogEventType.Error, LogFormatOptions.None, Format, Args); } /// /// Writes a verbose message to the console. /// /// Message format string /// Optional arguments [Conditional("TRACE")] [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceVerboseOnce(string Format, params object[] Args) { WriteLinePrivate(1, true, LogEventType.Verbose, LogFormatOptions.None, Format, Args); } /// /// Writes a message to the console. /// /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceInformationOnce(string Format, params object[] Args) { WriteLinePrivate(1, true, LogEventType.Console, LogFormatOptions.None, Format, Args); } /// /// Writes a warning message to the console. /// /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceWarningOnce(string Format, params object[] Args) { WriteLinePrivate(1, true, LogEventType.Warning, LogFormatOptions.None, Format, Args); } /// /// Writes a warning message to the console. /// /// The file containing the error /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceWarningOnce(FileReference File, string Format, params object[] Args) { WriteLinePrivate(1, true, LogEventType.Warning, LogFormatOptions.NoSeverityPrefix, "{0}: warning: {1}", File, String.Format(Format, Args)); } /// /// Writes a warning message to the console. /// /// The file containing the error /// Line number of the error /// Message format string /// Optional arguments [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceWarningOnce(FileReference File, int Line, string Format, params object[] Args) { WriteLinePrivate(1, true, LogEventType.Warning, LogFormatOptions.NoSeverityPrefix, "{0}({1}): warning: {2}", File, Line, String.Format(Format, Args)); } /// /// Writes a very verbose message to the console. /// /// Message format string /// Optional arguments [Conditional("TRACE")] [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceVeryVerboseOnce(string Format, params object[] Args) { WriteLinePrivate(1, true, LogEventType.VeryVerbose, LogFormatOptions.None, Format, Args); } /// /// Writes a message to the log only. /// /// Message format string /// Optional arguments [Conditional("TRACE")] [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void TraceLogOnce(string Format, params object[] Args) { WriteLinePrivate(1, true, LogEventType.Log, LogFormatOptions.None, Format, Args); } /// /// Flushes the current status text before writing out a new log line or status message /// static void FlushStatusHeading() { if(StatusMessageStack.Count > 0) { StatusMessage CurrentStatus = StatusMessageStack.Peek(); if(CurrentStatus.HeadingText.Length > 0 && !CurrentStatus.bHasFlushedHeadingText && AllowStatusUpdates) { SetStatusText(CurrentStatus.HeadingText); Console.WriteLine(); StatusText = ""; CurrentStatus.bHasFlushedHeadingText = true; } else { SetStatusText(""); } } } /// /// Enter a scope with the given status message. The message will be written to the console without a newline, allowing it to be updated through subsequent calls to UpdateStatus(). /// The message will be written to the log immediately. If another line is written while in a status scope, the initial status message is flushed to the console first. /// /// The status message [Conditional("TRACE")] [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void PushStatus(string Message) { lock(SyncObject) { FlushStatusHeading(); StatusMessage NewStatusMessage = new StatusMessage(); NewStatusMessage.HeadingText = Message; NewStatusMessage.CurrentText = Message; StatusMessageStack.Push(NewStatusMessage); StatusTimer.Restart(); if(Message.Length > 0) { WriteLine(LogEventType.Log, LogFormatOptions.NoConsoleOutput, "{0}", Message); SetStatusText(Message); } } } /// /// Updates the current status message. This will overwrite the previous status line. /// /// The status message [Conditional("TRACE")] [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void UpdateStatus(string Message) { lock(SyncObject) { StatusMessage CurrentStatusMessage = StatusMessageStack.Peek(); CurrentStatusMessage.CurrentText = Message; if(AllowStatusUpdates || StatusTimer.Elapsed.TotalSeconds > 10.0) { SetStatusText(Message); StatusTimer.Restart(); } } } /// /// Updates the Pops the top status message from the stack. The mess /// /// [Conditional("TRACE")] [MethodImplAttribute(MethodImplOptions.NoInlining)] public static void PopStatus() { lock(SyncObject) { StatusMessage CurrentStatusMessage = StatusMessageStack.Peek(); SetStatusText(CurrentStatusMessage.CurrentText); if(StatusText.Length > 0) { Console.WriteLine(); StatusText = ""; } StatusMessageStack.Pop(); } } /// /// Update the status text. For internal use only; does not modify the StatusMessageStack objects. /// /// New status text to display private static void SetStatusText(string NewStatusText) { if(NewStatusText.Length > 0) { NewStatusText = Indent + NewStatusText; } if(StatusText != NewStatusText) { int NumCommonChars = 0; while(NumCommonChars < StatusText.Length && NumCommonChars < NewStatusText.Length && StatusText[NumCommonChars] == NewStatusText[NumCommonChars]) { NumCommonChars++; } if(!AllowStatusUpdates && NumCommonChars < StatusText.Length) { // Prevent writing backspace characters if the console doesn't support it Console.WriteLine(); StatusText = ""; NumCommonChars = 0; } StringBuilder Text = new StringBuilder(); Text.Append('\b', StatusText.Length - NumCommonChars); Text.Append(NewStatusText, NumCommonChars, NewStatusText.Length - NumCommonChars); if(NewStatusText.Length < StatusText.Length) { int NumChars = StatusText.Length - NewStatusText.Length; Text.Append(' ', NumChars); Text.Append('\b', NumChars); } Console.Write(Text.ToString()); StatusText = NewStatusText; StatusTimer.Restart(); } } } }