NHibernate事务偶发未插入全部记录问题排查求助

问题背景 #

• 仅生产环境出现事务异常，本地测试无法复现
• 系统包含Booking和Rooms两张表，Rooms通过BookingID关联Booking，理论上每条Booking对应一条Rooms记录
• 每周约有两天出现数据不一致：比如存在400条Booking记录，但Rooms仅398条
• 测试异常场景时事务会正常回滚并日志记录，但问题发生时，即使Rooms未插入，事务提交日志仍显示成功
• 异常概率约每200次请求出现1次，怀疑是Session不一致或NHibernate未跟踪第二条插入语句
• 当前在Application_EndRequest中销毁Session，不确定事务提交后显式销毁Session是否能解决问题
• 需求：如何将Session ID传入日志，以及对现有代码进行调优

现有代码实现 #

Repository层 #

public class EntityRepository : IRepository
{
    private readonly string connectionStringKey;
    private NHibernate.ISession context;

    protected NHibernate.ISession Context
    {
        get
        {
            return (this.context == null || !this.context.IsOpen) ?
                (this.context = DataContextFactory.GetContextForConnection(this.connectionStringKey)) : this.context;
        }
    }
    
    public void Add<TObject>(TObject obj) where TObject : class
    {
        Context.Save(obj);
    }
    
    public NHibernate.ITransaction CreateTransaction()
    {
        return Context.BeginTransaction(); // flushmode is auto as default
    }
}

核心业务方法 #

public Models.BookingRequestResult BookingRoom(Models.Booking booking)
{
    ITransaction transaction = null;
    try
    {
        booking.BookingAppID = CodeGenerator.UniqueIdGenerator.Generate(10);
        transaction = repository.CreateTransaction(); 
        logger.InfoFormat("Transaction Started for: {0}", booking.BookingAppID );
        transaction.Begin(System.Data.IsolationLevel.Serializable);

        repository.Add(booking); // booking added
        logger.InfoFormat("Booking Added for {0}", booking.BookingAppID);

        var RoomAppt = new Rooms { Booking = booking , Type="Room" };

        repository.Add(RoomAppt); // room added and the BookingID is the ID of the newly created booking
                                    
        transaction.Commit();
        logger.InfoFormat("Booking: {0} has been committed", booking.BookingAppID); // 即使Room未插入，这条日志仍会输出

        ...        
    } catch(Exception e) {
        // 异常时记录日志并回滚事务
    }
}

DataContextFactory类 #

public static class DataContextFactory
{
    private static IDictionary<string, NHibernate.ISessionFactory> sFactories = new Dictionary<string, NHibernate.ISessionFactory>();

    public static NHibernate.ISession GetContextForConnection(string connectionStringKey = null)
    {
        if (string.IsNullOrEmpty(connectionStringKey)) connectionStringKey = GetCurrentContext();

        var context = sContextStore[connectionStringKey];
        if(context == null || !context.IsOpen)
        {
            lock (sCreateSyncRoot)
            {
                context = sContextStore[connectionStringKey];
                if (context == null || !context.IsOpen)
                {
                    if(sFactories.ContainsKey(connectionStringKey))
                    {
                        context = sFactories[connectionStringKey].OpenSession();
                        sContextStore[connectionStringKey] = context;
                    }
                    else
                    {
                        throw new ArgumentException("This connection string wasn't specified in Db Context configuration.");
                    }
                }
            }
        }
        return context;
    }

    public static void Initialize(System.Xml.Linq.XElement configNode = null)
    {
        lock (sInitSyncRoot)
        {
            if (sContextWrappers != null)
            {
                throw new InvalidOperationException("Context is already initialized");
            }

            if (configNode == null)
            {
                var configFile =
                    System.IO.Path.Combine(
                        System.Configuration.ConfigurationManager.AppSettings[ConfigurationTokens.ConfigurationPath],
                        "DataContextFactory.conf");
                if (System.IO.File.Exists(configFile))
                {
                    configNode = System.Xml.Linq.XElement.Load(configFile);
                    
                }
            }
            if (configNode == null)
            {
                throw new NullReferenceException("No configuration node or file was provided.");
            }

            var attrib = configNode.Attribute("storeType");
            if (attrib == null)
            {
                throw new NullReferenceException("Store type is undefined");
            }
            sContextStore = Utilities.ReflectionUtility.Get<IContextStore>(attrib.Value);

            attrib = configNode.Attribute("defaultConnectionStringKey");
            if (attrib != null)
            {
                sDefaultConnectionString = attrib.Value;
            }

            foreach (var dbContext in configNode.Elements("DbContext"))
            {
                var dbConnectionStringAttribute = dbContext.Attribute("connectionStringKey");
                if (dbConnectionStringAttribute == null || string.IsNullOrWhiteSpace(dbConnectionStringAttribute.Value))
                {
                    throw new ArgumentException("No connection string key specified in DataContextFactory.conf.");
                }
                FluentConfiguration configuration = 
                ConfigureWrapper(dbContext, dbConnectionStringAttribute.Value);
                configuration.Mappings(c => {
                    c.FluentMappings.Conventions.Add<EnumConvention>();
                });
                AddMappingAssemblies(dbContext, configuration);
                sFactories.Add(dbConnectionStringAttribute.Value, configuration.BuildSessionFactory());
                
            }
        }
    }
    
