Hibernating Rhinos

Zero friction databases

New: Uber Profiler “appender only” nuget package is now available

We started to provide nuget packages for our Uber Profilers early on when nuget was available. Back then, we decided to provide you with a one click solution: you add the NHibernate Profiler (or any other of our profilers) nuget package to your project, and you can start the profiler right away. We open the profiler interface after you install the package and add some initialization code the your project to hook the profiler.

That worked great most of time, when you do a fresh installation of the profiler. But when you are doing upgrades and you do not want to use the default initialization code we provide, it can be annoying to keep removing it once you upgrade. This is way we created this issue, based on user demand.

So you can now use the NHibernateProfiler.Appender or EntityFrameworkProfiler.Appender (the same for our other profilers) package, which contains just the appender dll. No code setup and it is also a much slimmer package, so package restore will also be faster.

Feedback is required: Can we require you to have .NET 4.5 in order to use the profiler UI?

As we want to use the async keyword in the profiler’s client, we think to start targeting the .NET Framework 4.5.

Considering that .NET Framework 4.5 came out a year ago and it is distributed on Windows 8, we think it is acceptable to ask our users to have the .NET Framework installed on the machine.

Users that still need to use the profiler on a machine with just .NET 4.0 would have to use the recent build of the profiler, which is 2197. But since that this build requires this update for the .NET Framework 4.0, we figure out that it is better to require the .NET Framework 4.5 (in order to avoid with strange error for users that do not have this update) or drop the use of the async keyword, which we hope to avoid.

Please let us know your opinion about this change. We will wait two weeks or so in order to get a feedback from you guys, before pushing a new version to production with this change.

Tags:

Published at

Originally posted at

Comments (13)

Use ProfilerIntegration static class in order to hook into the profiler

A user asked us how can he use this class so I thought it may be a good idea to blog about that.

You can use the HibernatingRhinos.Profiler.Appender.ProfilerIntegration static class in order to hook into the profiler and do some interesting staff.

The two most uses of this class is 1. telling the profiler to ignore some code and not record it. 2. record something that wasn’t executed by the ORM but by ADO.NET directly in the profiler.

Ignore and not profile a portion of code

This is mostly useful when running unit tests and you need to do some initialization to the database which you prefer not to see in the profiler output.

You can do this using:

using (ProfilerIntegration.IgnoreAll())
{
    // Do something
}

Or

ProfilerIntegration.IgnoreAll();
// Do something
ProfilerIntegration.ResumeProfiling();

Record custom messages inside the profiler

This is mostly useful if you doing some use of the pure ADO.NET api alongside to the ORM that you’re using and you want to record those actions.

In this case, since you aren’t using the DbConnection/DbDataReader/DbCommnad etc that the profiler created, you’ll need to notify the profiler about each action.

This can be done using the following code:

ProfilerIntegration.PublishProfilerEvent("session id", "logger name", "message");

This is 3 parameters:

Session ID = a string that identify the session to which this statement belongs. In NHibernate you’ll want to use ((SessionImpl)session).SessionId.ToString(). In the other ORM, you can use some GUID which should be the same for statements in this session.

Logger name = specifies the log type. This is ORM specific, in NHibernate you’ll use "NHibernate.SQL" in order to log a statement while that in EF this will be "EntityFramework.Sql".

Message = The actual message to record. If this an SQL statement, you’ll provide the SQL statement here.

Example:

            const string sql =
                @"SELECT
        first 5 this_.LOG_ID as LOG1_0_0_,
        this_.LOG_DATE as LOG2_0_0_,
        this_.APP_NAME as APP3_0_0_,
        this_.LOGGER as LOGGER0_0_,
        this_.LOG_LEVEL as LOG5_0_0_,
        this_.MESSAGE as MESSAGE0_0_,
        this_.EXCEPTION_MESSAGE as EXCEPTION7_0_0_,
        this_.CONTEXT as CONTEXT0_0_
FROM APP_LOG this_ ORDER BY this_.LOG_DATE desc";

            using (var s = (SessionImpl)factory.OpenSession())
            {
                ProfilerIntegration.PublishProfilerEvent(
                    s.SessionId.ToString(),
                    "NHibernate.SQL",
                    sql);
            }

PublishProfilerEvent is really low level API. If you’re using Entity Framework Profiler you can use the EntityFrameworkAppender class which provides more high level API:

   1:  var sessionId = Guid.NewGuid();
   2:  var entityFrameworkAppender = new EntityFrameworkAppender("My app");
   3:  entityFrameworkAppender.ConnectionStarted(sessionId);
   4:  var statementId = Guid.NewGuid();
   5:  entityFrameworkAppender.StatementExecuted(sessionId, statementId, "Select ...");
   6:  entityFrameworkAppender.StatementRowCount(sessionId, statementId, 8);
   7:  entityFrameworkAppender.StatementError(sessionId, new InvalidOperationException("Report an error to the profiler"));
   8:  entityFrameworkAppender.ConnectionDisposed(sessionId);

But this is considered internal API which may be changed.

NHibernateProfiler doesn’t expose a high level API like this, so you’ll need to call ProfilerIntegration.PublishProfilerEvent with the correct logger name. If you would like to know a particular logger name you can email us and we’ll provide you with the information that you need.

Tags:

Published at

Originally posted at

Uber Prof Production Profiling–Profiling production application on Azure

In this post I’m going to cover one of the great features of Uber Prof v2.0: production profiling of remote applications running on Windows Azure.

The production profiling feature is currently supported in the following profilers: NHibernate Profiler, Entity Framework Profiler, Linq to SQL Profiler, LLBLGen Profiler. In this post I’m going to demonstrate how to use this with the Entity Framework Profiler.

First, we need to create our project. Since we want to host the project on Windows Azure, I’ll use an ASP.NET MVC + Web API project.

ProductionProfiling1

The next thing is to enable production profiling. In order to so, we need to install the EntityFrameworkProfiler.Production NuGet package.

ProductionProfiling2

As a side note, if you wonder what is the other package called EntityFrameworkProfiler, you probably want to read this post.

After the package is installed, you can see that it created the following file in our project:

using System;
using System.IO;
using System.Web.Http;
using HibernatingRhinos.Profiler.Production;

[assembly: WebActivator.PreApplicationStartMethod(typeof(ProductionProfilingOnAzureSample.App_Start.EntityFrameworkProfilerProductionBootstrapper), "PreStart")]
namespace ProductionProfilingOnAzureSample.App_Start
{
    public static class EntityFrameworkProfilerProductionBootstrapper
    {
        public static void PreStart()
        {
            // Initialize the profiler with the production profiling feature. 
            // Production profiling let's you let you see profiling information remotely using the following URL: http://your-server/profiler/profiler.html
            string license = GetResource("ProductionProfilingOnAzureSample.App_Start.EntityFrameworkProfilerLicense.xml");
            ProductionProfiling.Initialize(license, GlobalConfiguration.Configuration);
        }

        private static string GetResource(string sourcesResource)
        {
            using (var sourceCodeStream = typeof(EntityFrameworkProfilerProductionBootstrapper).Assembly.GetManifestResourceStream(sourcesResource))
            {
                if (sourceCodeStream == null)
                    throw new InvalidOperationException(string.Format("Resource file is missing: {0}", sourcesResource));
                return new StreamReader(sourceCodeStream).ReadToEnd();
            }
        }
    }
}

