Grouper Developers Forum

[Tom Zeller <>]

I think this highlights that psp logging levels for bulk operations
are not always appropriate for change log provisioning, leading to
confusion.

The psp does the right thing, which is to not provision the grouper
object that should not be provisioned, but it logs an error that it
cannot do so, which is not really an error.

Take a look at the <identifier /> for the group membership provisioned
service object in psp.xml :

  <pso id="groupMembership">
    <identifier ref="changeLogMembershipGroupDn"

and follow the reference to the <AttributeDefinition /> in psp-resolver.xml :

  <resolver:AttributeDefinition id="changeLogMembershipGroupDn"
      <resolver:Dependency ref="changeLogMembershipGroupName" />

and follow the dependency chain to :

  <resolver:AttributeDefinition id="changeLogMembershipGroupName" ...
    <resolver:Dependency ref="AddMembershipChangeLogDataConnector" />
    <resolver:Dependency ref="DeleteMembershipChangeLogDataConnector" />
    ...
    <grouper:Filter xsi:type="grouper:MINUS">
      <grouper:Filter
        xsi:type="grouper:NameInStem"
        name="${edu.internet2.middleware.psp.baseStem}"
        scope="SUB" />
      <grouper:Filter
        xsi:type="grouper:NameInStem"
        name="etc"
        scope="SUB" />
    </grouper:Filter>
  </resolver:AttributeDefinition>

and you will find it has the same (err, similar) baseStem filter as
the <resolver:DataConnector id="GroupDataConnector" /> used in bulk
provisioning operations.

So, when the psp tries to provision 'sad:X', it cannot calculate an
identifier since 'sad:X' is not a child of the baseStem, and
consequently does not provision 'sad:X'. The issue is that the psp
logs an error that it cannot calculate an identifier.

When provisioning the changelog, the psp will log an error for every
group that does not match the relevant data connector filter.

It probably should log to info ?

TomZ

On Tue, Jun 19, 2012 at 2:38 PM, Gagné Sébastien
<>
 wrote:
> Hello TomZ,
>
>
>
> I believe that the baseStem is ignored while provisining changelog events.
> The base stem seems to be taken into account while doing bulkDiff / bulkSync
> operation and everything seems fine.
>
>
>
> Thanks
>
>
>
> Here are the details :
>
>
>
> I configured the PSP so that only the baseStem = “udem” is provisioned to
> AD.
>
> edu.internet2.middleware.psp.baseStem=udem
>
>
>
>
>
> The psp-resolver is only checking baseStem’s groups.
>
>
>
> <resolver:DataConnector
>
>     id="GroupDataConnector"
>
>     xsi:type="grouper:GroupDataConnector">
>
>     <!-- The MINUS filter matches stems which match the first child filter
> and not the second. -->
>
>     <grouper:Filter xsi:type="grouper:MINUS">
>
>       <!-- The GroupInStem filter matches groups which are children of the
> given stem. -->
>
>
>
> <grouper:Filter          xsi:type="grouper:GroupInStem"
>
>         name="${edu.internet2.middleware.psp.baseStem}"
>
>         scope="SUB" />
>
>
>
> <grouper:Filter         xsi:type="grouper:GroupInStem"
>
>         name="etc"
>
>         scope="SUB" />
>
>
>
>     </grouper:Filter>
>
>
>
>
>
> Doing a bulkDiff returns only items located under “udem” :
>
>
>
> <psp:bulkDiffResponse xmlns:psp='http://grouper.internet2.edu/psp'
> status='success' requestID='2012/06/19-15:17:19.453'>
>
>   <psp:diffResponse status='success' requestID='2012/06/19-15:17:19.548'>
>
>     <psp:synchronizedResponse xmlns:psp='http://grouper.internet2.edu/psp'>
>
>       <psp:psoID ID='ou=dgtic,OU=People,DC=devsim,DC=umontreal,DC=ca'
> targetID='ldap'/>
>
>     </psp:synchronizedResponse>
>
>     <psp:id ID='udem:dgtic'/>
>
>   </psp:diffResponse>
>
>   <psp:diffResponse status='success' requestID='2012/06/19-15:17:19.808'>
>
>     <psp:synchronizedResponse xmlns:psp='http://grouper.internet2.edu/psp'>
>
>       <psp:psoID
> ID='ou=Groupes,ou=dgtic,OU=People,DC=devsim,DC=umontreal,DC=ca'
> targetID='ldap'/>
>
>     </psp:synchronizedResponse>
>
>     <psp:id ID='udem:dgtic:Groupes'/>
>
>   </psp:diffResponse>
>
> [...]
>
>   <psp:diffResponse status='success' requestID='2012/06/19-15:17:26.502'>
>
>     <psp:synchronizedResponse xmlns:psp='http://grouper.internet2.edu/psp'>
>
>       <psp:psoID ID='cn=grpAD2,OU=People,DC=devsim,DC=umontreal,DC=ca'
> targetID='ldap'/>
>
>     </psp:synchronizedResponse>
>
>     <psp:id ID='udem:grpAD2'/>
>
>   </psp:diffResponse>
>
>   <psp:diffResponse status='success' requestID='2012/06/19-15:17:26.845'>
>
>     <psp:synchronizedResponse xmlns:psp='http://grouper.internet2.edu/psp'>
>
>       <psp:psoID ID='cn=grpAD3,OU=People,DC=devsim,DC=umontreal,DC=ca'
> targetID='ldap'/>
>
>     </psp:synchronizedResponse>
>
>     <psp:id ID='udem:grpAD3'/>
>
>   </psp:diffResponse>
>
>   <psp:diffResponse status='success' requestID='2012/06/19-15:17:27.126'>
>
>     <psp:synchronizedResponse xmlns:psp='http://grouper.internet2.edu/psp'>
>
>       <psp:psoID
> ID='cn=fromAD1,ou=udem2,OU=People,DC=devsim,DC=umontreal,DC=ca'
> targetID='ldap'/>
>
>     </psp:synchronizedResponse>
>
>     <psp:id ID='udem:udem2:fromAD1'/>
>
>   </psp:diffResponse>
>
> </psp:bulkDiffResponse>
>
>
>
>
>
> But when I created a group in another stem (named “sad”), I got these in the
> logs :
>
>
>
> 2012-06-19 15:10:00,033: [DefaultQuartzScheduler_Worker-10] INFO
> PspChangeLogConsumer.processChangeLogEntry(513) -  - PSP Consumer 'psp' -
> Change log entry 'ChangeLogEntry[timestamp=2012-06-19
> 15:09:43.77,sequence=1533,category=group, actionname=addGroup,
> contextId=fb9b9343e53140058a84013a20a80134,
> id=9be476b7d6e5413e8a26ca5a31ec3916, name=sad:deletefromSAD,
> parentStemId=2c2204b76f06496bbbda7e0a613b97dc,
> displayName=sad:deletefromSAD,description=<null>]'
>
> 2012-06-19 15:10:00,033: [DefaultQuartzScheduler_Worker-10] INFO
> Psp.execute(1281) -  - Psp 'psp' - Sync
> SyncRequest[id=sad:deletefromSAD,requestID=2012/06/19-15:10:00.033,returnData=everything]
>
> 2012-06-19 15:10:00,034: [DefaultQuartzScheduler_Worker-10] INFO
> Psp.execute(1285) -  - Psp 'psp' - Sync SPML:
>
> <psp:syncRequest xmlns:psp='http://grouper.internet2.edu/psp'
> requestID='2012/06/19-15:10:00.033' returnData='everything'>
>
>   <psp:id ID='sad:deletefromSAD'/>
>
> </psp:syncRequest>
>
>
>
> It eventually ended with an LDAP Error and this
>
>
>
> 2012-06-19 15:10:00,911: [DefaultQuartzScheduler_Worker-10] ERROR
> Psp.execute(922) -  - Psp 'psp' - Calc XML:
>
> <psp:calcResponse xmlns:psp='http://grouper.internet2.edu/psp'
> status='failure' requestID='2012/06/19-15:10:00.035'
> error='noSuchIdentifier'>
>
>   <errorMessage>Unable to calculate provisioned object.</errorMessage>
>
>   <psp:id ID='sad:deletefromSAD'/>
>
> </psp:calcResponse>
>
>
>
>
>
> Sébastien Gagné,     | Analyste en informatique
>
> 514-343-6111 x33844  | Université de Montréal,
>
>                      | Pavillon Roger-Gaudry, local X-100-11
>
>