public void TestPhaseScope()
{
var listener = new TestLoggerListener {
LogLevelThreshold = LogLevel.Diagnostic
};
var logLevel = Logger.LogLevelThreshold;
ILogItem item;
try
{
Logger.LogLevelThreshold = LogLevel.Diagnostic;
Logger.RegisterListener(listener);
Action <bool> callback;
Logger.LogInfo("test no phase scope");
Assert.Null(listener.TakeAndRemove().Phase);
using (new LoggerPhaseScope("A"))
{
Logger.LogInfo("test in phase scope A");
Assert.Equal("A", listener.TakeAndRemove().Phase);
using (new LoggerPhaseScope("B"))
{
Logger.LogInfo("test in phase scope B");
Assert.Equal("A.B", listener.TakeAndRemove().Phase);
var captured = LoggerPhaseScope.Capture();
Assert.NotNull(captured);
callback = shouldLogPerformance =>
{
using (LoggerPhaseScope.Restore(captured, shouldLogPerformance))
{
Logger.LogInfo("test in captured phase scope B");
}
};
} // exit scope B.
using (new LoggerPhaseScope("C", true))
{
Logger.LogInfo("test in phase scope C");
Assert.Equal("A.C", listener.TakeAndRemove().Phase);
// run callback in scope C.
callback(false);
Assert.Equal("A.B", listener.TakeAndRemove().Phase);
} // exit scope C.
item = listener.TakeAndRemove();
Assert.Equal("A.C", item.Phase);
Assert.Equal(LogLevel.Diagnostic, item.LogLevel);
} // exit scope A.
Logger.LogInfo("test no phase scope");
Assert.Null(listener.TakeAndRemove().Phase);
// run callback in no scope.
callback(true);
Assert.Equal("A.B", listener.TakeAndRemove().Phase);
item = listener.TakeAndRemove();
Assert.Equal("A.B", item.Phase);
Assert.Equal(LogLevel.Diagnostic, item.LogLevel);
Logger.LogInfo("test no phase scope again");
Assert.Null(listener.TakeAndRemove().Phase);
}
finally
{
Logger.UnregisterListener(listener);
Logger.LogLevelThreshold = logLevel;
}
}
public void TestFileScope()
{
var listener = new TestLoggerListener("TestFileScope");
try
{
Logger.RegisterListener(listener);
Action callback;
Logger.LogInfo("Not in file scope.", listener.Phase);
Assert.Null(listener.TakeAndRemove().File);
using (new LoggerFileScope("A"))
{
Logger.LogInfo("In file A", listener.Phase);
Assert.Equal("A", listener.TakeAndRemove().File);
using (new LoggerFileScope("B"))
{
Logger.LogInfo("In file B", listener.Phase);
Assert.Equal("B", listener.TakeAndRemove().File);
var captured = LoggerFileScope.Capture();
callback = () =>
{
using (LoggerFileScope.Restore(captured))
{
Logger.LogInfo("In captured file B", listener.Phase);
}
};
}
Logger.LogInfo("In file A", listener.Phase);
Assert.Equal("A", listener.TakeAndRemove().File);
callback();
Assert.Equal("B", listener.TakeAndRemove().File);
Logger.LogInfo("In file A", listener.Phase);
Assert.Equal("A", listener.TakeAndRemove().File);
using (new LoggerFileScope("C"))
{
Logger.LogInfo("In file C", listener.Phase);
Assert.Equal("C", listener.TakeAndRemove().File);
callback();
Assert.Equal("B", listener.TakeAndRemove().File);
}
}
Logger.LogInfo("Not in file scope.", listener.Phase);
Assert.Null(listener.TakeAndRemove().File);
callback();
Assert.Equal("B", listener.TakeAndRemove().File);
Logger.LogInfo("Not in file scope.", listener.Phase);
Assert.Null(listener.TakeAndRemove().File);
}
finally
{
Logger.UnregisterListener(listener);
}
}
public void TestFileScope()
{
var listener = new TestLoggerListener("TestFileScope");
try
{
Logger.RegisterListener(listener);
Action callback;
Logger.LogInfo("Not in file scope.", listener.Phase);
Assert.Null(listener.TakeAndRemove().File);
using (new LoggerFileScope("A"))
{
Logger.LogInfo("In file A", listener.Phase);
Assert.Equal("A", listener.TakeAndRemove().File);
using (new LoggerFileScope("B"))
{
Logger.LogInfo("In file B", listener.Phase);
Assert.Equal("B", listener.TakeAndRemove().File);
var captured = LoggerFileScope.Capture();
callback = () =>
{
using (LoggerFileScope.Restore(captured))
{
Logger.LogInfo("In captured file B", listener.Phase);
}
};
}
Logger.LogInfo("In file A", listener.Phase);
Assert.Equal("A", listener.TakeAndRemove().File);
callback();
Assert.Equal("B", listener.TakeAndRemove().File);
Logger.LogInfo("In file A", listener.Phase);
Assert.Equal("A", listener.TakeAndRemove().File);
using (new LoggerFileScope("C"))
{
Logger.LogInfo("In file C", listener.Phase);
Assert.Equal("C", listener.TakeAndRemove().File);
callback();
Assert.Equal("B", listener.TakeAndRemove().File);
}
}
Logger.LogInfo("Not in file scope.", listener.Phase);
Assert.Null(listener.TakeAndRemove().File);
callback();
Assert.Equal("B", listener.TakeAndRemove().File);
Logger.LogInfo("Not in file scope.", listener.Phase);
Assert.Null(listener.TakeAndRemove().File);
}
finally
{
Logger.UnregisterListener(listener);
}
}
public void TestPhaseScope()
{
var listener = new TestLoggerListener { LogLevelThreshold = LogLevel.Diagnostic };
var logLevel = Logger.LogLevelThreshold;
ILogItem item;
try
{
Logger.LogLevelThreshold = LogLevel.Diagnostic;
Logger.RegisterListener(listener);
Action<bool> callback;
Logger.LogInfo("test no phase scope");
Assert.Null(listener.TakeAndRemove().Phase);
using (new LoggerPhaseScope("A"))
{
Logger.LogInfo("test in phase scope A");
Assert.Equal("A", listener.TakeAndRemove().Phase);
using (new LoggerPhaseScope("B"))
{
Logger.LogInfo("test in phase scope B");
Assert.Equal("A.B", listener.TakeAndRemove().Phase);
var captured = LoggerPhaseScope.Capture();
Assert.NotNull(captured);
callback = shouldLogPerformance =>
{
using (LoggerPhaseScope.Restore(captured, shouldLogPerformance))
{
Logger.LogInfo("test in captured phase scope B");
}
};
} // exit scope B.
using (new LoggerPhaseScope("C", true))
{
Logger.LogInfo("test in phase scope C");
Assert.Equal("A.C", listener.TakeAndRemove().Phase);
// run callback in scope C.
callback(false);
Assert.Equal("A.B", listener.TakeAndRemove().Phase);
} // exit scope C.
item = listener.TakeAndRemove();
Assert.Equal("A.C", item.Phase);
Assert.Equal(LogLevel.Diagnostic, item.LogLevel);
} // exit scope A.
Logger.LogInfo("test no phase scope");
Assert.Null(listener.TakeAndRemove().Phase);
// run callback in no scope.
callback(true);
Assert.Equal("A.B", listener.TakeAndRemove().Phase);
item = listener.TakeAndRemove();
Assert.Equal("A.B", item.Phase);
Assert.Equal(LogLevel.Diagnostic, item.LogLevel);
Logger.LogInfo("test no phase scope again");
Assert.Null(listener.TakeAndRemove().Phase);
}
finally
{
Logger.UnregisterListener(listener);
Logger.LogLevelThreshold = logLevel;
}
}
public void TestPhaseScope()
{
var listener = TestLoggerListener.CreateLoggerListenerWithPhaseEqualFilter(null, LogLevel.Diagnostic);
var logLevel = Logger.LogLevelThreshold;
ILogItem item;
AmbientContext.InitializeAmbientContext("id");
try
{
Logger.LogLevelThreshold = LogLevel.Diagnostic;
Logger.RegisterListener(listener);
Action <bool, int> callback;
Logger.LogInfo("test no phase scope");
Assert.Null(TakeFirstLogItemAndRemove(listener.Items).Phase);
Assert.Equal("id", AmbientContext.CurrentContext.Id);
Assert.Equal("id.2", AmbientContext.CurrentContext.GenerateNextCorrelationId());
using (new LoggerPhaseScope("A"))
{
Logger.LogInfo("test in phase scope A");
Assert.Equal("A", TakeFirstLogItemAndRemove(listener.Items).Phase);
Assert.Equal("id.3", AmbientContext.CurrentContext.Id);
Assert.Equal("id.3.2", AmbientContext.CurrentContext.GenerateNextCorrelationId());
using (new LoggerPhaseScope("B"))
{
Logger.LogInfo("test in phase scope B");
Assert.Equal("A.B", TakeFirstLogItemAndRemove(listener.Items).Phase);
Assert.Equal("id.3.3", AmbientContext.CurrentContext.Id);
Assert.Equal("id.3.3.2", AmbientContext.CurrentContext.GenerateNextCorrelationId());
var captured = LoggerPhaseScope.Capture();
Assert.NotNull(captured);
callback = (shouldLogPerformance, round) =>
{
using (shouldLogPerformance ?
LoggerPhaseScope.Restore(captured, LogLevel.Diagnostic) :
LoggerPhaseScope.Restore(captured))
{
Logger.LogInfo("test in captured phase scope B");
if (round == 1)
{
Assert.Equal("id.3.3", AmbientContext.CurrentContext.Id);
Assert.Equal("id.3.3.4", AmbientContext.CurrentContext.GenerateNextCorrelationId());
}
if (round == 2)
{
Assert.Equal("id.3.3", AmbientContext.CurrentContext.Id);
Assert.Equal("id.3.3.6", AmbientContext.CurrentContext.GenerateNextCorrelationId());
}
}
};
} // exit scope B.
Assert.Equal("id.3", AmbientContext.CurrentContext.Id);
using (new LoggerPhaseScope("C", LogLevel.Diagnostic))
{
Logger.LogInfo("test in phase scope C");
Assert.Equal("A.C", TakeFirstLogItemAndRemove(listener.Items).Phase);
Assert.Equal("id.3.4", AmbientContext.CurrentContext.Id);
// run callback in scope C.
callback(false, 1);
Assert.Equal("A.B", TakeFirstLogItemAndRemove(listener.Items).Phase);
Assert.Equal("id.3.4", AmbientContext.CurrentContext.Id);
} // exit scope C.
Assert.Equal("id.3", AmbientContext.CurrentContext.Id);
item = TakeFirstLogItemAndRemove(listener.Items);
Assert.Equal("A.C", item.Phase);
Assert.Equal(LogLevel.Diagnostic, item.LogLevel);
} // exit scope A.
Assert.Equal("id", AmbientContext.CurrentContext.Id);
Logger.LogInfo("test no phase scope");
Assert.Null(TakeFirstLogItemAndRemove(listener.Items).Phase);
// run callback in no scope.
callback(true, 2);
Assert.Equal("A.B", TakeFirstLogItemAndRemove(listener.Items).Phase);
item = TakeFirstLogItemAndRemove(listener.Items);
Assert.Equal("A.B", item.Phase);
Assert.Equal(LogLevel.Diagnostic, item.LogLevel);
Logger.LogInfo("test no phase scope again");
Assert.Null(TakeFirstLogItemAndRemove(listener.Items).Phase);
}
finally
{
Logger.UnregisterListener(listener);
Logger.LogLevelThreshold = logLevel;
AmbientContext.CurrentContext.Dispose();
}
}
public void TestFileScope()
{
const string PhaseName = "TestFileScope";
var listener = TestLoggerListener.CreateLoggerListenerWithPhaseEqualFilter(PhaseName, LogLevel.Info);
try
{
Logger.RegisterListener(listener);
Action callback;
Logger.LogInfo("Not in file scope.", PhaseName);
Assert.Null(TakeFirstLogItemAndRemove(listener.Items).File);
using (new LoggerFileScope("A"))
{
Logger.LogInfo("In file A", PhaseName);
Assert.Equal("A", TakeFirstLogItemAndRemove(listener.Items).File);
using (new LoggerFileScope("B"))
{
Logger.LogInfo("In file B", PhaseName);
Assert.Equal("B", TakeFirstLogItemAndRemove(listener.Items).File);
var captured = LoggerFileScope.Capture();
callback = () =>
{
using (LoggerFileScope.Restore(captured))
{
Logger.LogInfo("In captured file B", PhaseName);
}
};
}
Logger.LogInfo("In file A", PhaseName);
Assert.Equal("A", TakeFirstLogItemAndRemove(listener.Items).File);
callback();
Assert.Equal("B", TakeFirstLogItemAndRemove(listener.Items).File);
Logger.LogInfo("In file A", PhaseName);
Assert.Equal("A", TakeFirstLogItemAndRemove(listener.Items).File);
using (new LoggerFileScope("C"))
{
Logger.LogInfo("In file C", PhaseName);
Assert.Equal("C", TakeFirstLogItemAndRemove(listener.Items).File);
callback();
Assert.Equal("B", TakeFirstLogItemAndRemove(listener.Items).File);
}
}
Logger.LogInfo("Not in file scope.", PhaseName);
Assert.Null(TakeFirstLogItemAndRemove(listener.Items).File);
callback();
Assert.Equal("B", TakeFirstLogItemAndRemove(listener.Items).File);
Logger.LogInfo("Not in file scope.", PhaseName);
Assert.Null(TakeFirstLogItemAndRemove(listener.Items).File);
}
finally
{
Logger.UnregisterListener(listener);
}
}
public void TestAggregatedPerformanceScope()
{
var listener = TestLoggerListener.CreateLoggerListenerWithPhaseEqualFilter(null, LogLevel.Diagnostic);
var logLevel = Logger.LogLevelThreshold;
try
{
Logger.RegisterListener(listener);
using (var aggregatedPerformanceScope = new AggregatedPerformanceScope(logLevel))
using (new LoggerPhaseScope("A", logLevel, aggregatedPerformanceScope))
{
using (new LoggerPhaseScope("B", logLevel, aggregatedPerformanceScope))
{
} // exit scope B.
for (int i = 0; i < 10; ++i)
{
using (new LoggerPhaseScope("C", logLevel, aggregatedPerformanceScope))
{
} // exit scope C.
}
using (new LoggerPhaseScope("B"))
{
} // exit scope B.
using (new LoggerPhaseScope("D"))
{
} // exit scope D.
using (new LoggerPhaseScope("B", logLevel, aggregatedPerformanceScope))
{
Parallel.ForEach(
Enumerable.Range(0, 100),
_ =>
{
using (new LoggerPhaseScope("E", logLevel, aggregatedPerformanceScope))
{
Thread.Sleep(10);
} // exit scope E.
});
} // exit scope B.
}// exit scope A.
var allItems = listener.Items.ToList();
Assert.Equal(117, allItems.Count);
Assert.Equal(10, allItems.Count(item => item.Phase == "A.C"));
Assert.Equal(100, allItems.Count(item => item.Phase == "A.B.E"));
allItems.Reverse();
var itemOfAC = TakeFirstLogItemAndRemove(allItems);
Assert.Equal(Logger.LogLevelThreshold, itemOfAC.LogLevel);
Assert.Contains("Phase 'A.C' runs 10 times with average time of", itemOfAC.Message);
var itemOfABE = TakeFirstLogItemAndRemove(allItems);
Assert.Equal(Logger.LogLevelThreshold, itemOfABE.LogLevel);
Assert.Contains("Phase 'A.B.E' runs 100 times with average time of", itemOfABE.Message);
var itemOfAB = TakeFirstLogItemAndRemove(allItems);
Assert.Equal(Logger.LogLevelThreshold, itemOfAB.LogLevel);
Assert.Contains("Phase 'A.B' runs 2 times with average time of", itemOfAB.Message);
var itemOfA = TakeFirstLogItemAndRemove(allItems);
Assert.Equal(Logger.LogLevelThreshold, itemOfA.LogLevel);
Assert.Contains("Phase 'A' runs 1 times with average time of", itemOfA.Message);
}
finally
{
Logger.UnregisterListener(listener);
Logger.LogLevelThreshold = logLevel;
}
}
