Unity Performance

Apr 16, 2008 at 2:02 PM
Hi again.

I need to compare the use of unity VS reflection.
when i ran a simple test that run the Assembly.CreateInstance on the one end,
and the Container.Resolve on the other, the result were unexplainable.

Using reflection, it took 109 MS.
Using Unity Resolve, it took 330 MS

is it possible that this is 3 times more expensive ?

thanks all, maorino
Apr 17, 2008 at 4:17 AM
Depending on what class you're creating, the first time you request an instance Unity could potentially be slower. However, the second or later times should be much, much faster.

Could you post your test code? I'm curious to see it; 3x does seem very expensive, and inconsistent with my experience.
Apr 21, 2008 at 10:39 AM
Hi, thanks for your post.

Here is the code that i am running.
This code build a MessageBoxLogger class using reflection on the one end (outer assembly)
And a MessageBoxLogger class using unity (Inner assembly)

As you can understand from it's name, the MessageBoxLogger class is a very small and naked class...
I run this code for 100 times, and the results ere posted in my first message.

/// <summary>
/// Initiate creation of the logger class using unity
/// </summary>
/// <param name="p">number of times to run creation</param>
/// <returns>total time to create the logger for 'p' times</returns>
private static TimeSpan RunUnityCreation(int times)
{
DateTime beginingUnityTime = DateTime.Now;
for (int i = 0; i < times; i++)
{
LoadLoggerUsingUnity();
}
DateTime endUnityTime = DateTime.Now;

TimeSpan diffUnity = endUnityTime - beginingUnityTime;
return diffUnity;
}

/// <summary>
/// Initiate creation of the logger class using reflection
/// </summary>
/// <param name="p">number of times to run creation</param>
/// <returns>total time to create the logger for 'p' times</returns>
private static TimeSpan RunReflectionCreation(int times)
{
DateTime beginingReflectionTime = DateTime.Now;
for (int i = 0; i < times; i++)
{
LoadLoggerUsingReflection();
}
DateTime endReflectionTime = DateTime.Now;

TimeSpan diffReflection = endReflectionTime - beginingReflectionTime;
return diffReflection;
}

Thanks, Maorino
Apr 21, 2008 at 10:40 AM
Sorry, it's the inner function you need :)

/// <summary>
/// Create the message box loger instance and place it as the actual
/// logger of the form (using unity)
/// </summary>
/// <returns>a frmUnityMain form with the message box logger as a data member</returns>
private static frmUnityMain LoadLoggerUsingUnity()
{
IUnityContainer container = new UnityContainer();
container.RegisterType<ILogger,MessageBoxLogger>();
frmUnityMain frm = container.Resolve<frmUnityMain>();
return frm;

}

/// <summary>
/// Create the message box loger instance and place it as the actual
/// logger of the form (using reflection)
/// </summary>
/// <returns>a frmUnityMain form with the message box logger as a data member</returns>
private static frmUnityMain LoadLoggerUsingReflection()
{
Assembly asm = Assembly.LoadFrom("LoggerImplementation.dll");
Type[] types = asm.GetTypes();
ILogger obj = (ILogger)asm.CreateInstance(types0.FullName);
frmUnityMain frm = new frmUnityMain();
frm.Logger = obj;
return frm;
}
Apr 21, 2008 at 3:03 PM
Edited Apr 21, 2008 at 3:11 PM
Could I suggest that you do NOT recreate the container and register your type each time. Otherwise, you are also benchmarking the container creation time. Creating and configuring the container should happen the once before the container is required and saved somewhere and used over and over. A singleton would be a good choice.

When I run this on my machine I get the following results:

     Unity: 00:00:25.5127045
Reflection: 00:00:25.5127045

using System;
using System.Diagnostics;
using System.Reflection;
using LoggerImplementation;
using Microsoft.Practices.Unity;
 
namespace UnityConsoleApplication
{
    class Program
    {
        private static readonly IUnityContainer container = new UnityContainer();
 
