locked <0x00000000e1472d20> (a org.hibernate.id.SequenceHiLoGenerator)问题定位

最新推荐文章于 2024-04-15 16:43:53 发布

原创

最新推荐文章于 2024-04-15 16:43:53 发布 · 866 阅读

博客讲述了在ncount项目运行中遇到的问题，即长时间运行后无法获取数据库连接。通过日志分析和DBA协助，确认数据库连接正常但应用无法获取。进一步调查发现8个线程被阻塞，而关键在于对象<0x00000000e1472d20>，一个org.hibernate.id.SequenceHiLoGenerator实例。锁定此对象导致系统运行异常，揭示了问题根源。

现象：

ncount项目运行一段时间后，所有ncount的请求获取不到数据库连接。从日志上分析，卡在数据库操作。

DBA协助查看oracle的数据库连接都正常，且为INACTIVE(数据库连接为活跃状态)

但程序获取不到连接

跟踪分析：

1. 补充日志，定位问题。

将hibernate的日志改为debug级别：

       <logger name="org.hibernate.SQL" level="DEBUG"/>

将sql打印出来：

        <prop key="hibernate.show_sql">true</prop>

开启debug日志


2019-08-26.11:56:13.985 [ttp-nio-8142-exec-35] - INFO   [    c.h.ncount.client.impl.KeyClientImpl.merVerify] ncountMerVerify结果：true
2019-08-26.11:56:13.985 [ttp-nio-8142-exec-35] - INFO   [   c.h.n.service.pre.impl.T007PreBizImpl.saveGatewayRecord] 保存请求流水开始
2019-08-26.11:56:13.985 [ttp-nio-8142-exec-35] -DEBUG   [          org.hibernate.impl.SessionImpl.<init>] opened session at timestamp: 15667917739
2019-08-26.11:56:13.986 [ttp-nio-8142-exec-35] -DEBUG   [      org.hibernate.jdbc.AbstractBatcher.logOpenPreparedStatement] about to open PreparedStatement (open PreparedStatements: 0, globally: 26)
2019-08-26.11:56:13.986 [ttp-nio-8142-exec-35] -DEBUG   [    org.hibernate.jdbc.ConnectionManager.openConnection] opening JDBC connection

日志卡在获取数据库连接

并且配合运维导出的jvm线程信息，BLOCKED线程数量有8个

"http-nio-8142-exec-130" #188 daemon prio=5 os_prio=0 tid=0x00007f1674581800 nid=0xb15 waiting for monitor entry [0x00007f16307c4000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.hibernate.id.SequenceHiLoGenerator.generate(SequenceHiLoGenerator.java:51)
        - waiting to lock <0x00000000e1472d20> (a org.hibernate.id.SequenceHiLoGenerator)
        at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:98)
        at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.saveWithGeneratedOrRequestedId(DefaultSaveOrUpdateEventListener.java:186)
        at org.hibernate.event.def.DefaultSaveEventListener.saveWithGeneratedOrRequestedId(DefaultSaveEventListener.java:33)
        at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:175)
        at org.hibernate.event.def.DefaultSaveEventListener.performSaveOrUpdate(DefaultSaveEventListener.java:27)
        at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:70)
        at org.hibernate.impl.SessionImpl.fireSave(SessionImpl.java:535)
        at org.hibernate.impl.SessionImpl.save(SessionImpl.java:523)
        at org.hibernate.impl.SessionImpl.save(SessionImpl.java:519)
        at org.springframework.orm.hibernate3.HibernateTemplate$12.doInHibernate(HibernateTemplate.java:686)
        at org.springframework.orm.hibernate3.HibernateTemp