#region Copyright & License
//
// Copyright 2001-2005 The Apache Software Foundation
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
//
#endregion
namespace NotLogging{
using System;
using System.Collections;
using log4net;
using log4net.Appender;
using log4net.Layout;
using log4net.Repository;
using log4net.Repository.Hierarchy;
public class NotLogging
{
#region Init Code
private static int WARM_UP_CYCLES = 10000;
static readonly ILog SHORT_LOG = LogManager.GetLogger("A0123456789");
static readonly ILog MEDIUM_LOG= LogManager.GetLogger("A0123456789.B0123456789");
static readonly ILog LONG_LOG = LogManager.GetLogger("A0123456789.B0123456789.C0123456789");
static readonly ILog INEXISTENT_SHORT_LOG = LogManager.GetLogger("I0123456789");
static readonly ILog INEXISTENT_MEDIUM_LOG= LogManager.GetLogger("I0123456789.B0123456789");
static readonly ILog INEXISTENT_LONG_LOG = LogManager.GetLogger("I0123456789.B0123456789.C0123456789");
static readonly ILog[] LOG_ARRAY = new ILog[] {
SHORT_LOG,
MEDIUM_LOG,
LONG_LOG,
INEXISTENT_SHORT_LOG,
INEXISTENT_MEDIUM_LOG,
INEXISTENT_LONG_LOG};
static readonly TimedTest[] TIMED_TESTS = new TimedTest[] {
new SimpleMessage_Bare(),
new SimpleMessage_Array(),
new SimpleMessage_MethodGuard_Bare(),
new SimpleMessage_LocalGuard_Bare(),
new ComplexMessage_Bare(),
new ComplexMessage_Array(),
new ComplexMessage_MethodGuard_Bare(),
new ComplexMessage_MethodGuard_Array(),
new ComplexMessage_MemberGuard_Bare(),
new ComplexMessage_LocalGuard_Bare()};
private static void Usage()
{
System.Console.WriteLine(
"Usage: NotLogging <true|false> <runLength>" + Environment.NewLine +
"\t true indicates shipped code" + Environment.NewLine +
"\t false indicates code in development" + Environment.NewLine +
"\t runLength is an int representing the run length of loops" + Environment.NewLine +
"\t We suggest that runLength be at least 1000000 (1 million).");
Environment.Exit(1);
}
/// <summary>
/// Program wide initialization method
/// </summary>
/// <param name="args"></param>
private static int ProgramInit(String[] args)
{
int runLength = 0;
try
{
runLength = int.Parse(args[1]);
}
catch(Exception e)
{
System.Console.Error.WriteLine(e);
Usage();
}
ConsoleAppender appender = new ConsoleAppender();
appender.Layout = new SimpleLayout();
((SimpleLayout)appender.Layout).ActivateOptions();
appender.ActivateOptions();
if("false" == args[0])
{
// nothing to do
}
else if ("true" == args[0])
{
System.Console.WriteLine("Flagging as shipped code.");
((Hierarchy)LogManager.GetRepository()).Threshold = log4net.Core.Level.Warn;
}
else
{
Usage();
}
((Logger)SHORT_LOG.Logger).Level = log4net.Core.Level.Info;
((Hierarchy)LogManager.GetRepository()).Root.Level = log4net.Core.Level.Info;
((Hierarchy)LogManager.GetRepository()).Root.AddAppender(appender);
return runLength;
}
#endregion
/// <summary>
/// The main entry point for the application.
/// </summary>
[STAThread]
static void Main(string[] argv)
{
if (System.Diagnostics.Debugger.IsAttached)
{
WARM_UP_CYCLES = 0;
argv = new string[] { "false", "2" };
}
if(argv.Length != 2)
{
Usage();
}
int runLength = ProgramInit(argv);
System.Console.WriteLine();
System.Console.Write("Warming Up...");
if (WARM_UP_CYCLES > 0)
{
foreach(ILog logger in LOG_ARRAY)
{
foreach(TimedTest timedTest in TIMED_TESTS)
{
timedTest.Run(logger, WARM_UP_CYCLES);
}
}
}
System.Console.WriteLine("Done");
System.Console.WriteLine();
// Calculate maximum description length
int maxDescLen = 0;
foreach(TimedTest timedTest in TIMED_TESTS)
{
maxDescLen = Math.Max(maxDescLen, timedTest.Description.Length);
}
string formatString = "{0,-"+(maxDescLen+1)+"} {1,9:G} ticks. Log: {2}";
double delta;
ArrayList averageData = new ArrayList();
foreach(TimedTest timedTest in TIMED_TESTS)
{
double total = 0;
foreach(ILog logger in LOG_ARRAY)
{
delta = timedTest.Run(logger, runLength);
System.Console.WriteLine(string.Format(formatString, timedTest.Description, delta, ((Logger)logger.Logger).Name));
total += delta;
}
System.Console.WriteLine();
averageData.Add(new object[] { timedTest, total/((double)LOG_ARRAY.Length) });
}
System.Console.WriteLine();
System.Console.WriteLine("Averages:");
System.Console.WriteLine();
foreach(object[] pair in averageData)
{
string avgFormatString = "{0,-"+(maxDescLen+1)+"} {1,9:G} ticks.";
System.Console.WriteLine(string.Format(avgFormatString, ((TimedTest)pair[0]).Description, ((double)pair[1])));
}
}
}
abstract class TimedTest
{
abstract public double Run(ILog log, long runLength);
abstract public string Description {get;}
}
#region Tests calling Debug(string)
class SimpleMessage_Bare : TimedTest
{
override public double Run(ILog log, long runLength)
{
DateTime before = DateTime.Now;
for(int i = 0; i < runLength; i++)
{
log.Debug("msg");
}
DateTime after = DateTime.Now;
TimeSpan diff = after - before;
return ((double)diff.Ticks)/((double)runLength);
}
override public string Description
{
get { return "log.Debug(\"msg\");"; }
}
}
class ComplexMessage_MethodGuard_Bare : TimedTest
{
override public double Run(ILog log, long runLength)
{
DateTime before = DateTime.Now;
for(int i = 0; i < runLength; i++)
{
if(log.IsDebugEnabled)
{
log.Debug("msg" + i + "msg");
}
}
DateTime after = DateTime.Now;
TimeSpan diff = after - before;
return ((double)diff.Ticks)/((double)runLength);
}
override public string Description
{
get { return "if(log.IsDebugEnabled) log.Debug(\"msg\" + i + \"msg\");"; }
}
}
class ComplexMessage_Bare : TimedTest
{
override public double Run(ILog log, long runLength)
{
DateTime before = DateTime.Now;
for(int i = 0; i < runLength; i++)
{
log.Debug("msg" + i + "msg");
}
DateTime after = DateTime.Now;
TimeSpan diff = after - before;
return ((double)diff.Ticks)/((double)runLength);
}
override public string Description
{
get { return "log.Debug(\"msg\" + i + \"msg\");"; }
}
}
#endregion
#region Tests calling Debug(new object[] { ... })
class SimpleMessage_Array : TimedTest
{
override public double Run(ILog log, long runLength)
{
DateTime before = DateTime.Now;
for(int i = 0; i < runLength; i++)
{
log.Debug(new object[] { "msg" });
}
DateTime after = DateTime.Now;
TimeSpan diff = after - before;
return ((double)diff.Ticks)/((double)runLength);
}
override public string Description
{
get { return "log.Debug(new object[] { \"msg\" });"; }
}
}
class ComplexMessage_MethodGuard_Array : TimedTest
{
override public double Run(ILog log, long runLength)
{
DateTime before = DateTime.Now;
for(int i = 0; i < runLength; i++)
{
if(log.IsDebugEnabled)
{
log.Debug(new object[] { "msg" , i , "msg" });
}
}
DateTime after = DateTime.Now;
TimeSpan diff = after - before;
return ((double)diff.Ticks)/((double)runLength);
}
override public string Description
{
get { return "if(log.IsDebugEnabled) log.Debug(new object[] { \"msg\" , i , \"msg\" });"; }
}
}
class ComplexMessage_Array : TimedTest
{
override public double Run(ILog log, long runLength)
{
DateTime before = DateTime.Now;
for(int i = 0; i < runLength; i++)
{
log.Debug(new object[] { "msg" , i , "msg" });
}
DateTime after = DateTime.Now;
TimeSpan diff = after - before;
return ((double)diff.Ticks)/((double)runLength);
}
override public string Description
{
get { return "log.Debug(new object[] { \"msg\" , i , \"msg\" });"; }
}
}
#endregion
#region Tests calling Debug(string) (using class members)
class ComplexMessage_MemberGuard_Bare : TimedTest
{
override public double Run(ILog log, long runLength)
{
return (new Impl(log)).Run(runLength);
}
override public string Description
{
get { return "if(m_isEnabled) m_log.Debug(\"msg\" + i + \"msg\");"; }
}
class Impl
{
private readonly ILog m_log;
private readonly bool m_isEnabled;
public Impl(ILog log)
{
m_log = log;
m_isEnabled = m_log.IsDebugEnabled;
}
public double Run(long runLength)
{
DateTime before = DateTime.Now;
for(int i = 0; i < runLength; i++)
{
if(m_isEnabled)
{
m_log.Debug("msg" + i + "msg");
}
}
DateTime after = DateTime.Now;
TimeSpan diff = after - before;
return ((double)diff.Ticks)/((double)runLength);
}
}
}
class SimpleMessage_LocalGuard_Bare : TimedTest
{
override public double Run(ILog log, long runLength)
{
bool isEnabled = log.IsDebugEnabled;
DateTime before = DateTime.Now;
for(int i = 0; i < runLength; i++)
{
if (isEnabled) log.Debug("msg");
}
DateTime after = DateTime.Now;
TimeSpan diff = after - before;
return ((double)diff.Ticks)/((double)runLength);
}
override public string Description
{
get { return "if (isEnabled) log.Debug(\"msg\");"; }
}
}
class SimpleMessage_MethodGuard_Bare : TimedTest
{
override public double Run(ILog log, long runLength)
{
DateTime before = DateTime.Now;
for(int i = 0; i < runLength; i++)
{
if (log.IsDebugEnabled) log.Debug("msg");
}
DateTime after = DateTime.Now;
TimeSpan diff = after - before;
return ((double)diff.Ticks)/((double)runLength);
}
override public string Description
{
get { return "if (log.IsDebugEnabled) log.Debug(\"msg\");"; }
}
}
class ComplexMessage_LocalGuard_Bare : TimedTest
{
override public double Run(ILog log, long runLength)
{
bool isEnabled = log.IsDebugEnabled;
DateTime before = DateTime.Now;
for(int i = 0; i < runLength; i++)
{
if(isEnabled) log.Debug("msg" + i + "msg");
}
DateTime after = DateTime.Now;
TimeSpan diff = after - before;
return ((double)diff.Ticks)/((double)runLength);
}
override public string Description
{
get { return "if (isEnabled) log.Debug(\"msg\" + i + \"msg\");"; }
}
}
#endregion
}
|