Grouper Users - Open Discussion List

["Klug, Lawrence" <>]

Tom,

Okay, the db is back up.  Here is the console output and the grouper_error 
log is attached.

Thanks,

Lawrence

[root@MI15
 bin]#  ./gsh.sh -ldappcng -logSpml -printRequests -sync 
"InfoTechServices:MiddlewareServices:IAMUCLA"
Using GROUPER_HOME: /usr/local/tomcat6/webapps/grouper/WEB-INF/bin/..
Using GROUPER_CONF: /usr/local/tomcat6/webapps/grouper/WEB-INF/bin/../classes
Using JAVA: /usr/java/jdk1.6.0_25//bin/java
using MEMORY: 64m-512m
Grouper starting up: version: 2.0.0, build date: null, env: grouper2-dev
grouper.properties read from: 
/usr/local/tomcat6/webapps/grouper/WEB-INF/classes/grouper.properties
Grouper current directory is: /usr/local/tomcat6/webapps/grouper/WEB-INF/bin
log4j.properties read from:   
/usr/local/tomcat6/webapps/grouper/WEB-INF/classes/log4j.properties
Grouper logs are not using log4j: class 
org.apache.commons.logging.impl.SLF4JLocationAwareLog
grouper.hibernate.properties: 
/usr/local/tomcat6/webapps/grouper/WEB-INF/classes/grouper.hibernate.properties
grouper.hibernate.properties: 
mi_grouper@jdbc:jtds:sqlserver://aisdevdb.ais.ucla.edu:1433/mi_grouper-devtest2
sources.xml read from:        
/usr/local/tomcat6/webapps/grouper/WEB-INF/classes/sources.xml
sources.xml groupersource id: g:gsa
sources.xml jndi source id:   ldap: uid=ldappc,ou=edimi 
consumers,dc=edtest,dc=ucla,dc=edu@ldap://eds7.ais.ucla.edu:389
sources.xml jdbc source id:   jdbc: GrouperJdbcConnectionProvider
<ldappc:syncRequest xmlns:ldappc='http://grouper.internet2.edu/ldappc' 
returnData='everything'>
  <ldappc:id ID='InfoTechServices:MiddlewareServices:IAMUCLA'/>
</ldappc:syncRequest>
<ldappc:syncResponse xmlns:ldappc='http://grouper.internet2.edu/ldappc' 
status='failure' requestID='2011/11/07-10:53:51.725_Q4Z37WL4' 
error='customError'>
  <modifyResponse xmlns='urn:oasis:names:tc:SPML:2:0' status='failure' 
requestID='2011/11/07-10:53:52.573_Q4Z37WMU' error='customError'>
    <errorMessage>[LDAP: error code 67 - Not Allowed On RDN]</errorMessage>
  </modifyResponse>
  <errorMessage>[LDAP: error code 67 - Not Allowed On RDN]</errorMessage>
  <ldappc:id ID='InfoTechServices:MiddlewareServices:IAMUCLA'/>
</ldappc:syncResponse>
[root@MI15
 bin]#




-----Original Message-----
From: 

 
[mailto:]
 On Behalf Of Tom Zeller
Sent: Friday, November 04, 2011 4:32 PM
To: Klug, Lawrence
Cc: 

Subject: Re: [grouper-users] LDAPCNG Sync issues

Could you run

 ./gsh.sh -ldappcng -logSpml -printRequests -sync 
"InfoTechServices:MiddlewareServices:IAMUCLA"

and post the logs and stdout, please ?

I am interested in the spml messages.

On Fri, Nov 4, 2011 at 5:37 PM, Klug, Lawrence 
<>
 wrote:
