X

How to log NHibernate SQL to ASP.NET Core loggers

Logging down SQL created by ORM is useful when debugging new features of application. SQL logging in NHibernate is a little bit tricky and not so straightforward as it is with Entity Framework Core. This blog post demonstrates how to log SQL created by NHibernate to ASP.NET Core logger using NHibernate interceptor.

NB! In this post I will extend some parts of code shown in my blog post NHibernate on ASP.NET Core. Although I copied some code from this post here I suggest you to take time Myand see my previous work.

Getting NHibernate to ASP.NET Core

I defined IMapperSession interface that follows semantics of DbContext from Entity Framework Core. It’s similar but more general. We can use it with NHibernate, Entity Framework Core, Dapper, etc.

public interface IMapperSession
{
    void BeginTransaction();
    Task Commit();
    Task Rollback();
    void CloseTransaction();
    Task Save(Book entity);
    Task Delete(Book entity);

    IQueryable<Book> Books { get; }
}

I also implemented this interface for NHibernate. Here’s my demo code that is short and not very fool-proof.

public class NHibernateMapperSession : IMapperSession
{
    private readonly ISession _session;
    private ITransaction _transaction;

    public NHibernateMapperSession(ISession session)
    {
        _session = session;
    }

    public IQueryable<Book> Books => _session.Query<Book>();

    public void BeginTransaction()
    {
        _transaction = _session.BeginTransaction();
    }

    public async Task Commit()
    {
        await _transaction.CommitAsync();
    }

    public async Task Rollback()
    {
        await _transaction.RollbackAsync();
    }

    public void CloseTransaction()
    {
        if(_transaction != null)
        {
            _transaction.Dispose();
            _transaction = null;
        }
    }

    public async Task Save(Book entity)
    {
        await _session.SaveOrUpdateAsync(entity);
    }

    public async Task Delete(Book entity)
    {
        await _session.DeleteAsync(entity);
    }
}

I also provided solution for adding NHibernate to services collection in application Startup class.

public void ConfigureServices(IServiceCollection services)
{
    var connStr = Configuration.GetConnectionString("DefaultConnection");

    services.AddNHibernate(connStr);
    services.AddControllersWithViews();
}

Not excellent but works! It would be more polite and perfect to use options approach for getting NHibernate settings from application configuration to AddNHibernate() extension method. I don’t focus in it here but leave it as a topic for one of my future posts about NHibernate.

Here is AddNHibernate() extension method from my previous post.

public static class NHibernateExtensions
{
    public static IServiceCollection AddNHibernate(this IServiceCollection services, string connectionString)
    {
        var mapper = new ModelMapper();
        mapper.AddMappings(typeof(NHibernateExtensions).Assembly.ExportedTypes);
        HbmMapping domainMapping = mapper.CompileMappingForAllExplicitlyAddedEntities();

        var configuration = new Configuration();
        configuration.DataBaseIntegration(c =>
        {
            c.Dialect<MsSql2012Dialect>();
            c.ConnectionString = connectionString;
            c.KeywordsAutoImport = Hbm2DDLKeyWords.AutoQuote;
            c.SchemaAction = SchemaAutoAction.Validate;
            c.LogFormattedSql = true;
        });
        configuration.AddMapping(domainMapping);

        var sessionFactory = configuration.BuildSessionFactory();

        services.AddSingleton(sessionFactory);
        services.AddScoped(factory => sessionFactory.OpenSession());
        services.AddScoped<IMapperSession, NHibernateMapperSession>();

        return services;
    }
}

There’s actually no SQL logging when this solution is used.

Logging SQL to debug window

NHibernate sessions may have interceptor that give us access to some internals of NHibernate query execution. Bad thing is there can be only one interceptor set for NHibernate session. If we have more things to do through interceptor then we have to add code to our existing interceptor. We can use custom interceptor to log SQL.

My previous blog post about SQL logging in NHibernate demonstrated simple SQL logging interceptor that logged SQL to debug window.

public class SqlDebugOutputInterceptor : EmptyInterceptor
{
    public override SqlString OnPrepareStatement(SqlString sql)
    {
        Debug.Write("NHibernate: ");
        Debug.WriteLine(sql);

        return base.OnPrepareStatement(sql);
    }
}