This class will run on the startup of your project and will expose a URL endpoint that we can use to load the profiler UI. In this case we’re using the GlobalConfiguration.Configuration from the WebAPI Web Host package, but please note that you can also expose your own self hosted server in order to production profile a different types of projects, like a service, or what not…

Also note that we’re embedding the license file as an embedded resource in our project and we’re passing the license string to the Initialize method of the ProductionProfiling class. This is needed since the profiler is now split into to parts, the server – which is embedded right into your application and will run within your application own process, and the UI client which is a Silverlight application that you can get from the remote server through your browser. So again, the license string is passed and evaluated right from the server initialization process.

Now it’s time to run our project. I’m running it but get the following exception: …

Resource file is missing: ProductionProfilingOnAzureSample.App_Start.EntityFrameworkProfilerLicense.xml

Description: An unhandled exception occurred during the execution of the current web request. Please review the stack trace for more information about the error and where it originated in the code.
Exception Details: System.InvalidOperationException: Resource file is missing: ProductionProfilingOnAzureSample.App_Start.EntityFrameworkProfilerLicense.xml
Source Error:

Line 22: 			{
Line 23: 				if (sourceCodeStream == null)
Line 24: 					throw new InvalidOperationException(string.Format("Resource file is missing: {0}", sourcesResource));
Line 25: 				return new StreamReader(sourceCodeStream).ReadToEnd();
Line 26: 			}

Source File: c:\Users\Fitzchak\Documents\Visual Studio 11\Projects\ProductionProfilingOnAzureSample\ProductionProfilingOnAzureSample\App_Start\EntityFrameworkProfilerBootstrapper.cs    Line: 24

Remember what I told you? We need to embedded a license file. So let’s go and ask for a trial license file: http://hibernatingrhinos.com/products/efprof/trial.

After that I’m doing that, I got a trial license in my email inbox. Now we need to include this in the project as an embedded resource.

ProductionProfiling3

And now we are ready to see the profiler in action. Run the project and browse to the /profiler/profiler.html endpoint:

ProductionProfiling4

Do you see that? This is Entity Framework Profiler running right in your browser and let you profile your remote production application right from your computer!

You may be wonder why we do not see actual data in the profiler yet but this is your work to do. Attach it to your application and you’ll see some nice information that will let you understand what your ORM is doing easily.

Here is an example:

ScreenShots-EFProf-InBrowser (1)

Wait a second… Didn’t you said that we’re going to run this on Azure?

Yes, I added the following code to the HomeController and pushed the code to azure:

public class HomeController : Controller
{
    public ActionResult Index()
    {
        for (int i = 0; i < 2; i++)
        {
            using (var context = new ApplicationContext())
            {

                context.Messages.Add(new Message {Text = "Text 1", CreatedAt = DateTime.UtcNow});
                context.SaveChanges();

                var messages = context.Messages.ToList();

                var messages2 = context.Messages
                                        .Where(message => message.Text == "Profiling on Azure" && message.Text.Length > 10)
                                        .ToList();
            }
        }
        return View();
    }
}

You can run the above code by opening the following page,  http://efprof.cloudapp.net/, and see the profiler in action here: http://efprof.cloudapp.net/profiler/profiler.html.

ProductionProfiling6

For any feedback, please contact us in the profilers forums, by email (support at hibernatingrhinos.com) or just leave a comment here.

Tags:

Published at

Originally posted at

Comments (3)

Entity Framework Profiler supports for LinqPAD

If you’re using LinqPAD and wants to profile your Entity Framework usage with the Entity Framework Profiler, you can use the following snippet of code in order to achieve that:

void Main()
{
    HibernatingRhinos.Profiler.Appender.EntityFramework.EntityFrameworkProfiler.Initialize();
    Blogs.Take(50).Dump();
}

Please make sure to use the "C# Program" option from the "language" ComboBox, and that’s it. You can now see the the profiling data in the Entity Framework Profiler.

LinqPAD

Published at

Originally posted at

Entity Framework Profiler supports for LinqPAD

If you’re using LinqPAD and wants to profile your Entity Framework usage with the Entity Framework Profiler, you can use the following snippet of code in order to achieve that:

void Main()
{
    HibernatingRhinos.Profiler.Appender.EntityFramework.EntityFrameworkProfiler.Initialize();
    Blogs.Take(50).Dump();
}

Please make sure to use the "C# Program" option from the "language" ComboBox, and that’s it. You can now see the the profiling data in the Entity Framework Profiler.

LinqPAD

Published at

Originally posted at

Comments (1)

Entity Framework June 2011 CTP (v4.2) is now supported in Entity Framework Profiler

When Entity Framework June 2011 CTP was out, we were asked by our users to provide support for it in the Entity Framework Profiler.

As we started to investigate how to provide support for it, we discovered that it’s not that easy task to do. The way that Entity Framework Profiler appender works in nutshell is by replacing the instances of DbProviderFactory (like SqlClientFactory or OracleClientFactory) that the client has on his machine with a custom provider factory that wrap the original provider factory. This wasn’t easy task to do, because Entity Framework June CTP made a few assumptions that make our life more complicated. Specifically:

  • There is an assumption that the provider factory type is not a generic type. This broke our code which is uses a generic provider factory type which wrap each of the providers factories that the client have on the fly, since the client can use any provider factory that he wants.
  • Even if we use non-generic providers for each of the client’s providers, we found out that each provider should be compiled in a separate assembly because of the way that Entity Framework matches providers.

We’re working with the Entity Framework team in order to find a solution for this in the future versions, but in the mean time if you’re using the Entity Framework June 2011 CTP we temporary worked around this issue with a temp API that by providing a non-generic provider factory of type SqlClientFactory, which means that in the meantime you’ll be able to use the Entity Framework profiler only with Sql Server:

EntityFrameworkProfiler.TempApi_InitializeForV42_CTP();

In addition, you’ll need to add the following assembly redirection to your config file in order to instruct the profiler to use the correct version of Entity Framework:

<runtime>
    <assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">
        <dependentAssembly>
            <assemblyIdentity name="System.Data.Entity" publicKeyToken="b77a5c561934e089" culture="neutral" />
            <bindingRedirect oldVersion="4.0.0.0" newVersion="4.2.0.0" />
        </dependentAssembly>
    </assemblyBinding>
</runtime>

The main problem is that we can’t currently easily support providers other than SqlClient, if you do need that support on the new CTP, please let us know, and we will provide you with a custom version for that purpose. Considering that this is a CTP version, we decided to provide a partial solution that will work for most of our users and we’re working with the Entity Framework team in order to find a better solution.

Happy Profiling

The Hibernating Rhinos Team

Tags:

Published at

Originally posted at

Comments (5)

Entity Framework June 2011 CTP (v4.2) is now supported in Entity Framework Profiler

When Entity Framework June 2011 CTP was out, we were asked by our users to provide support for it in the Entity Framework Profiler.

As we started to investigate how to provide support for it, we discovered that it’s not that easy task to do. The way that Entity Framework Profiler appender works in nutshell is by replacing the instances of DbProviderFactory (like SqlClientFactory or OracleClientFactory) that the client has on his machine with a custom provider factory that wrap the original provider factory. This wasn’t easy task to do, because Entity Framework June CTP made a few assumptions that make our life more complicated. Specifically:

  • There is an assumption that the provider factory type is not a generic type. This broke our code which is uses a generic provider factory type which wrap each of the providers factories that the client have on the fly, since the client can use any provider factory that he wants.
  • Even if we use non-generic providers for each of the client’s providers, we found out that each provider should be compiled in a separate assembly because of the way that Entity Framework matches providers.