> Here are the files, Tom.  Please let me know what you find...
>
> Lawrence
>
> -----Original Message-----
> From: 
> 
>  
> [mailto:]
>  On Behalf Of Tom
> Zeller
> Sent: Friday, November 04, 2011 2:51 PM
> To: Klug, Lawrence
> Cc: 
> 
> Subject: Re: [grouper-users] LDAPCNG Sync issues
>
> Hmm, I was expecting -logSpml to log the spml requests and response. I 
> think you need the -logSpml argument before -sync :
>
>  ./gsh.sh -ldappcng -logSpml -sync 
> "InfoTechServices:MiddlewareServices:IAMUCLA"
>
> In any case, we probably do not want to delete the cn, especially if
> it is part of the RDN :-)
>
> Could you send ldappcng.xml and ldappc-resolver.xml ? I am interested
> in the <attribute name="cn" ref="X" /> element of ldappcng.xml and
> corresponding <AttributeDefinition id="X" /> in ldappc-resolver.xml
>
> TomZ
>
> On Fri, Nov 4, 2011 at 1:44 PM, Klug, Lawrence 
> <>
>  wrote:
>> Tom - Increased log level and run:
>>
>> ./gsh.sh  -ldappcng -sync
>> "InfoTechServices:MiddlewareServices:IAMUCLA"  -logSpml
>>
>>  - this is what appears in the logs
>>
>> 2011-11-04 11:41:30,734: [main] INFO  LdapTargetProvider.execute(499)
>> -  -
>> ModifyRequest[psoID=PSOIdentifier[id='cn=InfoTechServices:MiddlewareS
>> e
>> rvices:IAMUCLA,ou=grouper,dc=edtest,dc=ucla,dc=edu',targetID=ldap,con
>> t
>> ainerID=<null>],mod=DSMLModification[name=cn,op=delete],mod=DSMLModif
>> i
>> cation[name=hasMember,op=add],mod=DSMLModification[name=isMemberOf,op
>> =
>> add],mod=DSMLModification[name=isMemberOf,op=delete],typeOfReference=
>> m
>> ember,typeOfReference=member,returnData=everything,requestID=2011/11/
>> 0
>> 4-11:41:30.730_Q4VTGGIZ]
>> 2011-11-04 11:41:30,734: [main] DEBUG LdapTargetProvider.execute(529)
>> -  -
>> ModifyRequest[psoID=PSOIdentifier[id='cn=InfoTechServices:MiddlewareS
>> e
>> rvices:IAMUCLA,ou=grouper,dc=edtest,dc=ucla,dc=edu',targetID=ldap,con
>> t
>> ainerID=<null>],mod=DSMLModification[name=cn,op=delete],mod=DSMLModif
>> i
>> cation[name=hasMember,op=add],mod=DSMLModification[name=isMemberOf,op
>> =
>> add],mod=DSMLModification[name=isMemberOf,op=delete],typeOfReference=
>> m
>> ember,typeOfReference=member,returnData=everything,requestID=2011/11/
>> 0 4-11:41:30.730_Q4VTGGIZ] mods [Remove attribute: cn:
>> InfoTechServices:MiddlewareServices:IAMUCLA, Add attribute: hasMember:
>> KLUG, LAWRENCE, KLUG, KARL J
>> , LEUNG, WARREN WAI LUN
>> , Add attribute: isMemberOf: InfoTechServices:ITServices, Remove
>> attribute: isMemberOf:
>> cn=InfoTechServices:ITServices,ou=grouper,dc=edtest,dc=ucla,dc=edu,
>> Add attribute: member:
>> uclappid=urn:mace:ucla.edu:ppid:person:4B375069ECA7458C9A3EC6935784C7
>> 8 0,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:6D074D02FC154605AE009EB8701849
>> 3 B,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:D7BED25A41E442EFBE721496196E0A
>> 8 1,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:C4196E1230C9452191D7E416FC4BD9
>> F 3,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:FEC691E858FB4A5889E5A4464488A6
>> B 7,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:98B84B1A62C9450CB3F0BC9E9B3ABA
>> D E,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:959630A150724E75ABE06370752707
>> D 2,ou=people,dc=edtest,dc=ucla,dc=edu, Remove attribute: member: ]
>> 2011-11-04 11:41:30,734: [main] DEBUG LdapTargetProvider.execute(531) -  - 
>> ModifyRequest[psoID=PSOIdentifier[id='cn=InfoTechServices:MiddlewareServices:IAMUCLA,ou=grouper,dc=edtest,dc=ucla,dc=edu',targetID=ldap,containerID=<null>],mod=DSMLModification[name=cn,op=delete],mod=DSMLModification[name=hasMember,op=add],mod=DSMLModification[name=isMemberOf,op=add],mod=DSMLModification[name=isMemberOf,op=delete],typeOfReference=member,typeOfReference=member,returnData=everything,requestID=2011/11/04-11:41:30.730_Q4VTGGIZ]
>>  escaped dn 
>> 'cn=InfoTechServices:MiddlewareServices:IAMUCLA,ou=grouper,dc=edtest,dc=ucla,dc=edu'
>> 2011-11-04 11:41:30,734: [main] DEBUG AbstractLdap.modifyAttributes(819) - 
>>  - Modify attributes with the following parameters:
>> 2011-11-04 11:41:30,735: [main] DEBUG
>> AbstractLdap.modifyAttributes(820) -  -   dn =
>> cn=InfoTechServices:MiddlewareServices:IAMUCLA,ou=grouper,dc=edtest,d
>> c
>> =ucla,dc=edu
>> 2011-11-04 11:41:30,735: [main] DEBUG
>> AbstractLdap.modifyAttributes(821) -  -   mods = [Remove attribute:
>> cn: InfoTechServices:MiddlewareServices:IAMUCLA, Add attribute:
>> hasMember: KLUG, LAWRENCE, KLUG, KARL J , LEUNG, WARREN WAI LUN , Add
>> attribute: isMemberOf: InfoTechServices:ITServices, Remove
>> attribute: isMemberOf:
>> cn=InfoTechServices:ITServices,ou=grouper,dc=edtest,dc=ucla,dc=edu,
>> Add attribute: member:
>> uclappid=urn:mace:ucla.edu:ppid:person:4B375069ECA7458C9A3EC6935784C7
>> 8 0,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:6D074D02FC154605AE009EB8701849
>> 3 B,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:D7BED25A41E442EFBE721496196E0A
>> 8 1,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:C4196E1230C9452191D7E416FC4BD9
>> F 3,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:FEC691E858FB4A5889E5A4464488A6
>> B 7,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:98B84B1A62C9450CB3F0BC9E9B3ABA
>> D E,ou=people,dc=edtest,dc=ucla,dc=edu,
>> uclappid=urn:mace:ucla.edu:ppid:person:959630A150724E75ABE06370752707
>> D 2,ou=people,dc=edtest,dc=ucla,dc=edu, Remove attribute: member: ]
>> 2011-11-04 11:41:30,738: [main] ERROR LdapTargetProvider.execute(567)
>> -  -
>> ModifyResponse[pso=<null>,status=failure,error=customError,errorMessa
>> g
>> es={[LDAP: error code 67 - Not Allowed On
>> RDN]},requestID=2011/11/04-11:41:30.730_Q4VTGGIZ]
>> javax.naming.directory.SchemaViolationException: [LDAP: error code 67 - 
>> Not Allowed On RDN]; remaining name 
>> 'cn=InfoTechServices:MiddlewareServices:IAMUCLA,ou=grouper,dc=edtest,dc=ucla,dc=edu'
>>        at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3072)
>>        at
>> com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2987)
>>        at
>> com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2794)
>>        at
>> com.sun.jndi.ldap.LdapCtx.c_modifyAttributes(LdapCtx.java:1455)
>>        at
>> com.sun.jndi.toolkit.ctx.ComponentDirContext.p_modifyAttributes(Compo
>> n
>> entDirContext.java:255)
>>        at
>> com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.modifyAttributes(
>> P
>> artialCompositeDirContext.java:172)
>>        at
>> com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.modifyAttributes(
>> P
>> artialCompositeDirContext.java:161)
>>        at
>> edu.vt.middleware.ldap.AbstractLdap.modifyAttributes(AbstractLdap.jav
>> a
>> :836)
>>        at edu.vt.middleware.ldap.Ldap.modifyAttributes(Ldap.java:665)
>>        at
>> edu.internet2.middleware.ldappc.spml.provider.LdapTargetProvider.exec
>> u
>> te(LdapTargetProvider.java:532)
>>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>        at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
>> j
>> ava:39)
>>        at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
>> s
>> orImpl.java:25)
>>        at java.lang.reflect.Method.invoke(Method.java:597)
>>        at
>> edu.internet2.middleware.ldappc.spml.provider.BaseSpmlProvider.execut
>> e
>> (BaseSpmlProvider.java:79)
>>        at
>> edu.internet2.middleware.ldappc.spml.PSP.execute(PSP.java:444)
>>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>        at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
>> j
>> ava:39)
>>        at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
>> s
>> orImpl.java:25)
>>        at java.lang.reflect.Method.invoke(Method.java:597)
>>        at
>> edu.internet2.middleware.ldappc.spml.provider.BaseSpmlProvider.execut
>> e
>> (BaseSpmlProvider.java:79)
>>        at
>> edu.internet2.middleware.ldappc.spml.PSP.execute(PSP.java:272)
>>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>        at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
>> j
>> ava:39)
>>        at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
>> s
>> orImpl.java:25)
>>        at java.lang.reflect.Method.invoke(Method.java:597)
>>        at
>> edu.internet2.middleware.ldappc.spml.provider.BaseSpmlProvider.execut
>> e
>> (BaseSpmlProvider.java:79)
>>        at
>> edu.internet2.middleware.ldappc.spml.PSPCLI.run(PSPCLI.java:176)
>>        at
>> edu.internet2.middleware.ldappc.spml.PSPCLI.main(PSPCLI.java:90)
>>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>        at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
>> j
>> ava:39)
>>        at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
>> s
>> orImpl.java:25)
>>        at java.lang.reflect.Method.invoke(Method.java:597)
>>        at
>> edu.internet2.middleware.grouper.app.gsh.GrouperShell.handleSpecialCa
>> s
>> e(GrouperShell.java:188)
>>        at
>> edu.internet2.middleware.grouper.app.gsh.GrouperShell.main(GrouperShe
>> l
>> l.java:128)
>>        at
>> edu.internet2.middleware.grouper.app.gsh.GrouperShellWrapper.main(Gro
>> u
>> perShellWrapper.java:16)
>> 2011-11-04 11:41:30,739: [main] ERROR PSP.execute(458) -  -
>> ModifyResponse[pso=<null>,status=failure,error=customError,errorMessa
>> g
>> es={[LDAP: error code 67 - Not Allowed On
>> RDN]},requestID=2011/11/04-11:41:30.730_Q4VTGGIZ]
>> 2011-11-04 11:41:30,739: [main] INFO  PSP.execute(460) -  -
>> <modifyResponse xmlns='urn:oasis:names:tc:SPML:2:0' status='failure'
>> requestID='2011/11/04-11:41:30.730_Q4VTGGIZ' error='customError'>
>>  <errorMessage>[LDAP: error code 67 - Not Allowed On
>> RDN]</errorMessage> </modifyResponse>
>>
>> 2011-11-04 11:41:30,739: [main] ERROR PSP.execute(277) -  -
>> SyncResponse[id=InfoTechServices:MiddlewareServices:IAMUCLA,status=fa
>> i
>> lure,error=customError,errorMessages={[LDAP: error code 67 - Not
>> Allowed On
>> RDN]},requestID=2011/11/04-11:41:30.120_Q4VTGGH6,ModifyResponse[pso=<
>> n
>> ull>,status=failure,error=customError,errorMessages={[LDAP: error
>> ull>code
>> 67 - Not Allowed On
>> RDN]},requestID=2011/11/04-11:41:30.730_Q4VTGGIZ]]
>> 2011-11-04 11:41:30,740: [main] INFO  PSP.execute(278) -  -
>> <ldappc:syncResponse
>> xmlns:ldappc='http://grouper.internet2.edu/ldappc' status='failure'
>> requestID='2011/11/04-11:41:30.120_Q4VTGGH6' error='customError'>
>>  <modifyResponse xmlns='urn:oasis:names:tc:SPML:2:0' status='failure'
>> requestID='2011/11/04-11:41:30.730_Q4VTGGIZ' error='customError'>
>>    <errorMessage>[LDAP: error code 67 - Not Allowed On
>> RDN]</errorMessage>
>>  </modifyResponse>
>>  <errorMessage>[LDAP: error code 67 - Not Allowed On
>> RDN]</errorMessage>
>>  <ldappc:id ID='InfoTechServices:MiddlewareServices:IAMUCLA'/>
>> </ldappc:syncResponse>
>>
>>
>> -----Original Message-----
>> From: 
>> 
>>  
>> [mailto:]
>>  On Behalf Of Tom
>> Zeller
>> Sent: Friday, November 04, 2011 10:22 AM
>> To: Klug, Lawrence
>> Cc: 
>> 
>> Subject: Re: [grouper-users] LDAPCNG Sync issues
>>
>> You are running 2.x, correct ?
>>
>> Run with -printRequests or -logSpml and increase the logging level in 
>> log4j.properties :
>>
>>  # LDAPPC[NG]
>>  log4j.logger.edu.internet2.middleware.ldappc = DEBUG  # vt-ldap,
>> used by LDAPPC[NG]  log4j.logger.edu.vt.middleware.ldap = DEBUG
>>
>> We need the request to understand the failure response.
>>
>> On Fri, Nov 4, 2011 at 12:03 PM, Klug, Lawrence 
>> <>
>>  wrote:
>>> Hi,
>>>
>>>
>>>
>>> We're getting  into LDAP errors when running sync or buldSync
>>> operations - they seem to be related to schema or constrain
>>> violations.  Can anyone suggest a strategy for fixing?
>>>
>>>
>>>
>>> Thanks,
>>>
>>>
>>>
>>> Lawrence
>>>
>>>
>>>
>>> <ldappc:syncResponse>
>>>
>>>     <modifyResponse xmlns='urn:oasis:names:tc:SPML:2:0' status='failure'
>>> requestID='2011/11/04-09:46:31.263_Q4VPCJ0Q' error='customError'>
>>>
>>>       <errorMessage>[LDAP: error code 67 - Not Allowed On
>>> RDN]</errorMessage>
>>>
>>>     </modifyResponse>
>>>
>>>     <ldappc:id ID='etc:sysadmingroup'/>
>>>
>>>   </ldappc:syncResponse>
>>>
>>>
>>>
>>>   <ldappc:syncResponse>
>>>
>>>     <modifyResponse xmlns='urn:oasis:names:tc:SPML:2:0' status='failure'
>>> requestID='2011/11/04-09:46:31.275_Q4VPCJ0V' error='customError'>
>>>
>>>       <errorMessage>[LDAP: error code 19 - Constraint violation in
>>> modifications]</errorMessage>
>>>
>>>     </modifyResponse>
>>>
>>>     <ldappc:id
>>> ID='urn:mace:ucla.edu:ppid:person:037C906A66444DFBAA8C4DB08035D62E'/
>>> >
>>>
>>>   </ldappc:syncResponse>
>>>
>>>
>>>
>>> Lawrence Klug
>>>
>>> UCLA Middleware Services
>>>
>>> Office: 310 825-2061
>>>
>>> Cell: 818 667-2386
>>>
>>>
>>
>

Attachment: grouper_error.log
Description: grouper_error.log