Grouper Developers Forum

[Gagné Sébastien <>]

Actually it's a little different, here's what I did :

ldap.properties :
edu.internet2.middleware.psp.groupsBaseDn=OU=People,DC=example,DC=ca
edu.internet2.middleware.psp.baseStem=UdeM

I understand that the groupsBaseDn has to exist and that's perfectly 
reasonable, but my problem came when I added the baseStem. Grouper will 
provision this baseStem and everything under it to People. If I don't 
manually create the OU=UdeM, OU=People,DC=example,DC=ca I will get errors.

I haven't tried it, but since I only have one base stem (besides "etc") in my 
grouper, I believe that removing the baseStem will give the same 
functionality without the initial exception.

There might be a possible side effect of related to this "bug" : before 
manually adding the baseStem to AD, whenever I'm doing searches in the 
Grouper UI there are multiple exception thrown in the logs. Now everything is 
Ok.



One thing that might be useful : would it be possible to specify a baseStem 
without provisioning it to the LDAP ? Using the configuration above, all the 
groups under the stem UdeM would be provisioned directly under 
OU=People,DC=example,DC=ca. The stem would only be a container 

It would give something like this :
In grouper : UdeM:TestGroup1
In AD : cn=TestGroup1,OU=People,DC=example,DC=ca

This isn't all that important, we could simulate this be having the 
groupBaseDn one level higher with the baseStem set to People



-----Message d'origine-----
De : Tom Zeller 
[mailto:]
 
Envoyé : 7 mars 2012 18:08
À : Gagné Sébastien
Cc : 

Objet : Re: [grouper-dev] Bug when using the baseStem configuration with AD 
(and more ldaps?)

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:DV
> GIAPPA
>
> 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.BulkProvi
> sioningRequest,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.BulkProvi
> sioningRequest,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=e
> verything,schemaEntityRef=SchemaEntityRef[targetID=ldap,entityName=ste
> m,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=e
> verything,schemaEntityRef=SchemaEntityRef[targetID=ldap,entityName=ste
> m,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=umon
> treal,DC=ca',targetID=ldap,containerID=<null>],returnData=everything,r
> equestID=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=umon
> treal,DC=ca',targetID=ldap,containerID=<null>],returnData=everything,r
> equestID=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,errorM
> essages={},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,errorM
> essages={},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=umontre
> al,DC=ca',targetID=ldap,containerID=<null>],targetID=ldap,returnData=e
> verything,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={},requestI
> D=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>