We’re working with the Entity Framework team in order to find a solution for this in the future versions, but in the mean time if you’re using the Entity Framework June 2011 CTP we temporary worked around this issue with a temp API that by providing a non-generic provider factory of type SqlClientFactory, which means that in the meantime you’ll be able to use the Entity Framework profiler only with Sql Server:

EntityFrameworkProfiler.TempApi_InitializeForV42_CTP();

In addition, you’ll need to add the following assembly redirection to your config file in order to instruct the profiler to use the correct version of Entity Framework:

<runtime>
    <assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">
        <dependentAssembly>
            <assemblyIdentity name="System.Data.Entity" publicKeyToken="b77a5c561934e089" culture="neutral" />
            <bindingRedirect oldVersion="4.0.0.0" newVersion="4.2.0.0" />
        </dependentAssembly>
    </assemblyBinding>
</runtime>

The main problem is that we can’t currently easily support providers other than SqlClient, if you do need that support on the new CTP, please let us know, and we will provide you with a custom version for that purpose. Considering that this is a CTP version, we decided to provide a partial solution that will work for most of our users and we’re working with the Entity Framework team in order to find a better solution.

Happy Profiling

The Hibernating Rhinos Team

Tags:

Published at

Originally posted at

Comments (5)

Entity Framework June 2011 CTP (v4.2) is now supported in Entity Framework Profiler

When Entity Framework June 2011 CTP was out, we were asked by our users to provide support for it in the Entity Framework Profiler.

As we started to investigate how to provide support for it, we discovered that it’s not that easy task to do. The way that Entity Framework Profiler appender works in nutshell is by replacing the instances of DbProviderFactory (like SqlClientFactory or OracleClientFactory) that the client has on his machine with a custom provider factory that wrap the original provider factory. This wasn’t easy task to do, because Entity Framework June CTP made a few assumptions that make our life more complicated. Specifically:

  • There is an assumption that the provider factory type is not a generic type. This broke our code which is uses a generic provider factory type which wrap each of the providers factories that the client have on the fly, since the client can use any provider factory that he wants.
  • Even if we use non-generic providers for each of the client’s providers, we found out that each provider should be compiled in a separate assembly because of the way that Entity Framework matches providers.

We’re working with the Entity Framework team in order to find a solution for this in the future versions, but in the mean time if you’re using the Entity Framework June 2011 CTP we temporary worked around this issue with a temp API that by providing a non-generic provider factory of type SqlClientFactory, which means that in the meantime you’ll be able to use the Entity Framework profiler only with Sql Server:

EntityFrameworkProfiler.TempApi_InitializeForV42_CTP();

In addition, you’ll need to add the following assembly redirection to your config file in order to instruct the profiler to use the correct version of Entity Framework:

<runtime>
    <assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">
        <dependentAssembly>
            <assemblyIdentity name="System.Data.Entity" publicKeyToken="b77a5c561934e089" culture="neutral" />
            <bindingRedirect oldVersion="4.0.0.0" newVersion="4.2.0.0" />
        </dependentAssembly>
    </assemblyBinding>
</runtime>

The main problem is that we can’t currently easily support providers other than SqlClient, if you do need that support on the new CTP, please let us know, and we will provide you with a custom version for that purpose. Considering that this is a CTP version, we decided to provide a partial solution that will work for most of our users and we’re working with the Entity Framework team in order to find a better solution.

Happy Profiling

The Hibernating Rhinos Team

Tags:

Published at

Originally posted at

Comments (5)

NuGet packages and VB.net application start code

In order to support one click install experience for our profilers we’re providing our users with NuGet packages for some of our profilers. The profilers that currently have NuGet package are:

When you install one of the profiler packages, your project is updated with some application start code that wiring your application with the profiler. This is great but it’s even greater since we are fully support VB projects alongside the C# once.

One thing that it’s interesting through is that no matter what project type you’re using, C# or VB, both files types are added to your project, one for each project type:

NuGetAppStartFiles

You may think that you’re going to get compilation error here, as C# projects can’t read the .vb file and vice versa, VB projects can’t read the .cs file, but it’s actually do compile. This is because that only one of the files are going to compile with your code while the other one added as content – which means that even that the file is there you actually do not do anything interesting with it - it’s not going to compile with your code.

In a C# project the files properties will like the following:

NuGetAppStartCSFile

The .cs file build action value is compile.

NuGetAppStartVBFile

The .vs file build action set value is content.

It’s may not be very intuitive to see a .vb file in C# project, but this behavior is inherited by NuGet, which is responsible to add those files. Looking on the NuGet documentation I wasn’t able to see any reference regards how is it behaves on different project types.

We can remove one of the files manually from the Install.ps1 files, depends on what project type you use, but since we think that this responsibility is of NuGet, we let NuGet to take care of that.

Tags:

Published at

Originally posted at

NuGet packages and VB.net application start code

In order to support one click install experience for our profilers we’re providing our users with NuGet packages for some of our profilers. The profilers that currently have NuGet package are:

When you install one of the profiler packages, your project is updated with some application start code that wiring your application with the profiler. This is great but it’s even greater since we are fully support VB projects alongside the C# once.

One thing that it’s interesting through is that no matter what project type you’re using, C# or VB, both files types are added to your project, one for each project type:

NuGetAppStartFiles

You may think that you’re going to get compilation error here, as C# projects can’t read the .vb file and vice versa, VB projects can’t read the .cs file, but it’s actually do compile. This is because that only one of the files are going to compile with your code while the other one added as content – which means that even that the file is there you actually do not do anything interesting with it - it’s not going to compile with your code.

In a C# project the files properties will like the following:

NuGetAppStartCSFile

The .cs file build action value is compile.

NuGetAppStartVBFile

The .vs file build action set value is content.

It’s may not be very intuitive to see a .vb file in C# project, but this behavior is inherited by NuGet, which is responsible to add those files. Looking on the NuGet documentation I wasn’t able to see any reference regards how is it behaves on different project types.

We can remove one of the files manually from the Install.ps1 files, depends on what project type you use, but since we think that this responsibility is of NuGet, we let NuGet to take care of that.

Tags:

Published at

Originally posted at

One click install NuGet Package and Console Applications

We started to provide NuGet packages for some of our profilers about 2 months ago. It’s provided you with a great one click install experience: all you have to do in order to start profiling your application is to install the NuGet package of the appropriate profiler and that’s it. The profiler application is opened up for you and your application is set up, all you left to do is to actually go to business and start profiling your application. This is a great on install experience, that we are proud to provide you with.

This is our currently provided NuGet packages:

But we did have one problem with it. It didn’t work well with non-web based applications. That’s because that the way to provide one click install experience with NuGet packages is by using a package named WebActivator. You can read more about the way that WebActivator works here, but in nutshell, it provided the package with a way to specify the method that should be run as part of the web application start process, by specifying an assembly attribute like the following one:

[assembly: WebActivator.PreApplicationStartMethod(typeof($rootnamespace$.App_Start.EntityFrameworkProfilerBootstrapper), "PreStart")]

But as I mentioned, this is works only with web-based projects. When you use with non-web based application, like a Console Application for example, things are starting to get weird. This is because that the WebActivor has a dependency on System.Web.dll which non-web projects not include a reference to it be default. Even more, the default template for Console Application in Visual Studio 2010 uses the .NET Framework Client Profile which does not include the System.Web.dll in it. So when you create a console application and install one of the profiler’s NuGet packages you get a mysterious compilation error:

