Files
UnrealEngineUWP/Engine/Source/Programs/AutomationTool/AutomationUtils/Log.cs
Wes Hunt 585af51d15 TempStorage Refactor
GUBP High Level
* Temp Storage is zipped into a single archive per node now. This results in ~75% reduction in temp storage usage and network traffic, not to mention the per-file overhead.
* Temp Storage is in P:\\Builds\\{Game}\\TmpStore instead of P:\\Builds\\{Game}\\GUBP (to facilitate easier cleaning of this new structure).
* Temp Storage nodes are in subdirectories of {Branch}\\{CL}\\{NodeName} now instead of a flat directory structure that was hard to manually sift through.

GUBP Mid Level
* Removed -Store= and -StoreSuffix= test parameters.
* Added -NoZipTempStorage parameter to turn off temp storage zipping if necessary.
* Created GUBP.JobInfo class that collects info about the job as a whole to be passed around by GUBP. Mostly used by any code that need to interact with TempStorage.
* Created TempStorageNodeInfo that describes the necessary parameters to find the temp storage location for a node.
* Fully XML commented TempStorage.cs, and commented internals all major functions.
* Added a bunch of telemetry data for storing, retrieving, and cleaning shared temp storage.

UAT Mid Level
* Fixed a bug in Ionic.Zip that make ExtractAll() not work on Mono, checked in new DLLs.
* Added UAT parameter -UseLocalBuildStorage that allows you to test build storage stuff completely locally. Writes to Engine\\Saved\\LocalBuilds\\...

GUBP Low Level
* Refactored some GUBP startup code so temp vars would be limited in scope. Makes it easier to track the impact of refactoring these things.
* CullNodesForPreflight is only called for preflight builds.
* Refactored TempStorage.FindTempStorageManifests to use new TmpStore structure and harden the brittle string/path parsing it was doing. See the new TempStorage FindMatchingSharedTempStorageNodeCLs().
* Refactored TempStorage Saving and Loading to use XDocument instead of older XmlDocument. Removed a bunch of redundant checks.
* Use StripBaseDirectory and MakeRerootedFilePath to remove the brittle directory manipulation code. Directories no longer require a '/' at the end.
* Removed a few redundant caching layers in cleaning temp storage that try to ensure we don't clean a folder twice. None of them were necessary.
* Removed unused single-threaded copy code from temp storage.
* Updated Temp Storage unit test, and fully commented the logic behind it.

UAT Low Level
* UAT top level exception handler is now a single log line now to help parsers find the error.
* Removed several uses of FormatException as it doesn't display the entire exception chain, and is not as good as the default exception formatter.
* Removed ExceptionToString as it used FormatException, which was not a good precedent.
* Fixed several cases of exception propagation that was not properly chaining the inner exception.
* Refactored ThreadedCopyFiles to use Parallel.For because it was just as fast (if not faster) and much simpler to maintain.
* Removed the suffix from Robust_FileExists_NoExceptions because it's sole purpose in life WAS to throw exceptions!
* Added a bunch of XML doc comments to CommandUtils.
* Modernized some container manipulation and iteration to use IEnumerable and extension methods more appropriately.
* Added several @todos for other minor cleanup stuff that should happen eventually.
* Fixed some uses of String.Compare to use invariant culture.
#codereview:ben.marsh

[CL 2644846 by Wes Hunt in Main branch]
2015-08-05 10:22:11 -04:00

277 lines
9.4 KiB
C#

