Introduction
NHibernate session is a gateway for all operations that you perform on your datastore. It also plays a role of the first-level cache, minimizing the number of roundtrips between your application and the database server. As NHibernate documentation states, session is "a single-threaded, short-lived object representing a conversation between the application and the persistent store". Pay special attention to the bolded words: single-threaded and short-lived. Single-threaded in web-development world basically means that you should not use the same session instance in two or more concurrent requests. Short-lived on the other hand instructs you not to "overuse" the session instance so it does not become a copy of the database. It's on the developer's shoulders to meet those requirements and implement a correct session management. Fortunately, there are several patterns already created for this purpose: session-per-request, session-per-conversation, session-per-thread, etc. with their implementation exemplars easily accessible in the Internet. But even if you take one of those examples and adapt it to your application needs, it may happen that the session does not behave in a way that you would expect: objects are not persisted, events are not fired or you get LazyLoadException. Those nasty bugs are usually quite tricky to resolve, especially in enterprise-level applications where objects lifetime is controlled by some kind of Inversion of Control container. In this article, I would like to show you how to find the exact moments when the session is created and destroyed (and by whom) and what information can be retrieved from its properties.
The usual approach in investigating NHibernate internals would be to turn on its fine-grained logging and check the log4net appenders output. However it's not the approach that I would like to describe in this post (please make a comment if you wish to read an article about detailed NHibernate logging). Today, we will focus on how to use the Visual Studio debugger to examine the session management. I prepared a sample application on which you may train the debugging process (details of the configuration are provided at the end of the post).
Prepare NHibernate Symbols
To be able to debug the NHibernate source code, the debugger must know how to find it. If you are using the 3.0.0 version of NHibernate, you may use http://www.symbolsource.org configuring Visual Studio to use their symbol store. If your NHibernate version is different, you need to either compile NHibernate on your own and reference the produced binaries in your project or make use of the sourcepack script. Here I will describe the second approach (especially because I'm the author of the sourcepack and I need to advertise it somehow ;)). To use sourcepack, you will need to install Debugging Tools for Windows (you may install them from the WDK image) and powershell v2. The next step is to download NHibernate binaries (you should have them already in your application bin folder) and NHibernate sources from their sourceforge page.
Now, we are ready to index the NHibernate symbol (PDB) files with the zipped sources. Open powershell console and type:
.\sourcepack.ps1 -sourcesRoot "d:\CSharp\NH\NH\nhibernate\" -sources
C:\src\NHibernate-3.1.0.GA-src.zip -symbols C:\temp\sample-app\bin
-archiverCommandPath C:\bin\7za\7za.exe -verbose
where:
- d:\CSharp\NH\NH\NHibernate\ is a path to the source root on a computer where the NHibernate was built (you may check this path using srctool.exe or dbh.exe from the Debugging Tools for Windows - please have a look at my blog for usage examples)
- C:\src\NHibernate-3.1.0.GA-src.zip is a place where you put the downloaded source codes
- C:\temp\sample-app\bin is a place where you have your application binaries (DLLs + PDBs)
- C:\bin\7za\7za.exe sourcepack requires a path to the 7za command that will be used by the debugger to extract the necessary source files (sourcepack release already contains the 7za.exe application so just copy it someplace)
After running the command, you should see some yellow (verbose) messages and NHibernate PDB files are now linked with the source code zip file. It's time to test if the debugger will be able to successfully extract them. For this purpose, you should again use srctool.exe (it's located in the srcsrv folder of the Debugging Tools for Windows installation):
srctool -l:*AbstractSessionImpl.cs NHibernate.pdb -x -d:c:\temp\nh-test
The output of the upper command should be:
c:\temp\nh-test\src\NHibernate\Impl\AbstractSessionImpl.cs
NHibernate.pdb: 1 source files were extracted
If you saw something different, you probably made some mistake in the indexing and you will need to rerun it (I know it's tedious and I have plans to make sourcepack usage a little bit more pleasant). If the previous sentence does not apply to your situation, you are ready to fire Visual Studio and start debugging NHibernate sources with your brand new symbol files :).
Break in Session Open
The best place to break into the session creation process is the SessionImpl constructor. You just need to choose New Breakpoint from the Debug menu and then Break at function... (or Ctrl + B) and in the Function box type NHibernate.Impl.SessionImpl.SessionImpl. The debugger will probably complain that it can't bind the breakpoint at this time - just ignore this message and confirm that you want to set your breakpoint. It's confusing that CLR uses .ctor as a constructor name when VS prefers the class name (although sometimes after binding the breakpoint it shows locations such as NHibernate.Impl.SessionImpl..ctor so don't worry - everything is fine;)). One more caveat - in Visual Studio, when you create a function breakpoint, it will be set on all functions which names match the pattern that you provided. In our case, we will end up with three child breakpoints as there are three constructs of the SessionImpl object (have a look at the first screenshot). There is no rule on when to create the breakpoint, but if you want to trace all the sessions you probably want to set it before even starting the debugging process.
Now, let's start the debugger and try to do some actions in the application that will require a new session. While starting, have a look at the breakpoints dialog (Debug -> Windows -> Breakpoints) and see how magically our breakpoints become available.
If you correctly prepared your symbols and sources, you should now become quite happy seeing:
After the breakpoint was hit, let's examine the thread call stack:
I marked with a red rectangle two frames that actually tell us everything. The session was opened on ApplicationBeginRequest_ event by the default ISessionFactory implementation (SessionFactoryImpl). The great thing is that you can add this to the watch window and examine all the properties of the session. Also, you may set a breakpoint in the callstack and come back to ISessionFactory instance and check its properties too (like currentSessionContext that defines how long session will last and where it will be stored).
Break in Session Close
In this paragraph, we are going to step through the closing session process in order to find places where things may go off the rails. The closing process may be divided into two parts: flushing and actual closing. While flushing, NHibernate synchronizes the state of the session with the database, preparing an ordered collection of queries that must be then executed. We will start our analysis from placing an unresolved breakpoint on the NHibernate.Impl.SessionImpl.Flush. After firing the debugger (F5), our breakpoint should become alive and stop the execution at the following code:
The upper part of the picture contains the current call stack and the bottom part - the code. Normally, you should first check if the Flush is called from where you planned it (in my case, it was called while committing the transaction in response to the Application_EndRequest event - so no surprise here). We will be interested in the flushEventListener[i].OnFlush(new FlushEvent(this)) line as this is where the hard work is done. If you didn't provide any own IFlushListener implementations to NHibernate, the default one (DefaultFlushListener) will be used:
The marked lines are the most interesting. FlushEverythingToExecution checks the session objects states and prepares the queries, when PerformExecutions (as its name suggests) executes the queries against the database. At this moment, it might be interesting to check what objects are stored in the session entity dictionary and what are their properties. To accomplish that, expand the @event.Session object and choose PersistenceContext property of the SessionImpl object or just add ((NHibernate.Impl.SessionImpl)(@event.Session)).PersistenceContext expression to your watch window. Browse through the EntitiesByKey and CollectionsByKey properties.
The comment over FlushEntities explains exactly what this method does:
private void FlushEntities(FlushEvent @event)
{
In the code below, you can see that it iterates through the EntityEntries collection firing OnFlushEntity event for each entity with the correct status:
The selected line above might be an interesting place for a conditional breakpoint filtering entries that we are interested in, like entry.Id.Equals(1) or entry.EntityName.Equals("NHibernate.Example.Web.Models.Item"). Our next place to visit will be DefaultFlushEntityEventListener and its OnFlushEntity handler:
The first red rectangle selects the code that checks the entity status - whether its properties had changed from loading or it was deleted or it's a new entity. You may debug this code if you find that your object is not being updated, but before you get your hands dirty you may first check if the SessionImpl.ActionQueues is being updated by this method. ActionQueues as its name suggests contains actions that must be executed in order to synchronize the session with the database. They are grouped into queues based on their category: insertions, updated, deletions, collectionCreations, collectionUpdates, collectionRemovals. At this point, you may wish to check if those collections contain a valid number of elements (or even the correct number of dirty properties). After filling the action queues, there comes a time to translate them to SQL queries. This is done in the PerformExecutions method of the DefaultFlushingEventListner (or rather AbstractFlushingEventListener):
Internally ExecuteActions calls NHibernate.Engine.ActionQueue.ExecuteActions method which iterates through all the actions in all queues calling their Execute method, which internally prepares SQL queries (Persister's Update method) and (if configured) puts them into batches or executes immediately.
This would be the end of the description of the session flush process. There is one more thing that needs some explanation - session's closing. Fortunately for you, probably already bored readers;), this method is fairly simple and its main role is to close all opened connections and dispose internal NHibernate objects (as batchers, transaction wrappers, etc.).
Sample Code
To run the sample code, you will need SQL Server instance (Express edition is fine). The zip file contains a db.sql script with commands needed to setup a sample database. Please don't consider the sample code as an ideal MVC implementation - it contains as little elements as possible and all the code is placed in the App_Code directory just to make the deployment faster.
Remarks
In this article, I tried to show you how you can debug your NHibernate applications to check few of the session characteristics. The whole debugging process may become more complicated if your session contains hundreds of entities, or a problem of different nature appears (such as invalid transaction management). Nevertheless, I hope that you enjoyed reading this article and that it will help you with your future NHibernate struggles.
This article is based on posts from my blog http://lowleveldesign.wordpress.com. If you find it interesting, please pay me a visit and see what else is there:).
History
- 12th October, 2011: Initial version
