When you work with ORM like nhibernate, having a tool like nhprof is the key of success. But even with NHProfiler you could not prevent people of doing wrong stuff because they do not use it :). I have a simple scenario, a developer changed a method on the server lazily fetching a property of a large resultset. The effect is that the service call, that usually responded in milliseconds starts to respond in 10 seconds.
The reason is really simple, the function loaded about 200 entities from the database and if you are sure you want to access for all 200 entities a property, you should do eager fetching because issuing ~200 queries to the database is not usually a good idea. Then after some time the function started to do timeout, so I inspected again the code and did not find anything strange, but NHprof reveals me that the query was actually fetching another related entity, from a table with millions of row causing timeout. This is due to a modification to a mapping, someone disabled proxy for that class, so NH decided to do a join with the table with millions of row, slowing the method again .
After the problem was fixed, I created some helpers that permits me to write a test that will alert me immediately in the future if such a problem is comeback again.
This test is not really a UnitTest, it is more an integration one, but it is able to verify that calling a function on a service class only one query is issued to the database and the query should not eager fetch data from the other table (relatedlin…). This is much more an integration test than a unit test, but it is quite interesting because it permits me to write assertion on number and text of SQL generated by NHibernate, a feature that is really interesting especially if you know that production database is quite big. To achieve this is really simple.
I wrote this simple test helper based on my infrastructure.
this helpers seems complex, but basically it simply add during FixtureSetup an appender to log4net, this appender basically raises an event whenever it receives a log.
This appender permits the helper to intercept all logs and since Nhibernate raise a log with name nhibernate.sql with the SQL Code whenever it raises a query to the database, the helper can filter for those kind of messages and store each query inside a standard String collection.
Now I can simply decorate my Test Fixture with a specific attribute and let the magic happens.
Inside a test I can use NhibernateQueryCount() to know the number of the queries issued by NH during the test and NhibernateGetQueries() to grab the whole list and assert on how NH interacted with the database during a test.