0001137: connections disappearing

Viewing Issue Advanced Details [ Jump to Notes ]

[ View Simple ] [ Issue History ] [ Print ]

Category

Severity

Reproducibility

Date Submitted

Last Update

0001137

[Resin]

minor

always

05-22-06 10:32

06-27-06 14:35

Reporter

ferg

View Status

public

Assigned To

ferg

Priority

urgent

Resolution

fixed

Platform

Status

closed

Projection

none

OS Version

ETA

none

Fixed in Version

3.0.20

Product Version

Product Build

Summary

0001137: connections disappearing

Description

(rep by Neil Fradkin)

First, we are running resin 3.0.14 (we plan to put 3.0.19 on our test machine next week).

We are having a very strange problem where it appears connections are dropping out from under us. Here's an example stack trace:

An error occured on 2006.05.19 at 04:44:58 PM null java.lang.NullPointerException
      at com.caucho.sql.UserConnection.getAutoCommit(UserConnection.java:557)
      at org.hibernate.jdbc.ConnectionManager.isAutoCommit(ConnectionManager.java:185)
      at org.hibernate.jdbc.ConnectionManager.isAggressiveRelease(ConnectionManager.java:208)
      at org.hibernate.jdbc.ConnectionManager.afterStatement(ConnectionManager.java:264)
      at org.hibernate.jdbc.AbstractBatcher.closePreparedStatement(AbstractBatcher.java:535)
      at org.hibernate.jdbc.AbstractBatcher.closeStatement(AbstractBatcher.java:265)
      at org.hibernate.jdbc.AbstractBatcher.closeQueryStatement(AbstractBatcher.java:281)
      at org.hibernate.jdbc.AbstractBatcher.closeQueryStatement(AbstractBatcher.java:209)
      at org.hibernate.loader.Loader.doQuery(Loader.java:714)
      at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
      at org.hibernate.loader.Loader.doList(Loader.java:2145)
      at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2029)
      at org.hibernate.loader.Loader.list(Loader.java:2024)
      at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:392)
      at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:333)
      at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
      at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1109)

As you can see we are using hibernate (3.1 to be exact). The database is Oracle. This error only happens during our stress testing when we are really banging on the system, with many threads simultaneously running our most expensive operations. It has happened in a few different places, the only common factor is that the places where it happens all seem to be our longer running queries (it has happened here and two other places where we call stored procedures that can take a few minutes under heavy stress). We did check resin's connection pool settings and we thought we had a culprit when we saw that we had max-active-time set to 180s, but we changed it to default (6 hrs according to the docs) and the problem still happens. I've gone over all our connection (and hibernate session) handling with a fine tooth comb to make sure we aren't doing this to ourselves. The queries themselves run without incident.

Steps To Reproduce

Additional Information

Attached Files

Relationships

Notes
(0001237) ferg 05-23-06 10:13	I wanted to give you an update on our investigation. We can reproduce the symptom easily by setting the max-active-time to a really low number like 10 seconds and running any query that takes longer. This setting was our first suspect since we had it set to several minutes initially. We had previous runs with the timeout increased that did exhibit the error, but right now we are retesting with the default and I haven't seen it happen yet. So we have a candidate for the culprit and I'm going to check the logs when it happens to see if there is a line like "closing pool item from active timeout:PoolItem[jdbc/foo,19,com.caucho.sql.ManagedConnectionImpl@141b392]" between the actual query and the commit. If we can't reproduce the error again with the default setting I can only assume that it was the timeout all along and we screwed something up when we had increased the timeout the other day.

Issue History
Date Modified	Username	Field	Change
05-22-06 10:32	ferg	New Issue
05-23-06 10:13	ferg	Note Added: 0001237
06-27-06 14:35	ferg	Assigned To	=> ferg
06-27-06 14:35	ferg	Status	new => closed
06-27-06 14:35	ferg	Resolution	open => fixed
06-27-06 14:35	ferg	Fixed in Version	=> 3.0.20

Mantis 1.0.0rc3[^]

28 total queries executed.
25 unique queries executed.