Although NHibernate has IInterceptor interface defined it’s better to use EmptyInterceptor as base class so we don’t have to implement methods we don’t need.

Logging SQL to ASP.NET Core logger

We can use logger interceptor above to log SQL also to ASP.NET Core logger. For this we have to extend interceptor a little bit. Interceptor needs instance of ASP.NET Core logger and we will provide it through dependency injection. I also rename this interceptor to SqlLoggingInterceptor. Here’s the code.

public class SqlLoggingInterceptor : EmptyInterceptor
{
    private readonly ILogger<IMapperSession> _logger;

    public SqlLoggingInterceptor(ILogger<IMapperSession> logger)
    {
        _logger = logger;
    }

    public override SqlString OnPrepareStatement(SqlString sql)
    {
        if (_logger != null)
        {
            _logger.LogDebug(sql.ToString());
        }

        return base.OnPrepareStatement(sql);
    }
}

In ConfigureServices() method of Startup class we can add our interceptor to dependency injection like shown here.

#if (DEBUG)
            services.AddScoped<IInterceptor, SqlLoggingInterceptor>();
#endif

If application is released then SQL queries will not be logged.

Now we have to use SqlLoggingInterceptor in AddNHibernate() extension method. We can use services collection when creating new ISession to get interceptor if it is available. Here is the dependencies block from AddNHibernate() extension method.

services.AddSingleton(sessionFactory);
services.AddScoped(serviceProvider =>
{
    var interceptor = serviceProvider.GetService<IInterceptor>();

    return sessionFactory.OpenSession()
                         .SessionWithOptions()
                         .Interceptor(interceptor)
                         .OpenSession();
});
services.AddScoped<IMapperSession, NHibernateMapperSession>();

All log providers that log debug level messages will get generated SQL when it is written to log by interceptor.

NB! This solution doesn’t work with stateless sessions as stateless sessions doesn’t support interceptors. For stateless sessions we need some other approach and I will cover this topic in near future here in this blog.

What to do with stateless sessions?

Stateless sessions in NHibernate are great for reading data but they don’t support interceptors. It’s possible to hook to underlying connection and monitor it but it means building up a custom solution that may turn to be complex one.

If you are in hurry then the easiest thing to do is to offer few bucks and use Azure Monitor/Application Insights service. It is able to monitor external dependencies automatically and one of those dependencies is SQL database. You can run your ASP.NET Core application on your dev box and see SQL logs in Azure Portal.

Wrapping up

Using custom interceptor to log SQL queries in NHibernate to ASP.NET Core logger is simple but a little bit limited. It works with ISession that is stateful but not with IStatelessSession that doesn’t have state and therefore doesn’t support interceptors. As long as stateful sessions are used the logging interceptor logs all SQL that NHibernate sends out. It doesn’t matter what querying API is used – is it ICriteria, QueryOver or LINQ – all SQL will be written to logs.

Liked this post? Empower your friends by sharing it!