// Copyright 1998-2015 Epic Games, Inc. All Rights Reserved.
using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.IO;
using System.Runtime.CompilerServices;
using System.Diagnostics;
namespace AutomationTool
{
#region LogUtils
//@todo: This class should be moved somewhere else or the file should be renamed LogUtils.cs
public class LogUtils
{
private static string LogFilename;
/// <summary>
/// Initializes trace logging.
/// </summary>
/// <param name="CommandLine">Command line.</param>
public static void InitLogging(string[] CommandLine)
{
// ensure UTF8Output flag is respected, since we are initializing logging early in the program.
if (CommandLine.Any(Arg => Arg.Equals("-utf8output", StringComparison.InvariantCultureIgnoreCase)))
{
Console.OutputEncoding = new System.Text.UTF8Encoding(false, false);
}
UnrealBuildTool.Log.InitLogging(
bLogTimestamps: CommandUtils.ParseParam(CommandLine, "-Timestamps"),
bLogVerbose: CommandUtils.ParseParam(CommandLine, "-Verbose"),
bLogSeverity: true,
bLogSources: true,
bColorConsoleOutput: true,
TraceListeners: new TraceListener[]
{
new ConsoleTraceListener(),
// could return null, but InitLogging handles this gracefully.
CreateLogFileListener(out LogFilename),
//@todo - this is only used by GUBP nodes. Ideally we don't waste this 20MB if we are not running GUBP.
new AutomationMemoryLogListener(),
});
}
/// <summary>
/// Shuts down logging. This is a nothrow function as shutdown errors are ignored.
/// </summary>
public static void ShutdownLogging()
{
// from here we can copy the log file to its final resting place
try
{
// This closes all the output streams immediately, inside the Global Lock, so it's threadsafe.
Trace.Close();
// Try to copy the log file to the log folder. The reason why it's done here is that
// at the time the log file is being initialized the env var may not yet be set (this
// applies to local log folder in particular)
var LogFolder = Environment.GetEnvironmentVariable(EnvVarNames.LogFolder);
if (!String.IsNullOrEmpty(LogFolder) && Directory.Exists(LogFolder) &&
!String.IsNullOrEmpty(LogFilename) && File.Exists(LogFilename))
{
var DestFilename = CommandUtils.CombinePaths(LogFolder, "UAT_" + Path.GetFileName(LogFilename));
SafeCopyLogFile(LogFilename, DestFilename);
}
}
catch (Exception)
{
// Silently ignore, logging is pointless because eveything is shut down at this point
}
}
/// <summary>
/// Copies log file to the final log folder, does multiple attempts if the destination file could not be created.
/// </summary>
/// <param name="SourceFilename"></param>
/// <param name="DestFilename"></param>
private static void SafeCopyLogFile(string SourceFilename, string DestFilename)
{
const int MaxAttempts = 10;
int AttemptNo = 0;
var DestLogFilename = DestFilename;
bool Result = false;
do
{
try
{
File.Copy(SourceFilename, DestLogFilename, true);
Result = true;
}
catch (Exception)
{
var ModifiedFilename = String.Format("{0}_{1}{2}", Path.GetFileNameWithoutExtension(DestFilename), AttemptNo, Path.GetExtension(DestLogFilename));
DestLogFilename = CommandUtils.CombinePaths(Path.GetDirectoryName(DestFilename), ModifiedFilename);
AttemptNo++;
}
}
while (Result == false && AttemptNo <= MaxAttempts);
}
/// <summary>
/// Creates the TraceListener used for file logging.
/// We cannot simply use a TextWriterTraceListener because we need more flexibility when the file cannot be created.
/// TextWriterTraceListener lazily creates the file, silently failing when it cannot.
/// </summary>
/// <returns>The newly created TraceListener, or null if it could not be created.</returns>
private static TraceListener CreateLogFileListener(out string LogFilename)
{
StreamWriter LogFile = null;
const int MaxAttempts = 10;
int Attempt = 0;
var TempLogFolder = Path.GetTempPath();
do
{
if (Attempt == 0)
{
LogFilename = CommandUtils.CombinePaths(TempLogFolder, "Log.txt");
}
else
{
LogFilename = CommandUtils.CombinePaths(TempLogFolder, String.Format("Log_{0}.txt", Attempt));
}
try
{
// We do not need to set AutoFlush on the StreamWriter because we set Trace.AutoFlush, which calls it for us.
// Not only would this be redundant, StreamWriter AutoFlush does not flush the encoder, while a direct call to
// StreamWriter.Flush() will, which is what the Trace system with AutoFlush = true will do.
// Internally, FileStream constructor opens the file with good arguments for writing to log files.
return new TextWriterTraceListener(new StreamWriter(LogFilename), "AutomationFileLogListener");
}
catch (Exception Ex)
{
if (Attempt == (MaxAttempts - 1))
{
// Clear out the LogFilename to indicate we were not able to write one.
LogFilename = null;
UnrealBuildTool.Log.TraceWarning("Unable to create log file: {0}", LogFilename);
UnrealBuildTool.Log.TraceWarning(LogUtils.FormatException(Ex));
}
}
} while (LogFile == null && ++Attempt < MaxAttempts);
return null;
}
/// <summary>
/// Dumps exception info to log.
/// @todo: Remove this function as it doesn't do a good job printing the exception information.
/// </summary>
/// <param name="Ex">Exception</param>
public static string FormatException(Exception Ex)
{
var Message = String.Format("Exception in {0}: {1}{2}Stacktrace: {3}", Ex.Source, Ex.Message, Environment.NewLine, Ex.StackTrace);
if (Ex.InnerException != null)
{
Message += String.Format("InnerException in {0}: {1}{2}Stacktrace: {3}", Ex.InnerException.Source, Ex.InnerException.Message, Environment.NewLine, Ex.InnerException.StackTrace);
}
return Message;
}
/// <summary>
/// Returns a unique logfile name.
/// </summary>
/// <param name="Base">Base name for the logfile</param>
/// <returns>Unique logfile name.</returns>
public static string GetUniqueLogName(string Base)
{
const int MaxAttempts = 1000;
var Now = DateTime.Now;
int Attempt = 0;
string LogFilename;
for (;;)
{
var NowStr = Now.ToString("yyyy.MM.dd-HH.mm.ss");
LogFilename = String.Format("{0}-{1}.txt", Base, NowStr);
if (!File.Exists(LogFilename))
{
break;
}
++Attempt;
if (Attempt == MaxAttempts)
{
throw new AutomationException(String.Format("Failed to create logfile {0}.", LogFilename));
}
Now = Now.AddSeconds(1);
}
return LogFilename;
}
public static string GetLogTail(string Filename = null, int NumLines = 250)
{
List<string> Lines;
if (Filename == null)
{
Lines = new List<string>(AutomationMemoryLogListener.GetAccumulatedLog().Split(new string[] { Environment.NewLine }, StringSplitOptions.RemoveEmptyEntries));
}
else
{
Lines = new List<string>(CommandUtils.ReadAllLines(Filename));
}
if (Lines.Count > NumLines)
{
Lines.RemoveRange(0, Lines.Count - NumLines);
}
string Result = "";
foreach (var Line in Lines)
{
Result += Line + Environment.NewLine;
}
return Result;
}
}
#endregion
#region AutomationMemoryLogListener
/// <summary>
/// Trace console listener.
/// </summary>
class AutomationMemoryLogListener : TraceListener
{
private static StringBuilder AccumulatedLog = new StringBuilder(1024 * 1024 * 20);
private static object SyncObject = new object();
public override bool IsThreadSafe { get { return true; } }
/// <summary>
/// Writes a formatted line to the console.
/// </summary>
private void WriteLinePrivate(string Message)
{
lock (SyncObject)
{
AccumulatedLog.AppendLine(Message);
}
}
public static string GetAccumulatedLog()
{
lock (SyncObject)
{
return AccumulatedLog.ToString();
}
}
#region TraceListener Interface
public override void Write(string message)
{
WriteLinePrivate(message);
}
public override void WriteLine(string message)
{
WriteLinePrivate(message);
}
#endregion
}
#endregion
}