The type or namespace name 'WebActivator' could not be found (are you missing a using directive or an assembly reference?)

This error is confusing because if you’ll take a look on the references of your project you will see a reference to the WebActivator. The missing assembly reference is actually the System.Web.dll. But in order to add a reference to System.Web you have to target the Full .Net Framework in your project. But those are not recommended steps to do, since that if you’ll do them your project will compile fine but you gained nothing from the use of WebActivator since the code that takes care to initialize the profiler (the PreStart method) does not execute. This break down the one click installs experience of the NuGet package for non-web projects.

So how are we going to solve this? Let’s take one problem by one. The first problem was that non-web projects (specifically those that even can’t use it, like projects that use the .Net Framework Client Profile) cannot compile because of the call to WebActivator. The solution for this is simple. We drop the call to WebActivator assembly attribute in non-web projects.

This is done by the Install.ps1 script included in the NuGet package. In order to determine whether the current project is a web project or not we determine if the web.config file exists on the target project. If it’s not, that’s a good indicator that this is not web project and the call to the WebActivator.PreApplicationStartMethod is removed by the scripts' code.

This is important step to eliminate the confusing compilation error, but we have a second problem: the initialization code is never run and this break the one click install experience that we so want to provide. What will be the solution for this? Well, a simple solution may be is to drop a call to the PreStart method of the profiler bootstrapper in the start code or your application.

But where is exactly the application’s start code? This can be vary depends on the current project type (WinForms or WPF for example) and the user’s actual code structure. Covering all the option of where is code can be can be very hard task to do. So what we decided to do is to cover just the simple case of a default console application. If you have a console application with a Program.cs file, we’ll drop a call to the App_Start.PreStart method in your Main method (assuming it exists).

This will cover the very basic case of when you just want to see how to work with the profiler by creating a console application and installing the profiler’s NuGet package. In this case it can be acceptable to edit the user’s code by the NuGet script. But this won’t interrupt you in more advances cases when you use other types of non-web projects like WinFroms or WPF application.

This is how the NuGet packages behaving right now. We think that this fairly elegant solution for what we can do with the NuGet package and we want to hear from you how this is working out for you!

Tags:

Published at

Originally posted at

Comments (1)

One click install NuGet Package and Console Applications

We started to provide NuGet packages for some of our profilers about 2 months ago. It’s provided you with a great one click install experience: all you have to do in order to start profiling your application is to install the NuGet package of the appropriate profiler and that’s it. The profiler application is opened up for you and your application is set up, all you left to do is to actually go to business and start profiling your application. This is a great on install experience, that we are proud to provide you with.

This is our currently provided NuGet packages:

But we did have one problem with it. It didn’t work well with non-web based applications. That’s because that the way to provide one click install experience with NuGet packages is by using a package named WebActivator. You can read more about the way that WebActivator works here, but in nutshell, it provided the package with a way to specify the method that should be run as part of the web application start process, by specifying an assembly attribute like the following one:

[assembly: WebActivator.PreApplicationStartMethod(typeof($rootnamespace$.App_Start.EntityFrameworkProfilerBootstrapper), "PreStart")]

But as I mentioned, this is works only with web-based projects. When you use with non-web based application, like a Console Application for example, things are starting to get weird. This is because that the WebActivor has a dependency on System.Web.dll which non-web projects not include a reference to it be default. Even more, the default template for Console Application in Visual Studio 2010 uses the .NET Framework Client Profile which does not include the System.Web.dll in it. So when you create a console application and install one of the profiler’s NuGet packages you get a mysterious compilation error:

The type or namespace name 'WebActivator' could not be found (are you missing a using directive or an assembly reference?)

This error is confusing because if you’ll take a look on the references of your project you will see a reference to the WebActivator. The missing assembly reference is actually the System.Web.dll. But in order to add a reference to System.Web you have to target the Full .Net Framework in your project. But those are not recommended steps to do, since that if you’ll do them your project will compile fine but you gained nothing from the use of WebActivator since the code that takes care to initialize the profiler (the PreStart method) does not execute. This break down the one click installs experience of the NuGet package for non-web projects.

So how are we going to solve this? Let’s take one problem by one. The first problem was that non-web projects (specifically those that even can’t use it, like projects that use the .Net Framework Client Profile) cannot compile because of the call to WebActivator. The solution for this is simple. We drop the call to WebActivator assembly attribute in non-web projects.

This is done by the Install.ps1 script included in the NuGet package. In order to determine whether the current project is a web project or not we determine if the web.config file exists on the target project. If it’s not, that’s a good indicator that this is not web project and the call to the WebActivator.PreApplicationStartMethod is removed by the scripts' code.

This is important step to eliminate the confusing compilation error, but we have a second problem: the initialization code is never run and this break the one click install experience that we so want to provide. What will be the solution for this? Well, a simple solution may be is to drop a call to the PreStart method of the profiler bootstrapper in the start code or your application.

But where is exactly the application’s start code? This can be vary depends on the current project type (WinForms or WPF for example) and the user’s actual code structure. Covering all the option of where is code can be can be very hard task to do. So what we decided to do is to cover just the simple case of a default console application. If you have a console application with a Program.cs file, we’ll drop a call to the App_Start.PreStart method in your Main method (assuming it exists).

This will cover the very basic case of when you just want to see how to work with the profiler by creating a console application and installing the profiler’s NuGet package. In this case it can be acceptable to edit the user’s code by the NuGet script. But this won’t interrupt you in more advances cases when you use other types of non-web projects like WinFroms or WPF application.

This is how the NuGet packages behaving right now. We think that this fairly elegant solution for what we can do with the NuGet package and we want to hear from you how this is working out for you!

Tags:

Published at

Originally posted at

Comments (1)

Nuget packages and an example use of the profiler

Recently, we started to provide a Nuget package for each of the following profilers:

In case that you wonder how frequently those packages are updated, well, we push new packages to Nuget repository each time that we have a new build. That means that you get a new Nuget package or update to an existing package as soon as we have a new build.

In this post I’ll show you a possible problem that you may encounter when using an ORM tool, which will be solved using the profiler and leverage the Nuget package of the profiler. For this example I’m going to use EF4 CTP5 as the ORM tool with Entity Framework Profiler, but the same example is applicable for all of the others ORM/Profilers that we support.

Let us consider the following application example, which makes a use of the Northwind sample database with the following domain model:

public class Customer
{
    public string CustomerId { get; set; }
    public string ContactName { get; set; }
    public string ContactTitle { get; set; }
    public string Address { get; set; }
    public string City { get; set; }
    public string Region { get; set; }
    public string PostalCode { get; set; }
    public string Country { get; set; }
    public string Phone { get; set; }
    public string Fax { get; set; }

    public virtual ICollection<Order> Orders { get; set; }
}
    
public class Order
{
    public int OrderId { get; set; }
    public string CustomerId { get; set; }
    public DateTime OrderDate { get; set; }
    public DateTime RequiredDate { get; set; }
    public DateTime ShippedDate { get; set; }
    public string ShipName { get; set; }
    public string ShipAddress { get; set; }
    public string ShipCity { get; set; }
    public string ShipRegion { get; set; }
    public string ShipPostalCode { get; set; }
    public string ShipCountry { get; set; }

    public virtual ICollection<OrderDetails> OrderDetails { get; set; }
}

