Grouper Users - Open Discussion List

[Francesco Malvezzi <>]

Hallo all,

my loader now fails to provision groups located in a certain stem. I am
quite sure I did something wrong while trying to allow members of a
group to administer the stem.

But I'm not able now to understand the error message:

AttributeDefName[name=etc:attribute:rules:rule,uuid=882ca8b0a872498a9380e1989852d1cc],
assign, AttributeAssignStemDelegate[

stem=Stem[displayName=unimore:plains:entitlements,name=unimore:plains:entitlements,uuid=d17ec55c75504522a443e4f17eae2183,creator=38b2fd58d1bb4d4bafd180df0b558781,modifier=38b2fd58d1bb4d4bafd180df0b558781]]

could you provide me a pointer to understand the message?

thank you,

Francesco

full trace:

2012-10-31 10:23:49,178: [main] INFO  EventLog.info(141) -  -
[685c907aef384273bbcd3b46646784b3,'GrouperSystem','application']
session: start (216ms)
2012-10-31 10:23:49,183: [main] INFO  EventLog.info(141) -  -
[2b71ef9a131d47d49ba16b51e943b109,'GrouperSystem','application']
session: start (4ms)
2012-10-31 10:23:49,267: [main] INFO  EventLog.info(141) -  -
[6ae80621baa94d44afd3dfaa9d616c4b,'GrouperSystem','application']
session: start (1ms)
2012-10-31 10:23:49,295: [main] INFO  EventLog.info(141) -  -
[e32c1d6dbf3e4a98a495e649a4c6edb9,'GrouperSystem','application']
session: start (2ms)
2012-10-31 10:23:49,374: [main] INFO  EventLog.info(141) -  -
[1230eedee9e3447eb9d797b25f22727d,'GrouperSystem','application']
session: start (4ms)
2012-10-31 10:23:49,758: [main] INFO  EventLog.info(141) -  -
[ae4b9b5e6f1f41479c97bde1f1e86184,'GrouperSystem','application']
session: start (1ms)
2012-10-31 10:23:50,026: [main] INFO  EventLog.info(141) -  -
[0ad816aab83e416e8776bbc8a4c851f7,'GrouperSystem','application']
session: start (1ms)
2012-10-31 10:23:50,041: [main] INFO  EventLog.info(141) -  -
[bec2055ecf4642be9403e2b34d83d0b8,'GrouperSystem','application']
session: start (1ms)
2012-10-31 10:23:50,254: [main] INFO  EventLog.info(141) -  -
[bc42de8181b84cd681f7f60f7616f5cc,'GrouperSystem','application']
session: start (16ms)
2012-10-31 10:23:50,259: [main] INFO  EventLog.info(141) -  -
[19fef317dcf7411085064a0df5fbfd21,'GrouperSystem','application']
session: start (1ms)
2012-10-31 10:23:50,262: [main] INFO  EventLog.info(141) -  -
[5cdb10f6f6f24cf9b63c45eb6517d1a1,'GrouperSystem','application']
session: start (1ms)
2012-10-31 10:23:50,272: [main] INFO  EventLog.info(141) -  -
[5cdb10f6f6f24cf9b63c45eb6517d1a1,'GrouperSystem','application'] add
group type: 'grouperLoader' (8ms)
2012-10-31 10:23:50,450: [main] INFO  EventLog.info(141) -  -
[ca01bbd4288147b99a3081a395aa4331,'GrouperSystem','application']
session: start (1ms)
2012-10-31 10:23:50,453: [main] INFO  EventLog.info(141) -  -
[71d52aedda7e4473a6b799d24e7e987e,'GrouperSystem','application']
session: start (1ms)
2012-10-31 10:23:52,257: [main] DEBUG Psp.onNewContextCreated(2008) -  -
PSP 'psp' - Loading [stem1, stem2, stem3, group1, sambaGroup1, group2,
sambaGroup2, group3, sambaGroup3, member1, member2, member3,
groupMembership1, groupMembership2, groupMembership3, memberMembership1,
memberMembership2, memberMembership3, groupMemberMembership1,
groupMemberMembership2, groupMemberMembership3] PSO definitions
2012-10-31 10:23:52,342: [main] DEBUG
LdapSpmlTarget.onNewContextCreated(1072) -  - Target 'ldap2' - Loading
ldap pool 'ldap2Pool'
2012-10-31 10:23:52,343: [main] DEBUG
LdapSpmlTarget.onNewContextCreated(1074) -  - Target 'ldap2' - Loading
ldap pool 'ldap2Pool' from spring
2012-10-31 10:23:52,373: [main] DEBUG
LdapSpmlTarget.onNewContextCreated(1072) -  - Target 'ldap2-secondary' -
Loading ldap pool 'ldap2secondaryPool'
2012-10-31 10:23:52,374: [main] DEBUG
LdapSpmlTarget.onNewContextCreated(1074) -  - Target 'ldap2-secondary' -
Loading ldap pool 'ldap2secondaryPool' from spring
2012-10-31 10:23:52,403: [main] DEBUG
LdapSpmlTarget.onNewContextCreated(1072) -  - Target 'b1' - Loading ldap
pool 'b1Pool'
2012-10-31 10:23:52,404: [main] DEBUG
LdapSpmlTarget.onNewContextCreated(1074) -  - Target 'b1' - Loading ldap
pool 'b1Pool' from spring
2012-10-31 10:23:52,422: [main] INFO  PspCLI.run(126) -  - Starting psp
2012-10-31 10:23:52,424: [main] DEBUG PspCLI.run(127) -  - Starting psp
with options
PspOptions[args={-sync,unimore:plains:entitlements},confDir=<null>,interval=0,iterations=0,logSpml=false,outputFile=<null>,printRequests=false]
2012-10-31 10:23:52,430: [main] INFO  Psp.execute(1281) -  - Psp 'psp' -
Sync
SyncRequest[id=unimore:plains:entitlements,requestID=<null>,returnData=everything]
2012-10-31 10:23:52,437: [main] INFO  Psp.execute(1285) -  - Psp 'psp' -
Sync SPML:
<psp:syncRequest xmlns:psp='http://grouper.internet2.edu/psp'
returnData='everything'>
  <psp:id ID='unimore:plains:entitlements'/>