    public static void DeInitialize()
    {
        if (sContextStore != null)
        {
            var ctxStores = sContextStore.GetAll();
            foreach (var ctx in ctxStores)
            {
                if (ctx.IsOpen)
                {
                    var objCtx = ctx.Close();
                }
                ctx.Dispose();
            }
        }
    }
}

Global.asax #

protected void Application_EndRequest(object sender, EventArgs args)
{
    PatientPoint.Infrastructure.Data.DataContextFactory.DeInitialize();
}

问题排查与优化方案 #

1. 将Session ID传入日志 #

在日志中加入Session ID可以精准追踪Session一致性问题，有两种实现方式：

• 直接在业务方法中获取Session ID并写入日志：

  // 在BookingRoom方法创建事务后添加
  logger.InfoFormat("Transaction Started for: {0}, Session ID: {1}", booking.BookingAppID, repository.Context.SessionId);
  

• 如果日志框架支持上下文属性（如NLog的Mapped Diagnostics Context），可以在Session创建时将Session ID注入日志上下文，后续所有日志自动携带该ID，无需重复编写。

2. 代码调优与事务问题修复 #

（1）修复冗余的事务Begin调用

当前代码中CreateTransaction()已经调用了Context.BeginTransaction()，后续再调用transaction.Begin()属于重复操作，可能引发不可预期的事务状态。修改如下：

// 修改Repository的CreateTransaction方法，支持传入隔离级别
public NHibernate.ITransaction CreateTransaction(IsolationLevel isolationLevel = IsolationLevel.ReadCommitted)
{
    return Context.BeginTransaction(isolationLevel);
}

// 业务方法中直接创建指定隔离级别的事务
transaction = repository.CreateTransaction(System.Data.IsolationLevel.Serializable);

（2）确保Session的请求级隔离

检查IContextStore的实现，必须保证它是请求级存储（比如基于HttpContext.Items），而非全局静态字典。多请求复用同一个Session是并发场景下事务异常的常见根源。

（3）显式Flush并验证数据状态

NHibernate的Save默认延迟执行，仅在Commit时Flush。如果Session状态异常，可能导致部分实体未被提交。可以在Commit前显式Flush，或者在Commit后验证数据一致性：

// 显式Flush所有未提交操作
repository.Context.Flush();
transaction.Commit();

// 可选：提交后验证Room记录是否存在
var savedRoom = repository.Get<Rooms>(room => room.BookingAppID == booking.BookingAppID);
if (savedRoom == null)
{
    logger.WarnFormat("Booking {0} committed but Room record missing, Session ID: {1}", booking.BookingAppID, repository.Context.SessionId);
}

（4）调整Session销毁逻辑

在事务完成后，显式清理当前请求的Session，避免后续代码复用异常Session：

// 在BookingRoom方法中添加finally块
finally
{
    if (transaction != null)
    {
        transaction.Dispose();
    }
    // 在DataContextFactory中新增ClearCurrentSession方法，移除当前请求的Session
    DataContextFactory.ClearCurrentSession();
}

（5）完善异常日志

当前catch块日志过于简略，需要捕获所有异常类型并记录关键信息：

catch (Exception e)
{
    logger.ErrorFormat("Booking failed for {0}, Session ID: {1}, Error: {2}", 
        booking.BookingAppID, 
        repository.Context.SessionId, 
        e.ToString());
    if (transaction != null && transaction.IsActive)
    {
        transaction.Rollback();
        logger.InfoFormat("Transaction rolled back for {0}", booking.BookingAppID);
    }
}

3. 根本原因猜测 #

结合现象分析，最大可能是Session在并发场景下被共享或污染：

• 如果IContextStore不是请求级存储，多个请求会复用同一个Session，导致事务操作互相干扰
• 或者Session的FlushMode被意外修改，导致部分实体未被NHibernate跟踪
• 数据库层面的死锁或超时通常会抛出异常，而非静默失败，因此概率较低

内容的提问来源于stack exchange，提问作者user1591668