I think this one is related to the blob we're saving, even though the Oracle error message doesn't says it's a date or number length problem. I've found some relevant information at
http://www.blueskyonmars.com/2004/09/02 ... e-edition/ and
http://www.hibernate.org/56.html but they don't seem to apply to our situation. The real kicker is that this code has been untouched in production since late October. Then, last Friday we started seeing this error. The first time, we turned debug logging on and bounced JBoss, and the problem went away. Then it came back last night, we tried different versions of the Oracle JDBC driver (10.1.0.2 and 10.1.0.4) and neither made a difference. We went home and when we came back in the morning, the problem had gone away. Then it came back this afternoon, and we tried switching from the thin driver to the OCI driver, and it has gone away again, but I'm not confident that we've really fixed the problem. I'm at a loss to explain what's going on.
The code was written by contractors and has some very weird transaction/session handling. They're supposed to be using JBoss JTA integration, but that doesn't look like what they're doing. I know that BLOBs have to be created in a transaction, and I'm concerned that may be the ultimate cause of the problem, but I think we'd see a different type of error if that really was the problem.
Has anyone seen this or have any ideas?
Hibernate version: 3.0.5.
Mapping documents:
Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
"-//Hibernate/Hibernate Mapping DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<hibernate-mapping >
<class name="com.cexp.quoteexpress.transfer.QuoteConfigurationTO"
table="TQTCF_QUOTE_CONFIGURATION" >
<id name="quoteId" column="QTCF_QUOTE_ID">
<generator class="sequence">
<param name="sequence">SQTCF_QUOTE_NO</param>
</generator>
</id>
<property name="name" column="QTCF_QUOTE_NAME" />
<property name="customerNo" column="QTCF_CUST_NO" />
<property name="custAccountType" column="QTCF_CUST_ACCT_TY_CD" />
<property name="arrangementNo" column="QTCF_ARRG_NO" />
<property name="priorityVendorCode" column="QTCF_PRIORITY_VENDOR_CD" />
<property name="itemNoStrategy" column="QTCF_ITEM_NO_STRATEGY" />
<property name="creator" column="QTCF_CREATOR_UID" />
<property name="creatorDivision" column="QTCF_CREATOR_DIVN" />
<property name="creationDate" column="QTCF_CREATION_DATE" type="timestamp" />
<property name="modifiedDate" column="QTCF_UPDT_DT" type="timestamp" />
<property name="modifier" column="QTCF_UPDT_UID" />
<property name="quoteFileName" column="QTCF_WORKFILE_NAME" />
<property name="status" column="QTCF_STS_CD" />
<property name="excelBlob" column="QTCF_EXCEL_BLOB" type="blob" />
</class>
</hibernate-mapping>
Code between sessionFactory.openSession() and session.close():Code:
private void readQuoteItems(QuoteConfigurationTO quote)
throws QEBusinessException {
byte[] quoteExcelData = quote.getExcelData();
if(quoteExcelData != null && quoteExcelData.length != 0){
QEExcelReader excelIn = new QEExcelReader();
excelIn.setInputStream(new ByteArrayInputStream(quoteExcelData));
QuoteItemTO[] quoteItemsArr = null;
try {
quoteItemsArr = excelIn.getWorkfileItems(quote.getItemNoStrategy());
} catch (QEExcelException e) {
LOGGER.error("Unable to read excel data", e);
if(e.getErrorType() == QEExcelException.ERROR_TYPE_USER){
Map keys = QEPropertyReader.getUserMessageMap(e.getMessage(), false);
throw new QEBusinessException(e,keys, e.getMessage());
}else{
throw new QEBusinessException(e,"Unable to read excel data."
);
}
}
quote.setQuotes(quoteItemsArr);
Blob excelBlob = null;
//Do this only if there is an excel file.
if(quote.getExcelData() != null){
excelBlob = Hibernate.createBlob(quote.getExcelData());
}
quote.setExcelBlob(excelBlob);
}
}
public QuoteConfigurationTO addQuote(QuoteConfigurationTO quote)
throws DAOException {
System.out.println(">>>>>>>>>>>>>>>>> addQuote in DAO");
Session hSession = null;
Transaction trx = null;
try{
hSession = DAOHelper.getHibernateSession();
//Save the Quote Configuration
trx = hSession.beginTransaction();
hSession.save(quote);
QuoteItemTO [] quoteItemsArr = quote.getQuotes();
if(LOGGER.isDebugEnabled() && quoteItemsArr != null){
LOGGER.debug("Saved Quote :" + quote.getQuoteId() + "Quote Items to be inserted: " +
quoteItemsArr.length);
}else if(LOGGER.isDebugEnabled() && quoteItemsArr == null){
LOGGER.debug("Saved Quote :" + quote.getQuoteId() + "No quote items.");
}
for(int i = 0; quoteItemsArr != null && i < quoteItemsArr.length; i++) {
QuoteItemTO quoteItem = quoteItemsArr[i];
quoteItem.setQuoteId(quote.getQuoteId());
//Save the quote item
hSession.save(quoteItem);
if( (i%20) == 0 ) {
hSession.flush();
hSession.clear();
}
}
trx.commit();
} catch(HibernateException he){
if(trx != null) {
trx.rollback();
}
LOGGER.error(he.getMessage(), he);
throw new DAOException(he, "Unable to add a quote");
} finally{
DAOHelper.closeHibernateSession(hSession);
}
return quote;
}
//Read QuoteItems from the Excel Data and assign it to the quote
readQuoteItems(quoteConfiguration);
QuoteItemTO [] quoteItemsArr = quoteConfiguration.getQuotes();
for(int i = 0; quoteItemsArr != null && i < quoteItemsArr.length; i++) {
QuoteItemTO quoteItem = quoteItemsArr[i];
//Assign default values for the quote item
assignDefaultValuesForQuoteItem(quoteConfiguration, quoteItem);
// validate values of quote item
validateQuoteItem(quoteItem);
}
try {
QuoteConfigurationTO quote = quoteDAO.addQuote(quoteConfiguration);
Full stack trace of any exception that occurs:Code:
java.sql.SQLException: ORA-01483: invalid length for DATE or NUMBER bind variable
at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:125)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:305)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:272)
at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:626)
at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:182)
at oracle.jdbc.driver.T4CPreparedStatement.execute_for_rows(T4CPreparedStatement.java:630)
at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1081)
at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:2905)
at oracle.jdbc.driver.OraclePreparedStatement.executeUpdate(OraclePreparedStatement.java:2977)
at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:324)
at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:22)
at org.hibernate.persister.entity.BasicEntityPersister.insert(BasicEntityPersister.java:1853)
at org.hibernate.persister.entity.BasicEntityPersister.insert(BasicEntityPersister.java:2200)
at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:46)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:239)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:223)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:136)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:274)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:730)
at com.cexp.quoteexpress.business.hdao.QuoteDAOImpl.addQuote(QuoteDAOImpl.java:88)
at com.cexp.quoteexpress.business.delegates.server.QuoteBD.createQuote(QuoteBD.java:126)
at com.cexp.quoteexpress.business.services.QuoteBean.createQuote(QuoteBean.java:107)
at sun.reflect.GeneratedMethodAccessor226.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:62)
at java.lang.reflect.Method.invoke(Method.java:391)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:683)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:185)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:72)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:240)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:128)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:118)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.StatelessSessionContainer.internalInvoke(StatelessSessionContainer.java:331)
at org.jboss.ejb.Container.invoke(Container.java:700)
at sun.reflect.GeneratedMethodAccessor124.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:62)
at java.lang.reflect.Method.invoke(Method.java:391)
at org.jboss.mx.capability.ReflectedMBeanDispatcher.invoke(ReflectedMBeanDispatcher.java:284)
at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:546)
at org.jboss.invocation.local.LocalInvoker.invoke(LocalInvoker.java:101)
at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:90)
at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:46)
at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:45)
at org.jboss.proxy.ejb.StatelessSessionInterceptor.invoke(StatelessSessionInterceptor.java:100)
at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:85)
at $Proxy75.createQuote(Unknown Source)
at sun.reflect.GeneratedMethodAccessor225.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:62)
at java.lang.reflect.Method.invoke(Method.java:391)
at com.cexp.common.locator.services.Invoker.invoke(Invoker.java:63)
at com.cexp.common.locator.services.MTTimedInvoker$Worker.run(MTTimedInvoker.java:157)
at java.lang.Thread.run(Thread.java:816)
Name and version of the database you are using:Oracle 10.1.0.3 database using 10.1.0.3 JDBC thin driver.
The generated SQL (show_sql=true):Code:
insert into TQTCF_QUOTE_CONFIGURATION (QTCF_QUOTE_NAME, QTCF_CUST_NO, QTCF_CUST_ACCT_TY_CD, QTCF_ARRG_NO,
QTCF_PRIORITY_VENDOR_CD, QTCF_ITEM_NO_STRATEGY, QTCF_CREATOR_UID, QTCF_CREATOR_DIVN, QTCF_CREATION_DATE, QTCF_UPDT_DT, QTCF_UP
DT_UID, QTCF_WORKFILE_NAME, QTCF_STS_CD, QTCF_EXCEL_BLOB, QTCF_QUOTE_ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
Debug level Hibernate log excerpt:Code:
2006-01-20 15:35:49,012 INFO [STDOUT] >>>>>>>>>>>>>>>>> addQuote in DAO
2006-01-20 15:35:49,012 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4660414664753152
2006-01-20 15:35:49,012 DEBUG [org.hibernate.transaction.JDBCTransaction] begin
2006-01-20 15:35:49,012 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2006-01-20 15:35:49,012 DEBUG [org.hibernate.transaction.JDBCTransaction] current autocommit status: true
2006-01-20 15:35:49,012 DEBUG [org.hibernate.transaction.JDBCTransaction] disabling autocommit
2006-01-20 15:35:49,012 DEBUG [org.hibernate.event.def.DefaultSaveOrUpdateEventListener] saving transient instance
2006-01-20 15:35:49,012 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0
, globally: 0)
2006-01-20 15:35:49,012 DEBUG [org.hibernate.SQL] select SQTCF_QUOTE_NO.nextval from dual
2006-01-20 15:35:49,012 DEBUG [org.hibernate.jdbc.AbstractBatcher] preparing statement
2006-01-20 15:35:49,013 DEBUG [org.hibernate.id.SequenceGenerator] Sequence identifier generated: 2247
2006-01-20 15:35:49,013 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements:
1, globally: 1)
2006-01-20 15:35:49,013 DEBUG [org.hibernate.jdbc.AbstractBatcher] closing statement
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] generated identifier: 2247, using strategy:
org.hibernate.id.SequenceGenerator
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] saving [com.cexp.quoteexpress.transfer.Quote
ConfigurationTO#2247]
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.DefaultSaveOrUpdateEventListener] saving transient instance
2006-01-20 15:35:49,013 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0
, globally: 0)
2006-01-20 15:35:49,013 DEBUG [org.hibernate.SQL] select SQTCF_QUOTE_ITEM_NO.nextval from dual
2006-01-20 15:35:49,013 DEBUG [org.hibernate.jdbc.AbstractBatcher] preparing statement
2006-01-20 15:35:49,013 DEBUG [org.hibernate.id.SequenceGenerator] Sequence identifier generated: 1181272
2006-01-20 15:35:49,013 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements:
1, globally: 1)
2006-01-20 15:35:49,013 DEBUG [org.hibernate.jdbc.AbstractBatcher] closing statement
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] generated identifier: 1181272, using strateg
y: org.hibernate.id.SequenceGenerator
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] saving [com.cexp.quoteexpress.transfer.Quote
ItemTO#1181272]
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] flushing session
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] dirty checking collections
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushing entities and processing referen
ced collections
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Processing unreferenced collections
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Scheduling collection removes/(re)create
s/updates
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 2 insertions, 0 updates, 0 dele
tions to 2 objects
2006-01-20 15:35:49,013 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 r
emovals to 0 collections
2006-01-20 15:35:49,013 DEBUG [org.hibernate.pretty.Printer] listing entities:
2006-01-20 15:35:49,013 DEBUG [org.hibernate.pretty.Printer] com.cexp.quoteexpress.transfer.QuoteItemTO{umresolutionUser=JGONZ
AL, xrefUpdateDate=2006-01-20 15:35:49, custItemPrefix=null, ceItemBean=component[itemSKU,itemMasterNo,cimmNo,UOM,uomLCDFactor
,parentClass,productClass,directCost,standardCost,macCost,listPrice,ceUsage,manufacturer]{UOM=null, manufacturer=null, listPri
ce=null, productClass=null, uomLCDFactor=0.0, cimmNo=0, itemMasterNo=0, parentClass=null, directCost=null, macCost=null, ceUsa
ge=0.0, itemSKU=null, standardCost=null}, modifier=JGONZAL, unitPrice=null, pricingUser=JGONZAL, custMfg=UNV, custUOMFactor=0.
0, matchType=null, umResolutionDate=2006-01-20 15:35:49, excelRowNo=1, custUOMCD=M, xrefUpdateUser=JGONZAL, quoteId=2247, pric
ingDate=2006-01-20 15:35:49, umResolutionStatus=U, matchCount=0, quoteItemId=1181272, custItemQty=0, preferredVendorCode=null,
lockFlag=N, xrefMatchStatus=U, custItemUOM=BX, custItemNo=UNV4000068, defaultPriced=N, modifiedDate=2006-01-20 15:35:49, dele
teFlag=N, custItemDesc=GBC BINDINGS, 1/2" BLACK,100/BOX, suppliedCustItemNo=4000068}
2006-01-20 15:35:49,014 DEBUG [org.hibernate.pretty.Printer] com.cexp.quoteexpress.transfer.QuoteConfigurationTO{quoteId=2247,
modifier=JGONZAL, creationDate=2006-01-20 15:35:48, excelBlob=org.hibernate.lob.SerializableBlob@437c437c, status=O, quoteFil
eName=AARON2.xls, itemNoStrategy=M, creatorDivision=98, creator=JGONZAL, customerNo=0, priorityVendorCode=UK, modifiedDate=200
6-01-20 15:35:48, custAccountType=null, name=AARON5, arrangementNo=0}
2006-01-20 15:35:49,014 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] executing flush
2006-01-20 15:35:49,014 DEBUG [org.hibernate.persister.entity.BasicEntityPersister] Inserting entity: [com.cexp.quoteexpress.t
ransfer.QuoteConfigurationTO#2247]
2006-01-20 15:35:49,014 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0
, globally: 0)
2006-01-20 15:35:49,014 DEBUG [org.hibernate.SQL] insert into TQTCF_QUOTE_CONFIGURATION (QTCF_QUOTE_NAME, QTCF_CUST_NO, QTCF_C
UST_ACCT_TY_CD, QTCF_ARRG_NO, QTCF_PRIORITY_VENDOR_CD, QTCF_ITEM_NO_STRATEGY, QTCF_CREATOR_UID, QTCF_CREATOR_DIVN, QTCF_CREATI
ON_DATE, QTCF_UPDT_DT, QTCF_UPDT_UID, QTCF_WORKFILE_NAME, QTCF_STS_CD, QTCF_EXCEL_BLOB, QTCF_QUOTE_ID) values (?, ?, ?, ?, ?,
?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2006-01-20 15:35:49,014 DEBUG [org.hibernate.jdbc.AbstractBatcher] preparing statement
2006-01-20 15:35:49,014 DEBUG [org.hibernate.persister.entity.BasicEntityPersister] Dehydrating entity: [com.cexp.quoteexpress
.transfer.QuoteConfigurationTO#2247]
2006-01-20 15:35:49,014 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements:
1, globally: 1)
2006-01-20 15:35:49,014 DEBUG [org.hibernate.jdbc.AbstractBatcher] closing statement
2006-01-20 15:35:49,014 DEBUG [org.hibernate.util.JDBCExceptionReporter] could not insert: [com.cexp.quoteexpress.transfer.Quo
teConfigurationTO] [insert into TQTCF_QUOTE_CONFIGURATION (QTCF_QUOTE_NAME, QTCF_CUST_NO, QTCF_CUST_ACCT_TY_CD, QTCF_ARRG_NO,
QTCF_PRIORITY_VENDOR_CD, QTCF_ITEM_NO_STRATEGY, QTCF_CREATOR_UID, QTCF_CREATOR_DIVN, QTCF_CREATION_DATE, QTCF_UPDT_DT, QTCF_UP
DT_UID, QTCF_WORKFILE_NAME, QTCF_STS_CD, QTCF_EXCEL_BLOB, QTCF_QUOTE_ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
java.sql.SQLException: ORA-01483: invalid length for DATE or NUMBER bind variable
JBoss/Hibernate JCA config:Code:
<?xml version="1.0"?>
<server>
<mbean code="org.hibernate.jmx.HibernateService"
name="jboss.jca:service=HibernateFactory,name=HibernateFactory">
<!-- Required services -->
<depends>jboss.jca:service=RARDeployer</depends>
<depends>jboss.jca:service=LocalTxCM,name=QuoteExpressDS</depends>
<!-- Bind the Hibernate service to JNDI -->
<attribute name="JndiName">java:/hibernate/quoteexpress/SessionFactory</attribute>
<!-- Datasource settings -->
<attribute name="Datasource">java:/QuoteExpressDS</attribute>
<attribute name="Dialect">org.hibernate.dialect.Oracle9Dialect</attribute>
<!-- Transaction integration -->
<attribute name="TransactionStrategy">
org.hibernate.transaction.JTATransactionFactory</attribute>
<attribute name="TransactionManagerLookupStrategy">
org.hibernate.transaction.JBossTransactionManagerLookup</attribute>
<attribute name="FlushBeforeCompletionEnabled">true</attribute>
<attribute name="AutoCloseSessionEnabled">true</attribute>
<!-- Fetching options -->
<attribute name="MaximumFetchDepth">5</attribute>
<!-- Second-level caching -->
<attribute name="SecondLevelCacheEnabled">true</attribute>
<attribute name="CacheProviderClass">org.hibernate.cache.EhCacheProvider</attribute>
<attribute name="QueryCacheEnabled">true</attribute>
<!-- Logging -->
<attribute name="ShowSqlEnabled">true</attribute>
</mbean>
</server>