        static void Main(string[] args)
        {
            const int iterations = 10000000;
 
            container.RegisterType<ILogger, TraceLogger>();
            container.RegisterType<frmUnityMain, frmUnityMain>();
 
            TimeSpan unityElapsed = RunUnityCreation(iterations);
            TimeSpan reflectionElapsed = RunReflectionCreation(iterations);
            Console.WriteLine("     Unity: {0}", unityElapsed);
            Console.WriteLine("Reflection: {0}", unityElapsed);
            Console.ReadLine();
        }
 
 
        /// <summary>
        /// Initiate creation of the logger class using unity
        /// </summary>
        /// <param name="times">number of times to run creation</param>
        /// <returns>total time to create the logger for 'p' times</returns>
        private static TimeSpan RunUnityCreation(int times)
        {
            Stopwatch stopwatch = Stopwatch.StartNew();
            for (int i = 0; i < times; i++)
            {
                LoadLoggerUsingUnity();
            }
            stopwatch.Stop();
 
            TimeSpan elapsed = new TimeSpan(stopwatch.ElapsedTicks);
            return elapsed;
        }
 
        /// <summary>
        /// Initiate creation of the logger class using reflection
        /// </summary>
        /// <param name="times">number of times to run creation</param>
        /// <returns>total time to create the logger for 'p' times</returns>
        private static TimeSpan RunReflectionCreation(int times)
        {
            Stopwatch stopwatch = Stopwatch.StartNew();
            for (int i = 0; i < times; i++)
            {
                LoadLoggerUsingReflection();
            }
            stopwatch.Stop();
 
            TimeSpan elapsed = new TimeSpan(stopwatch.ElapsedTicks);
            return elapsed;
        }
 
        /// <summary>
        /// Create the message box loger instance and place it as the actual
        /// logger of the form (using unity)
        /// </summary>
        /// <returns>a frmUnityMain form with the message box logger as a data member</returns>
        private static frmUnityMain LoadLoggerUsingUnity()
        {
            frmUnityMain frm = container.Resolve<frmUnityMain>();
            return frm;
 
        }
 
        /// <summary>
        /// Create the message box loger instance and place it as the actual
        /// logger of the form (using reflection)
        /// </summary>
        /// <returns>a frmUnityMain form with the message box logger as a data member</returns>
        private static frmUnityMain LoadLoggerUsingReflection()
        {
            Assembly asm = Assembly.LoadFrom("LoggerImplementation.dll");
            Type[] types = asm.GetTypes();
            ILogger obj = (ILogger)asm.CreateInstance("LoggerImplementation.TraceLogger, LoggerImplementation");
            frmUnityMain frm = new frmUnityMain();
            frm.Logger = obj;
            return frm;
        }
    }
 
    public class frmUnityMain
    {
        [Dependency]
        public ILogger Logger { get; set; }
    }
}


Maorino wrote:
Sorry, it's the inner function you need :)

/// <summary>
/// Create the message box loger instance and place it as the actual
/// logger of the form (using unity)
/// </summary>
/// <returns>a frmUnityMain form with the message box logger as a data member</returns>
private static frmUnityMain LoadLoggerUsingUnity()
{
IUnityContainer container = new UnityContainer();
container.RegisterType<ILogger,MessageBoxLogger>();
frmUnityMain frm = container.Resolve<frmUnityMain>();
return frm;

}

/// <summary>
/// Create the message box loger instance and place it as the actual
/// logger of the form (using reflection)
/// </summary>
/// <returns>a frmUnityMain form with the message box logger as a data member</returns>
private static frmUnityMain LoadLoggerUsingReflection()
{
Assembly asm = Assembly.LoadFrom("LoggerImplementation.dll");
Type[] types = asm.GetTypes();
ILogger obj = (ILogger)asm.CreateInstance(types0.FullName);
frmUnityMain frm = new frmUnityMain();
frm.Logger = obj;
return frm;
}

Apr 21, 2008 at 3:14 PM
Also, dynamically loading your logger class might be better accomplished this way.

        /// <summary>
        /// Create the message box loger instance and place it as the actual
        /// logger of the form (using reflection)
        /// </summary>
        /// <returns>a frmUnityMain form with the message box logger as a data member</returns>
        private static frmUnityMain LoadLoggerUsingReflection()
        {
            Type loggerType = Type.GetType("LoggerImplementation.TraceLogger, LoggerImplementation");
            ILogger logger = (ILogger)Activator.CreateInstance(loggerType);
            frmUnityMain frm = new frmUnityMain();
            frm.Logger = logger;
            return frm;
        }

pbolduc wrote:
Could I suggest that you do NOT recreate the container and register your type each time. Otherwise, you are also benchmarking the container creation time. Creating and configuring the container should happen the once before the container is required and saved somewhere and used over and over. A singleton would be a good choice.

When I run this on my machine I get the following results:

     Unity: 00:00:25.5127045
Reflection: 00:00:25.5127045

Apr 21, 2008 at 4:47 PM
As the above post mentioned, you're recreating the container every time, which will skew your results. Reuse the container and you'll get very different results.
Apr 22, 2008 at 1:42 AM

     Unity: 00:00:25.5127045
Reflection: 00:00:25.5127045

            Console.WriteLine("     Unity: {0}", unityElapsed);
            Console.WriteLine("Reflection: {0}", unityElapsed);


You weren't at all surprised that the two different methods took exactly the same time to run?
Apr 22, 2008 at 5:26 AM
Edited Apr 22, 2008 at 5:28 AM
Sorry, It was too early in the morning!! Yet another reason I post all my code! Interesting for the changes...

     Unity: 00:00:26.5653603
Reflection: 00:01:59.5051937

I supposed the following line makes the difference
Type loggerType = Type.GetType("LoggerImplementation.TraceLogger, LoggerImplementation");

Let me know if there is anything wrong with my methods/analysis.
using System;
using System.Diagnostics;
using System.Reflection;
using LoggerImplementation;
using Microsoft.Practices.Unity;
 
namespace UnityConsoleApplication
{
    class Program
    {
        private static readonly IUnityContainer container = new UnityContainer();
 
        static void Main(string[] args)
        {
            const int iterations = 10000000;
 
            container.RegisterType<ILogger, TraceLogger>();
            container.RegisterType<frmUnityMain, frmUnityMain>();
 
            TimeSpan unityElapsed = RunUnityCreation(iterations);
            TimeSpan reflectionElapsed = RunReflectionCreation(iterations);
            Console.WriteLine("     Unity: {0}", unityElapsed);
            Console.WriteLine("Reflection: {0}", reflectionElapsed);
            Console.ReadLine();
        }
 
 
        /// <summary>
        /// Initiate creation of the logger class using unity
        /// </summary>
        /// <param name="times">number of times to run creation</param>
        /// <returns>total time to create the logger for 'p' times</returns>
        private static TimeSpan RunUnityCreation(int times)
        {
            Stopwatch stopwatch = Stopwatch.StartNew();
            for (int i = 0; i < times; i++)
            {
                LoadLoggerUsingUnity();
            }
            stopwatch.Stop();
 
            TimeSpan elapsed = new TimeSpan(stopwatch.ElapsedTicks);
            return elapsed;
        }
 
        /// <summary>
        /// Initiate creation of the logger class using reflection
        /// </summary>
        /// <param name="times">number of times to run creation</param>
        /// <returns>total time to create the logger for 'p' times</returns>
        private static TimeSpan RunReflectionCreation(int times)
        {
            Stopwatch stopwatch = Stopwatch.StartNew();
            for (int i = 0; i < times; i++)
            {
                LoadLoggerUsingReflection();
            }
            stopwatch.Stop();
 
            TimeSpan elapsed = new TimeSpan(stopwatch.ElapsedTicks);
            return elapsed;
        }
 
        /// <summary>
        /// Create the message box loger instance and place it as the actual
        /// logger of the form (using unity)
        /// </summary>
        /// <returns>a frmUnityMain form with the message box logger as a data member</returns>
        private static frmUnityMain LoadLoggerUsingUnity()
        {
            frmUnityMain frm = container.Resolve<frmUnityMain>();
            return frm;
 
        }
 
        /// <summary>
        /// Create the message box loger instance and place it as the actual
        /// logger of the form (using reflection)
        /// </summary>
        /// <returns>a frmUnityMain form with the message box logger as a data member</returns>
        private static frmUnityMain LoadLoggerUsingReflection()
        {
            Type loggerType = Type.GetType("LoggerImplementation.TraceLogger, LoggerImplementation");
            ILogger logger = (ILogger)Activator.CreateInstance(loggerType);
            frmUnityMain frm = new frmUnityMain();
            frm.Logger = logger;
            return frm;
        }
    }
 
    public class frmUnityMain
    {
        [Dependency]
        public ILogger Logger { get; set; }
    }
}

KenLH wrote:

     Unity: 00:00:25.5127045
Reflection: 00:00:25.5127045

            Console.WriteLine("     Unity: {0}", unityElapsed);
            Console.WriteLine("Reflection: {0}", unityElapsed);


You weren't at all surprised that the two different methods took exactly the same time to run?