public class OrderDetails
{
    public int OrderId { get; set; }
    public int ProductId { get; set; }
    public decimal? UnitPrice { get; set; }
    public Int16 Quantity { get; set; }
    public Single Discount { get; set; }

    public virtual Product Product { get; set; }
}

public class Product
{
    public int ProductId { get; set; }
    public int CategoryId { get; set; }
    public string ProductName { get; set; }
    public decimal? UnitPrice { get; set; }
    public bool Discontinued { get; set; }
}

public class Northwind : DbContext
{
    public DbSet<Order> Orders { get; set; }
    public DbSet<Customer> Customers { get; set; }

    protected override void OnModelCreating(DbModelBuilder modelBuilder)
    {
        modelBuilder.Conventions.Remove<IncludeMetadataConvention>();
        modelBuilder.Entity<OrderDetails>()
            .HasKey(x => new { x.OrderId, x.ProductId })
            .ToTable("Order Details");
    }
}

As you can see, we have here a Customer entity which has many Orders, which in turn have many OrderDetails, which has a product. We also have here a Northwind context class that we will use in order to query the database.

The main scenario that we are going examine is the Orders action which takes a customer ID and prints a list of all of the orders that the customer had made. Consider the following Orders controller action and Orders view:

public class CustomerController : Controller
{
    private readonly Northwind _northwind = new Northwind();

    public ActionResult Orders(string customerId)
    {
        var customer = GetCustomer(customerId);
        if (customer == null)
            return HttpNotFound();
            
        var viewModel = new CustomerOrdersViewModel
        {
            Customer = customer,
            Orders = GetCustomerOrders(customer)
        };
        return View(viewModel);
    }

    private Customer GetCustomer(string customerId)
    {
        var customers = from customer1 in _northwind.Customers
                        where customer1.CustomerId == customerId
                        select customer1;
        var customer = customers.SingleOrDefault();
        return customer;
    }

    private IList<Order> GetCustomerOrders(Customer customer)
    {
        return customer.Orders.OrderByDescending(o => o.OrderDate).ToList();
    }
}
Orders.cshtml:
model CustomerOrdersViewModel
@{
    ViewBag.Title = "Orders for " + @Model.Customer.ContactName;
}
<div><strong>Customer ID:</strong> @Model.Customer.CustomerId</div>
<div><strong>Customer Name:</strong> @Model.Customer.ContactName</div>
<div><strong>Orders:</strong>
    <div class="orders">
        @foreach (var order in Model.Orders)
        {
            <div><strong>Order ID:</strong> @order.OrderId</div>
            <div><strong>Order Date:</strong> @order.OrderDate</div>
            <div><strong>Products:</strong>
                <div class="products">
                    @foreach (var orderDetail in order.OrderDetails)
                    {
                        <div class="product">
                            <div><strong>Product Name:</strong> @orderDetail.Product.ProductName</div>
                            <div><strong>Quantity:</strong> @orderDetail.Quantity</div>
                            <div><strong>Unit Price:</strong> @String.Format("{0:c}", orderDetail.UnitPrice)</div>
                        </div>
                    }
                </div>
            </div>
        }
    </div>
</div>

Running the code for customer ID “KOENE” will produce the following output (In order to save some space, I’m attaching here just part of the output):

Customer ID: KOENE
Customer Name: Philip Cramer
Orders:
Order ID: 11028
Order Date: 4/16/1998 12:00:00 AM
Products:
Product Name: Pâté chinois
Quantity: 35
Unit Price: $24.00
Product Name: Raclette Courdavault
Quantity: 24
Unit Price: $55.00
Order ID: 10893
Order Date: 2/18/1998 12:00:00 AM
Products:
Product Name: Northwoods Cranberry Sauce
Quantity: 30
Unit Price: $40.00
Product Name: Guaraná Fantástica
Quantity: 10
Unit Price: $4.50
Product Name: Thüringer Rostbratwurst
Quantity: 24
Unit Price: $123.79
Product Name: Nord-Ost Matjeshering
Quantity: 35
Unit Price: $25.89
Product Name: Inlagd Sill
Quantity: 20
Unit Price: $19.00
Order ID: 10849
Order Date: 1/23/1998 12:00:00 AM
Products:
Product Name: Aniseed Syrup
Quantity: 49
Unit Price: $10.00
Product Name: Gumbär Gummibärchen
Quantity: 18
Unit Price: $31.23
Order ID: 10817
Order Date: 1/6/1998 12:00:00 AM
Products:
Product Name: Gumbär Gummibärchen
Quantity: 40
Unit Price: $31.23
Product Name: Côte de Blaye
Quantity: 30
...

You may execute this code against a local database without notice any problem with it, because this code does what it supposed to. But as soon as you’ll use this code in production environment when you have to use a remote database, you’ll find that this method is very slow. Why? And how can I make this method run faster?

The way to solve these kinds of problems is to look on the actual SQL queries that the ORM was generated for you. This way you can have a better idea of what is going on under the scene which is important step before you can make your code to be more efficient. In this example, we have to look on the actual queries that EF4 generated for us. We’ll make a use of the Entity Framework Profiler, which will let you to see the generated SQL code in a very convenient way and will also produce warnings if it encounters any problem in the way that you use the ORM.

The easy way to start using the profiler is to add a NuGet Package Reference to your project:

NugetPackages

When you click on Install button, you’ll be asked to accept the End User License Agreement:

LicenseAcceptance

When you do so, the following actions will be take place:

  • A new assembly reference is added to your project: HibernatingRhinos.Profiler.Appender.dll or HibernatingRhinos.Profiler.Appender.v4.0.dll depending on the .net framework version target of you project.
  • A new file will be added to your code, which will be called on the startup of your application.
  • The profiler is now running on your computer.

If this is the first time that you are running the profiler on your computer, you will get the following screen:

LicensePromote

If you do, than you have to provide your license file or if you don’t have a license file you can start a 30 days trial, as described in this blog post. In short, when you’ll start a 30 days trial, you’ll be able to use the profiler immediately for 15 minutes, then you’ll be asked to provide the trial license file that we have sent to your email address.

Now that the Entity Framework Profiler is running, we run the project again but this time the profiler will catch every query that the ORM made to the database:

ProfilerResult

As we can see, the ORM generated for us 45 queries!. A query for each OrderDetail and a query for each product. I highlighted all the statements, and you can see that it took us 10 seconds! to query the database. (As I noted before, we are using an external database).

In addition, as you can see in the right side of the statements, the profiler is warning us that something is wrong with these queries. Let’s click on one of the red warnings and look in the Alerts pane:

NPlustOne

As you can see, there is a SELECT N+1 alert here. If you click on the read more link you’ll forwarded to a detailed explanation of this common error and a suggestion of how to solve it. Following the suggestion, now we are eager loading the OrderDetails and Products entities using the Include method:

private IList<Order> GetCustomerOrders(string customerId)
{
    var orders = from order in _northwind.Orders.Include("OrderDetails").Include("OrderDetails.Product")
                 where order.CustomerId == customerId
                 orderby order.OrderDate descending
                 select order;
    return orders.ToList();
}

Now, if we run the code again and look in the profiler, we can see that we generate now just two SQL queries, instead of 45, which is much faster.

ProfilerSolutionOutput

Let’s summarize what we did here. We got a problem in our application when one of our methods run slower than expected. We install the profiler using NuGet and were quickly been able to see that there is a SELECT N+1 issue in our code. We find out very quickly that we have to eager load some of our entities and that we can make use of the .Include() method in order to do so. Now that we have the NuGet packages of the profilers, getting the profiler running in order to solve a similar problem is quick and easy.