</psp:syncRequest>

2012-10-31 10:23:52,439: [main] INFO  Psp.execute(1030) -  - Psp 'psp' -
Diff
DiffRequest[id=unimore:plains:entitlements,requestID=2012/10/31-10:23:52.439,returnData=everything]
2012-10-31 10:23:52,440: [main] INFO  Psp.execute(1034) -  - Psp 'psp' -
Diff XML:
<psp:diffRequest xmlns:psp='http://grouper.internet2.edu/psp'
requestID='2012/10/31-10:23:52.439' returnData='everything'>
  <psp:id ID='unimore:plains:entitlements'/>
</psp:diffRequest>

2012-10-31 10:23:52,441: [main] INFO  Psp.execute(885) -  - Psp 'psp' -
Calc
CalcRequest[id=unimore:plains:entitlements,requestID=2012/10/31-10:23:52.441,returnData=everything]
2012-10-31 10:23:52,442: [main] INFO  Psp.execute(889) -  - Psp 'psp' -
Calc XML:
<psp:calcRequest xmlns:psp='http://grouper.internet2.edu/psp'
requestID='2012/10/31-10:23:52.441' returnData='everything'>
  <psp:id ID='unimore:plains:entitlements'/>
</psp:calcRequest>

2012-10-31 10:23:52,446: [main] DEBUG Psp.execute(970) -  - PSP 'psp' -
Calc
CalcRequest[id=unimore:plains:entitlements,requestID=2012/10/31-10:23:52.441,returnData=everything]
Resolving attributes '[stemDn, stemDnAlternateChangeLog,
stemObjectclass, stemOu, stemDescription, simpleGroupDn,
simpleGroupDnAlternate, simpleGroupDnAlternateChangeLog,
simpleGroupObjectclass, cn, groupDescription, hasMember, membersLdap,
membersGsa, sambaGroupDn, sambaGroupDnAlternate,
sambaGroupDnAlternateChangeLog, sambaGroupObjectclass, gidNumber,
sambaGroupType, sambaSID, memberUid, memberDn1, memberObjectclass,
memberIsMemberOf, changeLogMembershipGroupDn,
changeLogMembershipSubjectName, changeLogMembershipSambaSubjectId,
changeLogMembershipLdapSubjectId, changeLogMembershipGroupSubjectName,
changeLogMembershipMemberDn, changeLogMembershipGroupName,
changeLogMembershipGroupMemberDn, memberDn2, memberDn3]'.
2012-10-31 10:23:52,447: [main] DEBUG
SimpleAttributeAuthority.getAttributes(86) -  - get attributes
'unimore:plains:entitlements' aa 'psp.AttributeAuthority'
2012-10-31 10:23:52,514: [main] INFO  EventLog.info(141) -  -
[a32db7574e2347cd9679cc602dee5663,'GrouperSystem','application']
session: start (3ms)
2012-10-31 10:23:52,557: [main] ERROR BaseSpmlProvider.execute(139) -  -
Response[status=failure,error=unsupportedOperation,errorMessages={},requestID=2012/10/31-10:23:52.425]
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.PspCLI.run(PspCLI.java:138)
        at edu.internet2.middleware.psp.PspCLI.main(PspCLI.java:84)
        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.app.gsh.GrouperShell.handleSpecialCase(GrouperShell.java:189)
        at
