private static void BuildArticle(HostService hostService, int maxParallelism)
{
using (var aggregatedPerformanceScope = new AggregatedPerformanceScope())
{
hostService.Models.RunAll(
m =>
{
using (new LoggerFileScope(m.LocalPathFromRoot))
{
Logger.LogDiagnostic($"Processor {hostService.Processor.Name}: Building...");
BuildPhaseUtility.RunBuildSteps(
hostService.Processor.BuildSteps,
buildStep =>
{
Logger.LogDiagnostic($"Processor {hostService.Processor.Name}, step {buildStep.Name}: Building...");
using (new LoggerPhaseScope(buildStep.Name, LogLevel.Diagnostic, aggregatedPerformanceScope))
{
buildStep.Build(m, hostService);
}
});
}
},
maxParallelism);
}
}
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;
}
}
