private void testRawRecordingSpeedAtExpectedInterval(String label, AbstractHistogram histogram,
long expectedInterval, long timingLoopCount,
bool assertNoGC = true, bool multiThreaded = false)
{
Console.WriteLine("\nTiming recording speed with expectedInterval = " + expectedInterval + " :");
// Warm up:
var timer = Stopwatch.StartNew();
recordLoopWithExpectedInterval(histogram, warmupLoopLength, expectedInterval);
timer.Stop();
// 1 millisecond (ms) = 1000 microsoecond (µs or usec)
// 1 microsecond (µs or usec) = 1000 nanosecond (ns or nsec)
// 1 second = 1,000,000 usec or 1,000 ms
long deltaUsec = timer.ElapsedMilliseconds * 1000L;
long rate = 1000000 * warmupLoopLength / deltaUsec;
Console.WriteLine("{0}Warmup:\n{1:N0} value recordings completed in {2:N0} usec, rate = {3:N0} value recording calls per sec.",
label, warmupLoopLength, deltaUsec, rate);
histogram.reset();
// Wait a bit to make sure compiler had a chance to do it's stuff:
try
{
Thread.Sleep(1000);
}
catch (Exception)
{
}
var gcBefore = PrintGCAndMemoryStats("GC Before");
timer = Stopwatch.StartNew();
recordLoopWithExpectedInterval(histogram, timingLoopCount, expectedInterval);
timer.Stop();
var gcAfter = PrintGCAndMemoryStats("GC After ");
deltaUsec = timer.ElapsedMilliseconds * 1000L;
rate = 1000000 * timingLoopCount / deltaUsec;
Console.WriteLine(label + "Hot code timing:");
Console.WriteLine("{0}{1:N0} value recordings completed in {2:N0} usec, rate = {3:N0} value recording calls per sec.",
label, timingLoopCount, deltaUsec, rate);
if (multiThreaded == false)
{
rate = 1000000 * histogram.getTotalCount() / deltaUsec;
Console.WriteLine("{0}{1:N0} raw recorded entries completed in {2:N0} usec, rate = {3:N0} recorded values per sec.",
label, histogram.getTotalCount(), deltaUsec, rate);
}
if (assertNoGC)
{
//// TODO work out why we always seems to get at least 1 GC here, maybe it's due to the length of the test run??
//Assert.LessOrEqual(gcAfter.Item1 - gcBefore.Item1, 1, "There should be at MOST 1 Gen1 GC Collections");
//Assert.LessOrEqual(gcAfter.Item2 - gcBefore.Item2, 1, "There should be at MOST 1 Gen2 GC Collections");
//Assert.LessOrEqual(gcAfter.Item3 - gcBefore.Item3, 1, "There should be at MOST 1 Gen3 GC Collections");
// TODO work out why we always seems to get at least 1 GC here, maybe it's due to the length of the test run??
Assert.LessOrEqual(gcAfter.Gen1 - gcBefore.Gen1, 1, "There should be at MOST 1 Gen1 GC Collections");
Assert.LessOrEqual(gcAfter.Gen1 - gcBefore.Gen1, 1, "There should be at MOST 1 Gen2 GC Collections");
Assert.LessOrEqual(gcAfter.Gen3 - gcBefore.Gen3, 1, "There should be at MOST 1 Gen3 GC Collections");
}
}
private void testRawRecordingSpeedAtExpectedInterval(String label, AbstractHistogram histogram,
long expectedInterval, long timingLoopCount,
bool assertNoGC = true, bool multiThreaded = false)
{
Console.WriteLine("\nTiming recording speed with expectedInterval = " + expectedInterval + " :");
// Warm up:
var timer = Stopwatch.StartNew();
recordLoopWithExpectedInterval(histogram, warmupLoopLength, expectedInterval);
timer.Stop();
// 1 millisecond (ms) = 1000 microsoecond (µs or usec)
// 1 microsecond (µs or usec) = 1000 nanosecond (ns or nsec)
// 1 second = 1,000,000 usec or 1,000 ms
long deltaUsec = timer.ElapsedMilliseconds * 1000L;
long rate = 1000000 * warmupLoopLength / deltaUsec;
Console.WriteLine("{0}Warmup:\n{1:N0} value recordings completed in {2:N0} usec, rate = {3:N0} value recording calls per sec.",
label, warmupLoopLength, deltaUsec, rate);
histogram.reset();
// Wait a bit to make sure compiler had a chance to do it's stuff:
try
{
Thread.Sleep(1000);
}
catch (Exception)
{
}
var gcBefore = PrintGCAndMemoryStats("GC Before");
timer = Stopwatch.StartNew();
recordLoopWithExpectedInterval(histogram, timingLoopCount, expectedInterval);
timer.Stop();
var gcAfter = PrintGCAndMemoryStats("GC After ");
deltaUsec = timer.ElapsedMilliseconds * 1000L;
rate = 1000000 * timingLoopCount / deltaUsec;
Console.WriteLine(label + "Hot code timing:");
Console.WriteLine("{0}{1:N0} value recordings completed in {2:N0} usec, rate = {3:N0} value recording calls per sec.",
label, timingLoopCount, deltaUsec, rate);
if (multiThreaded == false)
{
rate = 1000000 * histogram.getTotalCount() / deltaUsec;
Console.WriteLine("{0}{1:N0} raw recorded entries completed in {2:N0} usec, rate = {3:N0} recorded values per sec.",
label, histogram.getTotalCount(), deltaUsec, rate);
}
if (assertNoGC)
{
//// TODO work out why we always seems to get at least 1 GC here, maybe it's due to the length of the test run??
//Assert.LessOrEqual(gcAfter.Item1 - gcBefore.Item1, 1, "There should be at MOST 1 Gen1 GC Collections");
//Assert.LessOrEqual(gcAfter.Item2 - gcBefore.Item2, 1, "There should be at MOST 1 Gen2 GC Collections");
//Assert.LessOrEqual(gcAfter.Item3 - gcBefore.Item3, 1, "There should be at MOST 1 Gen3 GC Collections");
// TODO work out why we always seems to get at least 1 GC here, maybe it's due to the length of the test run??
Assert.LessOrEqual(gcAfter.Gen1 - gcBefore.Gen1, 1, "There should be at MOST 1 Gen1 GC Collections");
Assert.LessOrEqual(gcAfter.Gen1 - gcBefore.Gen1, 1, "There should be at MOST 1 Gen2 GC Collections");
Assert.LessOrEqual(gcAfter.Gen3 - gcBefore.Gen3, 1, "There should be at MOST 1 Gen3 GC Collections");
}
}
