Grouper Users - Open Discussion List

["Bee-Lindgren, Bert" <>]

Hello,

> ... Did not get all the way through the batch! 88720 != 88721 ...

Changelog entry 88721 failed to be processed. It might help to know what that change was, and it might help try to duplicate the problem. Can you query the changelog for some details about it?

Of course, PSP should have logged something about its failure to process that change; I would have expected an error message to be there before the log lines you sent. Also, it's a long shot, but might there be some information in the grouper_event log?  Or search for 88720 and 88721 in the log directory, obviously ignoring the "Did not get all the way through the batch!" messages.

The "Did not get all the way through the batch! 88720 != 88721" repeated over and over, right? If not, then retryOnError might not have been working.

Finally, if there aren't any other error messages, then we'll probably have to try to duplicate the problem with more verbose logging.

--Bert

---

From: <> on behalf of Scott Koranda <>
Sent: Thursday, January 12, 2017 11:09 AM
To: grouper-users
Subject: [grouper-users] Error on job: CHANGE_LOG_consumer_psp

 

Hello,

We have a Grouper 2.2.2 running in production. The deployment
uses the PSP to provision grouper memberships to OpenLDAP,
including the 'isMemberOf' attribute on a person record.

The deployment includes this configuration in
grouper-loader.properties:

changeLog.changeLogTempToChangeLog.quartz.cron = 0/10 * * * * ?
changeLog.consumer.psp.class = edu.internet2.middleware.psp.grouper.PspChangeLogConsumer
changeLog.consumer.psp.quartzCron = 5/10 * * * * ?
changeLog.consumer.psp.retryOnError = true
changeLog.psp.fullSync.class = edu.internet2.middleware.psp.grouper.PspChangeLogConsumer
changeLog.psp.fullSync.quartzCron = 0 0 0 * * ?

So temporary change logs are moved every 10 seconds.
The PSP also fires every 10 seconds, with 5 seconds of offset
from the temporary change log job. This gives us on average an
upper limit on latency of 15 seconds.

Last night we saw these errors in grouper_error.log:

2017-01-12 01:01:15,059: [DefaultQuartzScheduler_Worker-7] ERROR ChangeLogHelper.processRecords(281) -  - Did not get all the way through the batch! 88720 != 88721
2017-01-12 01:01:15,059: [DefaultQuartzScheduler_Worker-7] 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! 88720 != 88721
    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)
2017-01-12 01:01:15,081: [DefaultQuartzScheduler_Worker-7] 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! 88720 != 88721
    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)
2017-01-12 01:01:20,014: [DefaultQuartzScheduler_Worker-10] INFO  EventLog.info(156) -  - [81bd39d7cdb946a8b44306cb0e5de3d3,'GrouperSystem','application'] session: start (2ms)
2017-01-12 01:01:25,014: [DefaultQuartzScheduler_Worker-2] INFO  EventLog.info(156) -  - [58af231ef1ec47d98e1dbaa9f16c5e66,'GrouperSystem','application'] session: start (3ms)

A restart of the Grouper loader process made these errors go
away and PSP provisioning proceeded as we expect.

What would have caused those errors?

Why did a restart of the Grouper loader clear those errors?

What can we do in the future to prevent similar errors?

Thanks,

Scott K