grouper-users - [grouper-users] PSPNG issue

Subject: Grouper Users - Open Discussion List

List archive

[grouper-users] PSPNG issue

From: Julio Macavilca <>
To: Grouper Users <>
Subject: [grouper-users] PSPNG issue
Date: Thu, 23 Feb 2017 13:30:19 -0500
Ironport-phdr: 9a23:Ww/2vhANtE8sLj3moRI+UyQJP3N1i/DPJgcQr6AfoPdwSPX5o8bcNUDSrc9gkEXOFd2CrakV1qyP4+u5ADZIyK3CmUhKSIZLWR4BhJdetC0bK+nBN3fGKuX3ZTcxBsVIWQwt1Xi6NU9IBJS2PAWK8TW94jEIBxrwKxd+KPjrFY7OlcS30P2594HObwlSijewZbN/IA+roQjSucUanJZuJrgswRbVv3VEfPhby3l1LlyJhRb84cmw/J9n8ytOvv8q6tBNX6bncakmVLJUFDspPXw7683trhnDUBCA5mAAXWUMkxpHGBbK4RfnVZrsqCT6t+592C6HPc3qSL0/RDqv47t3RBLulSwKLCAy/n3JhcNsjaJbuBOhqAJ5w47Ie4GeKf5ycrrAcd8GWWZNW8BcXDFDDIyhdYsCF+oPM+hboYfguVUBsQCzChOwCO710DJEmmP60K883u88EQ/GxgsgH9cWvXrQsdX1MKYSUeeox6fP1zrMc+lZ2Sn86IjMbh8uu+yHULVyccrMzUkvFgTFgk+VqYP/IzyazPoNs2mf7+V8T+2ikGgnqgFsojS12Mgjl5TJi5sTx1vZ+yt5x4M1Kse5SE59edOkH4FQtyaHN4tuXMwiWXtktzwiyr0eoZK7eigLyIk9yxHBdvOHbpCE4hDkVOmKOzd4mXRleKm/hxms9UigzvfwVtOp0FZMqCdOj9rCtmgV2hDN68WLVvlw80Kv2TuMzA/f9uRJLE8omabHNpEsx6I/moYOvknGGyL6hkv7gaGQe0454Oan8f7nba/jppKEN497lAX+MqM2l8y6G+s4MwwOU3GC+eSgyLHv5EL4TKtEg/A4iKXZv5faJcMUpq69HQBZyJos6xG6Dzu+0dQYm2cILE5ddR6ZjoXlJ1PDLfX2Dfq8mFugjDJmyv/aMrH9H5rAK2TMnKv8crt47kNQ1gQ+wN5H65JREL4BIfbzWkHrtNzfCx80Kw60w+PnBdh8144SRXmCAqmZMaPPq1OH+P8gI/SUaI8PpDn9M+Ql5+LpjXIhll8dZ66p3YYPaH+mBPRqOliZYWHyjdcbCmcHpQ4+TO3xiF2eSj5feWy+X6M65jEnFo2mF4HDSZ6xgLCfxiu0AIBZZn0VQmyLRFjycJicVu1EVTmfONQpxjMeUqW5RpVkyAqjrhTSyrx7I/DS9zFC85/vyY4myffUkEQQ6Dh1CIy42mqEUWBwlWpAEz0r2KF450l0wV6d0KxzitReBMEV6v9UBFRpfaXAxvB3XoihEjnKec2EHRP/Go2r

Hi folks,

I am testing the PSPNG in dev environment running pspng patch 7. When creating a group or stem with a name that includes a comma I am seeing that the changelog consumer becomes stuck when provisioning to LDAP. After looking at the logs the dn looks malformed whereas using the PSP we have similar ones but it includes the escape character in the dn so it doesn't cause an LDAP error 34.

thanks,

Julio

Name:	This_-_is_My,_Test
Path:	app:pspngtest:This_-_is_My,_Test
ID path:	app:pspngtest:This_-_is_My,_Test
Alternate ID path:
ID:	This_-_is_My,_Test
Created:	Thu Feb 23 1:09:24 PM EST 2017

