[GRP-737] [psp] fix "IllegalStateException: null session member" in a threaded environment Created: 22/Feb/12  Updated: 25/Feb/12  Resolved: 25/Feb/12

Status: Resolved
Project: Grouper
Component/s: provisioning
Affects Version/s: 2.1.0
Fix Version/s: 2.1.0

Type: Bug Priority: Blocker
Reporter: Tom Zeller Assignee: Tom Zeller
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   

Fix new session handling in 2.1.0.

https://lists.internet2.edu/sympa/arc/grouper-dev/2012-02/msg00050.html



 Comments   
Comment by Sebastien Gagne (Inactive) [ 23/Feb/12 ]

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)

Comment by Sebastien Gagne (Inactive) [ 23/Feb/12 ]

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)

Comment by tzeller@internet2.edu [ 23/Feb/12 ]

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

Comment by tzeller@internet2.edu [ 25/Feb/12 ]

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.

Generated at Thu Mar 28 12:50:03 UTC 2024 using Jira 9.4.15#940015-sha1:bdaa9cbecfb6791ea579749728cab771f0dfe90b.