I've been having an issue with Hibernate running under JBoss EAP V4.22.0.2 where my code sporatically cannot find a persisted object.
So what we're doing is creating a record in a MDB and persisting it, then calling a Stateless Session Bean with that record as a parameter which places that record on a Queue. That queue is read by an MDB, which tries to do an EntityManager.find on the same object (we're doing this so that it will be managed after it reaches the other side of the queue).
It works for about 99/100 records that we pass through, but it seems to be failing out every so often for no apparent reason.
I added code so that when it fails to find the record, it continues to attempt the find call for up to 100 times. When doing this the EntityManager eventually finds the object. My initial thought was that this was being caused by the Stateless Bean's transaction delaying on the commit, but the Hibernate logs don't show anything happening to the Entity between the times that it fails in the for loop and when it eventually finds it.
I've also added simple JDBC calls in the Stateless Bean and in the MDB to see if it exists outside of the EntityManager. It shows the row in the Database in the Stateless Bean, but not in the MDB for the records that also fail the find call. I'm not sure how accurate the JDBC call in the Stateless Bean is however, because I'm not sure if the JDBC call and the EntityManager would share the same database session.
If anyone has any idea what I'm doing wrong here, I'd greatly appreciate the input.
Note: Names have been changed to protect the innocent
Hibernate version: EntityManager 3.2.1
Record Builder MDB:
Code:
@MessageDriven(activationConfig =
{
@ActivationConfigProperty(propertyName="destinationType",
propertyValue="javax.jms.Topic"),
@ActivationConfigProperty(propertyName="destination",
propertyValue="topic/EventTopic")
})
public class EventMDB implements MessageListener
{
...
public void onMessage(Message msg) {
...
InputRecord record = new InputRecord();
record.setStatus(status);
record.addRecordAttr("FileAddress", event.getFileAddress());
record.setCustomerId(psd.getFileAddress());
manager.persist(record);
driver.processRecord(record);
}
...
}
Stateless Bean Code:Code:
@Stateless
public class DriverBean implements Driver{
...
@PersistenceContext(unitName="arch-persist")
private EntityManager manager;
public void processRecord (InputRecord record) throws Exception{
ObjectMessage om = tsbSess.createObjectMessage();
om.setObject((Serializable)record);
manager.flush();
// Added to double check what Hibernate was doing
java.sql.Connection conn = datasource.getConnection();
Statement stmt = conn.createStatement();
ResultSet rs = stmt.executeQuery("select * from Input_Record where sysid =" + Long.toString(record.getSysid()));
rs.next();
log.info("JDBC query returned: " + rs.getLong("SYSID") + " " + rs.getString("customer_id"));
stmt.close();
conn.close();
// Send to the Queue
sender.send(om);
}
}
RecordProcessorMDB:Code:
@LocalBinding(jndiBinding="RecordProcessorMDB")
@MessageDriven(activationConfig =
{
@ActivationConfigProperty(propertyName="destinationType",propertyValue="javax.jms.Queue"),
@ActivationConfigProperty(propertyName="destination",propertyValue="queue/TSBQueue")
})
public class RecordProcessorMDB implements MessageListener{
@PersistenceContext(unitName="arch-persist")
private EntityManager manager;
public void onMessage(Message msg) {
InputRecord record = (InputRecord)((ObjectMessage)msg).getObject();
// Added for troubleshooting purposes
sysid = record.getSysid();
// Added to double check what Hibernate was doing
try {
java.sql.Connection conn = datasource.getConnection();
Statement stmt = conn.createStatement();
ResultSet rs = stmt.executeQuery("select * from Record where sysid =" + Long.toString(sysid));
rs.next();
log.info("Proc JDBC query returned: " + rs.getLong("SYSID") + " " + rs.getString("customer_id"));
rs.close();
stmt.close();
conn.close();
} catch (Exception e) {
log.error(e.getMessage());
}
InputRecord tempRecord = null;
// loop until we find the record. Usually finds it on the first attempt
for (int i = 0; i < 100 && tempRecord == null; i++){
tempRecord = manager.find(Record.class, record.getSysid());
log.info("RecordProcessor record found " + i + " : " + tempRecord);
}
}
}
InputRecordCode:
@Entity
@Table(name = "INPUT_RECORD")
@SequenceGenerator(name = "INPUT_REC_SEQUENCE", sequenceName = "input_rec_seq", allocationSize=1)
public class InputRecord implements Serializable {
@Id
@GeneratedValue(strategy=GenerationType.SEQUENCE, generator="INPUT_REC_SEQUENCE")
private long sysid;
@OneToMany(mappedBy="inputRecId", cascade=CascadeType.ALL, fetch=FetchType.EAGER)
@org.hibernate.annotations.Cascade(org.hibernate.annotations.CascadeType.DELETE_ORPHAN)
private Collection<InputRecAttr> _attributes = new HashSet<InputRecAttr>();
...
}
my-ds.xmlCode:
<datasources>
<local-tx-datasource>
<jndi-name>DefaultDS</jndi-name>
<connection-url>jdbc:oracle:thin:@foo:1521:bar</connection-url>
<driver-class>oracle.jdbc.OracleDriver</driver-class>
<user-name>dbuser</user-name>
<password>password</password>
<metadata>
<type-mapping>Oracle9i</type-mapping>
</metadata>
<min-pool-size>100</min-pool-size>
<max-pool-size>200</max-pool-size>
<query-timeout>30</query-timeout>
<exception-sorter-class-name>org.jboss.resource.adapter.jdbc.vendor.OracleExceptionSorter</exception-sorter-class-name>
<new-connection-sql>select sysdate from dual</new-connection-sql>
<check-valid-connection-sql>select sysdate from dual</check-valid-connection-sql>
</local-tx-datasource>
</datasources>
Code:
<persistence>
<persistence-unit name="arch-persist">
<provider>org.hibernate.ejb.HibernatePersistence</provider>
<jta-data-source>java:/DefaultDS</jta-data-source>
<class>entities.InputRecord</class>
<class>entities.InputRecAttr</class>
<properties>
<!-- Uncomment to remake all DB tables referenced by Entity Beans
Will remove all data currently in tables
<property name="hibernate.hbm2ddl.auto"
value="create"/> -->
<property name="hibernate.dialect" value="org.hibernate.dialect.Oracle9iDialect"/>
</properties>
</persistence-unit>
</persistence>
Oracle 10.2.0.0
Debug level Hibernate log excerpt:[org.hibernate.impl.SessionImpl] opened session at timestamp: 4962645714690048
[org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
[org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
[org.hibernate.ejb.AbstractEntityManagerImpl] Looking for a JTA transaction to join
[org.hibernate.ejb.AbstractEntityManagerImpl] Transaction already joined
[org.hibernate.loader.Loader] loading entity: [InputRecord#61245]
[org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
[org.hibernate.jdbc.ConnectionManager] opening JDBC connection
[org.hibernate.SQL] select inputrecor0_.sysid as sysid7_1_, inputrecor0_.alert_name as alert2_7_1_, inputrecor0_.cu
stomer_id as customer3_7_1_, inputrecor0_.last_webget as last4_7_1_, inputrecor0_.next_module as next5_7_1_, inputrecor0_.status as status7_1_, a
ttribute1_.INPUT_REC_SYSID as INPUT1_3_, attribute1_.name as name3_, attribute1_.INPUT_REC_SYSID as INPUT1_8_0_, attribute1_.name as name8_0_, at
tribute1_.value as value8_0_ from INPUT_RECORD inputrecor0_, INPUT_RECORD_ATTR attribute1_ where inputrecor0_.sysid=attribute1_.INPUT_REC_SYSID(+
) and inputrecor0_.sysid=?
[org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
[org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
[org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
[org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
[org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open
ResultSets: 0, globally: 0)]
[org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
[org.hibernate.loader.Loader] done entity load
[infrastructure.transactional]
RecordProcessor record found 0 : null[org.hibernate.loader.Loader] loading entity: [entities.InputRecord#61245]
[org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
[org.hibernate.jdbc.ConnectionManager] opening JDBC connection
[org.hibernate.SQL] select inputrecor0_.sysid as sysid7_1_, inputrecor0_.alert_name as alert2_7_1_, inputrecor0_.cu
stomer_id as customer3_7_1_, inputrecor0_.last_webget as last4_7_1_, inputrecor0_.next_module as next5_7_1_, inputrecor0_.status as status7_1_, a
ttribute1_.INPUT_REC_SYSID as INPUT1_3_, attribute1_.name as name3_, attribute1_.INPUT_REC_SYSID as INPUT1_8_0_, attribute1_.name as name8_0_, at
tribute1_.value as value8_0_ from INPUT_RECORD inputrecor0_, INPUT_RECORD_ATTR attribute1_ where inputrecor0_.sysid=attribute1_.INPUT_REC_SYSID(+
) and inputrecor0_.sysid=?
[org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
[org.hibernate.loader.Loader] result row: EntityKey[entities.InputRecAttr#component[inputRecI
d,name]{name=FileAddress, inputRecId=61245}], EntityKey[entities.InputRecord#61245]
[org.hibernate.loader.Loader] found row of collection: [entities.InputRecord._attributes#6124
5]
[org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
[org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
[org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
[org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open
ResultSets: 0, globally: 0)]
[org.hibernate.engine.TwoPhaseLoad] resolving associations for [entities.InputRecAttr#compone
nt[inputRecId,name]{name=FileAddress, inputRecId=61245}]
[org.hibernate.engine.TwoPhaseLoad] done materializing entity [entities.InputRecAttr#componen
t[inputRecId,name]{name=FileAddress, inputRecId=61245}]
[org.hibernate.engine.TwoPhaseLoad] resolving associations for [entities.InputRecord#61245]
[org.hibernate.engine.TwoPhaseLoad] done materializing entity [entities.InputRecord#61245]
[org.hibernate.engine.loading.CollectionLoadContext] 1 collections were found in result set for role: entities.InputRecord._attributes
[org.hibernate.engine.loading.CollectionLoadContext] collection fully initialized: [entities.InputRecord._attributes#61245]
[org.hibernate.engine.loading.CollectionLoadContext] 1 collections initialized for role: entities.InputRecord._attributes
[org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
[org.hibernate.loader.Loader] done entity load
[infrastructure.transactional]
RecordProcessor record found 1 : 61245 Status: NEW NextModule:
TestAlertInput
InputRecId: 61245 Name: FileAddress Value: 0D740B3F [/code][/i]
Login
FAQ
Search