Posted By: Fitzchak Yitzchaki

Tags:

Published at

Nuget packages and an example use of the profiler

Recently, we started to provide a Nuget package for each of the following profilers:

In case that you wonder how frequently those packages are updated, well, we push new packages to Nuget repository each time that we have a new build. That means that you get a new Nuget package or update to an existing package as soon as we have a new build.

In this post I’ll show you a possible problem that you may encounter when using an ORM tool, which will be solved using the profiler and leverage the Nuget package of the profiler. For this example I’m going to use EF4 CTP5 as the ORM tool with Entity Framework Profiler, but the same example is applicable for all of the others ORM/Profilers that we support.

Let us consider the following application example, which makes a use of the Northwind sample database with the following domain model:

public class Customer
{
    public string CustomerId { get; set; }
    public string ContactName { get; set; }
    public string ContactTitle { get; set; }
    public string Address { get; set; }
    public string City { get; set; }
    public string Region { get; set; }
    public string PostalCode { get; set; }
    public string Country { get; set; }
    public string Phone { get; set; }
    public string Fax { get; set; }

    public virtual ICollection<Order> Orders { get; set; }
}
    
public class Order
{
    public int OrderId { get; set; }
    public string CustomerId { get; set; }
    public DateTime OrderDate { get; set; }
    public DateTime RequiredDate { get; set; }
    public DateTime ShippedDate { get; set; }
    public string ShipName { get; set; }
    public string ShipAddress { get; set; }
    public string ShipCity { get; set; }
    public string ShipRegion { get; set; }
    public string ShipPostalCode { get; set; }
    public string ShipCountry { get; set; }

    public virtual ICollection<OrderDetails> OrderDetails { get; set; }
}

public class OrderDetails
{
    public int OrderId { get; set; }
    public int ProductId { get; set; }
    public decimal? UnitPrice { get; set; }
    public Int16 Quantity { get; set; }
    public Single Discount { get; set; }

    public virtual Product Product { get; set; }
}

public class Product
{
    public int ProductId { get; set; }
    public int CategoryId { get; set; }
    public string ProductName { get; set; }
    public decimal? UnitPrice { get; set; }
    public bool Discontinued { get; set; }
}

public class Northwind : DbContext
{
    public DbSet<Order> Orders { get; set; }
    public DbSet<Customer> Customers { get; set; }

    protected override void OnModelCreating(DbModelBuilder modelBuilder)
    {
        modelBuilder.Conventions.Remove<IncludeMetadataConvention>();
        modelBuilder.Entity<OrderDetails>()
            .HasKey(x => new { x.OrderId, x.ProductId })
            .ToTable("Order Details");
    }
}

As you can see, we have here a Customer entity which has many Orders, which in turn have many OrderDetails, which has a product. We also have here a Northwind context class that we will use in order to query the database.

The main scenario that we are going examine is the Orders action which takes a customer ID and prints a list of all of the orders that the customer had made. Consider the following Orders controller action and Orders view:

public class CustomerController : Controller
{
    private readonly Northwind _northwind = new Northwind();

    public ActionResult Orders(string customerId)
    {
        var customer = GetCustomer(customerId);
        if (customer == null)
            return HttpNotFound();
            
        var viewModel = new CustomerOrdersViewModel
        {
            Customer = customer,
            Orders = GetCustomerOrders(customer)
        };
        return View(viewModel);
    }

    private Customer GetCustomer(string customerId)
    {
        var customers = from customer1 in _northwind.Customers
                        where customer1.CustomerId == customerId
                        select customer1;
        var customer = customers.SingleOrDefault();
        return customer;
    }

    private IList<Order> GetCustomerOrders(Customer customer)
    {
        return customer.Orders.OrderByDescending(o => o.OrderDate).ToList();
    }
}
Orders.cshtml:
model CustomerOrdersViewModel
@{
    ViewBag.Title = "Orders for " + @Model.Customer.ContactName;
}
<div><strong>Customer ID:</strong> @Model.Customer.CustomerId</div>
<div><strong>Customer Name:</strong> @Model.Customer.ContactName</div>
<div><strong>Orders:</strong>
    <div class="orders">
        @foreach (var order in Model.Orders)
        {
            <div><strong>Order ID:</strong> @order.OrderId</div>
            <div><strong>Order Date:</strong> @order.OrderDate</div>
            <div><strong>Products:</strong>
                <div class="products">
                    @foreach (var orderDetail in order.OrderDetails)
                    {
                        <div class="product">
                            <div><strong>Product Name:</strong> @orderDetail.Product.ProductName</div>
                            <div><strong>Quantity:</strong> @orderDetail.Quantity</div>
                            <div><strong>Unit Price:</strong> @String.Format("{0:c}", orderDetail.UnitPrice)</div>
                        </div>
                    }
                </div>
            </div>
        }
    </div>
</div>

Running the code for customer ID “KOENE” will produce the following output (In order to save some space, I’m attaching here just part of the output):

Customer ID: KOENE
Customer Name: Philip Cramer
Orders:
Order ID: 11028
Order Date: 4/16/1998 12:00:00 AM
Products:
Product Name: Pâté chinois
Quantity: 35
Unit Price: $24.00
Product Name: Raclette Courdavault
Quantity: 24
Unit Price: $55.00
Order ID: 10893
Order Date: 2/18/1998 12:00:00 AM
Products:
Product Name: Northwoods Cranberry Sauce
Quantity: 30
Unit Price: $40.00
Product Name: Guaraná Fantástica
Quantity: 10
Unit Price: $4.50
Product Name: Thüringer Rostbratwurst
Quantity: 24
Unit Price: $123.79
Product Name: Nord-Ost Matjeshering
Quantity: 35
Unit Price: $25.89
Product Name: Inlagd Sill
Quantity: 20
Unit Price: $19.00
Order ID: 10849
Order Date: 1/23/1998 12:00:00 AM
Products:
Product Name: Aniseed Syrup
Quantity: 49
Unit Price: $10.00
Product Name: Gumbär Gummibärchen
Quantity: 18
Unit Price: $31.23
Order ID: 10817
Order Date: 1/6/1998 12:00:00 AM
Products:
Product Name: Gumbär Gummibärchen
Quantity: 40
Unit Price: $31.23
Product Name: Côte de Blaye
Quantity: 30
...

You may execute this code against a local database without notice any problem with it, because this code does what it supposed to. But as soon as you’ll use this code in production environment when you have to use a remote database, you’ll find that this method is very slow. Why? And how can I make this method run faster?

The way to solve these kinds of problems is to look on the actual SQL queries that the ORM was generated for you. This way you can have a better idea of what is going on under the scene which is important step before you can make your code to be more efficient. In this example, we have to look on the actual queries that EF4 generated for us. We’ll make a use of the Entity Framework Profiler, which will let you to see the generated SQL code in a very convenient way and will also produce warnings if it encounters any problem in the way that you use the ORM.

The easy way to start using the profiler is to add a NuGet Package Reference to your project:

NugetPackages

When you click on Install button, you’ll be asked to accept the End User License Agreement:

LicenseAcceptance

When you do so, the following actions will be take place:

  • A new assembly reference is added to your project: HibernatingRhinos.Profiler.Appender.dll or HibernatingRhinos.Profiler.Appender.v4.0.dll depending on the .net framework version target of you project.
  • A new file will be added to your code, which will be called on the startup of your application.
  • The profiler is now running on your computer.