2017-02-23 13:09:51,375: [DefaultQuartzScheduler_Worker-1] INFO PspChangelogConsumerShim.processChangeLogEntries(52) - - pspng_activedirectory: +processChangeLogEntries(2)

2017-02-23 13:09:51,376: [DefaultQuartzScheduler_Worker-1] INFO ProvisionerFactory.createProvisionerWithName(80) - - Constructing provisioner: pspng_activedirectory

2017-02-23 13:09:51,416: [DefaultQuartzScheduler_Worker-2] INFO EventLog.info(156) - - [dbd228ec52b04b1dbb98aaedef378dfb,'GrouperSystem','application'] session: start (1ms)

2017-02-23 13:09:51,437: [DefaultQuartzScheduler_Worker-1] INFO EventLog.info(156) - - [9f5124c4b49d4247bc0d8aacbf2105dc,'GrouperSystem','application'] session: start (1ms)

2017-02-23 13:09:51,466: [DefaultQuartzScheduler_Worker-2] INFO EventLog.info(156) - - [3157a17bd1c0433c8fb6cefb4a191ee8,'GrouperSystem','application'] session: start (1ms)

2017-02-23 13:09:51,557: [DefaultQuartzScheduler_Worker-2] INFO EventLog.info(156) - - [7db294383c8340c58b14b5d02ec19576,'GrouperSystem','application'] session: start (2ms)

2017-02-23 13:09:51,570: [DefaultQuartzScheduler_Worker-1] INFO EhcacheController.getCache(200) - - cache not configured explicitly: PSP-pspng_activedirectory-GrouperGroupInfoCache, to override default values, configure in the resource /grouper.cache.base.properties and /grouper.cache.properties. Default values are:maxElementsInMemory: 10000, eternal: false, timeToIdleSeconds: 600, timeToLiveSeconds: 600, overFlowToDisk: false

2017-02-23 13:09:51,572: [DefaultQuartzScheduler_Worker-1] INFO EhcacheController.getCache(200) - - cache not configured explicitly: PSP-pspng_activedirectory-GrouperSubjectCache, to override default values, configure in the resource /grouper.cache.base.properties and /grouper.cache.properties. Default values are:maxElementsInMemory: 10000, eternal: false, timeToIdleSeconds: 600, timeToLiveSeconds: 600, overFlowToDisk: false

2017-02-23 13:09:51,573: [DefaultQuartzScheduler_Worker-1] INFO EhcacheController.getCache(200) - - cache not configured explicitly: PSP-pspng_activedirectory-TargetSystemUserCache, to override default values, configure in the resource /grouper.cache.base.properties and /grouper.cache.properties. Default values are:maxElementsInMemory: 10000, eternal: false, timeToIdleSeconds: 600, timeToLiveSeconds: 600, overFlowToDisk: false

2017-02-23 13:09:51,575: [DefaultQuartzScheduler_Worker-1] INFO EhcacheController.getCache(200) - - cache not configured explicitly: PSP-pspng_activedirectory-TargetSystemGroupCache, to override default values, configure in the resource /grouper.cache.base.properties and /grouper.cache.properties. Default values are:maxElementsInMemory: 10000, eternal: false, timeToIdleSeconds: 600, timeToLiveSeconds: 600, overFlowToDisk: false

2017-02-23 13:09:51,576: [DefaultQuartzScheduler_Worker-1] INFO EhcacheController.getCache(200) - - cache not configured explicitly: PSP-pspng_activedirectory-LdapUserCache, to override default values, configure in the resource /grouper.cache.base.properties and /grouper.cache.properties. Default values are:maxElementsInMemory: 10000, eternal: false, timeToIdleSeconds: 600, timeToLiveSeconds: 600, overFlowToDisk: false

2017-02-23 13:09:51,578: [DefaultQuartzScheduler_Worker-1] INFO ProvisionerFactory.createProvisionerWithName(80) - - Constructing provisioner: pspng_activedirectory

2017-02-23 13:09:51,587: [DefaultQuartzScheduler_Worker-2] INFO ProvisioningWorkItem.getSubjectId(201) - - Not a supported change for finding subject (not MEMBERSHIP_ADD nor MEMBERSHIP_DELETE): ChangeLog type: group: addGroup

