NHibernate - How to log Named Parameterised Query with parameter values?

Question

I have a parameterised named Query like this :

Query moveOutQuery = session.createSQLQuery(moveOutQueryStr.toString())
                .addEntity(MyClass.class)
                .setParameter("assignmentStatus", Constants.CHECKED_OUT)

I want to see the actual SQL query with parameters filled in. However while debugging I only get the following query:

Select * from my_assignment WHERE assignment_status in ( :assignmentStatus )

Why isn't the assignmentStatus being substituted for its real value?

Answer 1

Why isn't the assignmentStatus being substituted for its real value?

This is because NHibernate use query parameters to input values. This is efficient in many cases and also helpful against SQL Injection attack. Parameters are sent separately. You can find them at the bottom if SQL is logged as explained below.

---

You may log each SQL to file as explained below.

This is implemented through log4net.dll; you need to add reference.

Add namespaces as below:

using log4net;
using log4net.Appender;
using log4net.Core;
using log4net.Layout;
using log4net.Repository.Hierarchy;

Configure log4net in NHibernate as below:

Hierarchy hierarchy = (Hierarchy)LogManager.GetRepository();
hierarchy.Root.RemoveAllAppenders();

FileAppender fileAppender = new FileAppender();
fileAppender.Name = "NHFileAppender";
fileAppender.File = logFilePath;
fileAppender.AppendToFile = true;
fileAppender.LockingModel = new FileAppender.MinimalLock();
fileAppender.Layout = new PatternLayout("%d{yyyy-MM-dd HH:mm:ss}:%m%n%n");
fileAppender.ActivateOptions();

Logger logger = hierarchy.GetLogger("NHibernate.SQL") as Logger;
logger.Additivity = false;
logger.Level = Level.Debug;
logger.AddAppender(fileAppender);

hierarchy.Configured = true;

You also need to set ShowSql while configuration as below:

configuration.SetProperty(NHibernate.Cfg.Environment.ShowSql, "true");
configuration.SetProperty(NHibernate.Cfg.Environment.FormatSql, "true");

You need to call this code once at startup of your application. Output log includes values of parameters as well.

Following is the code:

session.CreateSQLQuery("SELECT * FROM MyEntity WHERE MyProperty = :MyProperty")
            .AddEntity(typeof(MyEntity))
            .SetParameter("MyProperty", "filterValue")
            .UniqueResult<MyEntity>();

Following is the logged query:

2020-01-09 14:25:39:
    SELECT
        * 
    FROM
        MyEntity 
    WHERE
        MyProperty = @p0;
    @p0 = 'filterValue' [Type: String (4000:0:0)]

As you can see, parameter value filterValue is listed at the bottom.

This works for all query APIs like IQueryOver, IQuery, ISQLQuery etc.

This logs both success and failed statements. You can play with FileAppender and Logger class to meet your additional requirements.

Also refer PatternLayout from documentation. More details can also be found here, here and here. This Q/A discusses the same.

Following Q/A may also help:

• Get executed SQL from nHibernate
• Using log4net to write to different loggers
• How to log SQL calls with NHibernate to the console of Visual Studio?

As you see, this logs the parameter values at bottom of the query. If you want those logged embedded in the query, please refer to this article.