Merged PR 705082: Clean up Linux sandbox logs in release mode

Let's leave all 'Detours debug message:' out of release bits for normal operation. Left some on exclusively for error conditions.
This commit is contained in:
Serge Mera 2023-03-03 17:30:16 +00:00
Родитель 5b8fd38e49
Коммит 33f143e51b
3 изменённых файлов: 20 добавлений и 20 удалений

Просмотреть файл

@ -121,7 +121,7 @@ namespace BuildXL.Processes
// the 'read' syscall won't receive EOF until we close this writer
m_lazyWriteHandle = new Lazy<SafeFileHandle>(() =>
{
Process.LogProcessState($"Opening FIFO '{ReportsFifoPath}' for writing");
Process.LogDebug($"Opening FIFO '{ReportsFifoPath}' for writing");
return IO.Open(ReportsFifoPath, IO.OpenFlags.O_WRONLY, 0);
});
@ -152,7 +152,7 @@ namespace BuildXL.Processes
{
if (!Dispatch.IsProcessAlive(pid))
{
Process.LogProcessState("CheckActiveProcesses");
Process.LogDebug("CheckActiveProcesses");
RemovePid(pid);
}
}
@ -169,7 +169,7 @@ namespace BuildXL.Processes
m_accessReportProcessingBlock.Complete();
m_accessReportProcessingBlock.Completion.ContinueWith(t =>
{
Process.LogProcessState("Posting OpProcessTreeCompleted message");
Process.LogDebug("Posting OpProcessTreeCompleted message");
Process.PostAccessReport(new AccessReport
{
Operation = FileOperation.OpProcessTreeCompleted,
@ -189,7 +189,7 @@ namespace BuildXL.Processes
return; // already stopped
}
Process.LogProcessState($"Closing the write handle for FIFO '{ReportsFifoPath}'");
Process.LogDebug($"Closing the write handle for FIFO '{ReportsFifoPath}'");
// this will cause read() on the other end of the FIFO to return EOF once all native writers are done writing
m_lazyWriteHandle.Value.Dispose();
m_activeProcessesChecker.Cancel();
@ -407,7 +407,7 @@ namespace BuildXL.Processes
var numRead = Read(readHandle, messageLengthBytes, 0, messageLengthBytes.Length);
if (numRead == 0) // EOF
{
Process.LogProcessState("Exiting 'receive reports' loop.");
Process.LogDebug("Exiting 'receive reports' loop.");
break;
}
@ -565,7 +565,7 @@ namespace BuildXL.Processes
File.WriteAllBytes(famPath, manifestBytes.ToArray());
}
process.LogProcessState($"Saved FAM to '{famPath}'");
process.LogDebug($"Saved FAM to '{famPath}'");
// create a FIFO (named pipe)
Analysis.IgnoreResult(FileUtilities.TryDeleteFile(fifoPath, retryOnFailure: false));
@ -574,7 +574,7 @@ namespace BuildXL.Processes
throw new BuildXLException($"Creating FIFO {fifoPath} failed. (errno: {Marshal.GetLastWin32Error()})");
}
process.LogProcessState($"Created FIFO at '{fifoPath}'");
process.LogDebug($"Created FIFO at '{fifoPath}'");
// create and save info for this pip
var info = new Info(m_failureCallback, process, fifoPath, famPath, IsInTestMode);

Просмотреть файл

@ -457,7 +457,7 @@ namespace BuildXL.Processes
if (m_pipKextStats != null)
{
var statsJson = Newtonsoft.Json.JsonConvert.SerializeObject(m_pipKextStats.Value);
LogProcessState($"Process Kext Stats: {statsJson}");
LogDebug($"Process Kext Stats: {statsJson}");
}
base.Dispose();
@ -483,7 +483,7 @@ namespace BuildXL.Processes
foreach (int processId in distinctProcessIds)
{
bool killed = BuildXL.Interop.Unix.Process.ForceQuit(processId);
LogProcessState($"KillAllChildProcesses: kill({processId}) = {killed}");
LogDebug($"KillAllChildProcesses: kill({processId}) = {killed}");
SandboxConnection.NotifyPipProcessTerminated(PipId, processId);
}
}
@ -508,7 +508,7 @@ namespace BuildXL.Processes
var aliveProcessNames = CoalesceProcesses(activeProcesses)?.Select(p => Path.GetFileName(p.Path));
if (aliveProcessNames != null)
{
LogProcessState("surviving processes: " + string.Join(",", aliveProcessNames));
LogDebug("surviving processes: " + string.Join(",", aliveProcessNames));
return aliveProcessNames
.Except(AllowedSurvivingChildProcessNames)
@ -590,7 +590,7 @@ namespace BuildXL.Processes
.Replace("`", "\\`");
string cmdLine = $"{CommandLineEscaping.EscapeAsCommandLineWord(info.FileName)} {escapedArguments} {redirectedStdin}";
LogProcessState("Feeding stdin");
LogDebug("Feeding stdin");
var lines = new List<string>();
@ -766,7 +766,7 @@ namespace BuildXL.Processes
bool shouldWait = ShouldWaitForSurvivingChildProcesses();
if (shouldWait)
{
LogProcessState($"Main process exited but some child processes are still alive. Waiting the specified nested child process timeout to see whether they end naturally.");
LogDebug($"Main process exited but some child processes are still alive. Waiting the specified nested child process timeout to see whether they end naturally.");
await Task.Delay(ChildProcessTimeout);
}
@ -775,7 +775,7 @@ namespace BuildXL.Processes
}
else
{
LogProcessState($"Process exited but still waiting for reports :: exit time = {m_processExitTimeNs}, " +
LogDebug($"Process exited but still waiting for reports :: exit time = {m_processExitTimeNs}, " +
$"min enqueue time = {minEnqueueTime}, current drought = {SandboxConnection.CurrentDrought.TotalMilliseconds}ms");
}
}
@ -797,7 +797,7 @@ namespace BuildXL.Processes
{
if (ShouldReportFileAccesses && report.Operation != FileOperation.OpDebugMessage)
{
LogProcessState("Access report received: " + AccessReportToString(report));
LogDebug("Access report received: " + AccessReportToString(report));
}
Counters.IncrementCounter(SandboxedProcessCounters.AccessReportCount);

Просмотреть файл

@ -170,7 +170,7 @@ namespace BuildXL.Processes
m_output.HookOutputStream ? line => FeedStdOut(m_output, line) : null,
m_error.HookOutputStream ? line => FeedStdErr(m_error, line) : null,
info.Provenance,
msg => LogProcessState(msg),
msg => LogDebug(msg),
() =>
{
if (string.IsNullOrEmpty(TimeoutDumpDirectory))
@ -179,7 +179,7 @@ namespace BuildXL.Processes
return;
}
LogProcessState($"Dumping process '{ProcessId}' and children into '{TimeoutDumpDirectory}'");
LogDebug($"Dumping process '{ProcessId}' and children into '{TimeoutDumpDirectory}'");
if (!ProcessDumper.TryDumpProcessAndChildren(ProcessId, TimeoutDumpDirectory, out m_dumpCreationException, debugLogger: (message) => LogDebug(message)))
{
@ -230,7 +230,7 @@ namespace BuildXL.Processes
var lifetime = DateTime.UtcNow - startTime;
var cpuTimes = GetCpuTimes();
LogProcessState(
LogDebug(
$"Process Times: " +
$"started = {startTime}, " +
$"exited = {exitTime} (since start = {toSeconds(exitTime - startTime)}s), " +
@ -295,7 +295,7 @@ namespace BuildXL.Processes
await KillAsync();
}
LogProcessState("Waiting for reports to be received");
LogDebug("Waiting for reports to be received");
SandboxedProcessReports? reports = await (GetReportsAsync() ?? Task.FromResult<SandboxedProcessReports?>(null));
m_reportsReceivedTime = DateTime.UtcNow;
reports?.Freeze();
@ -353,7 +353,7 @@ namespace BuildXL.Processes
{
Contract.Requires(Started);
LogProcessState($"UnsandboxedProcess::KillAsync({ProcessId})");
LogDebug($"UnsandboxedProcess::KillAsync({ProcessId})");
return m_processExecutor.KillAsync(dumpProcessTree);
}
@ -431,7 +431,7 @@ namespace BuildXL.Processes
/// <nodoc />
internal void LogProcessState(string message)
{
string fullMessage = I($"Exited: {m_processExecutor.ExitCompleted}, StdOut: {m_processExecutor.StdOutCompleted}, StdErr: {m_processExecutor.StdErrCompleted}, Reports: {ReportsCompleted()} :: {message}");
string fullMessage = I($"Ext: {m_processExecutor.ExitCompleted}, Out: {m_processExecutor.StdOutCompleted}, Err: {m_processExecutor.StdErrCompleted}, Rep: {ReportsCompleted()} :: {message}");
if (DetoursListener != null)
{