Uploaded image for project: 'Grouper'
  1. Grouper
  2. GRP-737

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

    Details

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

      Description

        Activity

        Hide
        sebgagne 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' 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
        sebgagne 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' 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
        sebgagne 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
        sebgagne 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
        tzeller@internet2.edu 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' 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' 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
        tzeller@internet2.edu 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' 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' 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
        tzeller@internet2.edu 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
        tzeller@internet2.edu 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:
            tzeller@internet2.edu Tom Zeller
            Reporter:
            tzeller@internet2.edu Tom Zeller
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: