Grouper Users - Open Discussion List

[Chris Hyzer <>]

This is an exception thrown from the exception handler.  So unfortunately the underlying exception is not being caught.  I think if there is not a valid savepoint, and it cant rollback in an exception situation, it should just proceed with logging that and handle the underlying exception (Shilen agrees).  If you want to try this patch maybe it will help:

 

https://bugs.internet2.edu/jira/browse/GRP-1095

 

I can make you a zip so you don’t have to recompile, let me know.

 

Thanks,

Chris

 

From: [mailto:] On Behalf Of Julio Polo
Sent: Tuesday, December 09, 2014 3:47 PM
To:
Subject: [grouper-users] SAVEPOINT does not exist

 

We seem to encounter this SAVEPOINT error when we hit Grouper hard.   Is this a Hibernate bug where the failure to create the SAVEPOINT should have been caught prior to the rollback attempt to use it?

We are running Grouper 2.1.005

The error occurred during a call to the Grouper web service to add several members at once to a group.  A couple of those members were not added due to this error.  Here's the full error stack for the first instance of this error (there were four such errors in a two-minute span):

2014-12-08 19:49:22,256: [http-0.0.0.0-(port)-10] INFO  EventLog.info(156) - < _app_username - (ip addr) > - [(redacted),'_app_username','person'] add member: group='hawaii.edu:auto:sis:registration:LEE:HWST:107:54672:201530:enrolled' list='members' subject='(redacted)'/'person'/'UH core LDAP' (58ms)
2014-12-08 19:49:22,326: [http-0.0.0.0-(port)-10] INFO  EventLog.info(156) - < _app_username - (ip addr) > - [(redacted),'_app_username','person'] add member: group='hawaii.edu:auto:sis:registration:LEE:HWST:107:54672:201530:enrolled' list='members' subject='(redacted'/'person'/'UH core LDAP' (39ms)
2014-12-08 19:49:22,472: [http-0.0.0.0-(port)-15] INFO  EventLog.info(156) - < _app_username - (ip addr) > - [(redacted),'_app_username','person'] add member: group='hawaii.edu:menu:sis:registration:201530:enrolled:WOA:SSCI:300' list='members' subject='(redacted)'/'group'/'g:gsa' (293ms)
2014-12-08 19:49:22,723: [http-0.0.0.0-(port)-15] INFO  EventLog.info(156) - < _app_username - (ip addr) > - [(redacted),'_app_username','person'] add member: group='hawaii.edu:menu:sis:registration:201530:enrolled:WOA:SSCI:300' list='members' subject='(redacted)'/'group'/'g:gsa' (214ms)
2014-12-08 19:49:22,821: [http-0.0.0.0-(port)-10] ERROR WsAddMemberResult.assignResultCodeException(251) - < _app_username - (ip addr) > - WsSubjectLookup[
  subject=Subject id: (redacted), sourceId: UH core LDAP, name: (redacted),
  subjectFindResult=SUCCESS,subjectId=(redacted)], java.lang.RuntimeException: Problem rolling back savepoint
java.lang.RuntimeException: Problem rolling back savepoint
        at edu.internet2.middleware.grouper.hibernate.HibernateSession._internal_hibernateSessionCatch(HibernateSession.java:464)
        at edu.internet2.middleware.grouper.hibernate.HibernateSession.callbackHibernateSession(HibernateSession.java:581)
        at edu.internet2.middleware.grouper.ws.GrouperServiceLogic$1.callback(GrouperServiceLogic.java:298)
        at edu.internet2.middleware.grouper.internal.dao.hib3.Hib3TransactionDAO$1.callback(Hib3TransactionDAO.java:66)
        at edu.internet2.middleware.grouper.hibernate.HibernateSession.callbackHibernateSession(HibernateSession.java:571)
        at edu.internet2.middleware.grouper.internal.dao.hib3.Hib3TransactionDAO.transactionCallback(Hib3TransactionDAO.java:56)
        at edu.internet2.middleware.grouper.hibernate.GrouperTransaction.callbackGrouperTransaction(GrouperTransaction.java:87)
        at edu.internet2.middleware.grouper.ws.GrouperServiceLogic.addMember(GrouperServiceLogic.java:234)
        at edu.internet2.middleware.grouper.ws.coresoap.GrouperService.addMember(GrouperService.java:1262)
        at edu.internet2.middleware.grouper.ws.rest.GrouperServiceRest.addMember(GrouperServiceRest.java:315)
        at edu.internet2.middleware.grouper.ws.rest.method.GrouperWsRestPutGroup$1.service(GrouperWsRestPutGroup.java:63)
        at edu.internet2.middleware.grouper.ws.rest.method.GrouperWsRestPut$1.service(GrouperWsRestPut.java:110)
        at edu.internet2.middleware.grouper.ws.rest.method.GrouperRestHttpMethod$3.service(GrouperRestHttpMethod.java:104)
        at edu.internet2.middleware.grouper.ws.rest.GrouperRestServlet.service(GrouperRestServlet.java:199)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:723)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at edu.internet2.middleware.grouper.ws.GrouperServiceJ2ee.doFilter(GrouperServiceJ2ee.java:659)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:615)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606)
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
        at java.lang.Thread.run(Thread.java:662)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: SAVEPOINT 3d56b48f_14a2c6437d5_69c1 does not exist
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
        at com.mysql.jdbc.Util.getInstance(Util.java:381)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1031)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:957)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3376)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3308)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1837)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1961)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2537)
        at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1564)
        at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1485)
        at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4615)
        at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:829)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.hibernate.jdbc.BorrowedConnectionProxy.invoke(BorrowedConnectionProxy.java:74)
        at com.sun.proxy.$Proxy8.rollback(Unknown Source)
        at edu.internet2.middleware.grouper.hibernate.HibernateSession._internal_hibernateSessionCatch(HibernateSession.java:462)
        ... 30 more

Is this a bug or shall we just throw more memory at the problem?

Julio Polo
University of Hawaii