Grouper Users - Open Discussion List

[Jeffrey Crawford <>]

We are starting to put grouper into production and I've noticed something strange.

We perform a full sync early Sunday morning, but when Monday rolls around and people start trying to provision new group members I get the following error type in the logs:

============================================================
2015-09-21 11:22:00,035: [DefaultQuartzScheduler_Worker-4] INFO  PspChangeLogConsumer.processChangeLogEntries(481) -  - PSP Consumer 'psp' - Full sync is running, returning sequence number '149686'
2015-09-21 11:22:00,057: [DefaultQuartzScheduler_Worker-4] ERROR ChangeLogHelper.processRecords(281) -  - Did not get all the way through the batch! 149686 != 149690
2015-09-21 11:22:00,057: [DefaultQuartzScheduler_Worker-4] ERROR GrouperLoaderJob.runJob(433) -  - Error on job: CHANGE_LOG_consumer_psp
java.lang.RuntimeException: Error in loader job: null, check logs: Did not get all the way through the batch! 149686 != 149690
        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(GrouperLoaderJob.java:422)
        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(GrouperLoaderJob.java:315)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
2015-09-21 11:22:00,070: [DefaultQuartzScheduler_Worker-4] ERROR GrouperLoaderJob.execute(318) -  - Error running up job
java.lang.RuntimeException: Error in loader job: null, check logs: Did not get all the way through the batch! 149686 != 149690
        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(GrouperLoaderJob.java:422)
        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(GrouperLoaderJob.java:315)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
============================================================

Its as if the Full Sync isn't being notified that it's finished. The only error I see during the full sync is:

============================================================
2015-09-20 01:06:28,211: [DefaultQuartzScheduler_Worker-2] ERROR Psp.execute(1187) -  - Psp 'psp' - Diff DiffResponse[id=G046553637,
status=failure,error=noSuchIdentifier,errorMessages={Unable to calculate provisioned object.},requestID=2015/09/20-01:06:28.208]
2015-09-20 01:06:28,211: [DefaultQuartzScheduler_Worker-2] ERROR Psp.execute(1189) -  - Psp 'psp' - Diff XML:
<psp:diffResponse xmlns:psp='http://grouper.internet2.edu/psp' status='failure' requestID='2015/09/20-01:06:28.208' error='noSuchIde
ntifier'>
  <errorMessage>Unable to calculate provisioned object.</errorMessage>
  <psp:id ID='G046553637'/>
</psp:diffResponse>

2015-09-20 01:06:28,211: [DefaultQuartzScheduler_Worker-2] ERROR Psp.execute(1452) -  - Psp 'psp' - Sync SyncResponse[id=G046553637,status=failure,error=noSuchIdentifier,errorMessages={Unable to calculate provisioned object.},requestID=2015/09/20-01:06:28.208]
2015-09-20 01:06:28,212: [DefaultQuartzScheduler_Worker-2] ERROR Psp.execute(1454) -  - Psp 'psp' - Sync SPML:
<psp:syncResponse xmlns:psp='http://grouper.internet2.edu/psp' status='failure' requestID='2015/09/20-01:06:28.208' error='noSuchIdentifier'>
  <errorMessage>Unable to calculate provisioned object.</errorMessage>
  <psp:id ID='G046553637'/>
</psp:syncResponse>
============================================================

Not sure if the above can be causing the issue at the top of the message.

Jeffrey

Both pilots and IT professionals require training and currency before charging into clouds!

---------------------------------------