Hi,

I got the exception below after a simple select only after I had gotten another exception (ConstraintViolationException). I dont understand what "dont flush the session after an exception occurs" mean here. What can be the reasons for this exception ?

Any help is really welcomed. Thank you.

Mete

I am using contextual session management provided by Hibernate.
Hibernate 3.1.3 with Java 5, SQL Server 2000

ERROR: 2006-07-20 10:21:28,419 (org.hibernate.AssertionFailure.<init>(AssertionFailure.java:22)) http-8080-Processor9 - an assertion failure occured (this may indicate a bug in Hibernate, but is more likely due to unsafe use of the session)
org.hibernate.AssertionFailure: null id in com.pozitron.boomerang.model.Person entry (don't flush the Session after an exception occurs)
at org.hibernate.event.def.DefaultFlushEntityEventListener.checkId(DefaultFlushEntityEventListener.java:48)
at org.hibernate.event.def.DefaultFlushEntityEventListener.getValues(DefaultFlushEntityEventListener.java:150)
at org.hibernate.event.def.DefaultFlushEntityEventListener.onFlushEntity(DefaultFlushEntityEventListener.java:106)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:195)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:76)
at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:35)
at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:954)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1526)
at org.hibernate.impl.CriteriaImpl.list(CriteriaImpl.java:283)
at com.pozitron.boomerang.dao.GenericDAO.getAll(GenericDAO.java:46)
at com.pozitron.boomerang.services.addressbook.AddressBookService.getGroups(AddressBookService.java:314)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.openamf.invoker.RankedMethod.invoke(RankedMethod.java:86)
at org.openamf.invoker.JavaServiceInvoker.invokeServiceMethod(JavaServiceInvoker.java:114)
at org.openamf.invoker.JavaServiceInvoker.invokeService(JavaServiceInvoker.java:56)
at org.openamf.DefaultGateway.invokeBody(DefaultGateway.java:208)
at org.openamf.DefaultGateway.processMessage(DefaultGateway.java:180)
at org.openamf.DefaultGateway.service(DefaultGateway.java:87)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:432)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommonAccessLogValve.java:495)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:868)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:744)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Unknown Source)

it means: Don't use the session after an exception has occurred.

Is it the only cause "using the session after an exception" ?

I am getting (hopefully) a fresh session by getCurrentSession in a new request (new thread). Then the first query (not a commit yet) causes this exception, so there is no previous exceptional state on that session. My configuration is same as indicated in the references to use contextual sessions as per thread. Should I check the session management ?

Mete

"after a simple select only after I had gotten another exception (ConstraintViolationException)."


you are implicitly flushing the session when doing the "simple" select and you do it just after another exception - that is a big no-no.

http://www.hibernate.org/hib_docs/v3/re ... exceptions

That is OK, but I am doing this in another request.

It is like that:

request 1: (so session1)
do something
commit -> constraint violation exception

request 2: (so session2)
do something -> AssertionFailure exception

One more thing; if I get an exception from somewhere, I should close the session. Since commit does closing implicitly for sessions managed by hibernate, what should I do ? Should I explicitly close it or it is already closed ?

but did you also throw away the objects/collection you had from session1?

Well.. It seems I need some help here. Because I assume when I close and get a new session, everything will be fine.

Do you mean throwing away the objects and collections from 2nd level cache since first level is only exist during the session ? or do you mean something different ?

Thank you.

Mete

I mean the objects you used in session1 might be/is most likely "half baked"/bad because of the exception that occurred in there.

So don't use them.

max, can you say something by looking at the stack trace ?