2017-02-23 13:09:51,591: [DefaultQuartzScheduler_Worker-2] INFO ProvisioningWorkItem.getSubjectSourceId(225) - - Not a supported change for finding subject (not MEMBERSHIP_ADD nor MEMBERSHIP_DELETE): ChangeLog type: group: addGroup

2017-02-23 13:09:51,674: [pspng_activedirectory-FullSync] INFO EventLog.info(156) - - [4e69be2f9f1d4f18a9855299ed4efd9b,'GrouperSystem','application'] session: start (3ms)

2017-02-23 13:09:51,692: [DefaultQuartzScheduler_Worker-1] INFO EventLog.info(156) - - [5d3ed92061e44293bea0c15cc3b82467,'GrouperSystem','application'] session: start (1ms)

2017-02-23 13:09:51,781: [DefaultQuartzScheduler_Worker-1] INFO EventLog.info(156) - - [24d06f83d7684a6090fd342b3025dc62,'GrouperSystem','application'] session: start (2ms)

2017-02-23 13:09:51,849: [DefaultQuartzScheduler_Worker-1] INFO Provisioner.getAllGroupsForProvisioner(1163) - - pspng_activedirectory: There are 0 folders that match etc:pspng:provision_to attribute

2017-02-23 13:09:51,850: [DefaultQuartzScheduler_Worker-1] INFO Provisioner.getAllGroupsForProvisioner(1164) - - pspng_activedirectory: There are 0 groups that match etc:pspng:provision_to attribute

2017-02-23 13:09:51,969: [DefaultQuartzScheduler_Worker-1] INFO Provisioner.getAllGroupsForProvisioner(1163) - - pspng_activedirectory: There are 0 folders that match etc:pspng:do_not_provision_to attribute

2017-02-23 13:09:51,970: [DefaultQuartzScheduler_Worker-1] INFO Provisioner.getAllGroupsForProvisioner(1164) - - pspng_activedirectory: There are 0 groups that match etc:pspng:do_not_provision_to attribute

2017-02-23 13:09:51,971: [DefaultQuartzScheduler_Worker-1] INFO Provisioner.flushCachesIfNecessary(1346) - - pspng_activedirectory: Keeping caches in tact for provisioning batch

2017-02-23 13:09:51,981: [DefaultQuartzScheduler_Worker-2] INFO LdapGroupProvisioner.createGroup(251) - - Creating LDAP group for GrouperGroup: app:pspngtest:This_-_is_My,_Test

2017-02-23 13:09:52,060: [DefaultQuartzScheduler_Worker-1] INFO EventLog.info(156) - - [16d7c162c83549cf89a7537c6ef2ae72,'GrouperSystem','application'] session: start (2ms)

2017-02-23 13:09:52,098: [DefaultQuartzScheduler_Worker-1] INFO ProvisioningWorkItem.getSubjectId(201) - - Not a supported change for finding subject (not MEMBERSHIP_ADD nor MEMBERSHIP_DELETE): ChangeLog type: group: addGroup

2017-02-23 13:09:52,099: [DefaultQuartzScheduler_Worker-1] INFO ProvisioningWorkItem.setStatus(125) - - Not a supported change for finding subject (not MEMBERSHIP_ADD nor MEMBERSHIP_DELETE): ChangeLog type: group: addGroup

