Grouper Users - Open Discussion List

[Philip Harle <>]

I've been doing some further work with this and have installed PSPNG on the 
server, and disabled PSP. However, I still experience a similar 
NullPointerException when using PSPNG - this leads me into thinking that it's 
not actually the PSP/PSPNG at fault.

On further investigation I note that the majority of users in the 
grouper_pit_members table have a context_id (assuming to have been set prior 
to the upgrade to 2.3?). They also have a hibernate_version_number of '0' and 
subject_identifier0 is NULL.
However, when an action involving any of these users is undertaken in 
Grouper, for instance adding the user to a group, their entry in 
grouper_pit_members is updated; the hibernate_version_number is set to '1', 
subject_identifier0 is set to the same as the subject_id, and most 
importantly the context_id is set to NULL.

It strikes me that this could be the source of the problem, however I'm not 
too sure where I should be looking to resolve it. Can anyone give me any 
pointers please?

Thanks,
Phil

> -----Original Message-----
> From: 
> 
>  [
> ]
>  On Behalf Of Philip Harle
> Sent: 17 October 2016 09:54
> To: Hyzer, Chris 
> <>;
>  
> 
> Subject: [grouper-users] RE: Grouper 2.3 upgrade - NULL context_id causing
> PSP issues
> 
> Hi Chris,
> 
> I've applied the patch and restarted, but unfortunately the issue persists.
> 
> 2016-10-17 09:49:02,810: [DefaultQuartzScheduler_Worker-2] ERROR
> ChangeLogHelper.processRecords(252) -  - Error
> java.lang.IllegalStateException: Stopwatch already started.
>         at org.apache.commons.lang.time.StopWatch.start(StopWatch.java:121)
>         at
> edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processCh
> angeLogEntries(PspChangeLogConsumer.java:489)
>         at
> edu.internet2.middleware.grouper.changeLog.ChangeLogHelper.processRec
> ords(ChangeLogHelper.java:242)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$4.runJo
> b(GrouperLoaderType.java:629)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(Gr
> ouperLoaderJob.java:416)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(
> GrouperLoaderJob.java:318)
>         at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
>         at
> org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> va:573)
> 2016-10-17 09:49:02,812: [DefaultQuartzScheduler_Worker-2] ERROR
> ChangeLogHelper.processRecords(283) -  - Did not get all the way through
> the batch! -1 != 3301924
> 2016-10-17 09:49:02,812: [DefaultQuartzScheduler_Worker-2] ERROR
> GrouperLoaderJob.runJob(436) -  - Error on job:
> CHANGE_LOG_consumer_psp
> java.lang.RuntimeException: Error in loader job: null, check logs: Error:
> java.lang.IllegalStateException: Stopwatch already started.
>         at org.apache.commons.lang.time.StopWatch.start(StopWatch.java:121)
>         at
> edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processCh
> angeLogEntries(PspChangeLogConsumer.java:489)
>         at
> edu.internet2.middleware.grouper.changeLog.ChangeLogHelper.processRec
> ords(ChangeLogHelper.java:242)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$4.runJo
> b(GrouperLoaderType.java:629)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(Gr
> ouperLoaderJob.java:416)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(
> GrouperLoaderJob.java:318)
>         at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
>         at
> org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> va:573)
> Did not get all the way through the batch! -1 != 3301924
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(Gr
> ouperLoaderJob.java:425)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(
> GrouperLoaderJob.java:318)
>         at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
>         at
> org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> va:573)
> 2016-10-17 09:49:02,843: [DefaultQuartzScheduler_Worker-2] ERROR
> GrouperLoaderJob.execute(321) -  - Error running up job
> java.lang.RuntimeException: Error in loader job: null, check logs: Error:
> java.lang.IllegalStateException: Stopwatch already started.
>         at org.apache.commons.lang.time.StopWatch.start(StopWatch.java:121)
>         at
> edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processCh
> angeLogEntries(PspChangeLogConsumer.java:489)
>         at
> edu.internet2.middleware.grouper.changeLog.ChangeLogHelper.processRec
> ords(ChangeLogHelper.java:242)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$4.runJo
> b(GrouperLoaderType.java:629)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(Gr
> ouperLoaderJob.java:416)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(
> GrouperLoaderJob.java:318)
>         at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
>         at
> org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> va:573)
> Did not get all the way through the batch! -1 != 3301924
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(Gr
> ouperLoaderJob.java:425)
>         at
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(
> GrouperLoaderJob.java:318)
>         at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
>         at
> org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> va:573)
> 2016-10-17 09:49:04,010: [DefaultQuartzScheduler_Worker-4] INFO
> EventLog.info(156) -  -
> [9a651f49eab44c94a319c212ee00100a,'GrouperSystem','application'] session:
> start (2ms)
> 
> Any further ideas?
> 
> Thanks,
> Phil
> 
> > -----Original Message-----
> > From: Hyzer, Chris 
> > [mailto:]
> > Sent: 15 October 2016 16:15
> > To: Philip Harle 
> > <>;
> >  grouper-
> > 
> > Subject: RE: Grouper 2.3 upgrade - NULL context_id causing PSP issues
> >
> > I made a patch for this, can you please try it?
> >
> > https://bugs.internet2.edu/jira/browse/GRP-1385
> >
> > grouper_v2_3_0_psp_patch_0
> >
> > Thanks
> > Chris
> >
> > -----Original Message-----
> > From: 
> > 
> >  [
> > ]
> >  On Behalf Of Philip Harle
> > Sent: Friday, October 14, 2016 10:22 AM
> > To: 
> > 
> > Subject: [grouper-users] Grouper 2.3 upgrade - NULL context_id causing
> > PSP issues
> >
> > Hi,
> >
> > We're currently upgrading of a clone of our live Grouper 2.2.2
> > installation to
> > 2.3.0 using the grouperInstaller upgrade method.
> > We've managed to upgrade the API, UI and WS, and all is looking well.
> > I'm now working on upgrading the PSP and have hit an issue.
> >
> > The background PSP sync (run as part of our grouperloader service)
> > isn't working and we're seeing the following in grouper_error.log:
> >
> > 2016-10-14 15:10:00,028: [DefaultQuartzScheduler_Worker-7] ERROR
> > ChangeLogHelper.processRecords(252) -  - Error
> > java.lang.NullPointerException
> >         at
> >
> edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processCh
> > angeLogEntries(PspChangeLogConsumer.java:510)
> >         at
> >
> edu.internet2.middleware.grouper.changeLog.ChangeLogHelper.processRec
> > ords(ChangeLogHelper.java:242)
> >         at
> >
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$4.runJo
> > b(GrouperLoaderType.java:629)
> >         at
> >
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(Gr
> > ouperLoaderJob.java:416)
> >         at
> >
> edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(
> > GrouperLoaderJob.java:318)
> >         at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
> >         at
> >
> org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.ja
> > va:573)
> > 2016-10-14 15:10:00,029: [DefaultQuartzScheduler_Worker-7] ERROR
> > ChangeLogHelper.processRecords(283) -  - Did not get all the way
> > through the batch! -1 != 3301919
> >
> > From what I can tell this is because we had a small number of entries
> > in grouper_change_log_entry with a NULL context_id. I cleared these
> > out of the table, and the error no longer appeared in the log.
> > However, when making any change in grouper it is still creating a new
> > entry in the table with a NULL context_id.
> > Any ideas why this might be the case?
> >
> >
> > Our eventual plan is to move away from PSP in favour of PSPNG, but I
> > feel we need to fix the above issue before proceeding.
> > Although, as an aside, can PSPNG be installed using the
> > grouperInstaller on an installation that has been upgraded from 2.2,
> > or do we need to install/configure it manually?
> >
> >
> > Thanks,
> > Phil
> >
> > ---
> > Phil Harle
> > IT Service
> > Newcastle University