0 Replies Latest reply on Dec 18, 2006 7:47 PM by Torkell Tagseth

    JBoss 4 CMP mixing database columns

    Torkell Tagseth Newbie

      During stress tests of out application on JBoss 4.0.4 and 4.0.5, we're seeing exceptions where JBoss apparently mixes up the database columns:


      2006-12-15 19:14:47,748 ERROR [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackLocalException in method: null, causedBy:
      org.postgresql.util.PSQLException: Bad value for type timestamp : WAP Ordbok
      at org.postgresql.jdbc2.TimestampUtils.loadCalendar(TimestampUtils.java:232)
      at org.postgresql.jdbc2.TimestampUtils.toTimestamp(TimestampUtils.java:307)
      ...
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMRFieldBridge.createRelationLinks(JDBCCMRFieldBridge.java:1000)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMRFieldBridge.createRelationLinks(JDBCCMRFieldBridge.java:976)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMRFieldBridge.setInstanceValue(JDBCCMRFieldBridge.java:912)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMRFieldBridge.setValue(JDBCCMRFieldBridge.java:723)
      at org.jboss.ejb.plugins.cmp.bridge.EntityBridgeInvocationHandler$FieldSetInvoker.invoke(EntityBridgeInvocationHandler.java:170)
      at org.jboss.ejb.plugins.cmp.bridge.EntityBridgeInvocationHandler.invoke(EntityBridgeInvocationHandler.java:105)
      at org.jboss.proxy.compiler.Runtime.invoke(Runtime.java:76)
      at no.boostcom.smsfusion.beans.InboxMessageBean$Proxy.setInbox(<generated>)
      ...


      And


      2006-12-15 19:14:47,860 ERROR [no.boostcom.receiver.DispatchMDB] Error occured when reader was trying to read message.
      org.jboss.tm.JBossTransactionRolledbackException: Internal error getting results for field member startTime; nested exception is:
      javax.ejb.EJBException: Internal error getting results for field member
      startTime; - nested throwable: (javax.ejb.EJBException: Internal error getting results for field member startTime)
      at org.jboss.ejb.plugins.LogInterceptor.handleException(LogInterceptor.java:280)
      at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:209)
      at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:136)
      at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
      ...
      Caused by: javax.ejb.EJBException: Internal error getting results for field member startTime
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCAbstractCMPFieldBridge.loadArgumentResults(JDBCAbstractCMPFieldBridge.java:498)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCAbstractCMPFieldBridge.loadArgumentResults(JDBCAbstractCMPFieldBridge.java:432)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCAbstractCMPFieldBridge.loadInstanceResults(JDBCAbstractCMPFieldBridge.java:393)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.execute(JDBCLoadEntityCommand.java:207)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.execute(JDBCLoadEntityCommand.java:88)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreManager.loadEntity(JDBCStoreManager.java:646)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreManager.loadEntity(JDBCStoreManager.java:628)
      at org.jboss.ejb.plugins.CMPPersistenceManager.loadEntity(CMPPersistenceManager.java:406)
      at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.loadEntity(CachedConnectionInterceptor.java:252)
      at org.jboss.ejb.plugins.EntitySynchronizationInterceptor.invoke(EntitySynchronizationInterceptor.java:243)
      at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
      at org.jboss.ejb.plugins.EntityReentranceInterceptor.invoke(EntityReentranceInterceptor.java:126)
      at org.jboss.ejb.plugins.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:276)
      at org.jboss.ejb.plugins.EntityLockInterceptor.invoke(EntityLockInterceptor.java:104)
      at org.jboss.ejb.plugins.EntityCreationInterceptor.invoke(EntityCreationInterceptor.java:68)
      at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
      at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
      at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:378)
      at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
      at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
      at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
      at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:136)
      at org.jboss.ejb.EntityContainer.internalInvoke(EntityContainer.java:527)
      at org.jboss.ejb.Container.invoke(Container.java:954)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMRFieldBridge.invokeAddRelation(JDBCCMRFieldBridge.java:1194)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMRFieldBridge.createRelationLinks(JDBCCMRFieldBridge.java:1000)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMRFieldBridge.createRelationLinks(JDBCCMRFieldBridge.java:976)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMRFieldBridge.setInstanceValue(JDBCCMRFieldBridge.java:912)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMRFieldBridge.setValue(JDBCCMRFieldBridge.java:723)
      at org.jboss.ejb.plugins.cmp.bridge.EntityBridgeInvocationHandler$FieldSetInvoker.invoke(EntityBridgeInvocationHandler.java:170)
      at org.jboss.ejb.plugins.cmp.bridge.EntityBridgeInvocationHandler.invoke(EntityBridgeInvocationHandler.java:105)
      at org.jboss.proxy.compiler.Runtime.invoke(Runtime.java:76)
      at no.boostcom.smsfusion.beans.InboxMessageBean$Proxy.setInbox(<generated>)
      at sun.reflect.GeneratedMethodAccessor276.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
      at org.jboss.ejb.EntityContainer$ContainerInterceptor.invoke(EntityContainer.java:1187)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCRelationInterceptor.invoke(JDBCRelationInterceptor.java:87)
      at org.jboss.ejb.plugins.EntitySynchronizationInterceptor.invoke(EntitySynchronizationInterceptor.java:284)
      at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
      at org.jboss.ejb.plugins.EntityReentranceInterceptor.invoke(EntityReentranceInterceptor.java:126)
      at org.jboss.ejb.plugins.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:276)
      at org.jboss.ejb.plugins.EntityLockInterceptor.invoke(EntityLockInterceptor.java:104)
      at org.jboss.ejb.plugins.EntityCreationInterceptor.invoke(EntityCreationInterceptor.java:68)
      at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
      at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
      at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:378)
      at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
      at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
      at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
      at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:136)
      at org.jboss.ejb.EntityContainer.internalInvoke(EntityContainer.java:527)
      at org.jboss.ejb.Container.invoke(Container.java:954)
      at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
      at org.jboss.ejb.plugins.local.EntityProxy.invoke(EntityProxy.java:65)
      at $Proxy438.setInbox(Unknown Source)
      at no.boostcom.smsfusion.smsfusionReceiverBeans.MtextHelperBean.storeMessage(MtextHelperBean.java:449)
      at no.boostcom.smsfusion.smsfusionReceiverBeans.MtextHelperBean.storeSMS(MtextHelperBean.java:410)
      at sun.reflect.GeneratedMethodAccessor270.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
      at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
      at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
      at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
      at org.jboss.ws.server.ServiceEndpointInterceptor.invoke(ServiceEndpointInterceptor.java:39)
      at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
      at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
      at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
      at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
      at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
      at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
      at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:136)
      at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
      at org.jboss.ejb.Container.invoke(Container.java:954)
      at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
      at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:103)
      at $Proxy502.storeSMS(Unknown Source)
      ...
      Caused by: org.postgresql.util.PSQLException: Bad value for type timestamp : WAP Ordbok
      at org.postgresql.jdbc2.TimestampUtils.loadCalendar(TimestampUtils.java:232)
      at org.postgresql.jdbc2.TimestampUtils.toTimestamp(TimestampUtils.java:307)
      at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getTimestamp(AbstractJdbc2ResultSet.java:422)
      at org.postgresql.jdbc2.AbstractJdbc2ResultSet.getTimestamp(AbstractJdbc2ResultSet.java:2091)
      at org.jboss.resource.adapter.jdbc.WrappedResultSet.getTimestamp(WrappedResultSet.java:945)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCResultSetReader$12.readResult(JDBCResultSetReader.java:241)
      at org.jboss.ejb.plugins.cmp.jdbc.JDBCResultSetReader$AbstractResultSetReader.get(JDBCResultSetReader.java:486)
      at org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCAbstractCMPFieldBridge.loadArgumentResults(JDBCAbstractCMPFieldBridge.java:482)
      ... 162 more
      Caused by: java.lang.NumberFormatException: Trailing junk on timestamp: ''
      at org.postgresql.jdbc2.TimestampUtils.loadCalendar(TimestampUtils.java:226)
      ... 169 more


      Most of the time we see the above exceptions, but we've also seen these:


      2006-12-15 23:31:37,773 ERROR [no.boostcom.receiver.DispatchMDB] Error occured when reader was trying to read message.
      java.rmi.ServerException: EJBException:; nested exception is:
      javax.ejb.EJBException: Reentrant method call detected: Inbox 50
      at org.jboss.ejb.plugins.LogInterceptor.handleException(LogInterceptor.java:365)
      at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:209)
      at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:136)
      at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
      at org.jboss.ejb.Container.invoke(Container.java:954)
      at sun.reflect.GeneratedMethodAccessor237.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
      at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
      at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
      at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
      at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
      at org.jboss.invocation.local.LocalInvoker$MBeanServerAction.invoke(LocalInvoker.java:169)
      at org.jboss.invocation.local.LocalInvoker.invoke(LocalInvoker.java:118) at org.jboss.invocation.InvokerInterceptor.invokeLocal(InvokerInterceptor.java:209)
      at org.jboss.invocation.InvokerInterceptor.invoke(InvokerInterceptor.java:195)
      at org.jboss.proxy.TransactionInterceptor.invoke(TransactionInterceptor.java:61)
      at org.jboss.proxy.SecurityInterceptor.invoke(SecurityInterceptor.java:70)
      at org.jboss.proxy.ejb.StatelessSessionInterceptor.invoke(StatelessSessionInterceptor.java:112)
      at org.jboss.proxy.ClientContainer.invoke(ClientContainer.java:100)
      at $Proxy495.processSMSMessage(Unknown Source)
      at no.boostcom.receiver.DispatchMDB.onMessage(DispatchMDB.java:134)
      at sun.reflect.GeneratedMethodAccessor250.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
      at org.jboss.ejb.MessageDrivenContainer$ContainerInterceptor.invoke(MessageDrivenContainer.java:495)
      at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
      at org.jboss.ejb.plugins.MessageDrivenInstanceInterceptor.invoke(MessageDrivenInstanceInterceptor.java:116)
      at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
      at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
      at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:315)
      at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
      at org.jboss.ejb.plugins.RunAsSecurityInterceptor.invoke(RunAsSecurityInterceptor.java:109)
      at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
      at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:136)
      at org.jboss.ejb.MessageDrivenContainer.internalInvoke(MessageDrivenContainer.java:402)
      at org.jboss.ejb.Container.invoke(Container.java:954)
      at org.jboss.ejb.plugins.jms.JMSContainerInvoker.invoke(JMSContainerInvoker.java:987)
      at org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1287)
      at org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:266)
      at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:905)
      at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:170)
      at org.jboss.mq.SpySession.run(SpySession.java:323)
      at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:194)
      at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
      at java.lang.Thread.run(Thread.java:595)
      Caused by: javax.ejb.EJBException: Reentrant method call detected: Inbox 50
      at org.jboss.ejb.plugins.EntityReentranceInterceptor.invoke(EntityReentranceInterceptor.java:118)
      at org.jboss.ejb.plugins.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:276)
      at org.jboss.ejb.plugins.EntityLockInterceptor.invoke(EntityLockInterceptor.java:104)
      at org.jboss.ejb.plugins.EntityCreationInterceptor.invoke(EntityCreationInterceptor.java:68)
      at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
      at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
      at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:378)
      at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
      at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
      at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
      at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:136)
      at org.jboss.ejb.EntityContainer.internalInvoke(EntityContainer.java:527)
      at org.jboss.ejb.Container.invoke(Container.java:954)
      at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
      at org.jboss.ejb.plugins.local.EntityProxy.invoke(EntityProxy.java:65)
      at $Proxy446.getInnboxVO(Unknown Source)
      at no.boostcom.smsfusion.smsfusionReceiverBeans.SmsfusionReaderBean.checkMtalk(SmsfusionReaderBean.java:358)
      at no.boostcom.smsfusion.smsfusionReceiverBeans.SmsfusionReaderBean.findAssosiationToInnmessage(SmsfusionReaderBean.java:277)
      at no.boostcom.smsfusion.smsfusionReceiverBeans.SmsfusionReaderBean.checkCodeword(SmsfusionReaderBean.java:254)
      at no.boostcom.smsfusion.smsfusionReceiverBeans.SmsfusionReaderBean.processSMSMessage(SmsfusionReaderBean.java:107)
      at sun.reflect.GeneratedMethodAccessor254.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
      at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
      at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
      at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
      at org.jboss.ws.server.ServiceEndpointInterceptor.invoke(ServiceEndpointInterceptor.java:39)
      at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
      at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
      at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:315)
      at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
      at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
      at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
      ... 46 more


      This happens to a CMP 2 EntityBean (Inbox). In the above case the value 'WAP Ordbok' comes from a text-column, but JBoss thinks it's comes from one of the timestamp columns. We're able to reproduce this on JBoss 4 using both postgresql 7 and 8 when testing our application with many simultaneous requests. The issues are not reproducible on JBoss 3.2.5. The issues also go away when we change the commit option for Inbox from B to D. Right now we're thinking this is a jboss bug. Please see:
      http://jira.jboss.com/jira/browse/JBAS-3923

      Any help on this would be greatly appreciated.