Skip to Content.
Sympa Menu

grouper-dev - RE: [grouper-dev] PSP changelog provisioning exception

Subject: Grouper Developers Forum

List archive

RE: [grouper-dev] PSP changelog provisioning exception


Chronological Thread 
  • From: Gagné Sébastien <>
  • To: "Tom Zeller" <>
  • Cc: <>
  • Subject: RE: [grouper-dev] PSP changelog provisioning exception
  • Date: Wed, 22 Feb 2012 14:42:54 -0500

For some reason, group renaming works.  I had failures with adding/deleting a member to a group before and after successful group rename, that’s strange. Maybe the bug is because the subject that was added is null (I don’t think so, it’s before the find…) ? But it’s related to a find subject request

 

I had hopes that setting the following to true would help, but it didn’t work :

subjects.startRootSessionIfOneIsntStarted = true

 

Checking in the code, I think a patch to this might be to add :

 

GrouperSourceAdapter.java

public static GrouperSession internal_getSessionOrRootForSubjectFinder() {

 

      if(activeSession !=null && (activeSession not stopped || we don’t want to create another one from config)) {

            return activeSession;

      }

 

This might work, but it won’t fix the root cause why the Session stops in the first place…

 

 

 

Full stack trace if you need it :

 

2012-02-22 14:17:00,150: [DefaultQuartzScheduler_Worker-1] ERROR BaseSpmlProvider.execute(139) -  - Response[status=failure,error=unsupportedOperation,errorMessages={},requestID=2012/02/22-14:17:00.149]

java.lang.reflect.InvocationTargetException

        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 edu.internet2.middleware.psp.spml.provider.BaseSpmlProvider.execute(BaseSpmlProvider.java:123)

        at edu.internet2.middleware.psp.spml.config.PsoReference.getReferences(PsoReference.java:112)

        at edu.internet2.middleware.psp.spml.config.PsoReferences.getReferences(PsoReferences.java:150)

        at edu.internet2.middleware.psp.spml.config.Pso.getPSO(Pso.java:253)

        at edu.internet2.middleware.psp.Psp.execute(Psp.java:964)

        at edu.internet2.middleware.psp.Psp.execute(Psp.java:893)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processModification(PspChangeLogConsumer.java:705)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processMembershipAdd(PspChangeLogConsumer.java:655)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer$EventType$6.process(PspChangeLogConsumer.java:126)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processChangeLogEntry(PspChangeLogConsumer.java:517)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processChangeLogEntries(PspChangeLogConsumer.java:451)

        at edu.internet2.middleware.grouper.changeLog.ChangeLogHelper.processRecords(ChangeLogHelper.java:204)

        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$4.runJob(GrouperLoaderType.java:539)

        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(GrouperLoaderJob.java:379)

        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(GrouperLoaderJob.java:281)

        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)

        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)

 