If this is the first time that you are running the profiler on your computer, you will get the following screen:

LicensePromote

If you do, than you have to provide your license file or if you don’t have a license file you can start a 30 days trial, as described in this blog post. In short, when you’ll start a 30 days trial, you’ll be able to use the profiler immediately for 15 minutes, then you’ll be asked to provide the trial license file that we have sent to your email address.

Now that the Entity Framework Profiler is running, we run the project again but this time the profiler will catch every query that the ORM made to the database:

ProfilerResult

As we can see, the ORM generated for us 45 queries!. A query for each OrderDetail and a query for each product. I highlighted all the statements, and you can see that it took us 10 seconds! to query the database. (As I noted before, we are using an external database).

In addition, as you can see in the right side of the statements, the profiler is warning us that something is wrong with these queries. Let’s click on one of the red warnings and look in the Alerts pane:

NPlustOne

As you can see, there is a SELECT N+1 alert here. If you click on the read more link you’ll forwarded to a detailed explanation of this common error and a suggestion of how to solve it. Following the suggestion, now we are eager loading the OrderDetails and Products entities using the Include method:

private IList<Order> GetCustomerOrders(string customerId)
{
    var orders = from order in _northwind.Orders.Include("OrderDetails").Include("OrderDetails.Product")
                 where order.CustomerId == customerId
                 orderby order.OrderDate descending
                 select order;
    return orders.ToList();
}

Now, if we run the code again and look in the profiler, we can see that we generate now just two SQL queries, instead of 45, which is much faster.

ProfilerSolutionOutput

Let’s summarize what we did here. We got a problem in our application when one of our methods run slower than expected. We install the profiler using NuGet and were quickly been able to see that there is a SELECT N+1 issue in our code. We find out very quickly that we have to eager load some of our entities and that we can make use of the .Include() method in order to do so. Now that we have the NuGet packages of the profilers, getting the profiler running in order to solve a similar problem is quick and easy.

Posted By: Fitzchak Yitzchaki

Tags:

Published at

Don’t leave the profiler. Start your trial right from it.

As you may already know, you can try any of the profilers for a 30 days period. This is out there, so anyone can start experiencing with the profiler right away.

Last week we improved the process of starting a trial, so now you can register for a trial right from the application, no need to go to the profiler website anymore. In addition for that, when you register for a trial, you get a period of time that you can use the application right away, before you even need to go to your email and download the provided trial license.

Let me summarize to you how this work right now:

You started the application. If you didn’t provided yet a license, a dialog screen will appear, asking you to provide a valid license:

LicensePromote

 

In case that you want to try the profiler, you can get a free 30 trial license. Just click on “Click here to register for a 30 days trial” link. If you do so, the following dialog will appear, asking you to provide your full name, email address, and optionally the company name:

TrialRegistration

When you click on start trial, two things happen:

  1. You send a request for a trial license. You should get this license to the your email address (that you provided in the dialog).
  2. You get initial trial period of time to use the application without providing the license.

After the period of the initial trial is passed (it is 15 minutes), you’ll be asked again to provide a license file. This time, you should check your email for a trial license file, download the license file and locate it from the “Browse for Your License” dialog.

This is one of steps that we doing in order to make the application easier to start with. The next step is to provide you a Nuget package of the profiler, which will make starting using the profiler even easier.

Posted By: Fitzchak Yitzchaki

Tags:

Published at

Don’t leave the profiler. Start your trial right from it.

As you may already know, you can try any of the profilers for a 30 days period. This is out there, so anyone can start experiencing with the profiler right away.

Last week we improved the process of starting a trial, so now you can register for a trial right from the application, no need to go to the profiler website anymore. In addition for that, when you register for a trial, you get a period of time that you can use the application right away, before you even need to go to your email and download the provided trial license.

Let me summarize to you how this work right now:

You started the application. If you didn’t provided yet a license, a dialog screen will appear, asking you to provide a valid license:

LicensePromote

 

In case that you want to try the profiler, you can get a free 30 trial license. Just click on “Click here to register for a 30 days trial” link. If you do so, the following dialog will appear, asking you to provide your full name, email address, and optionally the company name:

TrialRegistration

When you click on start trial, two things happen:

  1. You send a request for a trial license. You should get this license to the your email address (that you provided in the dialog).
  2. You get initial trial period of time to use the application without providing the license.

After the period of the initial trial is passed (it is 15 minutes), you’ll be asked again to provide a license file. This time, you should check your email for a trial license file, download the license file and locate it from the “Browse for Your License” dialog.

This is one of steps that we doing in order to make the application easier to start with. The next step is to provide you a Nuget package of the profiler, which will make starting using the profiler even easier.

Posted By: Fitzchak Yitzchaki

Tags:

Published at

How do NHibernate Profiler support NHibernate 3 logging

Recently we added support for NHibernate 3 Internal Logger, which is exciting because it means that if you use NHibernate 3 then:

  • You don’t have to be depended on log4net anymore when you use the profiler appender.
  • The profiler appender now compatible with client profile apps.

When we started to look on how we can support NHibernate 3 Internal Logger, we found that this is pretty simple task to do: you would just have to provide an implementation of IInternalLogger and ILoggerFactory, and tell NHibernate to use your own custom logger, using the config file:

<appSettings>
     <add key="nhibernate-logger" value="MyApp.CustomLogger, MyApp"/>
</appSettings>

Well this is all nice and good for you, as a user of NHibernate, but for us things are more complicated. Let me start with what we did already before with NHibernate 2 and than I’ll show you the problem that we faced when we tried to support NHibernate 3 Internal Logger and how we solved it.

When you execute the NHibernateProfiler.Initialize(), what it basically does is to wrap the current NHibernate logger with our own logger. This way the profiler can get noticed when something interesting happens in you application, and act accordingly.

This is all good, and as I noted, was done before with NHibernate 2 too. Actually it was done too with NHibernate 3, as we do have already NHibernate 3 support in production for a week, so what new now? Well, until now in order to support NHibernate 3 we wrapped just the most important loggers that we need for the profiler to do it’s work, but not all of them. Why? because that we couldn’t do so easily. Consider the following line of code which you can find all around in NHibernate 3:

private static readonly IInternalLogger logger = LoggerProvider.LoggerFor(typeof(AbstractSessionImpl));

As you can see, this code initialized a logger at the startup of the application, way before you get the chance to call NHibernateProfiler.Initialize(). That means that when we get to set our own logger factory it’s already too late, because all of the static loggers are already initialized using the user’s logger. So how do we solved this issue and what did we do to replace all those static loggers with our own logger?

In order to solve this what we decided to do, is to generate a list of all the static loggers that NHibernate 3 has, it’s 144 loggers to be exact, and replace them at runtime (using reflection) with our own logger. In case you wonder how we inspect the NHibernate code and generate this list, I’ll give here the steps that we took:

In order to replace a particular NHibernate logger using reflection, we need 3 pieces of information about each logger:

  1. The class that contains the logger. It's any class that has a static field with the IInternalLogger type.
  2. The name of the field. This is the actually logger that we want to replace.
  3. The logger name. This value is the distinction between loggers, and when we ask the LoggerProvider for a logger, we have to provide this value.

For example, consider the code bellow taken from NHibernate. In this example the values are:

  1. ClassName:  NHibernate.Transaction.AdoNetWithDistributedTransactionFactory
  2. FieldName: logger
  3. LoggerName: NHibernate.Impl.AbstractSessionImpl

 

