Grouper Users - Open Discussion List

[Julio Polo <>]

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