DEBUG: 2006-07-20 18:08:08,171 (org.hibernate.impl.SessionImpl.<init>(SessionImpl.java:219)) http-8080-Processor8 - opened session at timestamp: 4724359529148416
DEBUG: 2006-07-20 18:08:08,172 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:290)) http-8080-Processor8 - allowing method [beginTransaction] in non-transacted context
DEBUG: 2006-07-20 18:08:08,173 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) http-8080-Processor8 - allowing proxied method [beginTransaction] to proceed to real session
DEBUG: 2006-07-20 18:08:08,174 (org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:54)) http-8080-Processor8 - begin
DEBUG: 2006-07-20 18:08:08,181 (org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:415)) http-8080-Processor8 - opening JDBC connection
INFO: 2006-07-20 18:08:08,183 (com.pozitron.boomerang.util.BoomerangCP.logStatistics(BoomerangCP.java:230)) http-8080-Processor8 - active: 2 (max: 10 ) idle: 8 (max: 10 )
DEBUG: 2006-07-20 18:08:08,184 (org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:59)) http-8080-Processor8 - current autocommit status: false
DEBUG: 2006-07-20 18:08:08,187 (org.hibernate.jdbc.JDBCContext.afterTransactionBegin(JDBCContext.java:194)) http-8080-Processor8 - after transaction begin
DEBUG: 2006-07-20 18:08:08,188 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) http-8080-Processor8 - allowing proxied method [enableFilter] to proceed to real session
DEBUG: 2006-07-20 18:08:08,189 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) http-8080-Processor8 - allowing proxied method [createCriteria] to proceed to real session
DEBUG: 2006-07-20 18:08:08,191 (org.hibernate.jdbc.AbstractBatcher.logOpenPreparedStatement(AbstractBatcher.java:311)) http-8080-Processor8 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG: 2006-07-20 18:08:08,192 (org.hibernate.jdbc.AbstractBatcher.log(AbstractBatcher.java:346)) http-8080-Processor8 - select this_.ID as ID3_0_, this_.NAME as NAME3_0_, this_.DELETED_AT as DELETED3_3_0_, this_.DELETED as DELETED3_0_ from GROUPS this_ where ? = this_.deleted
DEBUG: 2006-07-20 18:08:08,193 (org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:424)) http-8080-Processor8 - preparing statement
DEBUG: 2006-07-20 18:08:08,194 (org.hibernate.type.NullableType.nullSafeSet(NullableType.java:80)) http-8080-Processor8 - binding 'false' to parameter: 1
DEBUG: 2006-07-20 18:08:08,199 (org.hibernate.jdbc.AbstractBatcher.logOpenResults(AbstractBatcher.java:327)) http-8080-Processor8 - about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG: 2006-07-20 18:08:08,200 (org.hibernate.loader.Loader.doQuery(Loader.java:682)) http-8080-Processor8 - processing result set
DEBUG: 2006-07-20 18:08:08,201 (org.hibernate.loader.Loader.doQuery(Loader.java:687)) http-8080-Processor8 - result set row: 0
DEBUG: 2006-07-20 18:08:08,202 (org.hibernate.type.NullableType.nullSafeGet(NullableType.java:122)) http-8080-Processor8 - returning '2' as column: ID3_0_
DEBUG: 2006-07-20 18:08:08,203 (org.hibernate.loader.Loader.getRow(Loader.java:1164)) http-8080-Processor8 - result row: EntityKey[com.pozitron.boomerang.model.Group#2]
DEBUG: 2006-07-20 18:08:08,204 (org.hibernate.loader.Loader.loadFromResultSet(Loader.java:1347)) http-8080-Processor8 - Initializing object from ResultSet: [com.pozitron.boomerang.model.Group#2]
DEBUG: 2006-07-20 18:08:08,205 (org.hibernate.persister.entity.AbstractEntityPersister.hydrate(AbstractEntityPersister.java:1860)) http-8080-Processor8 - Hydrating entity: [com.pozitron.boomerang.model.Group#2]
DEBUG: 2006-07-20 18:08:08,206 (org.hibernate.type.NullableType.nullSafeGet(NullableType.java:122)) http-8080-Processor8 - returning 'ist' as column: NAME3_0_
DEBUG: 2006-07-20 18:08:08,209 (org.hibernate.type.NullableType.nullSafeGet(NullableType.java:122)) http-8080-Processor8 - returning '1970-01-01 02:00:00' as column: DELETED3_3_0_
DEBUG: 2006-07-20 18:08:08,213 (org.hibernate.type.NullableType.nullSafeGet(NullableType.java:122)) http-8080-Processor8 - returning 'false' as column: DELETED3_0_
DEBUG: 2006-07-20 18:08:08,219 (org.hibernate.loader.Loader.doQuery(Loader.java:709)) http-8080-Processor8 - done processing result set (1 rows)
DEBUG: 2006-07-20 18:08:08,220 (org.hibernate.jdbc.AbstractBatcher.logCloseResults(AbstractBatcher.java:334)) http-8080-Processor8 - about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG: 2006-07-20 18:08:08,221 (org.hibernate.jdbc.AbstractBatcher.logClosePreparedStatement(AbstractBatcher.java:319)) http-8080-Processor8 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG: 2006-07-20 18:08:08,221 (org.hibernate.jdbc.AbstractBatcher.closePreparedStatement(AbstractBatcher.java:470)) http-8080-Processor8 - closing statement
DEBUG: 2006-07-20 18:08:08,222 (org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:839)) http-8080-Processor8 - total objects hydrated: 1
DEBUG: 2006-07-20 18:08:08,223 (org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:107)) http-8080-Processor8 - resolving associations for [com.pozitron.boomerang.model.Group#2]
DEBUG: 2006-07-20 18:08:08,224 (org.hibernate.engine.CollectionLoadContext.getLoadingCollection(CollectionLoadContext.java:141)) http-8080-Processor8 - creating collection wrapper:[com.pozitron.boomerang.model.Group.people#2]
DEBUG: 2006-07-20 18:08:08,225 (org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:135)) http-8080-Processor8 - adding entity to second-level cache: [com.pozitron.boomerang.model.Group#2]
DEBUG: 2006-07-20 18:08:08,226 (org.hibernate.cache.ReadWriteCache.put(ReadWriteCache.java:148)) http-8080-Processor8 - Caching: com.pozitron.boomerang.model.Group#2
DEBUG: 2006-07-20 18:08:08,226 (org.hibernate.cache.EhCache.get(EhCache.java:104)) http-8080-Processor8 - key: com.pozitron.boomerang.model.Group#2
DEBUG: 2006-07-20 18:08:08,227 (org.hibernate.cache.ReadWriteCache.put(ReadWriteCache.java:169)) http-8080-Processor8 - Item was already cached: com.pozitron.boomerang.model.Group#2
DEBUG: 2006-07-20 18:08:08,228 (org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:206)) http-8080-Processor8 - done materializing entity [com.pozitron.boomerang.model.Group#2]
DEBUG: 2006-07-20 18:08:08,229 (org.hibernate.engine.StatefulPersistenceContext.initializeNonLazyCollections(StatefulPersistenceContext.java:748)) http-8080-Processor8 - initializing non-lazy collections
DEBUG: 2006-07-20 18:08:08,230 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) http-8080-Processor8 - allowing proxied method [getTransaction] to proceed to real session
DEBUG: 2006-07-20 18:08:08,231 (org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:103)) http-8080-Processor8 - commit
DEBUG: 2006-07-20 18:08:08,232 (org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:332)) http-8080-Processor8 - automatically flushing session
DEBUG: 2006-07-20 18:08:08,233 (org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:58)) http-8080-Processor8 - flushing session
DEBUG: 2006-07-20 18:08:08,233 (org.hibernate.event.def.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:111)) http-8080-Processor8 - processing flush-time cascades
DEBUG: 2006-07-20 18:08:08,234 (org.hibernate.event.def.AbstractFlushingEventListener.prepareCollectionFlushes(AbstractFlushingEventListener.java:153)) http-8080-Processor8 - dirty checking collections
DEBUG: 2006-07-20 18:08:08,235 (org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:170)) http-8080-Processor8 - Flushing entities and processing referenced collections
DEBUG: 2006-07-20 18:08:08,235 (org.hibernate.engine.Collections.processReachableCollection(Collections.java:176)) http-8080-Processor8 - Collection found: [com.pozitron.boomerang.model.Group.people#2], was: [com.pozitron.boomerang.model.Group.people#2] (uninitialized)
DEBUG: 2006-07-20 18:08:08,236 (org.hibernate.event.def.AbstractFlushingEventListener.flushCollections(AbstractFlushingEventListener.java:209)) http-8080-Processor8 - Processing unreferenced collections
DEBUG: 2006-07-20 18:08:08,242 (org.hibernate.event.def.AbstractFlushingEventListener.flushCollections(AbstractFlushingEventListener.java:223)) http-8080-Processor8 - Scheduling collection removes/(re)creates/updates
DEBUG: 2006-07-20 18:08:08,243 (org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:85)) http-8080-Processor8 - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
DEBUG: 2006-07-20 18:08:08,244 (org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:91)) http-8080-Processor8 - Flushed: 0 (re)creations, 0 updates, 0 removals to 1 collections
DEBUG: 2006-07-20 18:08:08,244 (org.hibernate.pretty.Printer.toString(Printer.java:83)) http-8080-Processor8 - listing entities:
DEBUG: 2006-07-20 18:08:08,245 (org.hibernate.pretty.Printer.toString(Printer.java:90)) http-8080-Processor8 - com.pozitron.boomerang.model.Group{ub=component[name,deletedAt,deleted]{deleted=false, name=ist, deletedAt=1970-01-01 02:00:00}, people=<uninitialized>, id=2}
DEBUG: 2006-07-20 18:08:08,246 (org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:289)) http-8080-Processor8 - executing flush
DEBUG: 2006-07-20 18:08:08,246 (org.hibernate.jdbc.ConnectionManager.flushBeginning(ConnectionManager.java:463)) http-8080-Processor8 - registering flush begin
DEBUG: 2006-07-20 18:08:08,247 (org.hibernate.jdbc.ConnectionManager.flushEnding(ConnectionManager.java:472)) http-8080-Processor8 - registering flush end
DEBUG: 2006-07-20 18:08:08,248 (org.hibernate.event.def.AbstractFlushingEventListener.postFlush(AbstractFlushingEventListener.java:320)) http-8080-Processor8 - post flush
DEBUG: 2006-07-20 18:08:08,248 (org.hibernate.jdbc.JDBCContext.beforeTransactionCompletion(JDBCContext.java:185)) http-8080-Processor8 - before transaction completion
DEBUG: 2006-07-20 18:08:08,249 (org.hibernate.impl.SessionImpl.beforeTransactionCompletion(SessionImpl.java:388)) http-8080-Processor8 - before transaction completion
DEBUG: 2006-07-20 18:08:08,250 (org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:116)) http-8080-Processor8 - committed JDBC Connection
DEBUG: 2006-07-20 18:08:08,250 (org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:199)) http-8080-Processor8 - after transaction completion
DEBUG: 2006-07-20 18:08:08,251 (org.hibernate.jdbc.ConnectionManager.aggressiveRelease(ConnectionManager.java:398)) http-8080-Processor8 - aggressively releasing JDBC connection
DEBUG: 2006-07-20 18:08:08,251 (org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:435)) http-8080-Processor8 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
INFO: 2006-07-20 18:08:08,253 (com.pozitron.boomerang.util.BoomerangCP.logStatistics(BoomerangCP.java:230)) http-8080-Processor8 - active: 1 (max: 10 ) idle: 9 (max: 10 )
DEBUG: 2006-07-20 18:08:08,253 (org.hibernate.impl.SessionImpl.afterTransactionCompletion(SessionImpl.java:417)) http-8080-Processor8 - after transaction completion
DEBUG: 2006-07-20 18:08:08,254 (org.hibernate.impl.SessionImpl.managedClose(SessionImpl.java:348)) http-8080-Processor8 - automatically closing session
DEBUG: 2006-07-20 18:08:08,254 (org.hibernate.impl.SessionImpl.close(SessionImpl.java:268)) http-8080-Processor8 - closing session
DEBUG: 2006-07-20 18:08:08,255 (org.hibernate.jdbc.ConnectionManager.cleanup(ConnectionManager.java:369)) http-8080-Processor8 - connection already null in cleanup : no action
INFO: 2006-07-20 18:08:08,256 (com.pozitron.boomerang.util.ServiceUtil.serviceExit(ServiceUtil.java:61)) http-8080-Processor8 - com.pozitron.boomerang.services.addressbook.AddressBookService:getGroups lasted 86 ms
ERROR: 2006-07-20 18:08:08,256 (org.openamf.io.AMFSerializer.writeObject(AMFSerializer.java:235)) http-8080-Processor8 - unable to find readMethod for : key writing null!
DEBUG: 2006-07-20 18:08:10,239 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) http-8080-Processor9 - allowing proxied method [beginTransaction] to proceed to real session
DEBUG: 2006-07-20 18:08:10,240 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) http-8080-Processor9 - allowing proxied method [enableFilter] to proceed to real session
DEBUG: 2006-07-20 18:08:10,246 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) http-8080-Processor9 - allowing proxied method [createCriteria] to proceed to real session
DEBUG: 2006-07-20 18:08:10,247 (org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:58)) http-8080-Processor9 - flushing session
DEBUG: 2006-07-20 18:08:10,248 (org.hibernate.event.def.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:111)) http-8080-Processor9 - processing flush-time cascades
DEBUG: 2006-07-20 18:08:10,248 (org.hibernate.event.def.AbstractFlushingEventListener.prepareCollectionFlushes(AbstractFlushingEventListener.java:153)) http-8080-Processor9 - dirty checking collections
DEBUG: 2006-07-20 18:08:10,249 (org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:170)) http-8080-Processor9 - Flushing entities and processing referenced collections
ERROR: 2006-07-20 18:08:10,268 (org.hibernate.AssertionFailure.<init>(AssertionFailure.java:22)) http-8080-Processor9 - an assertion failure occured (this may indicate a bug in Hibernate, but is more likely due to unsafe use of the session)
org.hibernate.AssertionFailure: null id in com.pozitron.boomerang.model.Group entry (don't flush the Session after an exception occurs)
at org.hibernate.event.def.DefaultFlushEntityEventListener.checkId(DefaultFlushEntityEventListener.java:48)
at org.hibernate.event.def.DefaultFlushEntityEventListener.getValues(DefaultFlushEntityEventListener.java:150)
at org.hibernate.event.def.DefaultFlushEntityEventListener.onFlushEntity(DefaultFlushEntityEventListener.java:106)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:195)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:76)
at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:35)
at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:954)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1526)
at org.hibernate.impl.CriteriaImpl.list(CriteriaImpl.java:283)
at com.pozitron.boomerang.dao.GenericDAO.getAll(GenericDAO.java:46)
at com.pozitron.boomerang.services.addressbook.AddressBookService.getGroups(AddressBookService.java:314)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.openamf.invoker.RankedMethod.invoke(RankedMethod.java:86)
at org.openamf.invoker.JavaServiceInvoker.invokeServiceMethod(JavaServiceInvoker.java:114)
at org.openamf.invoker.JavaServiceInvoker.invokeService(JavaServiceInvoker.java:56)
at org.openamf.DefaultGateway.invokeBody(DefaultGateway.java:208)
at org.openamf.DefaultGateway.processMessage(DefaultGateway.java:180)
at org.openamf.DefaultGateway.service(DefaultGateway.java:87)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:432)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommonAccessLogValve.java:495)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:868)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:744)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Unknown Source)
ERROR: 2006-07-20 18:08:10,272 (org.openamf.DefaultGateway.logRequestException(DefaultGateway.java:134)) http-8080-Processor9 - ErrorLogRecord in service, detail=[AMFBody: {serviceName=com.pozitron.boomerang.services.addressbook.AddressBookService, serviceMethodName=getGroups, response=/9, type=ARRAY, value=[ASObject[type=com.pozitron.boomerang.services.addressbook.GetGroupsRequest]]}], ServiceRequest=[AMFBody: {serviceName=com.pozitron.boomerang.services.addressbook.AddressBookService, serviceMethodName=getGroups, response=/9, type=ARRAY, value=[ASObject[type=com.pozitron.boomerang.services.addressbook.GetGroupsRequest]]}]
org.openamf.invoker.ServiceInvocationException: org.hibernate.AssertionFailure: null id in com.pozitron.boomerang.model.Group entry (don't flush the Session after an exception occurs)
at org.openamf.invoker.JavaServiceInvoker.invokeService(JavaServiceInvoker.java:67)
at org.openamf.DefaultGateway.invokeBody(DefaultGateway.java:208)
at org.openamf.DefaultGateway.processMessage(DefaultGateway.java:180)
at org.openamf.DefaultGateway.service(DefaultGateway.java:87)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:432)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommonAccessLogValve.java:495)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:868)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:744)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Unknown Source)
Caused by: org.hibernate.AssertionFailure: null id in com.pozitron.boomerang.model.Group entry (don't flush the Session after an exception occurs)
at org.hibernate.event.def.DefaultFlushEntityEventListener.checkId(DefaultFlushEntityEventListener.java:48)
at org.hibernate.event.def.DefaultFlushEntityEventListener.getValues(DefaultFlushEntityEventListener.java:150)
at org.hibernate.event.def.DefaultFlushEntityEventListener.onFlushEntity(DefaultFlushEntityEventListener.java:106)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:195)
at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:76)
at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:35)
at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:954)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1526)
at org.hibernate.impl.CriteriaImpl.list(CriteriaImpl.java:283)
at com.pozitron.boomerang.dao.GenericDAO.getAll(GenericDAO.java:46)
at com.pozitron.boomerang.services.addressbook.AddressBookService.getGroups(AddressBookService.java:314)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.openamf.invoker.RankedMethod.invoke(RankedMethod.java:86)
at org.openamf.invoker.JavaServiceInvoker.invokeServiceMethod(JavaServiceInvoker.java:114)
at org.openamf.invoker.JavaServiceInvoker.invokeService(JavaServiceInvoker.java:56)
... 20 more
DEBUG: 2006-07-20 18:08:10,625 (org.hibernate.impl.SessionImpl.<init>(SessionImpl.java:219)) http-8080-Processor8 - opened session at timestamp: 4724359539191808
DEBUG: 2006-07-20 18:08:10,626 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:290)) http-8080-Processor8 - allowing method [getTransaction] in non-transacted context
DEBUG: 2006-07-20 18:08:10,627 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) http-8080-Processor8 - allowing proxied method [getTransaction] to proceed to real session
INFO: 2006-07-20 18:08:10,627 (com.pozitron.boomerang.util.ServiceUtil.serviceExit(ServiceUtil.java:61)) http-8080-Processor8 - com.pozitron.boomerang.services.login.LoginService:getInfo lasted 4 ms
ERROR: 2006-07-20 18:08:10,629 (org.openamf.io.AMFSerializer.writeObject(AMFSerializer.java:235)) http-8080-Processor8 - unable to find readMethod for : key writing null!
INFO: 2006-07-20 18:08:55,121 (com.pozitron.boomerang.tasks.Task.execute(Task.java:30)) Quartz_Worker-0 - TASK
INFO: 2006-07-20 18:08:55,121 (com.pozitron.boomerang.tasks.Task.execute(Task.java:32)) Quartz_Worker-0 - Checking one way messages...
INFO: 2006-07-20 18:08:55,121 (com.pozitron.boomerang.tasks.TriggerTask.TRIG(TriggerTask.java:27)) Quartz_Worker-0 - TRIG
DEBUG: 2006-07-20 18:08:55,122 (org.hibernate.impl.SessionImpl.<init>(SessionImpl.java:219)) Quartz_Worker-0 - opened session at timestamp: 4724359721459712
DEBUG: 2006-07-20 18:08:55,122 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:290)) Quartz_Worker-0 - allowing method [beginTransaction] in non-transacted context
DEBUG: 2006-07-20 18:08:55,123 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) Quartz_Worker-0 - allowing proxied method [beginTransaction] to proceed to real session
DEBUG: 2006-07-20 18:08:55,123 (org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:54)) Quartz_Worker-0 - begin
DEBUG: 2006-07-20 18:08:55,123 (org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:415)) Quartz_Worker-0 - opening JDBC connection
INFO: 2006-07-20 18:08:55,125 (com.pozitron.boomerang.util.BoomerangCP.logStatistics(BoomerangCP.java:230)) Quartz_Worker-0 - active: 2 (max: 10 ) idle: 8 (max: 10 )
DEBUG: 2006-07-20 18:08:55,131 (org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:59)) Quartz_Worker-0 - current autocommit status: false
DEBUG: 2006-07-20 18:08:55,131 (org.hibernate.jdbc.JDBCContext.afterTransactionBegin(JDBCContext.java:194)) Quartz_Worker-0 - after transaction begin
DEBUG: 2006-07-20 18:08:55,132 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) Quartz_Worker-0 - allowing proxied method [enableFilter] to proceed to real session
DEBUG: 2006-07-20 18:08:55,132 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) Quartz_Worker-0 - allowing proxied method [beginTransaction] to proceed to real session
DEBUG: 2006-07-20 18:08:55,133 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) Quartz_Worker-0 - allowing proxied method [enableFilter] to proceed to real session
DEBUG: 2006-07-20 18:08:55,133 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) Quartz_Worker-0 - allowing proxied method [createCriteria] to proceed to real session
DEBUG: 2006-07-20 18:08:55,135 (org.hibernate.jdbc.AbstractBatcher.logOpenPreparedStatement(AbstractBatcher.java:311)) Quartz_Worker-0 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG: 2006-07-20 18:08:55,135 (org.hibernate.jdbc.AbstractBatcher.log(AbstractBatcher.java:346)) Quartz_Worker-0 - select this_.SMS_ID as ID7_0_, this_1_.NAME as NAME7_0_, this_1_.DELETED_AT as DELETED3_7_0_, this_1_.DELETED as DELETED7_0_, this_1_.TYPE as TYPE7_0_, this_1_.CONTENT as CONTENT7_0_, this_1_.URL as URL7_0_, this_1_.EXPIRES_AFTER as EXPIRES8_7_0_, this_1_.SEND_NOTIFICATION as SEND9_7_0_, this_1_.OWNER_ID as OWNER10_7_0_, this_1_.SMSPROXY_ID as SMSPROXY11_7_0_, this_.LAST_SENT_DATE as LAST2_11_0_, this_2_.SCHEDULED_DATE as SCHEDULED2_12_0_, this_3_.SCHEDULED_HOUR as SCHEDULED2_13_0_, this_3_.SCHEDULED_MINUTE as SCHEDULED3_13_0_, this_4_.SCHEDULED_HOUR as SCHEDULED2_14_0_, this_4_.SCHEDULED_MINUTE as SCHEDULED3_14_0_, this_4_.SCHEDULED_DAYOFWEEK as SCHEDULED4_14_0_, this_5_.SCHEDULED_HOUR as SCHEDULED2_15_0_, this_5_.SCHEDULED_MINUTE as SCHEDULED3_15_0_, this_5_.SCHEDULED_DAYOFMONTH as SCHEDULED4_15_0_, this_6_.SPECIAL_TYPE as SPECIAL2_16_0_, this_6_.SCHEDULED_HOUR as SCHEDULED3_16_0_, this_6_.SCHEDULED_MINUTE as SCHEDULED4_16_0_, case when this_2_.ONEWAYSMS_ID is not null then 3 when this_3_.ONEWAYSMS_ID is not null then 4 when this_4_.ONEWAYSMS_ID is not null then 5 when this_5_.ONEWAYSMS_ID is not null then 6 when this_6_.ONEWAYSMS_ID is not null then 7 when this_7_.ONEWAYSMS_ID is not null then 8 when this_.SMS_ID is not null then 2 end as clazz_0_ from ONEWAY_SMS this_ inner join SMS this_1_ on this_.SMS_ID=this_1_.ID left outer join SCHEDULED_SMS this_2_ on this_.SMS_ID=this_2_.ONEWAYSMS_ID left outer join DAILY_SMS this_3_ on this_.SMS_ID=this_3_.ONEWAYSMS_ID left outer join WEEKLY_SMS this_4_ on this_.SMS_ID=this_4_.ONEWAYSMS_ID left outer join MONTHLY_SMS this_5_ on this_.SMS_ID=this_5_.ONEWAYSMS_ID left outer join SPECIAL_SMS this_6_ on this_.SMS_ID=this_6_.ONEWAYSMS_ID left outer join DIRECT_SMS this_7_ on this_.SMS_ID=this_7_.ONEWAYSMS_ID where ? = this_1_.deleted
DEBUG: 2006-07-20 18:08:55,136 (org.hibernate.jdbc.AbstractBatcher.getPreparedStatement(AbstractBatcher.java:424)) Quartz_Worker-0 - preparing statement
DEBUG: 2006-07-20 18:08:55,137 (org.hibernate.type.NullableType.nullSafeSet(NullableType.java:80)) Quartz_Worker-0 - binding 'false' to parameter: 1
DEBUG: 2006-07-20 18:08:55,139 (org.hibernate.jdbc.AbstractBatcher.logOpenResults(AbstractBatcher.java:327)) Quartz_Worker-0 - about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG: 2006-07-20 18:08:55,139 (org.hibernate.loader.Loader.doQuery(Loader.java:682)) Quartz_Worker-0 - processing result set
DEBUG: 2006-07-20 18:08:55,140 (org.hibernate.loader.Loader.doQuery(Loader.java:709)) Quartz_Worker-0 - done processing result set (0 rows)
DEBUG: 2006-07-20 18:08:55,140 (org.hibernate.jdbc.AbstractBatcher.logCloseResults(AbstractBatcher.java:334)) Quartz_Worker-0 - about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG: 2006-07-20 18:08:55,140 (org.hibernate.jdbc.AbstractBatcher.logClosePreparedStatement(AbstractBatcher.java:319)) Quartz_Worker-0 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG: 2006-07-20 18:08:55,141 (org.hibernate.jdbc.AbstractBatcher.closePreparedStatement(AbstractBatcher.java:470)) Quartz_Worker-0 - closing statement
DEBUG: 2006-07-20 18:08:55,141 (org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:839)) Quartz_Worker-0 - total objects hydrated: 0
DEBUG: 2006-07-20 18:08:55,142 (org.hibernate.engine.StatefulPersistenceContext.initializeNonLazyCollections(StatefulPersistenceContext.java:748)) Quartz_Worker-0 - initializing non-lazy collections
INFO: 2006-07-20 18:08:55,142 (com.pozitron.boomerang.tasks.TriggerTask.TRIG(TriggerTask.java:32)) Quartz_Worker-0 - There are 0 one way messages
INFO: 2006-07-20 18:08:55,143 (com.pozitron.boomerang.tasks.Task.execute(Task.java:36)) Quartz_Worker-0 - RECEIVE
INFO: 2006-07-20 18:08:55,143 (com.pozitron.boomerang.tasks.Task.execute(Task.java:48)) Quartz_Worker-0 - SEND
DEBUG: 2006-07-20 18:08:55,143 (org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:300)) Quartz_Worker-0 - allowing proxied method [getTransaction] to proceed to real session
DEBUG: 2006-07-20 18:08:55,143 (org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:103)) Quartz_Worker-0 - commit
DEBUG: 2006-07-20 18:08:55,144 (org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:332)) Quartz_Worker-0 - automatically flushing session
DEBUG: 2006-07-20 18:08:55,144 (org.hibernate.jdbc.JDBCContext.beforeTransactionCompletion(JDBCContext.java:185)) Quartz_Worker-0 - before transaction completion
DEBUG: 2006-07-20 18:08:55,144 (org.hibernate.impl.SessionImpl.beforeTransactionCompletion(SessionImpl.java:388)) Quartz_Worker-0 - before transaction completion
DEBUG: 2006-07-20 18:08:55,145 (org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:116)) Quartz_Worker-0 - committed JDBC Connection
DEBUG: 2006-07-20 18:08:55,145 (org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:199)) Quartz_Worker-0 - after transaction completion
DEBUG: 2006-07-20 18:08:55,145 (org.hibernate.jdbc.ConnectionManager.aggressiveRelease(ConnectionManager.java:398)) Quartz_Worker-0 - aggressively releasing JDBC connection
DEBUG: 2006-07-20 18:08:55,146 (org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:435)) Quartz_Worker-0 - releasing JDBC connection [ (o

that log does not change any of my previous statements.