2017-02-23 13:09:52,100: [DefaultQuartzScheduler_Worker-1] INFO ProvisioningWorkItem.setStatus(125) - - Work item done: ProvisioningWorkItem[successful=true,msg=Ignoring work item ProvisioningWorkItem[successful=true,clog=clog #285000 / ChangeLog type: group: addGroup,group=app:pspngtest:This_-_is_My,_Test ] because group app:pspngtest:This_-_is_My,_Test is not provisioned,clog=clog #285000 / ChangeLog type: group: addGroup,group=app:pspngtest:This_-_is_My,_Test ]

2017-02-23 13:09:52,101: [DefaultQuartzScheduler_Worker-1] INFO ProvisioningWorkItem.getSubjectId(201) - - Not a supported change for finding subject (not MEMBERSHIP_ADD nor MEMBERSHIP_DELETE): ChangeLog type: group: addGroup

2017-02-23 13:09:52,102: [DefaultQuartzScheduler_Worker-1] INFO ProvisioningWorkItem.getSubjectSourceId(225) - - Not a supported change for finding subject (not MEMBERSHIP_ADD nor MEMBERSHIP_DELETE): ChangeLog type: group: addGroup

2017-02-23 13:09:52,109: [DefaultQuartzScheduler_Worker-2] INFO LdapProvisioner.performLdapAdd(628) - - pspng_groupOfNames: Creating LDAP object: cn=This_-_is_My,_Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu

2017-02-23 13:09:52,136: [DefaultQuartzScheduler_Worker-2] ERROR LdapSystem.performLdapRead(387) - - Problem during ldap read _Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu

[org.ldaptive.LdapException@27941234::resultCode=INVALID_DN_SYNTAX, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1, message=javax.naming.InvalidNameException: _Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu: [LDAP: error code 34 - Invalid DN]; remaining name '_Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu', providerException=javax.naming.InvalidNameException: _Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu: [LDAP: error code 34 - Invalid DN]; remaining name '_Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu']

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$JndiSearchIterator.initialize(JndiConnection.java:741)

at org.ldaptive.provider.jndi.JndiConnection.search(JndiConnection.java:463)

at org.ldaptive.SearchOperation.executeSearch(SearchOperation.java:103)

at org.ldaptive.SearchOperation.invoke(SearchOperation.java:85)

at org.ldaptive.SearchOperation.invoke(SearchOperation.java:15)

at org.ldaptive.AbstractOperation.execute(AbstractOperation.java:126)

at edu.internet2.middleware.grouper.pspng.LdapSystem.performLdapRead(LdapSystem.java:372)

at edu.internet2.middleware.grouper.pspng.LdapProvisioner.ensureLdapOusExist(LdapProvisioner.java:585)

at edu.internet2.middleware.grouper.pspng.LdapProvisioner.performLdapAdd(LdapProvisioner.java:630)

at edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.createGroup(LdapGroupProvisioner.java:269)

at edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.createGroup(LdapGroupProvisioner.java:54)

at edu.internet2.middleware.grouper.pspng.Provisioner.prepareGroupCache(Provisioner.java:715)

at edu.internet2.middleware.grouper.pspng.Provisioner.startProvisioningBatch(Provisioner.java:468)

at edu.internet2.middleware.grouper.pspng.Provisioner.provisionBatchOfItems(Provisioner.java:1285)

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$4.runJob(GrouperLoaderType.java:652)

at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.runJob(GrouperLoaderJob.java:418)

at edu.internet2.middleware.grouper.app.loader.GrouperLoaderJob.execute(GrouperLoaderJob.java:318)

at org.quartz.core.JobRunShell.run(JobRunShell.java:202)

at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)

Caused by: javax.naming.InvalidNameException: _Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu: [LDAP: error code 34 - Invalid DN]; remaining name '_Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu'

at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:3026)

at com.sun.jndi.ldap.LdapCtx.processReturnCode(LdapCtx.java:2841)

at com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1850)

at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1773)

at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:386)

at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:356)

at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:339)

at org.ldaptive.provider.jndi.JndiConnection$JndiSearchIterator.search(JndiConnection.java:806)

at org.ldaptive.provider.jndi.JndiConnection$JndiSearchIterator.initialize(JndiConnection.java:735)

... 20 more

2017-02-23 13:09:52,146: [DefaultQuartzScheduler_Worker-2] ERROR LdapProvisioner.ensureLdapOusExist(593) - - pspng_groupOfNames: Unable to find existing OU (_Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu)

edu.internet2.middleware.grouper.pspng.PspException: Problem during LDAP read: javax.naming.InvalidNameException: _Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu: [LDAP: error code 34 - Invalid DN]; remaining name '_Test ,ou=pspngtest,ou=app,ou=nyu,ou=Groups,o=nyu.edu,o=nyu'

at edu.internet2.middleware.grouper.pspng.LdapSystem.performLdapRead(LdapSystem.java:388)