Grouper
  1. Grouper
  2. GRP-737

[psp] fix "IllegalStateException: null session member" in a threaded environment

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Blocker Blocker
    • Resolution: Fixed
    • Affects Version/s: 2.1.0
    • Fix Version/s: 2.1.0
    • Component/s: provisioning
    • Labels:
      None

      Description

        Activity

        Hide
        Sebastien Gagne added a comment - - edited
        The stack trace is now a little different, it's no longer "null session member" but "Grouper session subject is null"

        Full stack trace for a PSP add member request:

        2012-02-23 09:48:00,174: [DefaultQuartzScheduler_Worker-7] INFO Psp.execute(873) - - Psp 'psp' - Calc XML:
        <psp:calcRequest xmlns:psp='http://grouper.internet2.edu/psp&#39; returnData='identifier'>
          <psp:id ID='langloiv'/>
          <psp:schemaEntity targetID='ldap' entityName='member'/>
        </psp:calcRequest>

        2012-02-23 09:48:00,175: [DefaultQuartzScheduler_Worker-7] ERROR BaseSpmlProvider.execute(139) - - Response[status=failure,error=unsupportedOperation,errorMessages={},requestID=2012/02/23-09:48:00.174]
        java.lang.reflect.InvocationTargetException
                at sun.reflect.GeneratedMethodAccessor172.invoke(Unknown Source)
                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)
                ... 20 more
        2012-02-23 09:48:00,176: [DefaultQuartzScheduler_Worker-7] ERROR PspChangeLogConsumer.processChangeLogEntries(455) - - PSP Consumer 'psp' - An error occurred processing sequence number 457
        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-23 09:48:00,186: [DefaultQuartzScheduler_Worker-7] ERROR ChangeLogHelper.processRecords(222) - - Error: PSP Consumer 'psp' - An error occurred processing sequence number 457, sequenceNumber: 457, 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)
        Show
        Sebastien Gagne added a comment - - edited The stack trace is now a little different, it's no longer "null session member" but "Grouper session subject is null" Full stack trace for a PSP add member request: 2012-02-23 09:48:00,174: [DefaultQuartzScheduler_Worker-7] INFO Psp.execute(873) - - Psp 'psp' - Calc XML: <psp:calcRequest xmlns:psp=' http://grouper.internet2.edu/psp&#39; returnData='identifier'>   <psp:id ID='langloiv'/>   <psp:schemaEntity targetID='ldap' entityName='member'/> </psp:calcRequest> 2012-02-23 09:48:00,175: [DefaultQuartzScheduler_Worker-7] ERROR BaseSpmlProvider.execute(139) - - Response[status=failure,error=unsupportedOperation,errorMessages={},requestID=2012/02/23-09:48:00.174] java.lang.reflect.InvocationTargetException         at sun.reflect.GeneratedMethodAccessor172.invoke(Unknown Source)         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)         ... 20 more 2012-02-23 09:48:00,176: [DefaultQuartzScheduler_Worker-7] ERROR PspChangeLogConsumer.processChangeLogEntries(455) - - PSP Consumer 'psp' - An error occurred processing sequence number 457 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-23 09:48:00,186: [DefaultQuartzScheduler_Worker-7] ERROR ChangeLogHelper.processRecords(222) - - Error: PSP Consumer 'psp' - An error occurred processing sequence number 457, sequenceNumber: 457, 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)
        Hide
        Sebastien Gagne added a comment -
        The problem is also there when the PSP is doing the automated Full Sync (in the -loader process). A manual full sync (gsh.sh -psp -bulkSync) still works properly.

        A new stack trace for that :


        2012-02-23 10:00:00,051: [DefaultQuartzScheduler_Worker-7] ERROR GrouperLoaderJob.runJob(387) - - Error on job: PSP_FULL_SYNC
        java.lang.IllegalStateException: null session member,
        Problem calling method fullSync on edu.internet2.middleware.psp.grouper.PspChangeLogConsumer
                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.filter.ComplementFilter.getResults(ComplementFilter.java:61)
                at edu.internet2.middleware.grouper.shibboleth.filter.AbstractFilter.getResults(AbstractFilter.java:36)
                at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.getAllStemNames(AllStemNamesDataConnector.java:103)
                at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector$1.callback(AllStemNamesDataConnector.java:66)
                at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector$1.callback(AllStemNamesDataConnector.java:64)
                at edu.internet2.middleware.grouper.GrouperSession.callbackGrouperSession(GrouperSession.java:645)
                at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.resolve(AllStemNamesDataConnector.java:62)
                at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.resolve(AllStemNamesDataConnector.java:43)
                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.getAllSourceIdentifiers(Psp.java:1416)
                at edu.internet2.middleware.psp.Psp.execute(Psp.java:640)
                at edu.internet2.middleware.psp.Psp.execute(Psp.java:601)
                at edu.internet2.middleware.psp.Psp.execute(Psp.java:800)
                at edu.internet2.middleware.psp.Psp.execute(Psp.java:758)
                at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.fullSync(PspChangeLogConsumer.java:318)
                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.grouper.util.GrouperUtil.invokeMethod(GrouperUtil.java:3893)
                at edu.internet2.middleware.grouper.util.GrouperUtil.callMethod(GrouperUtil.java:3844)
                at edu.internet2.middleware.grouper.util.GrouperUtil.callMethod(GrouperUtil.java:4028)
                at edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$9.runJob(GrouperLoaderType.java:966)
                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-23 10:00:00,204: [DefaultQuartzScheduler_Worker-7] ERROR GrouperLoaderJob.execute(284) - - Error running up job
        java.lang.IllegalStateException: null session member,
        Problem calling method fullSync on edu.internet2.middleware.psp.grouper.PspChangeLogConsumer
                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.filter.ComplementFilter.getResults(ComplementFilter.java:61)
                at edu.internet2.middleware.grouper.shibboleth.filter.AbstractFilter.getResults(AbstractFilter.java:36)
                at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.getAllStemNames(AllStemNamesDataConnector.java:103)
                at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector$1.callback(AllStemNamesDataConnector.java:66)
                at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector$1.callback(AllStemNamesDataConnector.java:64)
                at edu.internet2.middleware.grouper.GrouperSession.callbackGrouperSession(GrouperSession.java:645)
                at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.resolve(AllStemNamesDataConnector.java:62)
                at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.resolve(AllStemNamesDataConnector.java:43)
                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.getAllSourceIdentifiers(Psp.java:1416)
                at edu.internet2.middleware.psp.Psp.execute(Psp.java:640)
                at edu.internet2.middleware.psp.Psp.execute(Psp.java:601)
                at edu.internet2.middleware.psp.Psp.execute(Psp.java:800)
                at edu.internet2.middleware.psp.Psp.execute(Psp.java:758)
                at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.fullSync(PspChangeLogConsumer.java:318)
                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.grouper.util.GrouperUtil.invokeMethod(GrouperUtil.java:3893)
                at edu.internet2.middleware.grouper.util.GrouperUtil.callMethod(GrouperUtil.java:3844)
                at edu.internet2.middleware.grouper.util.GrouperUtil.callMethod(GrouperUtil.java:4028)
                at edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$9.runJob(GrouperLoaderType.java:966)
                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)
        Show
        Sebastien Gagne added a comment - The problem is also there when the PSP is doing the automated Full Sync (in the -loader process). A manual full sync (gsh.sh -psp -bulkSync) still works properly. A new stack trace for that : 2012-02-23 10:00:00,051: [DefaultQuartzScheduler_Worker-7] ERROR GrouperLoaderJob.runJob(387) - - Error on job: PSP_FULL_SYNC java.lang.IllegalStateException: null session member, Problem calling method fullSync on edu.internet2.middleware.psp.grouper.PspChangeLogConsumer         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.filter.ComplementFilter.getResults(ComplementFilter.java:61)         at edu.internet2.middleware.grouper.shibboleth.filter.AbstractFilter.getResults(AbstractFilter.java:36)         at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.getAllStemNames(AllStemNamesDataConnector.java:103)         at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector$1.callback(AllStemNamesDataConnector.java:66)         at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector$1.callback(AllStemNamesDataConnector.java:64)         at edu.internet2.middleware.grouper.GrouperSession.callbackGrouperSession(GrouperSession.java:645)         at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.resolve(AllStemNamesDataConnector.java:62)         at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.resolve(AllStemNamesDataConnector.java:43)         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.getAllSourceIdentifiers(Psp.java:1416)         at edu.internet2.middleware.psp.Psp.execute(Psp.java:640)         at edu.internet2.middleware.psp.Psp.execute(Psp.java:601)         at edu.internet2.middleware.psp.Psp.execute(Psp.java:800)         at edu.internet2.middleware.psp.Psp.execute(Psp.java:758)         at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.fullSync(PspChangeLogConsumer.java:318)         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.grouper.util.GrouperUtil.invokeMethod(GrouperUtil.java:3893)         at edu.internet2.middleware.grouper.util.GrouperUtil.callMethod(GrouperUtil.java:3844)         at edu.internet2.middleware.grouper.util.GrouperUtil.callMethod(GrouperUtil.java:4028)         at edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$9.runJob(GrouperLoaderType.java:966)         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-23 10:00:00,204: [DefaultQuartzScheduler_Worker-7] ERROR GrouperLoaderJob.execute(284) - - Error running up job java.lang.IllegalStateException: null session member, Problem calling method fullSync on edu.internet2.middleware.psp.grouper.PspChangeLogConsumer         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.filter.ComplementFilter.getResults(ComplementFilter.java:61)         at edu.internet2.middleware.grouper.shibboleth.filter.AbstractFilter.getResults(AbstractFilter.java:36)         at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.getAllStemNames(AllStemNamesDataConnector.java:103)         at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector$1.callback(AllStemNamesDataConnector.java:66)         at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector$1.callback(AllStemNamesDataConnector.java:64)         at edu.internet2.middleware.grouper.GrouperSession.callbackGrouperSession(GrouperSession.java:645)         at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.resolve(AllStemNamesDataConnector.java:62)         at edu.internet2.middleware.psp.shibboleth.AllStemNamesDataConnector.resolve(AllStemNamesDataConnector.java:43)         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.getAllSourceIdentifiers(Psp.java:1416)         at edu.internet2.middleware.psp.Psp.execute(Psp.java:640)         at edu.internet2.middleware.psp.Psp.execute(Psp.java:601)         at edu.internet2.middleware.psp.Psp.execute(Psp.java:800)         at edu.internet2.middleware.psp.Psp.execute(Psp.java:758)         at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.fullSync(PspChangeLogConsumer.java:318)         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.grouper.util.GrouperUtil.invokeMethod(GrouperUtil.java:3893)         at edu.internet2.middleware.grouper.util.GrouperUtil.callMethod(GrouperUtil.java:3844)         at edu.internet2.middleware.grouper.util.GrouperUtil.callMethod(GrouperUtil.java:4028)         at edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$9.runJob(GrouperLoaderType.java:966)         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)
        Hide
        Tom Zeller added a comment -
        Also reported by PSU :

        2012-02-17 13:40:12,945: [main] WARN GrouperLoader.scheduleDailyReportJob(460) - - grouper-loa
        der.properties key: daily.report.quartz.cron is not filled in so the daily report will not run
        2012-02-17 13:41:00,137: [DefaultQuartzScheduler_Worker-2] INFO Psp.getPSP(172) - - Loading psp from configuration directory 'null'
        2012-02-17 13:42:00,070: [DefaultQuartzScheduler_Worker-5] INFO PspChangeLogConsumer.processChangeLogEntry(433) - - PSP Consumer 'psp' - Change log entry 'ChangeLogEntry[timestamp=2012-02-17 10:31:55.958,sequence=529,category=membership,actionname=addMembership,contextId=62276c32835045968da9cdafb8af4c28,id=e5d59acf761e4e178b4527a815ad9274,fieldName=members,subjectId=aaw11,sourceId=ldap,membershipType=flattened,groupId=6a1317ac57064dab979874ef233bff97,groupName=ldaptest:psu:standing:facstaff,memberId=e5b4b218fd424f13a45cdef3a9c42b61,fieldId=5d729d84620e481e80c83523273e10da]'
        2012-02-17 13:42:00,075: [DefaultQuartzScheduler_Worker-5] INFO Psp.execute(869) - - Psp 'psp' - Calc CalcRequest[id=change_log_sequence_number:529,requestID=2012/02/17-13:42:00.072,returnData=everything]
        2012-02-17 13:42:00,079: [DefaultQuartzScheduler_Worker-5] INFO Psp.execute(873) - - Psp 'psp' - Calc XML:
        <psp:calcRequest xmlns:psp='http://grouper.internet2.edu/psp&#39; requestID='2012/02/17-13:42:00.072' returnData='everything'>
         <psp:id ID='change_log_sequence_number:529'/>
        </psp:calcRequest>

        2012-02-17 13:42:00,166: [DefaultQuartzScheduler_Worker-5] INFO Psp.execute(869) - - Psp 'psp' - Calc CalcRequest[id=aaw11,requestID=<null>,returnData=identifier,schemaEntityRef=SchemaEntityRef[targetID=ldap,entityName=member,isContainer=false]]
        2012-02-17 13:42:00,167: [DefaultQuartzScheduler_Worker-5] INFO Psp.execute(873) - - Psp 'psp' - Calc XML:
        <psp:calcRequest xmlns:psp='http://grouper.internet2.edu/psp&#39; returnData='identifier'>
         <psp:id ID='aaw11'/>
         <psp:schemaEntity targetID='ldap' entityName='member'/>
        </psp:calcRequest>

        2012-02-17 13:42:00,168: [DefaultQuartzScheduler_Worker-5] ERROR BaseSpmlProvider.execute(139) - - Response[status=failure,error=unsupportedOperation,errorMessages={},requestID=2012/02/17-13:42:00.166]
        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.processMembershipChange(PspChangeLogConsumer.java:663)
               at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processMembershipAdd(PspChangeLogConsumer.java:511)
               at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer$EventType$4.process(PspChangeLogConsumer.java:117)
               at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processChangeLogEntry(PspChangeLogConsumer.java:437)
               at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processChangeLogEntries(PspChangeLogConsumer.java:371)
               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.grouper.app.loader.GrouperLoaderType$4.runJob(GrouperLoaderT
        ype.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 i
        s stopped. Dont use it anymore, start another
               at edu.internet2.middleware.grouper.GrouperSession.internal_ThrowIllegalStateIfStopped(G
        rouperSession.java:95)
               at edu.internet2.middleware.grouper.GrouperSession.getSubject(GrouperSession.java:428)
               at edu.internet2.middleware.grouper.subj.CachingResolver.getFromFindByIdOrIdentifierCach
        e(CachingResolver.java:329)
               at edu.internet2.middleware.grouper.subj.CachingResolver.findByIdOrIdentifier(CachingRes
        olver.java:360)
               at edu.internet2.middleware.grouper.subj.ValidatingResolver.findByIdOrIdentifier(Validat
        ingResolver.java:187)
               at edu.internet2.middleware.grouper.SubjectFinder.findByIdOrIdentifier(SubjectFinder.jav
        a:145)
               at edu.internet2.middleware.grouper.shibboleth.dataConnector.MemberDataConnector$1.callb
        ack(MemberDataConnector.java:87)
               at edu.internet2.middleware.grouper.shibboleth.dataConnector.MemberDataConnector$1.callb
        ack(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.ShibbolethAttr
        ibuteResolver.resolveDataConnector(ShibbolethAttributeResolver.java:374)
               at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttr
        ibuteResolver.resolveDependencies(ShibbolethAttributeResolver.java:410)
               at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttr
        ibuteResolver.resolveAttribute(ShibbolethAttributeResolver.java:332)
               at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttr
        ibuteResolver.resolveAttributes(ShibbolethAttributeResolver.java:284)
               at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttr
        ibuteResolver.resolveAttributes(ShibbolethAttributeResolver.java:131)
               at edu.internet2.middleware.psp.shibboleth.SimpleAttributeAuthority.getAttributes(Simple
        AttributeAuthority.java:96)
               at edu.internet2.middleware.psp.shibboleth.SimpleAttributeAuthority.getAttributes(Simple
        AttributeAuthority.java:39)
               at edu.internet2.middleware.psp.Psp.execute(Psp.java:956)
               at edu.internet2.middleware.psp.Psp.execute(Psp.java:893)
               ... 21 more
        Show
        Tom Zeller added a comment - Also reported by PSU : 2012-02-17 13:40:12,945: [main] WARN GrouperLoader.scheduleDailyReportJob(460) - - grouper-loa der.properties key: daily.report.quartz.cron is not filled in so the daily report will not run 2012-02-17 13:41:00,137: [DefaultQuartzScheduler_Worker-2] INFO Psp.getPSP(172) - - Loading psp from configuration directory 'null' 2012-02-17 13:42:00,070: [DefaultQuartzScheduler_Worker-5] INFO PspChangeLogConsumer.processChangeLogEntry(433) - - PSP Consumer 'psp' - Change log entry 'ChangeLogEntry[timestamp=2012-02-17 10:31:55.958,sequence=529,category=membership,actionname=addMembership,contextId=62276c32835045968da9cdafb8af4c28,id=e5d59acf761e4e178b4527a815ad9274,fieldName=members,subjectId=aaw11,sourceId=ldap,membershipType=flattened,groupId=6a1317ac57064dab979874ef233bff97,groupName=ldaptest:psu:standing:facstaff,memberId=e5b4b218fd424f13a45cdef3a9c42b61,fieldId=5d729d84620e481e80c83523273e10da]' 2012-02-17 13:42:00,075: [DefaultQuartzScheduler_Worker-5] INFO Psp.execute(869) - - Psp 'psp' - Calc CalcRequest[id=change_log_sequence_number:529,requestID=2012/02/17-13:42:00.072,returnData=everything] 2012-02-17 13:42:00,079: [DefaultQuartzScheduler_Worker-5] INFO Psp.execute(873) - - Psp 'psp' - Calc XML: <psp:calcRequest xmlns:psp=' http://grouper.internet2.edu/psp&#39; requestID='2012/02/17-13:42:00.072' returnData='everything'>  <psp:id ID='change_log_sequence_number:529'/> </psp:calcRequest> 2012-02-17 13:42:00,166: [DefaultQuartzScheduler_Worker-5] INFO Psp.execute(869) - - Psp 'psp' - Calc CalcRequest[id=aaw11,requestID=<null>,returnData=identifier,schemaEntityRef=SchemaEntityRef[targetID=ldap,entityName=member,isContainer=false]] 2012-02-17 13:42:00,167: [DefaultQuartzScheduler_Worker-5] INFO Psp.execute(873) - - Psp 'psp' - Calc XML: <psp:calcRequest xmlns:psp=' http://grouper.internet2.edu/psp&#39; returnData='identifier'>  <psp:id ID='aaw11'/>  <psp:schemaEntity targetID='ldap' entityName='member'/> </psp:calcRequest> 2012-02-17 13:42:00,168: [DefaultQuartzScheduler_Worker-5] ERROR BaseSpmlProvider.execute(139) - - Response[status=failure,error=unsupportedOperation,errorMessages={},requestID=2012/02/17-13:42:00.166] 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.processMembershipChange(PspChangeLogConsumer.java:663)        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processMembershipAdd(PspChangeLogConsumer.java:511)        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer$EventType$4.process(PspChangeLogConsumer.java:117)        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processChangeLogEntry(PspChangeLogConsumer.java:437)        at edu.internet2.middleware.psp.grouper.PspChangeLogConsumer.processChangeLogEntries(PspChangeLogConsumer.java:371)        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.grouper.app.loader.GrouperLoaderType$4.runJob(GrouperLoaderT ype.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 i s stopped. Dont use it anymore, start another        at edu.internet2.middleware.grouper.GrouperSession.internal_ThrowIllegalStateIfStopped(G rouperSession.java:95)        at edu.internet2.middleware.grouper.GrouperSession.getSubject(GrouperSession.java:428)        at edu.internet2.middleware.grouper.subj.CachingResolver.getFromFindByIdOrIdentifierCach e(CachingResolver.java:329)        at edu.internet2.middleware.grouper.subj.CachingResolver.findByIdOrIdentifier(CachingRes olver.java:360)        at edu.internet2.middleware.grouper.subj.ValidatingResolver.findByIdOrIdentifier(Validat ingResolver.java:187)        at edu.internet2.middleware.grouper.SubjectFinder.findByIdOrIdentifier(SubjectFinder.jav a:145)        at edu.internet2.middleware.grouper.shibboleth.dataConnector.MemberDataConnector$1.callb ack(MemberDataConnector.java:87)        at edu.internet2.middleware.grouper.shibboleth.dataConnector.MemberDataConnector$1.callb ack(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.ShibbolethAttr ibuteResolver.resolveDataConnector(ShibbolethAttributeResolver.java:374)        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttr ibuteResolver.resolveDependencies(ShibbolethAttributeResolver.java:410)        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttr ibuteResolver.resolveAttribute(ShibbolethAttributeResolver.java:332)        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttr ibuteResolver.resolveAttributes(ShibbolethAttributeResolver.java:284)        at edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.ShibbolethAttr ibuteResolver.resolveAttributes(ShibbolethAttributeResolver.java:131)        at edu.internet2.middleware.psp.shibboleth.SimpleAttributeAuthority.getAttributes(Simple AttributeAuthority.java:96)        at edu.internet2.middleware.psp.shibboleth.SimpleAttributeAuthority.getAttributes(Simple AttributeAuthority.java:39)        at edu.internet2.middleware.psp.Psp.execute(Psp.java:956)        at edu.internet2.middleware.psp.Psp.execute(Psp.java:893)        ... 21 more
        Hide
        Tom Zeller added a comment -
        The grouper.psp-2.1.0.tar.gz package from the 2.1.0 release url contained grouper-shib-2.1.0-snapshot.jar which suffered from this bug because it was not built against the correct tag. This was a packaging issue rather than a bug.
        Show
        Tom Zeller added a comment - The grouper.psp-2.1.0.tar.gz package from the 2.1.0 release url contained grouper-shib-2.1.0-snapshot.jar which suffered from this bug because it was not built against the correct tag. This was a packaging issue rather than a bug.

          People

          • Assignee:
            Tom Zeller
            Reporter:
            Tom Zeller
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: