Hi everyone,
i'm still testing PSPNG and i encountered another problem :
when i delete a group with at least a member, the group are
correctly deleted from the LDAP but i get this error in the log
:
2017-12-12 10:55:00,452:
[DefaultQuartzScheduler_Worker-1] WARN
LdapProvisioner.makeCoalescedLdapChanges(500) - - Problem
doing coalesced ldap modification (THIS WILL BE RETRIED):
cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz /
[org.ldaptive.ModifyRequest@1639929550::modifyDn=cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz,
attrMods=[[org.ldaptive.AttributeModification@1408611712::attrMod=REMOVE,
attribute=[uniqueMember[uid=ydelattre,ou=people,ou=wwwww,ou=xxxx,o=yyy,c=zz]]]],
controls=null, referralHandler=null,
intermediateResponseHandlers=null]
[org.ldaptive.LdapException@1053324437::resultCode=NO_SUCH_OBJECT,
matchedDn=null, responseControls=null, referralURLs=null,
messageId=-1, message=javax.naming.NameNotFoundException:
[LDAP: error code 32 - No Such Object]; remaining name
'cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz ',
providerException=javax.naming.NameNotFoundException: [LDAP:
error code 32 - No Such Object]; remaining name
'cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz']
at
org.ldaptive.provider.ProviderUtils.throwOperationException(ProviderUtils.java:55)
at
org.ldaptive.provider.jndi.JndiConnection.processNamingException(JndiConnection.java:619)
at
org.ldaptive.provider.jndi.JndiConnection.modify(JndiConnection.java:425)
at
edu.internet2.middleware.grouper.pspng.LdapProvisioner.makeCoalescedLdapChanges(LdapProvisioner.java:498)
at
edu.internet2.middleware.grouper.pspng.LdapProvisioner.finishProvisioningBatch(LdapProvisioner.java:291)
at
edu.internet2.middleware.grouper.pspng.Provisioner.provisionBatchOfItems(Provisioner.java:1405)
at
edu.internet2.middleware.grouper.pspng.PspChangelogConsumerShim.processChangeLogEntries(PspChangelogConsumerShim.java:71)
at
edu.internet2.middleware.grouper.changeLog.ChangeLogHelper.processRecords(ChangeLogHelper.java:245)
at
edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$5.runJob(GrouperLoaderType.java:720)
at
edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(GrouperLoaderJob.java:465)
at
edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(GrouperLoaderJob.java:345)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
Caused by: javax.naming.NameNotFoundException: [LDAP: error
code 32 - No Such Object]; remaining name
'cn=test-pspng4:test,ou=grouper,ou=xxxx,o=gouv,c=fr'
at
com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3179)
at
com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3100)
at
com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2891)
at
com.sun.jndi.ldap.LdapCtx.c_modifyAttributes(LdapCtx.java:1475)
at
com.sun.jndi.toolkit.ctx.ComponentDirContext.p_modifyAttributes(ComponentDirContext.java:277)
at
com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.modifyAttributes(PartialCompositeDirContext.java:192)
at
org.ldaptive.provider.jndi.JndiConnection.modify(JndiConnection.java:412)
... 10 more
2017-12-12 10:55:00,465: [DefaultQuartzScheduler_Worker-1]
WARN LdapProvisioner.finishProvisioningBatch(298) - -
Optimized, coalesced ldap provisioning failed
edu.internet2.middleware.grouper.pspng.PspException: Coalesced
LDAP Modification failed: javax.naming.NameNotFoundException:
[LDAP: error code 32 - No Such Object]; remaining name
'cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz'
at
edu.internet2.middleware.grouper.pspng.LdapProvisioner.makeCoalescedLdapChanges(LdapProvisioner.java:502)
at
edu.internet2.middleware.grouper.pspng.LdapProvisioner.finishProvisioningBatch(LdapProvisioner.java:291)
at
edu.internet2.middleware.grouper.pspng.Provisioner.provisionBatchOfItems(Provisioner.java:1405)
at
edu.internet2.middleware.grouper.pspng.PspChangelogConsumerShim.processChangeLogEntries(PspChangelogConsumerShim.java:71)
at
edu.internet2.middleware.grouper.changeLog.ChangeLogHelper.processRecords(ChangeLogHelper.java:245)
at
edu.internet2.middleware.grouper.app.loader.GrouperLoaderType$5.runJob(GrouperLoaderType.java:720)
at
edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(GrouperLoaderJob.java:465)
at
edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(GrouperLoaderJob.java:345)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
For me, it seems like it's a scheduling problem : PSPNG delete
the group in the LDAP then after it delete uniqueMember
attribute
Extract from the log :
2017-12-12
10:55:00,199: [DefaultQuartzScheduler_Worker-1] INFO
LdapGroupProvisioner.scheduleGroupModification(99) - - Will
change LDAP: REMOVE uid=ydelattre,ou=people,ou=ac-lille,ou=xxxx,o=yyy,c=zz
from uniqueMember of
LdapGroup[ldap=LdapObject[cn=[test-pspng4:test],dn=cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz]]
2017-12-12 10:55:00,201: [DefaultQuartzScheduler_Worker-1]
INFO LdapProvisioner.scheduleLdapModification(270) - -
pspng_brancheGrouper: Scheduling ldap modification:
[org.ldaptive.ModifyRequest@1176511300::modifyDn=cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz,
attrMods=[[org.ldaptive.AttributeModification@1037303482::attrMod=REMOVE,
attribute=[uniqueMember[uid=ydelattre,ou=people,ou=ac-lille,ou=xxxx,o=yyy,c=zz]]]],
controls=null, referralHandler=null,
intermediateResponseHandlers=null]
2017-12-12 10:55:00,202: [DefaultQuartzScheduler_Worker-1]
DEBUG Provisioner.provisionItem(911) - - Starting
provisioning of item: ProvisioningWorkItem[clog=clog #3921953
/ ChangeLog type: privilege: deletePrivilege]
2017-12-12 10:55:00,202: [DefaultQuartzScheduler_Worker-1]
INFO ProvisioningWorkItem.setStatus(143) - - Work item
handled: ProvisioningWorkItem[successful=true,msg=Nothing to
do (not a supported change),clog=clog #3921953 / ChangeLog
type: privilege: deletePrivilege]
2017-12-12 10:55:00,203: [DefaultQuartzScheduler_Worker-1]
DEBUG Provisioner.provisionItem(911) - - Starting
provisioning of item: ProvisioningWorkItem[clog=clog #3921954
/ ChangeLog type: group: deleteGroup,group=test-pspng4:test]
2017-12-12 10:55:00,203: [DefaultQuartzScheduler_Worker-1]
INFO LdapGroupProvisioner.deleteGroup(522) - - Deleting
group test-pspng4:test by deleting DN
cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz
2017-12-12 10:55:00,204: [DefaultQuartzScheduler_Worker-1]
INFO LdapSystem.performLdapDelete(349) - - aclille:
Deleting LDAP object: cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz
2017-12-12 10:55:00,417:
[DefaultQuartzScheduler_Worker-1] DEBUG
LdapProvisioner.makeCoalescedLdapChanges(340) - -
pspng_brancheGrouper: Making coalescedLdapChanges
2017-12-12 10:55:00,418:
[DefaultQuartzScheduler_Worker-1] INFO
LdapProvisioner.makeCoalescedLdapChanges(353) - -
pspng_brancheGrouper: WorkItem
ProvisioningWorkItem[clog=clog #3921952 / ChangeLog type:
membership:
deleteMembership,group=test-pspng4:test,subject=ydelattre@ldapPerso]
needs 1 ldap modifications
2017-12-12 10:55:00,418:
[DefaultQuartzScheduler_Worker-1] DEBUG
LdapProvisioner.makeCoalescedLdapChanges(356) - -
pspng_brancheGrouper: Mod for WorkItem: [uniqueMember: -1
value(s)]
2017-12-12 10:55:00,423:
[DefaultQuartzScheduler_Worker-1] INFO
LdapProvisioner.makeCoalescedLdapChanges(497) - -
Performing LDAP modification: [uniqueMember: -1 value(s)]
2017-12-12
10:55:00,452: [DefaultQuartzScheduler_Worker-1] WARN
LdapProvisioner.makeCoalescedLdapChanges(500) - - Problem
doing coalesced ldap modification (THIS WILL BE RETRIED):
cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz /
[org.ldaptive.ModifyRequest@1639929550::modifyDn=cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz,
attrMods=[[org.ldaptive.AttributeModification@1408611712::attrMod=REMOVE,
attribute=[uniqueMember[uid=ydelattre,ou=people,ou=wwwww,ou=xxxx,o=yyy,c=zz]]]],
controls=null, referralHandler=null,
intermediateResponseHandlers=null]
[org.ldaptive.LdapException@1053324437::resultCode=NO_SUCH_OBJECT,
matchedDn=null, responseControls=null, referralURLs=null,
messageId=-1, message=javax.naming.NameNotFoundException:
[LDAP: error code 32 - No Such Object]; remaining name
'cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz ',
providerException=javax.naming.NameNotFoundException: [LDAP:
error code 32 - No Such Object]; remaining name
'cn=test-pspng4:test,ou=grouper,ou=xxxx,o=yyy,c=zz']
at
org.ldaptive.provider.ProviderUtils.throwOperationException(ProviderUtils.java:55)
...
Anyone encounter this issue ?
Thanks for your help,
Yoann