Caused by: java.lang.IllegalStateException: Grouper session subject is null, probably since it is stopped.  Dont use it anymore, start another

        at edu.internet2.middleware.grouper.GrouperSession.internal_ThrowIllegalStateIfStopped(GrouperSession.java:95)

        at edu.internet2.middleware.grouper.GrouperSession.getSubject(GrouperSession.java:428)

        at edu.internet2.middleware.grouper.subj.CachingResolver.getFromFindByIdOrIdentifierCache(CachingResolver.java:329)

        at edu.internet2.middleware.grouper.subj.CachingResolver.findByIdOrIdentifier(CachingResolver.java:360)

        at edu.internet2.middleware.grouper.subj.ValidatingResolver.findByIdOrIdentifier(ValidatingResolver.java:187)

        at edu.internet2.middleware.grouper.SubjectFinder.findByIdOrIdentifier(SubjectFinder.java:145)

        at edu.internet2.middleware.grouper.shibboleth.dataConnector.MemberDataConnector$1.callback(MemberDataConnector.java:87)

        at edu.internet2.middleware.grouper.shibboleth.dataConnector.MemberDataConnector$1.callback(MemberDataConnector.java:61)

        at edu.internet2.middleware.grouper.GrouperSession.callbackGrouperSession(GrouperSession.java:645)

        at edu.internet2.middleware.grouper.shibboleth.dataConnector.MemberDataConnector.resolve(MemberDataConnector.java:60)

        at edu.internet2.middleware.grouper.shibboleth.dataConnector.MemberDataConnector.resolve(MemberDataConnector.java:51)

        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.ContextualDataConnector.resolve(ContextualDataConnector.java:77)

        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.ContextualDataConnector.resolve(ContextualDataConnector.java:31)

        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver.resolveDataConnector(ShibbolethAttributeResolver.java:374)

        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver.resolveDependencies(ShibbolethAttributeResolver.java:410)

        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver.resolveAttribute(ShibbolethAttributeResolver.java:332)

        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver.resolveAttributes(ShibbolethAttributeResolver.java:284)

        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttributeResolver.resolveAttributes(ShibbolethAttributeResolver.java:131)

        at edu.internet2.middleware.psp.shibboleth.SimpleAttributeAuthority.getAttributes(SimpleAttributeAuthority.java:96)

        at edu.internet2.middleware.psp.shibboleth.SimpleAttributeAuthority.getAttributes(SimpleAttributeAuthority.java:39)

        at edu.internet2.middleware.psp.Psp.execute(Psp.java:956)

        at edu.internet2.middleware.psp.Psp.execute(Psp.java:893)

        ... 21 more

 

 

2012-02-22 14:17:00,151: [DefaultQuartzScheduler_Worker-1] ERROR PspChangeLogConsumer.processChangeLogEntries(455) -  - PSP Consumer 'psp' - An error occurred processing sequence number 425

java.lang.ClassCastException: org.openspml.v2.msg.spml.Response cannot be cast to edu.internet2.middleware.psp.spml.request.CalcResponse

        at edu.internet2.middleware.psp.spml.config.PsoReference.getReferences(PsoReference.java:112)

        at edu.internet2.middleware.psp.spml.config.PsoReferences.getReferences(PsoReferences.java:150)

        at edu.internet2.middleware.psp.spml.config.Pso.getPSO(Pso.java:253)

        at edu.internet2.middleware.psp.Psp.execute(Psp.java:964)

        at edu.internet2.middleware.psp.Psp.execute(Psp.java:893)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processModification(PspChangeLogConsumer.java:705)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processMembershipAdd(PspChangeLogConsumer.java:655)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer$EventType$6.process(PspChangeLogConsumer.java:126)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processChangeLogEntry(PspChangeLogConsumer.java:517)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processChangeLogEntries(PspChangeLogConsumer.java:451)

        at edu.internet2.middleware.grouper.changeLog.ChangeLogHelper.processRecords(ChangeLogHelper.java:204)

        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$4.runJob(GrouperLoaderType.java:539)

        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(GrouperLoaderJob.java:379)

        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(GrouperLoaderJob.java:281)

        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)

        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)

 

 

2012-02-22 14:17:00,168: [DefaultQuartzScheduler_Worker-1] ERROR ChangeLogHelper.processRecords(222) -  - Error: PSP Consumer 'psp' - An error occurred processing sequence number 425, sequenceNumber: 425, java.lang.ClassCastException: org.openspml.v2.msg.spml.Response cannot be cast to edu.internet2.middleware.psp.spml.request.CalcResponse

        at edu.internet2.middleware.psp.spml.config.PsoReference.getReferences(PsoReference.java:112)

        at edu.internet2.middleware.psp.spml.config.PsoReferences.getReferences(PsoReferences.java:150)

        at edu.internet2.middleware.psp.spml.config.Pso.getPSO(Pso.java:253)

        at edu.internet2.middleware.psp.Psp.execute(Psp.java:964)

        at edu.internet2.middleware.psp.Psp.execute(Psp.java:893)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processModification(PspChangeLogConsumer.java:705)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processMembershipAdd(PspChangeLogConsumer.java:655)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer$EventType$6.process(PspChangeLogConsumer.java:126)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processChangeLogEntry(PspChangeLogConsumer.java:517)

        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processChangeLogEntries(PspChangeLogConsumer.java:451)

        at edu.internet2.middleware.grouper.changeLog.ChangeLogHelper.processRecords(ChangeLogHelper.java:204)

        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$4.runJob(GrouperLoaderType.java:539)

        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(GrouperLoaderJob.java:379)

        at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(GrouperLoaderJob.java:281)

        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)

        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)

 

 

