We are getting an intermittent staleObjectException when switching WebLogic container threads. We are using the following patterns:
1. Session-per-request
2. ThreadLocal Pattern
3. Optimistic concurrency using version numbers
At the beginning of each request we load() a Vehicle object and update it according to the data submitted in the request. Most of the time this works fine, but occasionally, when consequent requests are handled by different threads we get a StaleObjectException. Our analysis of the logs below shows that an exception does not happen every time the threads are switched and that a new Hibernate session is used in each and every request (see table below).
Code:
Thread HibernateSession Old Version No / New Version No
13 83bfbc 11 / 12
14 2884d8 12 / 13
14 302af7 13 / 14
13 6490a9 14 / 15
13 6a47cf 15 / 16
13 52bdde 16 / 17
14 8439cb 17 / 18
14 6211f5 18 / 19
13 3aafe6 18 / 19
-->Fails with staleObjectException
At the beginning of reach transaction there is a SELECT issued. But this is not done at the last transaction when there is a change in WL threads used. Therefore a stale value cached (in Hibernate Session?) is used. Any idea why Hibernate would NOT issue a SELECT?
Hibernate version: 2.1.7 Mapping documents:
Code:
<class name="com.idiominc.gm.datamodel.Vehicle" table="VEHICLE" >
<meta attribute="class-description">
Represents a vehicle from the gm database.
</meta>
<id name="sysKey" type="int" column="VEHICLE_SYSKEY">
<meta attribute="scope-set">public</meta>
<generator class="native"/>
</id>
<version name="version" column="VERSION"/>
<property name="createdBy" type="string" column="CREATE_USER" not-null="true" />
<property name="createdDate" type="date" column="CREATE_DATE" not-null="true" />
<property name="modifiedBy" type="string" column="MODIFIED_USER" not-null="true" />
<property name="modifiedDate" type="date" column="MODIFIED_DATE" not-null="true" />
<property name="midYearInd" type="string" column="MID_YEAR_IND" not-null="true" />
<property name="sorpDate" type="date" column="SORP_DATE" not-null="true" />
<many-to-one name="vehicleType" class="com.idiominc.gm.datamodel.VehicleType" column="VEHICLE_TYPE_SYSKEY" unique="true"/>
<many-to-one name="vehicleLine" class="com.idiominc.gm.datamodel.VehicleLine" column="VEHICLE_LINE_SYSKEY" unique="true"/>
<many-to-one name="region" class="com.idiominc.gm.datamodel.Region" column="REGION_SYSKEY" unique="true"/>
<many-to-one name="modelYear" class="com.idiominc.gm.datamodel.ModelYear" column="MODEL_YEAR_SYSKEY" unique="true"/>
<many-to-one name="model" class="com.idiominc.gm.datamodel.Model" column="MODEL_SYSKEY" unique="true"/>
<many-to-one name="manufacturer" class="com.idiominc.gm.datamodel.Manufacturer" column="MANUF_SYSKEY" unique="true"/>
<many-to-one name="make" class="com.idiominc.gm.datamodel.Make" column="MAKE_SYSKEY" unique="true"/>
<many-to-one name="countryOfSale" class="com.idiominc.gm.datamodel.Country" column="COUNTRY_SYSKEY" unique="true"/>
<set name="vehicleCountryOfOrigin" table="VEHICLE_COUNTRY_OF_ORIGIN" inverse="false" lazy="true">
<meta attribute="field-description">Maps a vehicle to More than one country</meta>
<key column="VEHICLE_SYSKEY"/>
<many-to-many column="COUNTRY_SYSKEY" class="com.idiominc.gm.datamodel.Country" />
</set>
<set name="vehicleProductionOption" table="VEHICLE_PRODUCTION_OPTION" inverse="false" lazy="true">
<meta attribute="field-description">Maps a vehicle to More than one Production Options that can be associated</meta>
<key column="VEHICLE_SYSKEY"/>
<many-to-many column="PROD_OPT_SYSKEY" class="com.idiominc.gm.datamodel.ProdOption" />
</set>
</class>
Code between sessionFactory.openSession() and session.close():
Code:
/**
*This is the code that is run in the action class
*/
HibernateUtil.beginTransaction();
vehicleObj = (Vehicle)vehicleManager.findByPrimaryKey(vehicleContextForm.getSysKey());
s_log.debug("******** -->"+Thread.currentThread().getName().toString());
/** Updating set of properties of vehicleObj **/
vehicleManager.update(vehicleObj);
s_log.debug("VehicleActionSaveProdOptions:AfterUpdate:vehicleObj:["+vehicleObj.toString()+"]");
HibernateUtil.commitTransaction();
/**
* method to fetch object
*/
public DisplayableDao findByPrimaryKey(Integer primaryKey) throws GmObjectNotFoundException,
GmDataAccessException {
try {
Session session = HibernateUtil.getSession();
Object rez = session.get(getManagedDaoClass(), primaryKey);
if (null == rez) {
throw new GmObjectNotFoundException(getManagedDaoClass().getName(), primaryKey.toString());
}
return (DisplayableDao) rez;
} catch (HibernateException he) {
String errMsg = "Problem finding " + getManagedDaoClass() + " by PK = [" + primaryKey + "]";
s_log.error(errMsg, he);
throw new GmDataAccessException (errMsg, he);
}
}
/**
*This is the code that we are using for Transaction Management from Hiberante in Action + added session.clear and session.close to implement session-per-request
*/
public class HibernateUtil {
// statics
private static SessionFactory s_sessionFactory = null;
private static final ThreadLocal s_threadSession = new ThreadLocal();
private static final ThreadLocal s_threadTransaction = new ThreadLocal();
private static final ThreadLocal s_threadLanguageId = new ThreadLocal();
// logging support
private static final Logger s_log = Logger.getLogger(GmConstants.log_GM_COMMON);
static {
try {
Configuration cfg = new Configuration();
s_sessionFactory = (new Configuration()).configure().buildSessionFactory();
} catch (HibernateException he) {
s_log.error ("Problem initializing Hibernate", he);
he.printStackTrace();
}
}
public static Session getSession () throws GmInfrastructureException {
Session s = (Session) s_threadSession.get();
// open a new session is there is not one associated with this thread so far
try {
if (null == s) {
s = s_sessionFactory.openSession();
s_threadSession.set(s);
s_log.debug("* gotSess " + getState());
}
} catch (HibernateException he) {
s_log.error("Failed to get Session", he);
throw new GmInfrastructureException (he);
}
return s;
}
public static void closeSession () throws GmInfrastructureException {
Session s = (Session) s_threadSession.get();
s_threadSession.set(null);
try {
if ((null != s) && (s.isOpen())){
s.clear();
s.close();
s_log.debug("* closedSess " + getState());
}
} catch (HibernateException he) {
s_log.error ("Failed to close session", he);
throw new GmInfrastructureException (he);
}
}
public static void beginTransaction () throws GmInfrastructureException {
Transaction tx = (Transaction) s_threadTransaction.get();
try {
if (null == tx) {
tx = getSession().beginTransaction();
s_threadTransaction.set(tx);
s_log.debug("* began " + getState());
}
} catch (HibernateException he) {
s_log.error ("Failed to beging transaction", he);
throw new GmInfrastructureException (he);
}
}
public static void commitTransaction () throws GmInfrastructureException, GmAppLogicErrorException {
System.out.println ("--- commiting tx ---");
Transaction tx = (Transaction) s_threadTransaction.get();
try {
System.out.println ("--- tx " + tx + " ----");
if ((null != tx) && (!tx.wasCommitted()) && (!tx.wasRolledBack())) {
tx.commit();
closeSession();
}
s_threadTransaction.set(null);
s_threadLanguageId.set(null);
s_log.debug("* comitted " + getState());
} catch (ConstraintViolationException ce) {
rollbackTransaction();
String msg = "Constraint Violation "+ ce.getConstraintName() +" on transaction commit "+ce.getMessage();
s_log.error ("Constraint Violation on transaction commit", ce);
throw new GmAppLogicErrorException (msg,ce);
} catch (HibernateException he) {
rollbackTransaction();
s_log.error ("Failed to commit transaction", he);
throw new GmInfrastructureException (he);
}
}
static String getState() throws HibernateException {
Session s = (Session) s_threadSession.get();
Transaction t = (Transaction) s_threadTransaction.get();
Integer l = (Integer) s_threadLanguageId.get();
String rez = "Context: Sess=[" + s +" ]Thread ["+Thread.currentThread().getName()+"]";
if (null != s) rez += " is " + (s.isOpen() ? "open" : "closed");
rez += ", tx=" + t;
if (null != t) rez += " " +
(t.wasCommitted() ? "was commited" : (t.wasRolledBack() ? "was rolledBack" : "isActive"));
rez += ", lang=" + l + ".";
return rez;
}
}
Full Stack Trace
Code:
17:20:01,628 WARN StaleObjectStateException:27 - An operation failed due to stale data
net.sf.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) for com.idiominc.gm.datamodel.Vehicle instance with identifier: 108
at net.sf.hibernate.persister.AbstractEntityPersister.check(ILjava.io.Serializable;)V(AbstractEntityPersister.java:513)
at net.sf.hibernate.persister.EntityPersister.update(Ljava.io.Serializable;[Ljava.lang.Object;[Ljava.lang.Object;[ZLjava.lang.Object;Ljava.lang.Object;Ljava.lang.String;Lnet.sf.hibernate.engine.SessionImplementor;)V(EntityPersister.java:664)
at net.sf.hibernate.persister.EntityPersister.update(Ljava.io.Serializable;[Ljava.lang.Object;[I[Ljava.lang.Object;Ljava.lang.Object;Ljava.lang.Object;Lnet.sf.hibernate.engine.SessionImplementor;)V(EntityPersister.java:621)
at net.sf.hibernate.impl.ScheduledUpdate.execute()V(ScheduledUpdate.java:52)
at net.sf.hibernate.impl.SessionImpl.execute(Lnet.sf.hibernate.impl.SessionImpl$Executable;)V(SessionImpl.java:2449)
at net.sf.hibernate.impl.SessionImpl.executeAll(Ljava.util.List;)V(SessionImpl.java:2435)
at net.sf.hibernate.impl.SessionImpl.execute()V(SessionImpl.java:2393)
at net.sf.hibernate.impl.SessionImpl.flush()V(SessionImpl.java:2261)
at net.sf.hibernate.transaction.JDBCTransaction.commit()V(JDBCTransaction.java:61)
at com.idiominc.gm.util.HibernateUtil.commitTransaction()V(HibernateUtil.java:98)
at com.idiominc.gm.struts.action.vehicle.VehicleActionSaveProdOptions.executePerform(Lorg.apache.struts.action.ActionMapping;Lorg.apache.struts.action.ActionForm;Ljavax.servlet.http.HttpServletRequest;Ljavax.servlet.http.HttpServletResponse;)Lorg.apache.struts.action.ActionForward;(VehicleActionSaveProdOptions.java:82)
at com.idiominc.gm.struts.action.GMBaseAction.execute(Lorg.apache.struts.action.ActionMapping;Lorg.apache.struts.action.ActionForm;Ljavax.servlet.http.HttpServletRequest;Ljavax.servlet.http.HttpServletResponse;)Lorg.apache.struts.action.ActionForward;(GMBaseAction.java:36)
at org.apache.struts.action.RequestProcessor.processActionPerform(Ljavax.servlet.http.HttpServletRequest;Ljavax.servlet.http.HttpServletResponse;Lorg.apache.struts.action.Action;Lorg.apache.struts.action.ActionForm;Lorg.apache.struts.action.ActionMapping;)Lorg.apache.struts.action.ActionForward;(RequestProcessor.java:419)
at org.apache.struts.action.RequestProcessor.process(Ljavax.servlet.http.HttpServletRequest;Ljavax.servlet.http.HttpServletResponse;)V(RequestProcessor.java:224)
at org.apache.struts.action.ActionServlet.process(Ljavax.servlet.http.HttpServletRequest;Ljavax.servlet.http.HttpServletResponse;)V(ActionServlet.java:1194)
at org.apache.struts.action.ActionServlet.doPost(Ljavax.servlet.http.HttpServletRequest;Ljavax.servlet.http.HttpServletResponse;)V(ActionServlet.java:432)
at javax.servlet.http.HttpServlet.service(Ljavax.servlet.http.HttpServletRequest;Ljavax.servlet.http.HttpServletResponse;)V(HttpServlet.java:760)
at javax.servlet.http.HttpServlet.service(Ljavax.servlet.ServletRequest;Ljavax.servlet.ServletResponse;)V(HttpServlet.java:853)
at weblogic.servlet.internal.ServletStubImpl$ServletInvocationAction.run()Ljava.lang.Object;(ServletStubImpl.java:1006)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(Ljavax.servlet.ServletRequest;Ljavax.servlet.ServletResponse;Lweblogic.servlet.internal.FilterChainImpl;)V(ServletStubImpl.java:419)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(Ljavax.servlet.ServletRequest;Ljavax.servlet.ServletResponse;)V(ServletStubImpl.java:315)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run()Ljava.lang.Object;(WebAppServletContext.java:6718)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(Lweblogic.security.subject.AbstractSubject;Ljava.security.PrivilegedAction;)Ljava.lang.Object;(AuthenticatedSubject.java:321)
at weblogic.security.service.SecurityManager.runAs(Lweblogic.security.acl.internal.AuthenticatedSubject;Lweblogic.security.acl.internal.AuthenticatedSubject;Ljava.security.PrivilegedAction;)Ljava.lang.Object;(SecurityManager.java:121)
at weblogic.servlet.internal.WebAppServletContext.invokeServlet(Lweblogic.servlet.internal.ServletRequestImpl;Lweblogic.servlet.internal.ServletResponseImpl;)V(WebAppServletContext.java:3764)
at weblogic.servlet.internal.ServletRequestImpl.execute(Lweblogic.kernel.ExecuteThread;)V(ServletRequestImpl.java:2644)
at weblogic.kernel.ExecuteThread.execute(Lweblogic.kernel.ExecuteRequest;)V(ExecuteThread.java:219)
at weblogic.kernel.ExecuteThread.run()V(ExecuteThread.java:178)
at java.lang.Thread.startThreadFromVM(Ljava.lang.Thread;)V(Unknown Source)
Name and version of the database you are using:
Oracle 9.2
The generated SQL (show_sql=true):
Code:
17:16:50,922 DEBUG gm:76 - * began Context: Sess=[net.sf.hibernate.impl.SessionImpl@83bfbc ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'] is open, tx=net.sf.hibernate.transaction.JDBCTransaction@884ca9 isActive, lang=null.
17:16:50,922 DEBUG gm:41 - ******** -->ExecuteThread: '13' for queue: 'weblogic.kernel.Default'
17:16:50,969 DEBUG SQL:230 - update VEHICLE set VERSION=?, CREATE_USER=?, CREATE_DATE=?, MODIFIED_USER=?, MODIFIED_DATE=?, MID_YEAR_IND=?, SORP_DATE=?, VEHICLE_TYPE_SYSKEY=?, VEHICLE_LINE_SYSKEY=?, REGION_SYSKEY=?, MODEL_YEAR_SYSKEY=?, MODEL_SYSKEY=?, MANUF_SYSKEY=?, MAKE_SYSKEY=?, COUNTRY_SYSKEY=? where VEHICLE_SYSKEY=? and VERSION=?
17:16:50,985 DEBUG IntegerType:46 - binding '12' to parameter: 1
17:16:50,985 DEBUG StringType:46 - binding 'unknown' to parameter: 2
17:16:50,985 DEBUG DateType:46 - binding '22 June 2005' to parameter: 3
17:16:51,000 DEBUG StringType:46 - binding 'unknown' to parameter: 4
17:16:51,000 DEBUG DateType:46 - binding '30 June 2005' to parameter: 5
17:16:51,000 DEBUG StringType:46 - binding 'Y' to parameter: 6
17:16:51,000 DEBUG DateType:46 - binding '01 June 2006' to parameter: 7
17:16:51,000 DEBUG IntegerType:41 - binding null to parameter: 8
17:16:51,000 DEBUG IntegerType:41 - binding null to parameter: 9
17:16:51,016 DEBUG IntegerType:41 - binding null to parameter: 10
17:16:51,016 DEBUG IntegerType:46 - binding '1' to parameter: 11
17:16:51,016 DEBUG IntegerType:46 - binding '4' to parameter: 12
17:16:51,016 DEBUG IntegerType:41 - binding null to parameter: 13
17:16:51,016 DEBUG IntegerType:46 - binding '10' to parameter: 14
17:16:51,016 DEBUG IntegerType:41 - binding null to parameter: 15
17:16:51,016 DEBUG IntegerType:46 - binding '108' to parameter: 16
17:16:51,032 DEBUG IntegerType:46 - binding '11' to parameter: 17
17:16:51,032 DEBUG gm:61 - * closedSess Context: Sess=[null ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'], tx=net.sf.hibernate.transaction.JDBCTransaction@884ca9 was commited, lang=null.
17:16:51,032 DEBUG gm:103 - * comitted Context: Sess=[null ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'], tx=null, lang=null.
17:17:50,064 DEBUG gm:76 - * began Context: Sess=[net.sf.hibernate.impl.SessionImpl@2884d8 ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'] is open, tx=net.sf.hibernate.transaction.JDBCTransaction@20ba13 isActive, lang=null.
17:17:50,064 DEBUG gm:41 - ******** -->ExecuteThread: '14' for queue: 'weblogic.kernel.Default'
17:17:50,064 DEBUG SQL:230 - update VEHICLE set VERSION=?, CREATE_USER=?, CREATE_DATE=?, MODIFIED_USER=?, MODIFIED_DATE=?, MID_YEAR_IND=?, SORP_DATE=?, VEHICLE_TYPE_SYSKEY=?, VEHICLE_LINE_SYSKEY=?, REGION_SYSKEY=?, MODEL_YEAR_SYSKEY=?, MODEL_SYSKEY=?, MANUF_SYSKEY=?, MAKE_SYSKEY=?, COUNTRY_SYSKEY=? where VEHICLE_SYSKEY=? and VERSION=?
17:17:50,064 DEBUG IntegerType:46 - binding '13' to parameter: 1
17:17:50,064 DEBUG StringType:46 - binding 'unknown' to parameter: 2
17:17:50,064 DEBUG DateType:46 - binding '22 June 2005' to parameter: 3
17:17:50,064 DEBUG StringType:46 - binding 'unknown' to parameter: 4
17:17:50,064 DEBUG DateType:46 - binding '30 June 2005' to parameter: 5
17:17:50,064 DEBUG StringType:46 - binding 'Y' to parameter: 6
17:17:50,064 DEBUG DateType:46 - binding '01 April 2004' to parameter: 7
17:17:50,064 DEBUG IntegerType:41 - binding null to parameter: 8
17:17:50,064 DEBUG IntegerType:41 - binding null to parameter: 9
17:17:50,064 DEBUG IntegerType:41 - binding null to parameter: 10
17:17:50,079 DEBUG IntegerType:46 - binding '1' to parameter: 11
17:17:50,079 DEBUG IntegerType:46 - binding '4' to parameter: 12
17:17:50,079 DEBUG IntegerType:41 - binding null to parameter: 13
17:17:50,079 DEBUG IntegerType:46 - binding '10' to parameter: 14
17:17:50,079 DEBUG IntegerType:41 - binding null to parameter: 15
17:17:50,079 DEBUG IntegerType:46 - binding '108' to parameter: 16
17:17:50,079 DEBUG IntegerType:46 - binding '12' to parameter: 17
17:17:50,079 DEBUG gm:61 - * closedSess Context: Sess=[null ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'], tx=net.sf.hibernate.transaction.JDBCTransaction@20ba13 was commited, lang=null.
17:17:50,079 DEBUG gm:103 - * comitted Context: Sess=[null ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'], tx=null, lang=null.
17:17:56,548 DEBUG gm:76 - * began Context: Sess=[net.sf.hibernate.impl.SessionImpl@302af7 ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'] is open, tx=net.sf.hibernate.transaction.JDBCTransaction@91692f isActive, lang=null.
17:17:56,548 DEBUG gm:41 - ******** -->ExecuteThread: '14' for queue: 'weblogic.kernel.Default'
17:17:56,564 DEBUG IntegerType:46 - binding '14' to parameter: 1
17:17:56,564 DEBUG StringType:46 - binding 'unknown' to parameter: 2
17:17:56,564 DEBUG DateType:46 - binding '22 June 2005' to parameter: 3
17:17:56,564 DEBUG StringType:46 - binding 'unknown' to parameter: 4
17:17:56,564 DEBUG DateType:46 - binding '30 June 2005' to parameter: 5
17:17:56,564 DEBUG StringType:46 - binding 'Y' to parameter: 6
17:17:56,564 DEBUG DateType:46 - binding '01 February 2002' to parameter: 7
17:17:56,564 DEBUG IntegerType:41 - binding null to parameter: 8
17:17:56,564 DEBUG IntegerType:41 - binding null to parameter: 9
17:17:56,564 DEBUG IntegerType:41 - binding null to parameter: 10
17:17:56,564 DEBUG IntegerType:46 - binding '1' to parameter: 11
17:17:56,564 DEBUG IntegerType:46 - binding '4' to parameter: 12
17:17:56,564 DEBUG IntegerType:41 - binding null to parameter: 13
17:17:56,564 DEBUG IntegerType:46 - binding '10' to parameter: 14
17:17:56,564 DEBUG IntegerType:41 - binding null to parameter: 15
17:17:56,564 DEBUG IntegerType:46 - binding '108' to parameter: 16
17:17:56,564 DEBUG IntegerType:46 - binding '13' to parameter: 17
17:17:56,579 DEBUG gm:61 - * closedSess Context: Sess=[null ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'], tx=net.sf.hibernate.transaction.JDBCTransaction@91692f was commited, lang=null.
17:17:56,579 DEBUG gm:103 - * comitted Context: Sess=[null ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'], tx=null, lang=null.
17:18:18,767 DEBUG gm:76 - * began Context: Sess=[net.sf.hibernate.impl.SessionImpl@6490a9 ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'] is open, tx=net.sf.hibernate.transaction.JDBCTransaction@64c421 isActive, lang=null.
17:18:18,798 DEBUG gm:41 - ******** -->ExecuteThread: '13' for queue: 'weblogic.kernel.Default'
17:18:18,892 DEBUG SQL:230 - update VEHICLE set VERSION=?, CREATE_USER=?, CREATE_DATE=?, MODIFIED_USER=?, MODIFIED_DATE=?, MID_YEAR_IND=?, SORP_DATE=?, VEHICLE_TYPE_SYSKEY=?, VEHICLE_LINE_SYSKEY=?, REGION_SYSKEY=?, MODEL_YEAR_SYSKEY=?, MODEL_SYSKEY=?, MANUF_SYSKEY=?, MAKE_SYSKEY=?, COUNTRY_SYSKEY=? where VEHICLE_SYSKEY=? and VERSION=?
17:18:18,892 DEBUG IntegerType:46 - binding '15' to parameter: 1
17:18:18,892 DEBUG StringType:46 - binding 'unknown' to parameter: 2
17:18:18,892 DEBUG DateType:46 - binding '22 June 2005' to parameter: 3
17:18:18,892 DEBUG StringType:46 - binding 'unknown' to parameter: 4
17:18:18,892 DEBUG DateType:46 - binding '30 June 2005' to parameter: 5
17:18:18,892 DEBUG StringType:46 - binding 'Y' to parameter: 6
17:18:18,892 DEBUG DateType:46 - binding '01 July 2007' to parameter: 7
17:18:18,892 DEBUG IntegerType:41 - binding null to parameter: 8
17:18:18,892 DEBUG IntegerType:41 - binding null to parameter: 9
17:18:18,892 DEBUG IntegerType:41 - binding null to parameter: 10
17:18:18,892 DEBUG IntegerType:46 - binding '1' to parameter: 11
17:18:18,892 DEBUG IntegerType:46 - binding '4' to parameter: 12
17:18:18,892 DEBUG IntegerType:41 - binding null to parameter: 13
17:18:18,892 DEBUG IntegerType:46 - binding '10' to parameter: 14
17:18:18,892 DEBUG IntegerType:41 - binding null to parameter: 15
17:18:18,892 DEBUG IntegerType:46 - binding '108' to parameter: 16
17:18:18,892 DEBUG IntegerType:46 - binding '14' to parameter: 17
17:18:18,908 DEBUG gm:61 - * closedSess Context: Sess=[null ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'], tx=net.sf.hibernate.transaction.JDBCTransaction@64c421 was commited, lang=null.
17:18:18,908 DEBUG gm:103 - * comitted Context: Sess=[null ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'], tx=null, lang=null.
17:19:09,987 DEBUG gm:76 - * began Context: Sess=[net.sf.hibernate.impl.SessionImpl@6a47cf ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'] is open, tx=net.sf.hibernate.transaction.JDBCTransaction@4720f6 isActive, lang=null.
17:19:09,987 DEBUG gm:41 - ******** -->ExecuteThread: '13' for queue: 'weblogic.kernel.Default'
17:19:09,987 DEBUG SQL:230 - update VEHICLE set VERSION=?, CREATE_USER=?, CREATE_DATE=?, MODIFIED_USER=?, MODIFIED_DATE=?, MID_YEAR_IND=?, SORP_DATE=?, VEHICLE_TYPE_SYSKEY=?, VEHICLE_LINE_SYSKEY=?, REGION_SYSKEY=?, MODEL_YEAR_SYSKEY=?, MODEL_SYSKEY=?, MANUF_SYSKEY=?, MAKE_SYSKEY=?, COUNTRY_SYSKEY=? where VEHICLE_SYSKEY=? and VERSION=?
17:19:10,002 DEBUG IntegerType:46 - binding '16' to parameter: 1
17:19:10,002 DEBUG StringType:46 - binding 'unknown' to parameter: 2
17:19:10,002 DEBUG DateType:46 - binding '22 June 2005' to parameter: 3
17:19:10,002 DEBUG StringType:46 - binding 'unknown' to parameter: 4
17:19:10,002 DEBUG DateType:46 - binding '30 June 2005' to parameter: 5
17:19:10,002 DEBUG StringType:46 - binding 'Y' to parameter: 6
17:19:10,002 DEBUG DateType:46 - binding '01 February 2002' to parameter: 7
17:19:10,002 DEBUG IntegerType:41 - binding null to parameter: 8
17:19:10,002 DEBUG IntegerType:41 - binding null to parameter: 9
17:19:10,002 DEBUG IntegerType:41 - binding null to parameter: 10
17:19:10,002 DEBUG IntegerType:46 - binding '1' to parameter: 11
17:19:10,002 DEBUG IntegerType:46 - binding '4' to parameter: 12
17:19:10,002 DEBUG IntegerType:41 - binding null to parameter: 13
17:19:10,002 DEBUG IntegerType:46 - binding '10' to parameter: 14
17:19:10,002 DEBUG IntegerType:41 - binding null to parameter: 15
17:19:10,002 DEBUG IntegerType:46 - binding '108' to parameter: 16
17:19:10,002 DEBUG IntegerType:46 - binding '15' to parameter: 17
17:19:10,002 DEBUG gm:61 - * closedSess Context: Sess=[null ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'], tx=net.sf.hibernate.transaction.JDBCTransaction@4720f6 was commited, lang=null.
17:19:10,002 DEBUG gm:103 - * comitted Context: Sess=[null ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'], tx=null, lang=null.
17:19:17,518 DEBUG gm:76 - * began Context: Sess=[net.sf.hibernate.impl.SessionImpl@52bdde ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'] is open, tx=net.sf.hibernate.transaction.JDBCTransaction@33ae4a isActive, lang=null.
17:19:17,518 DEBUG gm:41 - ******** -->ExecuteThread: '13' for queue: 'weblogic.kernel.Default'
17:19:17,533 DEBUG SQL:230 - update VEHICLE set VERSION=?, CREATE_USER=?, CREATE_DATE=?, MODIFIED_USER=?, MODIFIED_DATE=?, MID_YEAR_IND=?, SORP_DATE=?, VEHICLE_TYPE_SYSKEY=?, VEHICLE_LINE_SYSKEY=?, REGION_SYSKEY=?, MODEL_YEAR_SYSKEY=?, MODEL_SYSKEY=?, MANUF_SYSKEY=?, MAKE_SYSKEY=?, COUNTRY_SYSKEY=? where VEHICLE_SYSKEY=? and VERSION=?
17:19:17,533 DEBUG IntegerType:46 - binding '17' to parameter: 1
17:19:17,533 DEBUG StringType:46 - binding 'unknown' to parameter: 2
17:19:17,533 DEBUG DateType:46 - binding '22 June 2005' to parameter: 3
17:19:17,533 DEBUG StringType:46 - binding 'unknown' to parameter: 4
17:19:17,533 DEBUG DateType:46 - binding '30 June 2005' to parameter: 5
17:19:17,533 DEBUG StringType:46 - binding 'Y' to parameter: 6
17:19:17,533 DEBUG DateType:46 - binding '01 November 2011' to parameter: 7
17:19:17,533 DEBUG IntegerType:41 - binding null to parameter: 8
17:19:17,533 DEBUG IntegerType:41 - binding null to parameter: 9
17:19:17,533 DEBUG IntegerType:41 - binding null to parameter: 10
17:19:17,533 DEBUG IntegerType:46 - binding '1' to parameter: 11
17:19:17,533 DEBUG IntegerType:46 - binding '4' to parameter: 12
17:19:17,533 DEBUG IntegerType:41 - binding null to parameter: 13
17:19:17,533 DEBUG IntegerType:46 - binding '10' to parameter: 14
17:19:17,533 DEBUG IntegerType:41 - binding null to parameter: 15
17:19:17,533 DEBUG IntegerType:46 - binding '108' to parameter: 16
17:19:17,533 DEBUG IntegerType:46 - binding '16' to parameter: 17
17:19:17,549 DEBUG gm:61 - * closedSess Context: Sess=[null ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'], tx=net.sf.hibernate.transaction.JDBCTransaction@33ae4a was commited, lang=null.
17:19:17,549 DEBUG gm:103 - * comitted Context: Sess=[null ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'], tx=null, lang=null.
17:19:31,393 DEBUG gm:76 - * began Context: Sess=[net.sf.hibernate.impl.SessionImpl@8439cb ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'] is open, tx=net.sf.hibernate.transaction.JDBCTransaction@617ac1 isActive, lang=null.
17:19:31,393 DEBUG gm:41 - ******** -->ExecuteThread: '14' for queue: 'weblogic.kernel.Default'
17:19:31,409 DEBUG SQL:230 - update VEHICLE set VERSION=?, CREATE_USER=?, CREATE_DATE=?, MODIFIED_USER=?, MODIFIED_DATE=?, MID_YEAR_IND=?, SORP_DATE=?, VEHICLE_TYPE_SYSKEY=?, VEHICLE_LINE_SYSKEY=?, REGION_SYSKEY=?, MODEL_YEAR_SYSKEY=?, MODEL_SYSKEY=?, MANUF_SYSKEY=?, MAKE_SYSKEY=?, COUNTRY_SYSKEY=? where VEHICLE_SYSKEY=? and VERSION=?
17:19:31,409 DEBUG IntegerType:46 - binding '18' to parameter: 1
17:19:31,409 DEBUG StringType:46 - binding 'unknown' to parameter: 2
17:19:31,409 DEBUG DateType:46 - binding '22 June 2005' to parameter: 3
17:19:31,409 DEBUG StringType:46 - binding 'unknown' to parameter: 4
17:19:31,409 DEBUG DateType:46 - binding '30 June 2005' to parameter: 5
17:19:31,409 DEBUG StringType:46 - binding 'Y' to parameter: 6
17:19:31,409 DEBUG DateType:46 - binding '01 April 2004' to parameter: 7
17:19:31,409 DEBUG IntegerType:41 - binding null to parameter: 8
17:19:31,409 DEBUG IntegerType:41 - binding null to parameter: 9
17:19:31,409 DEBUG IntegerType:41 - binding null to parameter: 10
17:19:31,409 DEBUG IntegerType:46 - binding '1' to parameter: 11
17:19:31,409 DEBUG IntegerType:46 - binding '4' to parameter: 12
17:19:31,409 DEBUG IntegerType:41 - binding null to parameter: 13
17:19:31,409 DEBUG IntegerType:46 - binding '10' to parameter: 14
17:19:31,409 DEBUG IntegerType:41 - binding null to parameter: 15
17:19:31,409 DEBUG IntegerType:46 - binding '108' to parameter: 16
17:19:31,409 DEBUG IntegerType:46 - binding '17' to parameter: 17
17:19:31,424 DEBUG gm:61 - * closedSess Context: Sess=[null ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'], tx=net.sf.hibernate.transaction.JDBCTransaction@617ac1 was commited, lang=null.
17:19:31,424 DEBUG gm:103 - * comitted Context: Sess=[null ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'], tx=null, lang=null.
17:19:46,018 DEBUG gm:76 - * began Context: Sess=[net.sf.hibernate.impl.SessionImpl@6211f5 ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'] is open, tx=net.sf.hibernate.transaction.JDBCTransaction@4584f4 isActive, lang=null.
17:19:46,018 DEBUG gm:41 - ******** -->ExecuteThread: '14' for queue: 'weblogic.kernel.Default'
17:19:46,034 DEBUG SQL:230 - update VEHICLE set VERSION=?, CREATE_USER=?, CREATE_DATE=?, MODIFIED_USER=?, MODIFIED_DATE=?, MID_YEAR_IND=?, SORP_DATE=?, VEHICLE_TYPE_SYSKEY=?, VEHICLE_LINE_SYSKEY=?, REGION_SYSKEY=?, MODEL_YEAR_SYSKEY=?, MODEL_SYSKEY=?, MANUF_SYSKEY=?, MAKE_SYSKEY=?, COUNTRY_SYSKEY=? where VEHICLE_SYSKEY=? and VERSION=?
17:19:46,034 DEBUG IntegerType:46 - binding '19' to parameter: 1
17:19:46,034 DEBUG StringType:46 - binding 'unknown' to parameter: 2
17:19:46,034 DEBUG DateType:46 - binding '22 June 2005' to parameter: 3
17:19:46,034 DEBUG StringType:46 - binding 'unknown' to parameter: 4
17:19:46,034 DEBUG DateType:46 - binding '30 June 2005' to parameter: 5
17:19:46,034 DEBUG StringType:46 - binding 'Y' to parameter: 6
17:19:46,034 DEBUG DateType:46 - binding '01 June 2006' to parameter: 7
17:19:46,034 DEBUG IntegerType:41 - binding null to parameter: 8
17:19:46,034 DEBUG IntegerType:41 - binding null to parameter: 9
17:19:46,034 DEBUG IntegerType:41 - binding null to parameter: 10
17:19:46,034 DEBUG IntegerType:46 - binding '1' to parameter: 11
17:19:46,034 DEBUG IntegerType:46 - binding '4' to parameter: 12
17:19:46,034 DEBUG IntegerType:41 - binding null to parameter: 13
17:19:46,034 DEBUG IntegerType:46 - binding '10' to parameter: 14
17:19:46,034 DEBUG IntegerType:41 - binding null to parameter: 15
17:19:46,034 DEBUG IntegerType:46 - binding '108' to parameter: 16
17:19:46,049 DEBUG IntegerType:46 - binding '18' to parameter: 17
17:19:46,049 DEBUG gm:61 - * closedSess Context: Sess=[null ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'], tx=net.sf.hibernate.transaction.JDBCTransaction@4584f4 was commited, lang=null.
17:19:46,049 DEBUG gm:103 - * comitted Context: Sess=[null ]Thread [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'], tx=null, lang=null.
17:20:01,612 DEBUG gm:76 - * began Context: Sess=[net.sf.hibernate.impl.SessionImpl@3aafe6 ]Thread [ExecuteThread: '13' for queue: 'weblogic.kernel.Default'] is open, tx=net.sf.hibernate.transaction.JDBCTransaction@1ea9af isActive, lang=null.
17:20:01,612 DEBUG gm:41 - ******** -->ExecuteThread: '13' for queue: 'weblogic.kernel.Default'
17:20:01,628 DEBUG SQL:230 - update VEHICLE set VERSION=?, CREATE_USER=?, CREATE_DATE=?, MODIFIED_USER=?, MODIFIED_DATE=?, MID_YEAR_IND=?, SORP_DATE=?, VEHICLE_TYPE_SYSKEY=?, VEHICLE_LINE_SYSKEY=?, REGION_SYSKEY=?, MODEL_YEAR_SYSKEY=?, MODEL_SYSKEY=?, MANUF_SYSKEY=?, MAKE_SYSKEY=?, COUNTRY_SYSKEY=? where VEHICLE_SYSKEY=? and VERSION=?
17:20:01,628 DEBUG IntegerType:46 - binding '19' to parameter: 1
17:20:01,628 DEBUG StringType:46 - binding 'unknown' to parameter: 2
17:20:01,628 DEBUG DateType:46 - binding '22 June 2005' to parameter: 3
17:20:01,628 DEBUG StringType:46 - binding 'unknown' to parameter: 4
17:20:01,628 DEBUG DateType:46 - binding '30 June 2005' to parameter: 5
17:20:01,628 DEBUG StringType:46 - binding 'Y' to parameter: 6
17:20:01,628 DEBUG DateType:46 - binding '01 May 2005' to parameter: 7
17:20:01,628 DEBUG IntegerType:41 - binding null to parameter: 8
17:20:01,628 DEBUG IntegerType:41 - binding null to parameter: 9
17:20:01,628 DEBUG IntegerType:41 - binding null to parameter: 10
17:20:01,628 DEBUG IntegerType:46 - binding '1' to parameter: 11
17:20:01,628 DEBUG IntegerType:46 - binding '4' to parameter: 12
17:20:01,628 DEBUG IntegerType:41 - binding null to parameter: 13
17:20:01,628 DEBUG IntegerType:46 - binding '10' to parameter: 14
17:20:01,628 DEBUG IntegerType:41 - binding null to parameter: 15
17:20:01,628 DEBUG IntegerType:46 - binding '108' to parameter: 16
17:20:01,628 DEBUG IntegerType:46 - binding '18' to parameter: 17
17:20:01,628 WARN StaleObjectStateException:27 - An operation failed due to stale data
net.sf.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) for com.idiominc.gm.datamodel.Vehicle instance with identifier: 108
Debug level Hibernate log excerpt: