public void MeasureIncreasingDoublingLoop()
{
UT_INIT();
Log.SetVerbosity(new ConsoleLogger(), Verbosity.Verbose, "/");
Log.MapThreadName("UnitTest");
Log.SetDomain("TickWatch", Scope.Method);
Log.Info("This test shows quite nicely, how the just in time compiler steps in when we are looping heavily!");
String testString = "-------------------------------------------------------------------------------------------#";
AString testAString = new AString(testString);
TickWatch ttString = new TickWatch();
TickWatch ttAString = new TickWatch();
for (int run = 4; run < 20; run++)
{
int qtyLoops = (run == 0) ? 0 : (1 << (run - 1));
// use String.IndexOf()
ttString.Reset();
int nonOptimizableUsedResultValue = 0;
for (int i = 0; i < qtyLoops; i++)
{
nonOptimizableUsedResultValue += testString.IndexOf('#');
}
Ticks sSample = ttString.Sample();
// use AString.IndexOf()
ttAString.Reset();
for (int i = 0; i < qtyLoops; i++)
{
nonOptimizableUsedResultValue += testAString.IndexOf('#');
}
Ticks aSample = ttAString.Sample();
if (nonOptimizableUsedResultValue > -1) // this is always true, just for the sake that the compiler does not optimize the whole code!
{
Log.Info(Log.Buf()._("Search loops ").Field()._(qtyLoops.ToString()).Field(6)
._(": time needed: ").Field()._((int)sSample.InNanos()).Field(8)
._(" / ").Field()._((int)aSample.InNanos()).Field(8)
._(" Ratio String/AString: ")._(((double)sSample.Raw()) / ((double)aSample.Raw()))
);
}
}
}
public void Ages()
{
UT_INIT();
Log.SetVerbosity(new ConsoleLogger(), Verbosity.Verbose, "/");
Log.MapThreadName("UnitTest");
Log.SetDomain("TickWatch", Scope.Method);
TickWatch tt = new TickWatch();
// minimum time measuring
{
tt.Start();
tt.Sample();
tt.Reset(); // we need to do this once before, otherwise C# might be
// very slow. Obviously the optimizer...
tt.Start();
tt.Sample();
long ttAverageInNanos = tt.GetAverage().InNanos();
long ttAverageInMicros = tt.GetAverage().InMicros();
long ttAverageInMillis = tt.GetAverage().InMillis();
Log.Info("TickWatch minimum measurement nanos: " + ttAverageInNanos);
Log.Info("TickWatch minimum measurement micros: " + ttAverageInMicros);
Log.Info("TickWatch minimum measurement millis: " + ttAverageInMillis);
UT_TRUE(ttAverageInNanos < 5000);
UT_TRUE(ttAverageInMicros <= 5);
UT_TRUE(ttAverageInMillis == 0);
}
// minimum sleep time measuring
{
tt.Reset();
for (int i = 0; i < 100; i++)
{
ALIB.SleepNanos(1);
tt.Sample();
}
Ticks avg = tt.GetAverage();
Log.Info("100 probes of 1 ns of sleep leads to average sleep time of " + avg.InNanos() + " ns");
}
// sleep two times 20 ms and probe it to an average
{
tt.Reset();
tt.Start();
ALIB.SleepMillis(20);
tt.Sample();
ALIB.SleepMillis(80);
tt.Start();
ALIB.SleepMillis(20);
tt.Sample();
long cnt = tt.GetSampleCnt();
long avg = tt.GetAverage().InMillis();
double hertz = tt.GetAverage().InHertz(1);
Log.Info("TickWatch sum is " + tt.GetCumulated().InMillis() + " after " + cnt + " times 20 ms sleep");
Log.Info(" average is: " + avg + " ms");
Log.Info(" in Hertz: " + hertz);
UT_TRUE(hertz < 53);
UT_TRUE(hertz > 30); // should work even on heavily loaded machines
UT_EQ(2, cnt);
UT_TRUE(avg >= 18);
UT_TRUE(avg < 45); // should work even on heavily loaded machines
}
// Ticks Since
{
Ticks tt1 = new Ticks(); tt1.FromSeconds(1000);
Ticks tt2 = new Ticks(); tt2.FromSeconds(1001);
UT_TRUE(tt2.Since(tt1).InMillis() == 1000L);
UT_TRUE(tt2.Since(tt1).InMicros() == 1000L * 1000L);
UT_TRUE(tt2.Since(tt1).InNanos() == 1000L * 1000L * 1000L);
}
}
