[
https://issues.jboss.org/browse/JBJCA-676?page=com.atlassian.jira.plugin....
]
Jesper Pedersen resolved JBJCA-676.
-----------------------------------
Fix Version/s: 1.1.0.Alpha3
Resolution: Done
The default cache policy has changed to LRU_OLD.
The cache policy can be changed by setting the system property
"ironjacamar.jdbc.cache" to LRU, LRU_OLD or LIRS.
Evicted and closed CachedPreparedStatement leased out again on next
call to prepareStatement by LIRS cache.
-----------------------------------------------------------------------------------------------------------
Key: JBJCA-676
URL:
https://issues.jboss.org/browse/JBJCA-676
Project: IronJacamar
Issue Type: Bug
Components: JDBC
Affects Versions: 1.0.4.Final
Environment: Using MySQL5 database on linux.
Reporter: Jeremy Whiting
Assignee: Jesper Pedersen
Priority: Critical
Fix For: 1.0.5.Final, 1.1.0.Alpha3
Attachments: added-logging-messages.diff, as7.1-server-log-extract.txt,
evictionTest-03.tar, evictionTest-with-patched-BoundedConcurrentHashMap.tar,
evictionTest.tar
My application throws an exception that reports the PreparedStatement cannot be used
after it is closed. The exception is
javax.persistence.PersistenceException: org.hibernate.exception.JDBCConnectionException:
No operations allowed after statement closed.
It appears the PreparedStatementCache is not flushing an evicted item from the cache.
The cache does call PreparedStatementEvictionListener.onEntryEviction(Map) which closes
all the cached items being evicted. But it does not remove the item from the cache in that
same call.
When a client then calls prepareStatement(String) using the identical sql as a cached
item the lookup in the cache returns the closed CachedPreparedStatement.
I have a test case that calls the transaction on the server. The client makes an EJB
call using a web service endpoint. The test case only executes one client call at a time.
Observed behaviour
This behaviour has only been seen to occur when eviction and prepare call are for
identical SQL and when no other JDBC work happens between the two calls. Additionally it
is timing sensitive. Turning on DEBUG logging makes the issue go away. To generate the
logs attached I used a ramdisk and an ASYNC logging appender to eliminate delays due to
saving to disk.
Attached are logs with DEBUG level messages turned on for these categories:
org.hibernate.SQL, org.hibernate.engine.jdbc.internal.JdbcResourceRegistryImpl and
jboss.jdbc.spy
To highlight the behaviour I added two logging messages. Source files are attached as a
diff.
a) The first is when items in the cache are evicted. The log message shows the hash
identity of the CachedPreparedStatement and the SQL statement. Message added to
org.jboss.jca.adapters.jdbc.PreparedStatementCache.onEntryEviction(Map) on line 255.
b) The second is just before the first parameter (a String) is bound to a
PreparedStatement. The message logs the hash identity of the CachedPreparedStatement, the
SQL and hashed identity of the underlying driver com.mysql.jdbc.JDBC4PreparedStatement.
The message is added to
org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.setString(int, String) on line 637
The log file shows the two events that match the behaviour detailed earlier. The log
file is an small extract of the original. The first (the eviction) on line 21 and the
second (the parameter binding) on 24.
A test case will follow with an attempt to use H2 rather than MySQL.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see:
http://www.atlassian.com/software/jira