Grouper Developers Forum

[Tom Zeller <>]

My assumption has been that the containers (e.g.
ou=groups,dc=example,dc=edu) for provisioned objects already exist.

In ldap.properties, you changed

 edu.internet2.middleware.psp.groupsBaseDn=ou=groups,dc=example,dc=edu

to

 
edu.internet2.middleware.psp.groupsBaseDn=ou=UdeM,OU=People,DC=umontreal,DC=ca

correct ?

I am not sure I would characterize this as a bug, perhaps a gotcha,
which should be documented better.

Is better documentation acceptable ?

TomZ

2012/3/6 Gagné Sébastien 
<>:
> Hi,
>
> I encountered a weird bug when retesting our installation.
>
>
>
> I specified a base stem in grouper.properties
> (edu.internet2.middleware.psp.baseStem=UdeM). This stem will start a new
> branch in our AD (i.e. ou=UdeM,ou=People,dc=test,dc=ca) which does not
> currently exists (ou=People does exist). This caused bulkSync and the
> changelog Provisionning to return error each time they tried to provision a
> new stem I created under UdeM (i.e. UdeM:Test1). I tried a lot of things
> before finding the problem : you need to manually create the baseStem in AD,
> doing so solved all the problems and allowed me to do a full sync without
> problems.
>
>
>
> Is this normal behaviour ? I would think that Grouper should provision the
> baseStem if it’s required in the LDAP. Should I open a JIRA about it ?
>
>
>
>
>
> I should mention that bulkDiff and bulkCalc were returning the appropriate
> data during all this time.
>
>
>
> Here is our trace logs for the exception during bulkSync :
>
>
>
> --- in the console ---
>
>
>
> <psp:bulkSyncResponse xmlns:psp='http://grouper.internet2.edu/psp'
> status='failure' requestID='2012/03/06-13:08:57.833'>
>
>   <psp:syncResponse>
>
>     <addResponse xmlns='urn:oasis:names:tc:SPML:2:0' status='failure'
> requestID='2012/03/06-13:08:58.151' error='customError'>
>
>       <errorMessage>[LDAP: error code 32 - 0000208D: NameErr: DSID-0310020A,
> problem 2001 (NO_OBJECT), data 0, best match of:
>
>         'OU=People,DC=umontreal,DC=ca'
>
> _]</errorMessage>
>
>     </addResponse>
>
>     <psp:id ID='UdeM:tt1'/>
>
>   </psp:syncResponse>
>
> </psp:bulkSyncResponse>
>
>
>
>
>
> --- In the logs ---
>
>
>
> 2012-03-06 13:08:50,533: [main] WARN  ApiConfig.printConfigOnce(212) -  -
> Grouper starting up: version: 2.1.0, build date: 2012/03/05 13:12:33, env:
> <no label configured>
>
> grouper.properties read from:
> /app/grouper/grouper.apiBinary-2.1.0/conf/grouper.properties
>
> Grouper current directory is: /app/grouper/grouper.apiBinary-2.1.0/bin
>
> log4j.properties read from:
> /app/grouper/grouper.apiBinary-2.1.0/conf/log4j.properties
>
> Grouper logs are not using log4j: class
> org.apache.commons.logging.impl.SLF4JLocationAwareLog
>
> grouper.hibernate.properties:
> /app/grouper/grouper.apiBinary-2.1.0/conf/grouper.hibernate.properties
>
> grouper.hibernate.properties:
> dv_grouper@jdbc:oracle:thin:@s-or-DVGDIs-dev1.dit.umontreal.ca:1521:DVGIAPPA
>
> sources.xml read from:
> /app/grouper/grouper.apiBinary-2.1.0/conf/sources.xml
>
> sources.xml groupersource id: g:gsa
>
> sources.xml ldap source id:   ldap: ldap.properties
>
> sources.xml groupersource id: grouperEntities
>
> 2012-03-06 13:08:55,334: [main] INFO  EventLog.info(141) -  -
> [ecbf9c3265754050bab89553cb09e13b,'GrouperSystem','application'] session:
> start (129ms)
>
> 2012-03-06 13:08:55,387: [main] INFO  EventLog.info(141) -  -
> [6d717a4adccb4b0b9fad59c03c8057d0,'GrouperSystem','application'] session:
> start (3ms)
>
> 2012-03-06 13:08:55,405: [main] INFO  EventLog.info(141) -  -
> [5e6b99abb0dd47d897ea453e7e36723a,'GrouperSystem','application'] session:
> start (0ms)
>
> 2012-03-06 13:08:55,465: [main] INFO  EventLog.info(141) -  -
> [8dde71641a91402380ceda240239b9d8,'GrouperSystem','application'] session:
> start (5ms)
>
> 2012-03-06 13:08:55,825: [main] INFO  EventLog.info(141) -  -
> [6fca0c69a91e417aae42c3644ee2015c,'GrouperSystem','application'] session:
> start (1ms)
>
> 2012-03-06 13:08:56,080: [main] INFO  EventLog.info(141) -  -
> [a12c6b2548114d92a962b0a89d6c2adb,'GrouperSystem','application'] session:
> start (0ms)
>
> 2012-03-06 13:08:56,089: [main] INFO  EventLog.info(141) -  -
> [50a2f06f2ae144f787512505ab80a520,'GrouperSystem','application'] session:
> start (1ms)
>
> 2012-03-06 13:08:56,798: [main] INFO  EventLog.info(141) -  -
> [a2972065bd624c0191763056269bf6d0,'GrouperSystem','application'] session:
> start (5ms)
>
> 2012-03-06 13:08:56,809: [main] INFO  EventLog.info(141) -  -
> [3f36c3789313421399a648277177ffc9,'GrouperSystem','application'] session:
> start (7ms)
>
> 2012-03-06 13:08:56,811: [main] INFO  EventLog.info(141) -  -
> [4b2bb66ce4084abd8a35ec5ab6d1d7aa,'GrouperSystem','application'] session:
> start (1ms)
>
> 2012-03-06 13:08:56,818: [main] INFO  EventLog.info(141) -  -
> [4b2bb66ce4084abd8a35ec5ab6d1d7aa,'GrouperSystem','application'] add group
> type: 'grouperLoader' (6ms)
>
> 2012-03-06 13:08:56,948: [main] INFO  EventLog.info(141) -  -
> [d899fc36a79b43fba9518da56399a0bf,'GrouperSystem','application'] session:
> start (1ms)
>
> 2012-03-06 13:08:56,950: [main] INFO  EventLog.info(141) -  -
> [5522f0dad5e545359cf9a6215bd4eabd,'GrouperSystem','application'] session:
> start (1ms)
>
> 2012-03-06 13:08:57,818: [main] INFO  PspCLI.run(126) -  - Starting psp
>
> 2012-03-06 13:08:57,829: [main] INFO  Psp.execute(750) -  - Psp 'psp' -
> BulkSync
> BulkSyncRequest[id=edu.internet2.middleware.psp.spml.request.BulkProvisioningRequest,requestID=<null>,returnData=everything,onError=resume]
>
> 2012-03-06 13:08:57,833: [main] INFO  Psp.execute(754) -  - Psp 'psp' -
> BulkSync SPML:
>
> <psp:bulkSyncRequest xmlns:psp='http://grouper.internet2.edu/psp'
> returnData='everything' onError='resume'>
>
>   <psp:id
> ID='edu.internet2.middleware.psp.spml.request.BulkProvisioningRequest'/>
>
> </psp:bulkSyncRequest>
>
>
>
> 2012-03-06 13:08:57,834: [main] INFO  Psp.execute(593) -  - Psp 'psp' -
> BulkDiff
> BulkDiffRequest[id=edu.internet2.middleware.psp.spml.request.BulkProvisioningRequest,requestID=2012/03/06-13:08:57.834,returnData=everything,onError=resume]
>
> 2012-03-06 13:08:57,834: [main] INFO  Psp.execute(597) -  - Psp 'psp' -
> BulkDiff SPML:
>
> <psp:bulkDiffRequest xmlns:psp='http://grouper.internet2.edu/psp'
> requestID='2012/03/06-13:08:57.834' returnData='everything'
> onError='resume'>
>
>   <psp:id
> ID='edu.internet2.middleware.psp.spml.request.BulkProvisioningRequest'/>
>
> </psp:bulkDiffRequest>
>
>
>
> 2012-03-06 13:08:57,888: [main] INFO  EventLog.info(141) -  -
> [14a5cb07b37945afa31fd61cdff9f336,'GrouperSystem','application'] session:
> start (4ms)
>
> 2012-03-06 13:08:57,907: [main] WARN  Psp.getAllSourceIdentifiers(1447) -  -
> PSP 'psp' - Unable to resolve attribute 'groupNames'
>
> 2012-03-06 13:08:57,908: [main] INFO  Psp.execute(1030) -  - Psp 'psp' -
> Diff
> DiffRequest[id=UdeM:tt1,requestID=2012/03/06-13:08:57.908,returnData=everything,schemaEntityRef=SchemaEntityRef[targetID=ldap,entityName=stem,isContainer=false]]
>
> 2012-03-06 13:08:57,909: [main] INFO  Psp.execute(1034) -  - Psp 'psp' -
> Diff XML:
>
> <psp:diffRequest xmlns:psp='http://grouper.internet2.edu/psp'
> requestID='2012/03/06-13:08:57.908' returnData='everything'>
>
>   <psp:id ID='UdeM:tt1'/>
>
>   <psp:schemaEntity targetID='ldap' entityName='stem'/>
>
> </psp:diffRequest>
>
>
>
> 2012-03-06 13:08:57,911: [main] INFO  Psp.execute(885) -  - Psp 'psp' - Calc
> CalcRequest[id=UdeM:tt1,requestID=2012/03/06-13:08:57.911,returnData=everything,schemaEntityRef=SchemaEntityRef[targetID=ldap,entityName=stem,isContainer=false]]
>
> 2012-03-06 13:08:57,911: [main] INFO  Psp.execute(889) -  - Psp 'psp' - Calc
> XML:
>
> <psp:calcRequest xmlns:psp='http://grouper.internet2.edu/psp'
> requestID='2012/03/06-13:08:57.911' returnData='everything'>
>
>   <psp:id ID='UdeM:tt1'/>
>
>   <psp:schemaEntity targetID='ldap' entityName='stem'/>
>
> </psp:calcRequest>
>
>
>
> 2012-03-06 13:08:57,944: [main] INFO  Psp.execute(914) -  - Psp 'psp' - Calc
> CalcResponse[status=success,requestID=2012/03/06-13:08:57.911]
>
> 2012-03-06 13:08:57,945: [main] INFO  Psp.execute(916) -  - Psp 'psp' - Calc
> XML:
>
> <psp:calcResponse xmlns:psp='http://grouper.internet2.edu/psp'
> status='success' requestID='2012/03/06-13:08:57.911'>
>
>   <psp:id ID='UdeM:tt1'/>
>
>   <psp:pso entityName='stem'>
>
>     <psoID ID='ou=tt1,ou=UdeM,OU=People,DC=umontreal,DC=ca'
> targetID='ldap'/>
>
>     <data>
>
>       <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core'
> name='objectClass'>
>
>         <dsml:value>top</dsml:value>
>
>         <dsml:value>organizationalUnit</dsml:value>
>
>       </dsml:attr>
>
>       <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core' name='ou'>
>
>         <dsml:value>tt1</dsml:value>
>
>       </dsml:attr>
>
>       <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core'
> name='description'>
>
>         <dsml:value>tt1</dsml:value>
>
>       </dsml:attr>
>
>     </data>
>
>   </psp:pso>
>
> </psp:calcResponse>
>
>
>
> 2012-03-06 13:08:57,945: [main] INFO  BaseSpmlProvider.execute(285) -  -
> Target 'psp' - Lookup
> LookupRequest[psoID=PSOIdentifier[id='ou=tt1,ou=UdeM,OU=People,DC=umontreal,DC=ca',targetID=ldap,containerID=<null>],returnData=everything,requestID=2012/03/06-13:08:57.945]
>
> 2012-03-06 13:08:57,946: [main] INFO  BaseSpmlProvider.execute(289) -  -
> Target 'psp' - Lookup XML:
>
> <lookupRequest xmlns='urn:oasis:names:tc:SPML:2:0'
> requestID='2012/03/06-13:08:57.945' returnData='everything'>
>
>   <psoID ID='ou=tt1,ou=UdeM,OU=People,DC=umontreal,DC=ca' targetID='ldap'/>
>
> </lookupRequest>
>
>
>
> 2012-03-06 13:08:57,946: [main] INFO  BaseSpmlProvider.execute(285) -  -
> Target 'ldap' - Lookup
> LookupRequest[psoID=PSOIdentifier[id='ou=tt1,ou=UdeM,OU=People,DC=umontreal,DC=ca',targetID=ldap,containerID=<null>],returnData=everything,requestID=2012/03/06-13:08:57.945]
>
> 2012-03-06 13:08:57,947: [main] INFO  BaseSpmlProvider.execute(289) -  -
> Target 'ldap' - Lookup XML:
>
> <lookupRequest xmlns='urn:oasis:names:tc:SPML:2:0'
> requestID='2012/03/06-13:08:57.945' returnData='everything'>
>
>   <psoID ID='ou=tt1,ou=UdeM,OU=People,DC=umontreal,DC=ca' targetID='ldap'/>
>
> </lookupRequest>
>
>
>
> 2012-03-06 13:08:58,149: [main] ERROR BaseSpmlProvider.execute(320) -  -
> Target 'ldap' - Lookup
> LookupResponse[pso=<null>,status=failure,error=noSuchIdentifier,errorMessages={},requestID=2012/03/06-13:08:57.945]
>
> 2012-03-06 13:08:58,149: [main] ERROR BaseSpmlProvider.execute(322) -  -
> Target 'ldap' - Lookup XML:
>
> <lookupResponse xmlns='urn:oasis:names:tc:SPML:2:0' status='failure'
> requestID='2012/03/06-13:08:57.945' error='noSuchIdentifier'/>
>
>
>
> 2012-03-06 13:08:58,150: [main] ERROR BaseSpmlProvider.execute(320) -  -
> Target 'psp' - Lookup
> LookupResponse[pso=<null>,status=failure,error=noSuchIdentifier,errorMessages={},requestID=2012/03/06-13:08:57.945]
>
> 2012-03-06 13:08:58,150: [main] ERROR BaseSpmlProvider.execute(322) -  -
> Target 'psp' - Lookup XML:
>
> <lookupResponse xmlns='urn:oasis:names:tc:SPML:2:0' status='failure'
> requestID='2012/03/06-13:08:57.945' error='noSuchIdentifier'/>
>
>
>
> 2012-03-06 13:08:58,154: [main] INFO  Psp.execute(1059) -  - Psp 'psp' -
> Diff DiffResponse[status=success,requestID=2012/03/06-13:08:57.908]
>
> 2012-03-06 13:08:58,154: [main] INFO  Psp.execute(1061) -  - Psp 'psp' -
> Diff XML:
>
> <psp:diffResponse xmlns:psp='http://grouper.internet2.edu/psp'
> status='success' requestID='2012/03/06-13:08:57.908'>
>
>   <addRequest xmlns='urn:oasis:names:tc:SPML:2:0' entityName='stem'
> requestID='2012/03/06-13:08:58.151' targetId='ldap' returnData='everything'>
>
>     <psoID ID='ou=tt1,ou=UdeM,OU=People,DC=umontreal,DC=ca'
> targetID='ldap'/>
>
>     <data>
>
>       <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core'
> name='objectClass'>
>
>         <dsml:value>top</dsml:value>
>
>         <dsml:value>organizationalUnit</dsml:value>
>
>       </dsml:attr>
>
>       <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core' name='ou'>
>
>         <dsml:value>tt1</dsml:value>
>
>       </dsml:attr>
>
>       <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core'
> name='description'>
>
>         <dsml:value>tt1</dsml:value>
>
>       </dsml:attr>
>
>     </data>
>
>   </addRequest>
>
>   <psp:id ID='UdeM:tt1'/>
>
> </psp:diffResponse>
>
>
>
> 2012-03-06 13:08:58,155: [main] INFO  Psp.execute(622) -  - Psp 'psp' -
> BulkDiff BulkDiffResponse[status=success,requestID=2012/03/06-13:08:57.834]
>
> 2012-03-06 13:08:58,155: [main] INFO  Psp.execute(624) -  - Psp 'psp' -
> BulkDiff SPML:
>
> <psp:bulkDiffResponse xmlns:psp='http://grouper.internet2.edu/psp'
> status='success' requestID='2012/03/06-13:08:57.834'>
>
>   <psp:diffResponse status='success' requestID='2012/03/06-13:08:57.908'>
>
>     <addRequest xmlns='urn:oasis:names:tc:SPML:2:0' entityName='stem'
> requestID='2012/03/06-13:08:58.151' targetId='ldap' returnData='everything'>
>
>       <psoID ID='ou=tt1,ou=UdeM,OU=People,DC=umontreal,DC=ca'
> targetID='ldap'/>
>
>       <data>
>
>         <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core'
> name='objectClass'>
>
>           <dsml:value>top</dsml:value>
>
>           <dsml:value>organizationalUnit</dsml:value>
>
>         </dsml:attr>
>
>         <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core' name='ou'>
>
>           <dsml:value>tt1</dsml:value>
>
>         </dsml:attr>
>
>         <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core'
> name='description'>
>
>           <dsml:value>tt1</dsml:value>
>
>         </dsml:attr>
>
>       </data>
>
>     </addRequest>
>
>     <psp:id ID='UdeM:tt1'/>
>
>   </psp:diffResponse>
>
> </psp:bulkDiffResponse>
>
>
>
> 2012-03-06 13:08:58,156: [main] INFO  BaseSpmlProvider.execute(153) -  -
> Target 'ldap' - Add
> AddRequest[psoID=PSOIdentifier[id='ou=tt1,ou=UdeM,OU=People,DC=umontreal,DC=ca',targetID=ldap,containerID=<null>],targetID=ldap,returnData=everything,requestID=2012/03/06-13:08:58.151]
>
> 2012-03-06 13:08:58,156: [main] INFO  BaseSpmlProvider.execute(157) -  -
> Target 'ldap' - Add XML:
>
> <addRequest xmlns='urn:oasis:names:tc:SPML:2:0' entityName='stem'
> requestID='2012/03/06-13:08:58.151' targetId='ldap' returnData='everything'>
>
>   <psoID ID='ou=tt1,ou=UdeM,OU=People,DC=umontreal,DC=ca' targetID='ldap'/>
>
>   <data>
>
>     <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core'
> name='objectClass'>
>
>       <dsml:value>top</dsml:value>
>
>       <dsml:value>organizationalUnit</dsml:value>
>
>     </dsml:attr>
>
>     <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core' name='ou'>
>
>       <dsml:value>tt1</dsml:value>
>
>     </dsml:attr>
>
>     <dsml:attr xmlns:dsml='urn:oasis:names:tc:DSML:2:0:core'
> name='description'>
>
>       <dsml:value>tt1</dsml:value>
>
>     </dsml:attr>
>
>   </data>
>
> </addRequest>
>
>
>
> 2012-03-06 13:08:58,367: [main] ERROR BaseSpmlProvider.execute(188) -  -
> Target 'ldap' - Add
> AddResponse[pso=<null>,status=failure,error=customError,errorMessages={[LDAP:
> error code 32 - 0000208D: NameErr: DSID-0310020A, problem 2001 (NO_OBJECT),
> data 0, best match of:
>
>         'OU=People,DC=umontreal,DC=ca'
>
> _]},requestID=2012/03/06-13:08:58.151]
>
> 2012-03-06 13:08:58,368: [main] ERROR BaseSpmlProvider.execute(190) -  -
> Target 'ldap' - Add XML:
>
> <addResponse xmlns='urn:oasis:names:tc:SPML:2:0' status='failure'
> requestID='2012/03/06-13:08:58.151' error='customError'>
>
>   <errorMessage>[LDAP: error code 32 - 0000208D: NameErr: DSID-0310020A,
> problem 2001 (NO_OBJECT), data 0, best match of:
>
>         'OU=People,DC=umontreal,DC=ca'
>
> _]</errorMessage>
>
> </addResponse>
>
>
>
> 2012-03-06 13:08:58,368: [main] ERROR Psp.execute(785) -  - Psp 'psp' -
> BulkSync
> BulkSyncResponse[status=failure,error=<null>,errorMessages={},requestID=2012/03/06-13:08:57.833]
>
> 2012-03-06 13:08:58,369: [main] ERROR Psp.execute(787) -  - Psp 'psp' -
> BulkSync SPML:
>
> <psp:bulkSyncResponse xmlns:psp='http://grouper.internet2.edu/psp'
> status='failure' requestID='2012/03/06-13:08:57.833'>
>
>   <psp:syncResponse>
>
>     <addResponse xmlns='urn:oasis:names:tc:SPML:2:0' status='failure'
> requestID='2012/03/06-13:08:58.151' error='customError'>
>
>       <errorMessage>[LDAP: error code 32 - 0000208D: NameErr: DSID-0310020A,
> problem 2001 (NO_OBJECT), data 0, best match of:
>
>         'OU=People,DC=umontreal,DC=ca'
>
> _]</errorMessage>
>
>     </addResponse>
>
>     <psp:id ID='UdeM:tt1'/>
>
>   </psp:syncResponse>
>
> </psp:bulkSyncResponse>