edu.internet2.middleware.grouper.app.gsh.GrouperShell.main(GrouperShell.java:129)
        at
edu.internet2.middleware.grouper.app.gsh.GrouperShellWrapper.main(GrouperShellWrapper.java:16)
Caused by: java.lang.RuntimeException: Multiple assignments exist:
AttributeDefName[name=etc:attribute:rules:rule,uuid=882ca8b0a872498a9380e1989852d1cc],
assign, AttributeAssignStemDelegate[

stem=Stem[displayName=unimore:plains:entitlements,name=unimore:plains:entitlements,uuid=d17ec55c75504522a443e4f17eae2183,creator=38b2fd58d1bb4d4bafd180df0b558781,modifier=38b2fd58d1bb4d4bafd180df0b558781]]
        at
edu.internet2.middleware.grouper.attr.assign.AttributeAssignBaseDelegate.retrieveAssignmentHelper(AttributeAssignBaseDelegate.java:248)
        at
edu.internet2.middleware.grouper.attr.assign.AttributeAssignBaseDelegate.retrieveAssignment(AttributeAssignBaseDelegate.java:228)
        at
edu.internet2.middleware.grouper.attr.value.AttributeValueDelegate.retrieveAssignmentForRead(AttributeValueDelegate.java:608)
        at
edu.internet2.middleware.grouper.attr.value.AttributeValueDelegate.retrieveValuesString(AttributeValueDelegate.java:411)
        at
edu.internet2.middleware.grouper.shibboleth.dataConnector.StemDataConnector.buildAttributes(StemDataConnector.java:158)
        at
edu.internet2.middleware.grouper.shibboleth.dataConnector.StemDataConnector$1.callback(StemDataConnector.java:97)
        at
edu.internet2.middleware.grouper.shibboleth.dataConnector.StemDataConnector$1.callback(StemDataConnector.java:56)
        at
edu.internet2.middleware.grouper.GrouperSession.callbackGrouperSession(GrouperSession.java:654)
        at
edu.internet2.middleware.grouper.shibboleth.dataConnector.StemDataConnector.resolve(StemDataConnector.java:55)
        at
edu.internet2.middleware.grouper.shibboleth.dataConnector.StemDataConnector.resolve(StemDataConnector.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.resolveDependencies(ShibbolethAttributeResolver.java:412)
        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:972)
        at edu.internet2.middleware.psp.Psp.execute(Psp.java:909)
        at edu.internet2.middleware.psp.Psp.execute(Psp.java:1099)
        at edu.internet2.middleware.psp.Psp.execute(Psp.java:1054)
        at edu.internet2.middleware.psp.Psp.execute(Psp.java:1351)
        at edu.internet2.middleware.psp.Psp.execute(Psp.java:1305)
        ... 14 more
2012-10-31 10:23:52,559: [main] INFO  PspCLI.run(146) -  - End of psp
execution : 135 ms