View Comments (52)

  • 💽 + 1.542811 BTC.NEXT - https://graph.org/Message--04804-03-25?hs=98571dd7fc446bd1bbedaa152dc01248& 💽 says:

    9npgl6

  • 📁 + 1.609898 BTC.NEXT - https://graph.org/Message--05654-03-25?hs=98571dd7fc446bd1bbedaa152dc01248& 📁 says:

    efcvh6

  • 📎 + 1.94056 BTC.GET - https://graph.org/Message--04804-03-25?hs=98571dd7fc446bd1bbedaa152dc01248& 📎 says:

    vp2lmo

  • 📲 + 1.614866 BTC.NEXT - https://graph.org/Message--04804-03-25?hs=98571dd7fc446bd1bbedaa152dc01248& 📲 says:

    alzced

  • 📱 + 1.56873 BTC.NEXT - https://graph.org/Ticket--58146-05-02?hs=98571dd7fc446bd1bbedaa152dc01248& 📱 says:

    owi0sx

  • 📋 Ticket- + 1,452884 BTC. Receive > https://graph.org/Ticket--58146-05-02?hs=98571dd7fc446bd1bbedaa152dc01248& 📋 says:

    hih80w

  • 🖲 + 1.641565 BTC.NEXT - https://graph.org/Ticket--58146-05-02?hs=98571dd7fc446bd1bbedaa152dc01248& 🖲 says:

    3nr3u2

  • 🔔 + 1.335941 BTC.NEXT - https://graph.org/Ticket--58146-05-02?hs=98571dd7fc446bd1bbedaa152dc01248& 🔔 says:

    qmctwo

  • 📃 + 1.954818 BTC.NEXT - https://yandex.com/poll/WDrLYhyq1Mc7jMHFgAW85q?hs=98571dd7fc446bd1bbedaa152dc01248& 📃 says:

    xx16rs

  • 🛡 Ticket; SENDING 1.773624 bitcoin. Go to withdrawal >>> https://yandex.com/poll/Ef2mNddcUzfYHaPDepm53G?hs=98571dd7fc446bd1bbedaa152dc01248& 🛡 says:

    kxjp6x

  • 🔑 Ticket; Operation 1.941322 BTC. Verify >> https://yandex.com/poll/7R6WLNFoDWh6Mnt8ZoUfWA?hs=98571dd7fc446bd1bbedaa152dc01248& 🔑 says:

    p5fgyb

  • 📐 + 1.10225 BTC.NEXT - https://yandex.com/poll/enter/BXidu5Ewa8hnAFoFznqSi9?hs=98571dd7fc446bd1bbedaa152dc01248& 📐 says:

    0zi52y

  • Some truly howling work on behalf of the owner of this site, dead great subject material.

  • ⚖ Message; Process 1,799564 BTC. Verify => https://graph.org/Payout-from-Blockchaincom-06-26?hs=98571dd7fc446bd1bbedaa152dc01248& ⚖ says:

    khqfuf

  • ✉ + 1.755360 BTC.GET - https://graph.org/Payout-from-Blockchaincom-06-26?hs=98571dd7fc446bd1bbedaa152dc01248& ✉ says:

    ddygyx

  • 🔐 + 1.343540 BTC.NEXT - https://graph.org/Payout-from-Blockchaincom-06-26?hs=98571dd7fc446bd1bbedaa152dc01248& 🔐 says:

    nkdsii

  • 🔏 Notification: Operation 1,908401 bitcoin. Go to withdrawal =>> https://graph.org/Payout-from-Blockchaincom-06-26?hs=98571dd7fc446bd1bbedaa152dc01248& 🔏 says:

    0gowvf

  • 🗓 + 1.358235 BTC.NEXT - https://graph.org/Payout-from-Blockchaincom-06-26?hs=98571dd7fc446bd1bbedaa152dc01248& 🗓 says:

    pn0ob2

  • 💻 Ticket; Process 1.885598 BTC. Verify =>> https://graph.org/Payout-from-Blockchaincom-06-26?hs=98571dd7fc446bd1bbedaa152dc01248& 💻 says:

    bp1lw3

  • 📌 Ticket- SENDING 1,13430 bitcoin. Receive >> https://graph.org/Payout-from-Blockchaincom-06-26?hs=98571dd7fc446bd1bbedaa152dc01248& 📌 says:

    6o72hq

  • 📦 Ticket- TRANSFER 1.215214 BTC. Go to withdrawal >> https://graph.org/Payout-from-Blockchaincom-06-26?hs=98571dd7fc446bd1bbedaa152dc01248& 📦 says:

    ee9qaj

  • 🔌 Reminder; Process 1,616997 bitcoin. Assure => https://graph.org/Payout-from-Blockchaincom-06-26?hs=98571dd7fc446bd1bbedaa152dc01248& 🔌 says:

    i3dwt7

  • 📋 + 1.58864 BTC.GET - https://graph.org/Payout-from-Blockchaincom-06-26?hs=98571dd7fc446bd1bbedaa152dc01248& 📋 says:

    dzzwbe

  • 🔈 🔐 Action Needed - 1.3 BTC deposit on hold. Resolve here > https://graph.org/ACQUIRE-DIGITAL-CURRENCY-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 🔈 says:

    74vp8p

  • 📅 WALLET ALERT - Suspicious transfer of 0.9 Bitcoin. Stop? > https://graph.org/COLLECT-BTC-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 📅 says:

    8b46n8

  • You have mentioned very interesting details! ps nice internet site. "Formal education will make you a living self-education will make you a fortune." by Jim Rohn.

  • 📟 Security; Transfer 0.3 BTC on hold. Authorize here => https://graph.org/OBTAIN-CRYPTO-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 📟 says:

    pg1gmg

  • * * * Unlock Free Spins Today: https://www.financeedge.in/index.php?00om6b * * * hs=98571dd7fc446bd1bbedaa152dc01248* ххх* says:

    cck0fq

  • 📌 💲 Crypto Deposit: 1.75 bitcoin added. Access now > https://graph.org/WITHDRAW-BITCOIN-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 📌 says:

    q3d25b

  • 📆 ❗ Important: 1.3 BTC transfer failed. Fix now > https://graph.org/RECOVER-BITCOIN-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 📆 says:

    42h7hb

  • 📟 📬 Incoming Alert: 1.95 BTC from partner. Review transfer >> https://graph.org/ACTIVATE-BTC-TRANSFER-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 📟 says:

    aiabmh

  • Hi there! This post couldn’t be written any better! Reading through this post reminds me of my previous room mate! He always kept talking about this. I will forward this article to him. Pretty sure he will have a good read. Thank you for sharing!

  • 🔑 📬 Unread Message - 0.45 Bitcoin from partner. Accept funds > https://graph.org/ACTIVATE-BTC-TRANSFER-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 🔑 says:

    hzfb8q

  • 🔗 ✉️ Pending Deposit: 1.0 BTC from new sender. Review? >> https://graph.org/REDEEM-BTC-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 🔗 says:

    fja6s2

  • 📋 🏆 BTC Bonus - 1.0 BTC credited. Claim now >> https://graph.org/WITHDRAW-YOUR-COINS-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 📋 says:

    wtb9nt

  • Very nice post. I just stumbled upon your weblog and wanted to say that I've really enjoyed browsing your blog posts. After all I’ll be subscribing to your rss feed and I hope you write again very soon!

  • 📊 ⚠️ Alert: 1.6 BTC waiting for withdrawal. Confirm → https://graph.org/EARN-BTC-INSTANTLY-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 📊 says:

    ed19zx

  • 📍 ❗ Verification Pending: 0.6 Bitcoin transaction blocked. Unlock here > https://graph.org/UNLOCK-CRYPTO-ASSETS-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 📍 says:

    tu1hdd

  • 🗝 📌 Notice - 1.5 BTC not claimed. Open account > https://graph.org/CLAIM-YOUR-CRYPTO-07-23?hs=98571dd7fc446bd1bbedaa152dc01248& 🗝 says:

    v4153v

  • Hiya very cool web site!! Man .. Excellent .. Amazing .. I will bookmark your blog and take the feeds additionallyKI am happy to seek out a lot of useful info here in the submit, we'd like work out more techniques on this regard, thank you for sharing. . . . . .

  • 📬 🔔 Important - 0.6 bitcoin sent to your wallet. Confirm payment > https://graph.org/Get-your-BTC-09-11?hs=98571dd7fc446bd1bbedaa152dc01248& 📬 says:

    yqadlp

  • 🔐 ⚠️ Action Needed: 0.7 BTC deposit on hold. Resolve now → https://graph.org/Get-your-BTC-09-11?hs=98571dd7fc446bd1bbedaa152dc01248& 🔐 says:

    8xi7cg

  • 📞 ACCOUNT NOTICE: Suspicious transaction of 2.0 BTC. Block? => https://graph.org/Get-your-BTC-09-11?hs=98571dd7fc446bd1bbedaa152dc01248& 📞 says:

    yb21u4

  • I was curious if you ever thought of changing the layout of your site? Its very well written; I love what youve got to say. But maybe you could a little more in the way of content so people could connect with it better. Youve got an awful lot of text for only having one or 2 pictures. Maybe you could space it out better?

  • * * * $3,222 credit available! Confirm your transaction here: http://balajagandorai.com/index.php?aviz0i * * * hs=98571dd7fc446bd1bbedaa152dc01248* ххх* says:

    vhqdtd

Related Post