Logger

 

So, how do we get this values?

Our first take was to use NRefactory on the source code of NHibernate. Taking this approach I was able to easily take the ClassName and the FieldName of each logger but I couldn’t take the LoggerName. This is because that using NRefactory I couldn’t tell what AbstractSessionImpl full type name is actually is, as NRefactory looks on each file on their own. But what we actually need to look at is the NHibernate compiled assembly. This way we can tell what is exactly the actual logger type is.

In order to get those values from the compiled assembly, I can just use plain reflection. But in order to have more fun, I decided to use Mono.Cecil which was written specifically to inspect compiled assemblies. Using this approach I could just easily generate a list of all the static loggers in NHibernate.

But I did had one more problem though. Using this approach alone I couldn’t get the LoggerName easily, since this value is in the code that instantiate the logger. How would I get this value using reflection? Well, there is a way actually. If you think about it, what the C# compiler actually does when you instantiate a variable in the class level is to put the variable-initializer code in the default contactor. Take a look on the static constructor of the AdoNetWithDistributedTransactionFactory class using reflector, and you’ll see the following IL code:

ConstructorILCode

What it does here is fairly simple, it loads the token “NHibernate.Impl.AbstractSessionImpl” to the stack and than call the LoggerFor method of the LoggerProvider with this value. Well, I do can parse this IL code, and get the LoggerName. But it’s too complicated. I wished there is a better way to handle this.

Then we came up with a better idea. We can run NHibernate and just ask the logger instance what type is it. Well, I couldn’t do it with the default implementation of IInternalLogger as it don’t have a field with this value. But what I can do is to provide a custom logger, that will do just this task: provide the logger name. The code of this logger is fairly simple:

LoggerImplementation

So now we got a list of all the static loggers that we can now replace at runtime with our own logger. This was an easy task to do, and it means that we now fully supporting NHibernate 3. But what does it all means to you as the user of the profiler?

This is means that from now on, if you using NHibernate 3 and the latest build of the profiler, the NHibernate Profiler will catch every warn or error that NHibernate producing, and show you them. (One of the features that we’re considering to add to the next main version of the profiler is to add a detailed explanation of how to solve a common problems). We’re sure that this will help you a lot next time when you’ll need to debug your NHibernate 3 applications.

Posted by: Fitzchak Yitzchaki

Tags:

Published at

How do NHibernate Profiler support NHibernate 3 logging

Recently we added support for NHibernate 3 Internal Logger, which is exciting because it means that if you use NHibernate 3 then:

  • You don’t have to be depended on log4net anymore when you use the profiler appender.
  • The profiler appender now compatible with client profile apps.

When we started to look on how we can support NHibernate 3 Internal Logger, we found that this is pretty simple task to do: you would just have to provide an implementation of IInternalLogger and ILoggerFactory, and tell NHibernate to use your own custom logger, using the config file:

<appSettings>
     <add key="nhibernate-logger" value="MyApp.CustomLogger, MyApp"/>
</appSettings>

Well this is all nice and good for you, as a user of NHibernate, but for us things are more complicated. Let me start with what we did already before with NHibernate 2 and than I’ll show you the problem that we faced when we tried to support NHibernate 3 Internal Logger and how we solved it.

When you execute the NHibernateProfiler.Initialize(), what it basically does is to wrap the current NHibernate logger with our own logger. This way the profiler can get noticed when something interesting happens in you application, and act accordingly.

This is all good, and as I noted, was done before with NHibernate 2 too. Actually it was done too with NHibernate 3, as we do have already NHibernate 3 support in production for a week, so what new now? Well, until now in order to support NHibernate 3 we wrapped just the most important loggers that we need for the profiler to do it’s work, but not all of them. Why? because that we couldn’t do so easily. Consider the following line of code which you can find all around in NHibernate 3:

private static readonly IInternalLogger logger = LoggerProvider.LoggerFor(typeof(AbstractSessionImpl));

As you can see, this code initialized a logger at the startup of the application, way before you get the chance to call NHibernateProfiler.Initialize(). That means that when we get to set our own logger factory it’s already too late, because all of the static loggers are already initialized using the user’s logger. So how do we solved this issue and what did we do to replace all those static loggers with our own logger?

In order to solve this what we decided to do, is to generate a list of all the static loggers that NHibernate 3 has, it’s 144 loggers to be exact, and replace them at runtime (using reflection) with our own logger. In case you wonder how we inspect the NHibernate code and generate this list, I’ll give here the steps that we took:

In order to replace a particular NHibernate logger using reflection, we need 3 pieces of information about each logger:

  1. The class that contains the logger. It's any class that has a static field with the IInternalLogger type.
  2. The name of the field. This is the actually logger that we want to replace.
  3. The logger name. This value is the distinction between loggers, and when we ask the LoggerProvider for a logger, we have to provide this value.

For example, consider the code bellow taken from NHibernate. In this example the values are:

  1. ClassName:  NHibernate.Transaction.AdoNetWithDistributedTransactionFactory
  2. FieldName: logger
  3. LoggerName: NHibernate.Impl.AbstractSessionImpl

 

Logger

 

So, how do we get this values?

Our first take was to use NRefactory on the source code of NHibernate. Taking this approach I was able to easily take the ClassName and the FieldName of each logger but I couldn’t take the LoggerName. This is because that using NRefactory I couldn’t tell what AbstractSessionImpl full type name is actually is, as NRefactory looks on each file on their own. But what we actually need to look at is the NHibernate compiled assembly. This way we can tell what is exactly the actual logger type is.

In order to get those values from the compiled assembly, I can just use plain reflection. But in order to have more fun, I decided to use Mono.Cecil which was written specifically to inspect compiled assemblies. Using this approach I could just easily generate a list of all the static loggers in NHibernate.

But I did had one more problem though. Using this approach alone I couldn’t get the LoggerName easily, since this value is in the code that instantiate the logger. How would I get this value using reflection? Well, there is a way actually. If you think about it, what the C# compiler actually does when you instantiate a variable in the class level is to put the variable-initializer code in the default contactor. Take a look on the static constructor of the AdoNetWithDistributedTransactionFactory class using reflector, and you’ll see the following IL code:

ConstructorILCode

What it does here is fairly simple, it loads the token “NHibernate.Impl.AbstractSessionImpl” to the stack and than call the LoggerFor method of the LoggerProvider with this value. Well, I do can parse this IL code, and get the LoggerName. But it’s too complicated. I wished there is a better way to handle this.

Then we came up with a better idea. We can run NHibernate and just ask the logger instance what type is it. Well, I couldn’t do it with the default implementation of IInternalLogger as it don’t have a field with this value. But what I can do is to provide a custom logger, that will do just this task: provide the logger name. The code of this logger is fairly simple:

LoggerImplementation

So now we got a list of all the static loggers that we can now replace at runtime with our own logger. This was an easy task to do, and it means that we now fully supporting NHibernate 3. But what does it all means to you as the user of the profiler?

This is means that from now on, if you using NHibernate 3 and the latest build of the profiler, the NHibernate Profiler will catch every warn or error that NHibernate producing, and show you them. (One of the features that we’re considering to add to the next main version of the profiler is to add a detailed explanation of how to solve a common problems). We’re sure that this will help you a lot next time when you’ll need to debug your NHibernate 3 applications.

Posted by: Fitzchak Yitzchaki

Tags:

Published at