De : [mailto:] De la part de Tom Zeller
Envoyé : 22 février 2012 11:52
À : Gagné Sébastien
Cc :
Objet : Re: [grouper-dev] PSP changelog provisioning exception

 

Yeah, sigh. For some reason I have not tracked down yet, I am not doing the right thing with grouper sessions in the threaded loader environment. 

 

It is on my list, and must be resolved before the 2.1.0 release.

 

TomZ

On Tuesday, February 21, 2012, Gagné Sébastien wrote:

I forgot to say that I’m using the 2.1 release (API, UI and PSP) I downloaded today from http://www.internet2.edu/grouper/release/2.1.0/

 

 

 

Hi,

I’m testing out the provisioning from the changelog and ran into this exception :

 

From grouper_error.log

 

2012-02-21 14:16:00,072: [DefaultQuartzScheduler_Worker-2] INFO  Psp.execute(869) -  - Psp 'psp' - Calc CalcRequest[id=UdeM:Stem2:LalalaHumansteps,requestID=2012/02/21-14:16:00.072,returnData=everything]

2012-02-21 14:16:00,072: [DefaultQuartzScheduler_Worker-2] INFO  Psp.execute(873) -  - Psp 'psp' - Calc XML:

<psp:calcRequest xmlns:psp='http://grouper.internet2.edu/psp' requestID='2012/02/21-14:16:00.072' returnData='everything'>

  <psp:id ID='UdeM:Stem2:LalalaHumansteps'/>

</psp:calcRequest>

 

2012-02-21 14:16:00,073: [DefaultQuartzScheduler_Worker-2] ERROR PspChangeLogConsumer.processChangeLogEntries(455) -  - PSP Consumer 'psp' - An error occurred processing sequence number 380

java.lang.IllegalStateException: null session member

        at edu.internet2.middleware.grouper.GrouperSession.validate(GrouperSession.java:511)

        at edu.internet2.middleware.grouper.GrouperSession.validate(GrouperSession.java:301)

        at edu.internet2.middleware.grouper.StemFinder.findByName(StemFinder.java:96)

        at edu.internet2.middleware.grouper.StemFinder.findByName(StemFinder.java:77)

(and much more exceptions after that)

 

I checked tried with manual the psp operations and everything seems  fine (see excerpts below) : bulkDiff returns appropriate data and no error;  bulkSync completes successfully and the group is provisioned to AD.

 

I tried making another change via the UI and I get the same exception. bulkSync still provisions to AD

 

 

 

$ bin/gsh.sh -psp -bulkDiff

 

<psp:diffResponse status='success' requestID='2012/02/21-14:30:08.976'>

    <addRequest xmlns='urn:oasis:names:tc:SPML:2:0' entityName='group' requestID='2012/02/21-14:30:09.245' targetId='ldap' returnData='everything'>

      <psoID ID='cn=LalalaHumansteps,ou=Stem2,ou=UdeM,ou=People,dc=devsim,dc=umontreal,dc=ca' targetID='ldap'/>

      <data>

        <dsml:attr xmlns:dsml='urn




Archive powered by MHonArc 2.6.16.

Top of Page