Grouper Users - Open Discussion List

[Colin Hudler <>]

I'm in the midst of some operational concerns at the moment. I hope to 
have time to investigate what happened to me. The sequence of events and 
immediate error suggested it would be easy to reproduce. I haven't tried 
yet, but the error hasn't happened again either. On this system, 
grouper-loader runs the SyncFlatTables job every minute. There was no 
upgrade. Perhaps I had accidentally started multiple grouper-loaders...again

On 3/2/11 8:59 AM, Shilen Patel wrote:
> I think this error can only happen if the change log daemon did not
> process the group creation that's the owner of the membership that's
> failing to get created in the flat table. And I think that should only
> happen if change log entries were removed from the change log before
> getting processed by the change log daemon or if the Grouper instance
> was upgraded from 1.5 (or before) and the SyncFlatTables script was not
> run. And actually, I'm not sure if xml-import adds change log entries.
> If it doesn't, then the SyncFlatTables script would need to run after an
> xml-import too and we should document that.
>
> So as long as you do an initial sync and you're running the change log
> daemon often (every minute is the default if the loader is running),
> then this shouldn't become a problem. Though I suppose if we wanted to,
> we could have the code verify that all the foreign keys exist, but that
> might get expensive.
>
> Thanks!
>
> -- Shilen
>
>
> On 3/1/11 9:53 PM, Tom Barton wrote:
> > Grouper developers,
> >
> > Is this a bug? If so, is there a jira issue for it?
> >
> > Thanks,
> > Tom
> >
> > On 2/23/2011 11:57 AM, Chris Hyzer wrote:
> > > Shilen can correct me if wrong, but I think a membership is trying to
> > > be inserted into the flat membership table where the group is not in
> > > the flat group table. I think if you run this in GSH it should fix it...
> > >
> > > new SyncFlatTables().sendNotifications(false).syncAllFlatTables();
> > >
> > > Thanks,
> > > Chris
> > >
> > >
> > > -----Original Message-----
> > > From: 
> > >
> > > [mailto:]
> > >  On Behalf Of Colin Hudler
> > > Sent: Wednesday, February 23, 2011 12:45 PM
> > > To: 
> > >
> > > Subject: [grouper-users] Grouper changelog/flatmembership error
> > >
> > > Greetings,
> > >
> > > Today I decided to toy around with grouper ESB things, and get
> > > notifications over XMPP. I'm running 1.6.3 with a large registry on
> > > Oracle 11g2. It is a purely development server. I setup
> > > grouper-loader.properties like this:
> > >
> > > changeLog.consumer.xmpp.class =
> > > edu.internet2.middleware.grouper.changeLog.esb.consumer.EsbConsumer
> > > changeLog.consumer.xmpp.quartzCron = 0 * * * * ?
> > > changeLog.consumer.xmpp.elfilter = event.eventType eq 'GROUP_DELETE'
> > > \|\| event.eventType eq 'GROUP_ADD' \|\| event.eventType eq
> > > 'MEMBERSHIP_DELETE' \|\| event.eventType eq 'MEMBERSHIP_ADD'
> > > changeLog.consumer.xmpp.publisher.class =
> > > edu.internet2.middleware.grouper.changeLog.esb.consumer.EsbXmppPublisher
> > > changeLog.consumer.xmpp.publisher.server = im.uchicago.edu
> > > changeLog.consumer.xmpp.publisher.port = 5222
> > > changeLog.consumer.xmpp.publisher.username = grouper_user
> > > changeLog.consumer.xmpp.publisher.password = sekret
> > > changeLog.consumer.xmpp.publisher.recipient = 
> > >
> > > changeLog.consumer.xmpp.publisher.addSubjectAttributes = uid
> > >
> > > I took most of this from
> > > <https://spaces.internet2.edu/display/Grouper/Grouper+ESB+connector+configuration+examples>.
> > >
> > > I fired up gsh.sh -loader, and everything worked *really well*.. for a
> > > while. Every minute I got a huge batch (backlog?) of notification
> > > messages via jabber in json. Things went sour when some changes were
> > > made to grouper (via java API) while the consumer was running. The
> > > following was logged:
> > >
> > > 2011-02-23 11:19:54,077: [main] INFO EventLog.info(141) - -
> > > [70466727b03f4c4fb6e2799da6fa1da2,'GrouperSystem','application'] delete
> > > member: group='uc:Reference:email:routing:oncampus' list='members'
> > > subject='51884090U'/'person'/'ucmcdb
> > > ' (433ms)
> > > 2011-02-23 11:20:00,032: [DefaultQuartzScheduler_Worker-1] INFO
> > > EventLog.info(141) - -
> > > [2da2780ac728490a916b8ea833e24fc4,'GrouperSystem','application']
> > > session: start (3ms)
> > > 2011-02-23 11:20:14,720: [DefaultQuartzScheduler_Worker-2] WARN
> > > JDBCExceptionReporter.logExceptions(77) - - SQL Error: 2291, SQLState:
> > > 23000
> > > 2011-02-23 11:20:14,721: [DefaultQuartzScheduler_Worker-2] ERROR
> > > JDBCExceptionReporter.logExceptions(78) - - ORA-02291: integrity
> > > constraint (GROUPER.FK_FLAT_MSHIP_OWNER_GROUP_ID) violated - parent key
> > > not found
> > >
> > > 2011-02-23 11:20:14,721: [DefaultQuartzScheduler_Worker-2] WARN
> > > JDBCExceptionReporter.logExceptions(77) - - SQL Error: 2291, SQLState:
> > > 23000
> > > 2011-02-23 11:20:14,721: [DefaultQuartzScheduler_Worker-2] ERROR
> > > JDBCExceptionReporter.logExceptions(78) - - ORA-02291: integrity
> > > constraint (GROUPER.FK_FLAT_MSHIP_OWNER_GROUP_ID) violated - parent key
> > > not found
> > >
> > > 2011-02-23 11:20:14,722: [DefaultQuartzScheduler_Worker-2] ERROR
> > > AbstractFlushingEventListener.performExecutions(301) - - Could not
> > > synchronize database state with session
> > > org.hibernate.exception.ConstraintViolationException: could not insert:
> > > [edu.internet2.middleware.grouper.flat.FlatMembership]
> > > at
> > > org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:71)
> > >
> > > at
> > > org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
> > >
> > > at
> > > org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2272)
> > >
> > > at
> > > org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2665)
> > >
> > > at
> > > org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:60)
> > >
> > > at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:279)
> > > at
> > > org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263)
> > > at
> > > org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:167)
> > > at
> > > org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
> > >
> > > at
> > > org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
> > >
> > > at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
> > > at
> > > edu.internet2.middleware.grouper.hibernate.ByObject.saveBatch(ByObject.java:254)
> > >
> > > at
> > > edu.internet2.middleware.grouper.hibernate.ByObjectStatic$8.callback(ByObjectStatic.java:518)
> > >
> > > at
> > > edu.internet2.middleware.grouper.hibernate.HibernateSession.callbackHibernateSession(HibernateSession.java:500)
> > >
> > > at
> > > edu.internet2.middleware.grouper.hibernate.ByObjectStatic.saveBatch(ByObjectStatic.java:505)
> > >
> > > at
> > > edu.internet2.middleware.grouper.internal.dao.hib3.Hib3FlatMembershipDAO.saveBatch(Hib3FlatMembershipDAO.java:49)
> > >
> > > at
> > > edu.internet2.middleware.grouper.changeLog.ChangeLogTempToEntity.processMembershipAdd(ChangeLogTempToEntity.java:581)
> > >
> > > at
> > > edu.internet2.middleware.grouper.changeLog.ChangeLogTempToEntity.processMembershipAdd(ChangeLogTempToEntity.java:622)
> > >
> > > at
> > > edu.internet2.middleware.grouper.changeLog.ChangeLogTempToEntity.access$800(ChangeLogTempToEntity.java:47)
> > >
> > > at
> > > edu.internet2.middleware.grouper.changeLog.ChangeLogTempToEntity$1.callback(ChangeLogTempToEntity.java:108)
> > >
> > > at
> > > edu.internet2.middleware.grouper.hibernate.HibernateSession.callbackHibernateSession(HibernateSession.java:500)
> > >
> > > at
> > > edu.internet2.middleware.grouper.changeLog.ChangeLogTempToEntity.convertRecords(ChangeLogTempToEntity.java:85)
> > >
> > > at
> > > edu.internet2.middleware.grouper.changeLog.ChangeLogTempToEntity.convertRecords(ChangeLogTempToEntity.java:153)
> > >
> > > at
> > > edu.internet2.middleware.grouper.changeLog.ChangeLogTempToEntity.convertRecords(ChangeLogTempToEntity.java:153)
> > >
> > > <...repeated many times...>
> > > at
> > > edu.internet2.middleware.grouper.changeLog.ChangeLogTempToEntity.convertRecords(ChangeLogTempToEntity.java:153)
> > >
> > > at
> > > edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$4.runJob(GrouperLoaderType.java:755)
> > >
> > > at
> > > edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(GrouperLoaderJob.java:344)
> > >
> > > at
> > > edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(GrouperLoaderJob.java:247)
> > >
> > > at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
> > > at
> > > org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
> > >
> > > Caused by: java.sql.BatchUpdateException: ORA-02291: integrity
> > > constraint (GROUPER.FK_FLAT_MSHIP_OWNER_GROUP_ID) violated - parent key
> > > not found
> > >
> > > at
> > > oracle.jdbc.driver.OraclePreparedStatement.executeBatch(OraclePreparedStatement.java:10055)
> > >
> > > at
> > > oracle.jdbc.driver.OracleStatementWrapper.executeBatch(OracleStatementWrapper.java:213)
> > >
> > > at
> > > com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1723)
> > >
> > > at
> > > org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48)
> > >
> > > at
> > > org.hibernate.jdbc.BatchingBatcher.addToBatch(BatchingBatcher.java:34)
> > > at
> > > org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2252)
> > >
> > > ... 63 more
> > > 2011-02-23 11:20:14,736: [DefaultQuartzScheduler_Worker-2] ERROR
> > > GrouperUtil.logErrorNextException(562) - - Next exception
> > > java.sql.SQLException: ORA-02291: integrity constraint
> > > (GROUPER.FK_FLAT_MSHIP_OWNER_GROUP_ID) violated - parent key not found
> > >
> > > This problem stays (the loader keeps logging it), and change
> > > notifications simply stopped coming through XMPP.