public void TrackingEventListenerHasFailuresOrWarnings()
{
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
TestEvents.Log.VerboseEvent("1");
TestEvents.Log.InfoEvent("1");
TestEvents.Log.AlwaysEvent("1");
XAssert.IsFalse(listener.HasFailuresOrWarnings);
}
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
TestEvents.Log.WarningEvent("1");
XAssert.IsTrue(listener.HasFailuresOrWarnings);
}
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
TestEvents.Log.ErrorEvent("1");
XAssert.IsTrue(listener.HasFailuresOrWarnings);
}
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
TestEvents.Log.CriticalEvent("1");
XAssert.IsTrue(listener.HasFailuresOrWarnings);
}
}
public void TestErrorReplayedFromWorker(bool isUserError)
{
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(global::BuildXL.Engine.ETWLogger.Log);
const string ErrorName = "MyTestEvent";
const string ErrorText = "Event logged from worker";
LoggingContext loggingContext = BuildXL.TestUtilities.Xunit.XunitBuildXLTest.CreateLoggingContextForTest();
global::BuildXL.Engine.Tracing.Logger.Log.DistributionWorkerForwardedError(loggingContext, new global::BuildXL.Engine.Tracing.WorkerForwardedEvent()
{
EventId = 100,
EventName = ErrorName,
EventKeywords = isUserError ? (int)global::BuildXL.Utilities.Instrumentation.Common.Keywords.UserError : 0,
Text = ErrorText,
});
XAssert.IsTrue(listener.HasFailures);
if (isUserError)
{
XAssert.AreEqual(1, listener.UserErrorDetails.Count);
XAssert.AreEqual(0, listener.InternalErrorDetails.Count);
XAssert.AreEqual(ErrorName, listener.UserErrorDetails.FirstErrorName);
XAssert.AreEqual(ErrorText, listener.UserErrorDetails.FirstErrorMessage);
}
else
{
XAssert.AreEqual(0, listener.UserErrorDetails.Count);
XAssert.AreEqual(1, listener.InternalErrorDetails.Count);
XAssert.AreEqual(ErrorName, listener.InternalErrorDetails.FirstErrorName);
XAssert.AreEqual(ErrorText, listener.InternalErrorDetails.FirstErrorMessage);
}
}
}
public void DistributedBuildConnectivityIssueTrumpsOtherErrors()
{
var loggingContext = XunitBuildXLTest.CreateLoggingContextForTest();
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(global::BuildXL.Engine.ETWLogger.Log);
listener.RegisterEventSource(global::BuildXL.Scheduler.ETWLogger.Log);
global::BuildXL.Scheduler.Tracing.Logger.Log.PipMaterializeDependenciesFromCacheFailure(loggingContext, "ArbitraryPip", "ArbitraryMessage");
global::BuildXL.Engine.Tracing.Logger.Log.DistributionExecutePipFailedNetworkFailure(loggingContext, "ArbitraryPip", "ArbitraryWorker", "ArbitraryMessage", "ArbitraryStep", "ArbitraryCaller");
global::BuildXL.Scheduler.Tracing.Logger.Log.PipMaterializeDependenciesFromCacheFailure(loggingContext, "ArbitraryPip", "ArbitraryMessage");
var infrastructureErrorClassification = BuildXLApp.ClassifyFailureFromLoggedEvents(listener);
XAssert.AreEqual(ExitKind.InfrastructureError, infrastructureErrorClassification.ExitKind);
XAssert.AreEqual(global::BuildXL.Engine.Tracing.LogEventId.DistributionExecutePipFailedNetworkFailure.ToString(), infrastructureErrorClassification.ErrorBucket);
}
}
private void TelemetryStartup()
{
if (!Debugger.IsAttached && m_configuration.EnableTelemetry)
{
AriaV2StaticState.Enable(BuildXL.Tracing.AriaTenantToken.Key);
TrackingEventListener.RegisterEventSource(ETWLogger.Log);
m_telemetryStopwatch.Start();
}
}
public void WarningMapping()
{
TestEvents log = TestEvents.Log;
var wm = new WarningManager();
using (var listener = new TrackingEventListener(Events.Log, warningMapper: wm.GetState))
{
listener.RegisterEventSource(TestEvents.Log);
// should log as a warning
XAssert.AreEqual(0, listener.WarningCount);
log.WarningEvent("1");
XAssert.AreEqual(1, listener.WarningCount);
XAssert.AreEqual(0, listener.TotalErrorCount);
wm.SetState(WarningEventId, WarningState.AsError);
// should log as an error
log.WarningEvent("1");
XAssert.AreEqual(1, listener.TotalErrorCount);
XAssert.AreEqual(1, listener.WarningCount);
wm.SetState(WarningEventId, WarningState.Suppressed);
// should be suppressed
log.WarningEvent("1");
XAssert.AreEqual(1, listener.WarningCount);
XAssert.AreEqual(1, listener.TotalErrorCount);
}
using (var listener = new TrackingEventListener(Events.Log, warningMapper: wm.GetState))
{
listener.RegisterEventSource(TestEvents.Log);
// should log as a info
XAssert.AreEqual(0, listener.InformationalCount);
log.InfoEvent("1");
XAssert.AreEqual(1, listener.InformationalCount);
XAssert.AreEqual(0, listener.WarningCount);
XAssert.AreEqual(0, listener.TotalErrorCount);
wm.SetState(InfoEventId, WarningState.AsError);
// should not log as an error (only warnings are managed by warning mapper)
log.InfoEvent("1");
XAssert.AreEqual(2, listener.InformationalCount);
XAssert.AreEqual(0, listener.TotalErrorCount);
wm.SetState(InfoEventId, WarningState.Suppressed);
// should not be suppressed (only warnings are managed by warning mapper)
log.InfoEvent("1");
XAssert.AreEqual(3, listener.InformationalCount);
XAssert.AreEqual(0, listener.TotalErrorCount);
}
}
public void TestErrorCategorization()
{
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
string testMessage = "Message from test event";
TestEvents.Log.UserErrorEvent(testMessage);
XAssert.IsTrue(listener.HasFailures);
XAssert.AreEqual(1, listener.UserErrorDetails.Count);
XAssert.AreEqual(0, listener.InfrastructureErrorDetails.Count);
XAssert.AreEqual(0, listener.InternalErrorDetails.Count);
XAssert.AreEqual("UserErrorEvent", listener.UserErrorDetails.FirstErrorName);
XAssert.IsTrue(listener.UserErrorDetails.FirstErrorMessage.Contains(testMessage));
}
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
TestEvents.Log.InfrastructureErrorEvent("1");
XAssert.IsTrue(listener.HasFailures);
XAssert.AreEqual(0, listener.UserErrorDetails.Count);
XAssert.AreEqual(1, listener.InfrastructureErrorDetails.Count);
XAssert.AreEqual(0, listener.InternalErrorDetails.Count);
XAssert.AreEqual("InfrastructureErrorEvent", listener.InfrastructureErrorDetails.FirstErrorName);
}
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
TestEvents.Log.ErrorEvent("1");
XAssert.IsTrue(listener.HasFailures);
XAssert.AreEqual(0, listener.UserErrorDetails.Count);
XAssert.AreEqual(0, listener.InfrastructureErrorDetails.Count);
XAssert.AreEqual(1, listener.InternalErrorDetails.Count);
XAssert.AreEqual("ErrorEvent", listener.InternalErrorDetails.FirstErrorName);
}
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
string testMessage = "message";
TestEvents.Log.CriticalEvent(testMessage);
XAssert.IsTrue(listener.InternalErrorDetails.FirstErrorMessage.Contains(testMessage));
}
}
private void TelemetryStartup()
{
AppDomain.CurrentDomain.UnhandledException +=
(sender, eventArgs) =>
{
HandleUnhandledFailure(
eventArgs.ExceptionObject as Exception
);
};
if (!Debugger.IsAttached && !m_telemetryDisabled)
{
AriaV2StaticState.Enable(global::BuildXL.Tracing.AriaTenantToken.Key);
TrackingEventListener.RegisterEventSource(ETWLogger.Log);
m_telemetryStopwatch.Start();
}
}
public void BaseEventListener()
{
// make sure this thing only deals with the BuildXL event source
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
// this one should get through
TestEvents log = TestEvents.Log;
log.InfoEvent("Test 1");
XAssert.AreEqual(listener.InformationalCount, 1);
// this one should not
using (var log2 = new TestEventSource())
{
log2.InfoEvent("Test 1");
XAssert.AreEqual(listener.InformationalCount, 1);
}
}
}
public void UnexpectedConditionTelemetryCapTest()
{
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(global::BuildXL.Tracing.ETWLogger.Log);
LoggingContext context = new LoggingContext("Test");
int maxTelemetryUnexpectedConditions = global::BuildXL.Tracing.Logger.MaxTelemetryUnexpectedConditions;
for (int i = 0; i < maxTelemetryUnexpectedConditions + 1; i++)
{
global::BuildXL.Tracing.Logger.Log.UnexpectedCondition(context, "UnexpectedConditionTest");
}
// Make sure only 5 of the 6 events went to telemetry. The 6th events should only go local
XAssert.AreEqual(maxTelemetryUnexpectedConditions, listener.CountsPerEventId(EventId.UnexpectedConditionTelemetry));
XAssert.AreEqual(1, listener.CountsPerEventId(EventId.UnexpectedConditionLocal));
// Now change the logging context for a new session and make sure the event goes to telemetry again
context = new LoggingContext("Test2");
global::BuildXL.Tracing.Logger.Log.UnexpectedCondition(context, "UnexpectedConditionTest");
XAssert.AreEqual(maxTelemetryUnexpectedConditions + 1, listener.CountsPerEventId(EventId.UnexpectedConditionTelemetry));
XAssert.AreEqual(1, listener.CountsPerEventId(EventId.UnexpectedConditionLocal));
}
}
public void TrackingEventListener()
{
const int NumVerbose = 9;
const int NumInfo = 8;
const int NumWarning = 7;
const int NumError = 6;
const int NumCritical = 5;
const int NumAlways = 4;
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
TestEvents log = TestEvents.Log;
for (int i = 0; i < NumVerbose; i++)
{
log.VerboseEvent("1");
}
for (int i = 0; i < NumInfo; i++)
{
log.InfoEvent("1");
}
for (int i = 0; i < NumWarning; i++)
{
log.WarningEvent("1");
}
for (int i = 0; i < NumError; i++)
{
log.ErrorEvent("1");
}
for (int i = 0; i < NumCritical; i++)
{
log.CriticalEvent("1");
}
for (int i = 0; i < NumAlways; i++)
{
log.AlwaysEvent("1");
}
XAssert.AreEqual(listener.VerboseCount, NumVerbose);
XAssert.AreEqual(listener.InformationalCount, NumInfo);
XAssert.AreEqual(listener.WarningCount, NumWarning);
XAssert.AreEqual(listener.TotalErrorCount, NumError + NumCritical);
XAssert.AreEqual(listener.CriticalCount, NumCritical);
XAssert.AreEqual(listener.AlwaysCount, NumAlways);
XAssert.IsTrue(listener.HasFailures);
XAssert.IsTrue(listener.HasFailuresOrWarnings);
}
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
TestEvents log = TestEvents.Log;
XAssert.IsFalse(listener.HasFailures);
XAssert.IsFalse(listener.HasFailuresOrWarnings);
log.WarningEvent("1");
XAssert.IsFalse(listener.HasFailures);
XAssert.IsTrue(listener.HasFailuresOrWarnings);
log.ErrorEvent("1");
XAssert.IsTrue(listener.HasFailures);
XAssert.IsTrue(listener.HasFailuresOrWarnings);
}
using (var listener = new TrackingEventListener(Events.Log))
{
listener.RegisterEventSource(TestEvents.Log);
TestEvents log = TestEvents.Log;
log.CriticalEvent("1");
XAssert.IsTrue(listener.HasFailures);
XAssert.IsTrue(listener.HasFailuresOrWarnings);
}
using (var listener = new TrackingEventListener(Events.Log, warningMapper: _ => WarningState.AsError))
{
listener.RegisterEventSource(TestEvents.Log);
TestEvents log = TestEvents.Log;
log.WarningEvent("1");
XAssert.AreEqual(1, listener.TotalErrorCount);
XAssert.IsTrue(listener.HasFailures);
XAssert.IsTrue(listener.HasFailuresOrWarnings);
}
}
