Grouper Users - Open Discussion List

[Ben Beecher <>]

We are upgrading from Grouper 2.3 to Grouper 2.4 and we are getting these errors from PSPNG

[org.ldaptive.LdapException@1271503185::resultCode=NOT_ALLOWED_ON_RDN, matchedDn=null, responseControls=null, referralURLs=null, messageId=-1, message=javax.naming.directory.SchemaViolationException: [LDAP: error code 67 - 000020B1: UpdErr: DSID-030F1087, problem 6004 (CANT_ON_RDN), data 0

I have attached the error log and the relevant portion of our grouper-loader.properties

Thanks for any assistance,

Ben

2020-04-08 12:34:43,655 [main] WARN  (GrouperStartup.java:232) - Grouper 
starting up: version: 2.4.0, build date: null, env: dev
grouperPatchStatus read from: 
/var/grouper/installGrouper2.4/grouper.apiBinary-2.4.0/grouperPatchStatus.properties
api patches installed:        0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 
14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 
33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 
52, 53, 54, 55, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68, 69, 70, 
71, 72, 73, 74, 75, 76, 77, 78, 79, 80, 81, 82, 83, 84, 85, 86, 87, 88, 89, 
90, 91, 92, 93
pspng patches installed:      0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12
grouper.properties read from: 
/var/grouper/installGrouper2.4/grouper.apiBinary-2.4.0/conf/grouper.properties
Grouper current directory is: 
/var/grouper/installGrouper2.4/grouper.apiBinary-2.4.0/bin
log4j.properties read from:   
/var/grouper/installGrouper2.4/grouper.apiBinary-2.4.0/conf/log4j.properties
Grouper logs are not using log4j: class 
org.apache.commons.logging.impl.SLF4JLocationAwareLog
grouper.hibernate.properties: 
/var/grouper/installGrouper2.4/grouper.apiBinary-2.4.0/conf/grouper.hibernate.properties
grouper.hibernate.properties: 
grouper@jdbc:oracle:thin:@grouperdevdb01.cc.columbia.edu:1527:grp1d

2020-04-08 12:34:48,607 [main] WARN  (GrouperCheckConfig.java:334) - jarfile 
mismatch, expecting name: 'aws-java-sdk-kms-1.11.533.jar' size: LinkedHashSet 
size: 1: [0]: 476065
 manifest version: null.  However the jar detected is: 
/var/grouper/installGrouper2.4/grouper.apiBinary-2.4.0/lib/grouper/aws-java-sdk-bundle-1.11.155.jar,
 name: aws-java-sdk-bundle-1.11.155.jar size: 66645026 manifest version: null
2020-04-08 12:34:48,630 [main] WARN  (GrouperCheckConfig.java:334) - jarfile 
mismatch, expecting name: 'aws-java-sdk-s3-1.11.529.jar' size: LinkedHashSet 
size: 1: [0]: 1009728
 manifest version: null.  However the jar detected is: 
/var/grouper/installGrouper2.4/grouper.apiBinary-2.4.0/lib/grouper/aws-java-sdk-bundle-1.11.155.jar,
 name: aws-java-sdk-bundle-1.11.155.jar size: 66645026 manifest version: null
2020-04-08 12:34:48,634 [main] WARN  (GrouperCheckConfig.java:334) - jarfile 
mismatch, expecting name: 'aws-java-sdk-sns-1.11.567.jar' size: LinkedHashSet 
size: 1: [0]: 368806
 manifest version: null.  However the jar detected is: 
/var/grouper/installGrouper2.4/grouper.apiBinary-2.4.0/lib/grouper/aws-java-sdk-bundle-1.11.155.jar,
 name: aws-java-sdk-bundle-1.11.155.jar size: 66645026 manifest version: null
2020-04-08 12:34:48,657 [main] WARN  (GrouperCheckConfig.java:334) - jarfile 
mismatch, expecting name: 'aws-java-sdk-sqs-1.11.567.jar' size: LinkedHashSet 
size: 1: [0]: 308744
 manifest version: null.  However the jar detected is: 
/var/grouper/installGrouper2.4/grouper.apiBinary-2.4.0/lib/grouper/aws-java-sdk-bundle-1.11.155.jar,
 name: aws-java-sdk-bundle-1.11.155.jar size: 66645026 manifest version: null
2020-04-08 12:34:48,899 [main] WARN  (C3p0JdbcConnectionProvider.java:144) - 
maxIdle is not available for c3p0 (in subject API: idm)
2020-04-08 12:34:53,692 [main] INFO  (EventLog.java:156) - 
[798ffa227b3740c6a54bb41a51f7ff20,'GrouperSystem','application'] add group 
type: 'grouperLoader' (33ms)
2020-04-08 12:34:53,744 [main] WARN  (GrouperStartup.java:164) - 
subject.properties read from: 
/var/grouper/installGrouper2.4/grouper.apiBinary-2.4.0/conf/subject.properties
sources configured in:        subject.properties
subject.properties jdbc source id:   idm: 
grouper@jdbc:oracle:thin:@//idmsysdevdb01.cc.columbia.edu:1527/idmdev1.cc.columbia.edu
subject.properties internalsource id:g:isa
subject.properties groupersource id: g:gsa
subject.properties groupersource id: grouperEntities
subject.properties jdbc source id:   externalUsers: 
GrouperJdbcConnectionProvider
2020-04-08 12:48:09,801 [main] WARN  (GrouperLoader.java:836) - 
grouper-loader.properties key: otherJob.tierInstrumentationDaemon.quartzCron 
is blank so disabling job tierInstrumentationDaemon.
2020-04-08 12:48:11,070 [main] WARN  (GrouperLoader.java:1858) - Full 
synchronization provisioning jobs are not scheduled. To schedule full 
synchronization jobs, set grouper-loader.properties key 
'changeLog.psp.fullSync.quartzCron' to a cron expression.
2020-04-08 12:48:11,076 [main] WARN  (GrouperLoader.java:1930) - A full 
synchronization provisioning job will not run once at startup. To run one 
full synchronization job at startup, set grouper-loader.properties key 
'changeLog.psp.fullSync.runAtStartup' to 'true'.
2020-04-08 12:48:11,700 [DefaultQuartzScheduler_Worker-2] DEBUG 
(PspChangelogConsumerShim.java:43) - Constructing PspngChangelogConsumerShim
2020-04-08 12:49:00,028 [DefaultQuartzScheduler_Worker-9] DEBUG 
(PspChangelogConsumerShim.java:43) - Constructing PspngChangelogConsumerShim
2020-04-08 12:50:00,106 [DefaultQuartzScheduler_Worker-6] DEBUG 
(PspChangelogConsumerShim.java:43) - Constructing PspngChangelogConsumerShim
2020-04-08 12:51:00,040 [DefaultQuartzScheduler_Worker-2] DEBUG 
(PspChangelogConsumerShim.java:43) - Constructing PspngChangelogConsumerShim
2020-04-08 12:52:00,022 [DefaultQuartzScheduler_Worker-8] DEBUG 
(PspChangelogConsumerShim.java:43) - Constructing PspngChangelogConsumerShim


2020-04-08 15:55:54,325 [FullSyncer(gsbdev)-Thread] WARN  
(Provisioner.java:1577) - gsbdev-full: Member in grouper group 
cu:app:adcu:gsb:stuclubs:green/#122853(Existing) is being ignored because 
subject is not present in target system: 'cbs2169'/'person'/'idm'
2020-04-08 15:55:54,325 [FullSyncer(gsbdev)-Thread] WARN  
(Provisioner.java:1577) - gsbdev-full: Member in grouper group 
cu:app:adcu:gsb:stuclubs:green/#122853(Existing) is being ignored because 
subject is not present in target system: 'vfs2109'/'person'/'idm'
2020-04-08 15:55:54,325 [FullSyncer(gsbdev)-Thread] WARN  
(Provisioner.java:1577) - gsbdev-full: Member in grouper group 
cu:app:adcu:gsb:stuclubs:green/#122853(Existing) is being ignored because 
subject is not present in target system: 'dtm2124'/'person'/'idm'
2020-04-08 15:55:54,325 [FullSyncer(gsbdev)-Thread] WARN  
(Provisioner.java:1577) - gsbdev-full: Member in grouper group 
cu:app:adcu:gsb:stuclubs:green/#122853(Existing) is being ignored because 
subject is not present in target system: 'mr3622'/'person'/'idm'
2020-04-08 15:55:54,325 [FullSyncer(gsbdev)-Thread] WARN  
(Provisioner.java:1577) - gsbdev-full: Member in grouper group 
cu:app:adcu:gsb:stuclubs:green/#122853(Existing) is being ignored because 
subject is not present in target system: 'ma3653'/'person'/'idm'
2020-04-08 15:55:54,325 [FullSyncer(gsbdev)-Thread] WARN  
(Provisioner.java:1577) - gsbdev-full: Member in grouper group 
cu:app:adcu:gsb:stuclubs:green/#122853(Existing) is being ignored because 
subject is not present in target system: 'cmp2230'/'person'/'idm'
2020-04-08 15:55:54,326 [FullSyncer(gsbdev)-Thread] DEBUG 
(Provisioner.java:1588) - 
gsbdev-full/cu:app:adcu:gsb:stuclubs:green/#122853(Existing): All correct 
member subjects: ['mdg2188'/'person'/'idm', 'ptb2114'/'person'/'idm', 
'vs2650'/'person'/'idm', 'ss5197'/'person'/'idm', 'kb2912'/'person'/'idm', 
'sn2010'/'person'/'idm', 'swm2131'/'person'/'idm', 'ac4375'/'person'/'idm', 
'ddr2121'/'person'/'idm', 'yn2297'/'person'/'idm', 'ih2286'/'person'/'idm']
2020-04-08 15:55:54,326 [FullSyncer(gsbdev)-Thread] INFO  
(Provisioner.java:1591) - 
gsbdev-full/cu:app:adcu:gsb:stuclubs:green/#122853(Existing): 11 correct 
member subjects. Sample: ['mdg2188'/'person'/'idm', 'ptb2114'/'person'/'idm', 
'vs2650'/'person'/'idm', 'ss5197'/'person'/'idm', 'kb2912'/'person'/'idm', 
'sn2010'/'person'/'idm', 'swm2131'/'person'/'idm', 'ac4375'/'person'/'idm', 
'ddr2121'/'person'/'idm', 'yn2297'/'person'/'idm']...
2020-04-08 15:55:54,326 [FullSyncer(gsbdev)-Thread] DEBUG 
(LdapGroupProvisioner.java:250) - gsbdev-full: Making sure (non-membership) 
attributes of group are up to date: 
cn=cu.app.adcu.gsb.stuclubs.green,ou=grouper_groups,ou=gsb_users,dc=dev,dc=gsb,dc=columbia,dc=edu
2020-04-08 15:55:54,544 [FullSyncer(gsbdev)-Thread] DEBUG 
(Provisioner.java:777) - Evaluated GroupTemplate Jexl expression: 
'cu.app.adcu.gsb.stuclubs.green'
2020-04-08 15:55:54,544 [FullSyncer(gsbdev)-Thread] DEBUG 
(Provisioner.java:777) - Evaluated GroupTemplate Jexl expression: 
'cu.app.adcu.gsb.stuclubs.green'
2020-04-08 15:55:54,544 [FullSyncer(gsbdev)-Thread] DEBUG 
(Provisioner.java:777) - Evaluated GroupTemplate Jexl expression: 
'cu.app.adcu.gsb.stuclubs.green'
2020-04-08 15:55:54,544 [FullSyncer(gsbdev)-Thread] DEBUG 
(Provisioner.java:777) - Evaluated GroupTemplate Jexl expression: 
'cu.app.adcu.gsb.stuclubs.green'
2020-04-08 15:55:54,544 [FullSyncer(gsbdev)-Thread] DEBUG 
(Provisioner.java:797) - Evaluated entire GroupTemplate Jexl expression: 'dn: 
cn=cu.app.adcu.gsb.stuclubs.green
cn: cu.app.adcu.gsb.stuclubs.green
objectclass: group
samAccountName: cu.app.adcu.gsb.stuclubs.green
name: cu.app.adcu.gsb.stuclubs.green
groupType: -2147483640'
2020-04-08 15:55:54,552 [FullSyncer(gsbdev)-Thread] INFO  
(LdapProvisioner.java:770) - gsbdev-full: Checking for (and creating) missing 
OUs in DN: 
cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu
 (wholeDnIsOu=false)
2020-04-08 15:55:54,552 [FullSyncer(gsbdev)-Thread] DEBUG 
(LdapProvisioner.java:811) - gsbdev-full: Checking to see if ou exists: 
OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu
2020-04-08 15:55:54,552 [FullSyncer(gsbdev)-Thread] DEBUG 
(LdapSystem.java:676) - Doing ldap read: 
OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu attributes []
2020-04-08 15:55:54,560 [FullSyncer(gsbdev)-Thread] INFO  
(LdapSystem.java:688) - Active Directory: Searching with Ldap 
RangeEntryHandler
2020-04-08 15:55:54,571 [FullSyncer(gsbdev)-Thread] DEBUG 
(LdapSystem.java:703) - gsbdev: Object does exist: 
OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu
2020-04-08 15:55:54,571 [FullSyncer(gsbdev)-Thread] INFO  
(LdapSystem.java:985) - 
cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu:
 Attribute groupType is incorrect: <none> Current values, 1 Correct values
2020-04-08 15:55:54,572 [FullSyncer(gsbdev)-Thread] INFO  
(LdapSystem.java:219) - gsbdev: Performing ldap mod (with retry) Mod Summary: 
dn=cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu|REPLACE
 1 groupType values|
2020-04-08 15:55:54,572 [FullSyncer(gsbdev)-Thread] DEBUG 
(LdapSystem.java:222) - gsbdev: Performing ldap mod (with retry) Mod Details: 
[org.ldaptive.ModifyRequest@173415677::modifyDn=cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu,
 attrMods=[[org.ldaptive.AttributeModification@1969225263::attrMod=REPLACE, 
attribute=[groupType[-2147483640]]]], controls=null, referralHandler=null, 
intermediateResponseHandlers=null]
2020-04-08 15:55:54,611 [FullSyncer(gsbdev)-Thread] INFO  
(LdapSystem.java:985) - 
cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu:
 Attribute name is incorrect: <none> Current values, 1 Correct values
2020-04-08 15:55:54,611 [FullSyncer(gsbdev)-Thread] INFO  
(LdapSystem.java:219) - gsbdev: Performing ldap mod (with retry) Mod Summary: 
dn=cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu|REPLACE
 1 name values|
2020-04-08 15:55:54,611 [FullSyncer(gsbdev)-Thread] DEBUG 
(LdapSystem.java:222) - gsbdev: Performing ldap mod (with retry) Mod Details: 
[org.ldaptive.ModifyRequest@1354018344::modifyDn=cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu,
 attrMods=[[org.ldaptive.AttributeModification@6078647::attrMod=REPLACE, 
attribute=[name[cu.app.adcu.gsb.stuclubs.green]]]], controls=null, 
referralHandler=null, intermediateResponseHandlers=null]
2020-04-08 15:55:54,627 [FullSyncer(gsbdev)-Thread] WARN  
(LdapSystem.java:450) - gsbdev: Problem while modifying ldap system based on 
grouper expectations. Starting to perform adaptive modifications based on 
data already on server: 
cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu:
 NOT_ALLOWED_ON_RDN
2020-04-08 15:55:54,627 [FullSyncer(gsbdev)-Thread] INFO  
(LdapSystem.java:615) - gsbdev: Performaing Ldap comparison operation: 
[name[cu.app.adcu.gsb.stuclubs.green]] on 
dn=cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu...
2020-04-08 15:55:54,647 [FullSyncer(gsbdev)-Thread] ERROR 
(LdapSystem.java:474) - gsbdev: Single-attribute-value Ldap mod-replace 
failed when Ldap server does already have 
name=cu.app.adcu.gsb.stuclubs.green. Mod that failed: 
[org.ldaptive.ModifyRequest@1354018344::modifyDn=cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu,
 attrMods=[[org.ldaptive.AttributeModification@6078647::attrMod=REPLACE, 
attribute=[name[cu.app.adcu.gsb.stuclubs.green]]]], controls=null, 
referralHandler=null, intermediateResponseHandlers=null]
[org.ldaptive.LdapException@1271503185::resultCode=NOT_ALLOWED_ON_RDN, 
matchedDn=null, responseControls=null, referralURLs=null, messageId=-1, 
message=javax.naming.directory.SchemaViolationException: [LDAP: error code 67 
- 000020B1: UpdErr: DSID-030F1087, problem 6004 (CANT_ON_RDN), data 0
]; remaining name 
'cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu',
 providerException=javax.naming.directory.SchemaViolationException: [LDAP: 
error code 67 - 000020B1: UpdErr: DSID-030F1087, problem 6004 (CANT_ON_RDN), 
data 0
]; remaining name 
'cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu']
        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.LdapSystem.performLdapModify(LdapSystem.java:440)
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.performLdapModify(LdapSystem.java:422)
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.makeLdapDataCorrect(LdapSystem.java:993)
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.makeLdapObjectCorrect(LdapSystem.java:904)
        at 
edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.updateGroupFromTemplate(LdapGroupProvisioner.java:257)
        at 
edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.doFullSync(LdapGroupProvisioner.java:166)
        at 
edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.doFullSync(LdapGroupProvisioner.java:42)
        at 
edu.internet2.middleware.grouper.pspng.Provisioner.doFullSync(Provisioner.java:1597)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner.fullSyncGroup(FullSyncProvisioner.java:762)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner.processQueueItem(FullSyncProvisioner.java:456)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner.thread_manageFullSyncProcessing(FullSyncProvisioner.java:252)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner$1.run(FullSyncProvisioner.java:147)
        at java.lang.Thread.run(Thread.java:748)
Caused by: javax.naming.directory.SchemaViolationException: [LDAP: error code 
67 - 000020B1: UpdErr: DSID-030F1087, problem 6004 (CANT_ON_RDN), data 0
]; remaining name 
'cn=cu.app.adcu.gsb.stuclubs.green,OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu'
        at com.sun.jndi.ldap.LdapCtx.mapErrorCode(LdapCtx.java:3185)
        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)
        ... 13 more
2020-04-08 15:55:54,652 [FullSyncer(gsbdev)-Thread] ERROR 
(LdapGroupProvisioner.java:266) - gsbdev-full: Problem checking and updating 
group's template attributes
edu.internet2.middleware.grouper.pspng.PspException: LDAP Modification Failed
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.performLdapModify(LdapSystem.java:480)
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.performLdapModify(LdapSystem.java:422)
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.makeLdapDataCorrect(LdapSystem.java:993)
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.makeLdapObjectCorrect(LdapSystem.java:904)
        at 
edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.updateGroupFromTemplate(LdapGroupProvisioner.java:257)
        at 
edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.doFullSync(LdapGroupProvisioner.java:166)
        at 
edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.doFullSync(LdapGroupProvisioner.java:42)
        at 
edu.internet2.middleware.grouper.pspng.Provisioner.doFullSync(Provisioner.java:1597)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner.fullSyncGroup(FullSyncProvisioner.java:762)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner.processQueueItem(FullSyncProvisioner.java:456)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner.thread_manageFullSyncProcessing(FullSyncProvisioner.java:252)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner$1.run(FullSyncProvisioner.java:147)
        at java.lang.Thread.run(Thread.java:748)
2020-04-08 15:55:54,652 [FullSyncer(gsbdev)-Thread] ERROR 
(FullSyncProvisioner.java:775) - FullSyncer(gsbdev): Problem doing full sync. 
Requeuing group cu:app:adcu:gsb:stuclubs:green/#122853(Existing)
edu.internet2.middleware.grouper.pspng.PspException: LDAP Modification Failed
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.performLdapModify(LdapSystem.java:480)
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.performLdapModify(LdapSystem.java:422)
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.makeLdapDataCorrect(LdapSystem.java:993)
        at 
edu.internet2.middleware.grouper.pspng.LdapSystem.makeLdapObjectCorrect(LdapSystem.java:904)
        at 
edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.updateGroupFromTemplate(LdapGroupProvisioner.java:257)
        at 
edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.doFullSync(LdapGroupProvisioner.java:166)
        at 
edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner.doFullSync(LdapGroupProvisioner.java:42)
        at 
edu.internet2.middleware.grouper.pspng.Provisioner.doFullSync(Provisioner.java:1597)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner.fullSyncGroup(FullSyncProvisioner.java:762)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner.processQueueItem(FullSyncProvisioner.java:456)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner.thread_manageFullSyncProcessing(FullSyncProvisioner.java:252)
        at 
edu.internet2.middleware.grouper.pspng.FullSyncProvisioner$1.run(FullSyncProvisioner.java:147)
        at java.lang.Thread.run(Thread.java:748)
2020-04-08 15:55:54,653 [FullSyncer(gsbdev)-Thread] INFO  
(FullSyncQueueItem.java:324) - FullSync Item done 
(edu.internet2.middleware.grouper.pspng.PspException: LDAP Modification 
Failed). Stats: ins=0|del=0|upd=0|tot=11|t=1 secs/ProcTime: 01.505s Timing 
breakdown: 
init=1%/ReadGroupFromGrouper=7%/ClearingGroupCache=1%/StartCoordination=0%/StartProvisioning(get
 group & subject info)=50%/doFullSync=39%/: 
Action=cu:app:adcu:gsb:stuclubs:green|qid=1|Trigger=Scheduled full 
sync|ExternalRef=null|AsOf=Apr 8, 2020 3:55:53 PM|QTime=00.001s|Age=01.506s
2020-04-08 15:55:54,653 [FullSyncer(gsbdev)-Thread] DEBUG 
(Provisioner.java:1682) - gsbdev-full: Found existing group 
cu:app:adcu:gsb:stuclubs:green/#122853(Existing)
2020-04-08 15:55:54,653 [FullSyncer(gsbdev)-Thread] DEBUG 
(ProvisioningWorkItem.java:203) - WorkItem ProvisioningWorkItem[done=false,
  cmd=FULL_SYNC_GROUP] is related to Group: 
cu:app:adcu:gsb:stuclubs:green/#122853(Existing)
2020-04-08 15:55:54,653 [FullSyncer(gsbdev)-Thread] DEBUG 
(ProvisionerCoordinator.java:108) - gsbdev: Unlocking group after full sync: 
cu:app:adcu:gsb:stuclubs:green/#122853(Existing)
2020-04-08 15:55:54,653 [FullSyncer(gsbdev)-Thread] DEBUG 
(FullSyncProvisioner.java:265) - Caching Stats: TSSubject: [  name = 
PSP-gsbdev-TargetSystemUserCache cacheHits = 0 onDiskHits = 0 offHeapHits = 0 
inMemoryHits = 0 misses = 0 onDiskMisses = 0 offHeapMisses = 0 inMemoryMisses 
= 0 size = 11 averageGetTime = 0.0 evictionCount = 0 ] || TSGroup: [  name = 
PSP-gsbdev-full-TargetSystemGroupCache cacheHits = 0 onDiskHits = 0 
offHeapHits = 0 inMemoryHits = 0 misses = 0 onDiskMisses = 0 offHeapMisses = 
0 inMemoryMisses = 0 size = 1 averageGetTime = 0.0 evictionCount = 0 ]
2020-04-08 15:55:54,654 [FullSyncer(gsbdev)-Thread] INFO  
(FullSyncProvisioner.java:524) - FullSyncer(gsbdev): Next full-sync request: 
Action=cu:app:adcu:gsb:stuclubs:european|qid=2|Trigger=Scheduled full 
sync|ExternalRef=null|AsOf=Apr 8, 2020 3:55:53 PM|QTime=01.506s|Age=01.506s
# Grouper loader uses Grouper Configuration Overlays (documented on wiki)
# By default the configuration is read from grouper-loader.base.properties
# (which should not be edited), and the grouper-loader.properties overlays
# the base settings.  See the grouper-loader.base.properties for the possible
# settings that can be applied to the grouper.properties

# CUIT installation
# we can run Google Apps Provisioner and PSPNG on dev or qa grouper but not 
both
# we don't want two grouper hosts updating the same Google groups, same LDAP 
server

## General settings
default.subject.source.id = idm

# number of days to retain db rows in grouper_loader_log, -1 is forever, 
default is 7
loader.retain.db.logs.days = 1

# number of days to retain db rows in grouper_change_log_entry, -1 is 
forever, default is 14
loader.retain.db.change_log_entry.days = 1

# message settings for loader processes
loader.messaging.settings.autocreate.objects = false

## DB connections
# specify the db connection with user, pass, url, and driver class
# the string after "db." is the name of the connection, and it should not have
# spaces or other special chars in it
db.idm.user = grouper
db.idm.pass = /var/grouper/auth/idmdev1_grouper_pass
db.idm.url = 
jdbc:oracle:thin:@//idmsysdevdb01.cc.columbia.edu:1527/idmdev1.cc.columbia.edu
db.idm.driver = oracle.jdbc.driver.OracleDriver

## TIER Instrumentation daemon
# disable this cron because Grouper hosts cannot connect to the internet
otherJob.tierInstrumentationDaemon.quartzCron =

########################################
#
# pspng: gsbdev provisioner
#
ldap.gsbdev.ldapUrl = ldaps://dev-uni-ad.gsb.columbia.edu
ldap.gsbdev.bindDn = CN=Grouper 
Provisioner,CN=Users,DC=dev,DC=gsb,DC=columbia,DC=edu
ldap.gsbdev.bindCredential = /var/grouper/auth/gsbad_dev_bind_credential
ldap.gsbdev.useStartTLS = false
changeLog.consumer.gsbdev.ldapPoolName = gsbdev
changeLog.consumer.gsbdev.class = 
edu.internet2.middleware.grouper.pspng.PspChangelogConsumerShim
changeLog.consumer.gsbdev.type = 
edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner
changeLog.consumer.gsbdev.quartzCron = 0 * * * * ?
changeLog.consumer.gsbdev.isActiveDirectory = true
changeLog.consumer.gsbdev.memberAttributeName = member
changeLog.consumer.gsbdev.memberAttributeValueFormat = ${ldapUser.getDn()}
changeLog.consumer.gsbdev.groupSearchBaseDn = 
OU=Grouper_Groups,OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu
changeLog.consumer.gsbdev.allGroupsSearchFilter = objectclass=group
changeLog.consumer.gsbdev.singleGroupSearchFilter = 
(&(objectclass=group)(cn=${group.name.replace(":",".")}))
changeLog.consumer.gsbdev.groupSearchAttributes = dn,entryDN,cn,objectclass
changeLog.consumer.gsbdev.groupCreationLdifTemplate = dn: 
cn=${group.name.replace(":",".")}||cn: 
${group.name.replace(":",".")}||objectclass: group||samAccountName: 
${group.name.replace(":",".")}||name: 
${group.name.replace(":",".")}||groupType: -2147483640
changeLog.consumer.gsbdev.supportsEmptyGroups = false
changeLog.consumer.gsbdev.retryOnError = false
changeLog.consumer.gsbdev.sleepTimeAfterError_ms = 30000
changeLog.consumer.gsbdev.searchResultPagingEnabled = false
changeLog.consumer.gsbdev.createMissingUsers = false
changeLog.consumer.gsbdev.userSearchBaseDn = 
OU=GSB_Users,DC=dev,DC=gsb,DC=columbia,DC=edu
changeLog.consumer.gsbdev.userSearchFilter = samAccountName=${subject.id}
changeLog.consumer.gsbdev.userSearchAttributes = 
samAccountName,dn,objectClass,cn
changeLog.consumer.gsbdev.grouperIsAuthoritative = true
otherJob.gsbdev_full.class = 
edu.internet2.middleware.grouper.pspng.FullSyncStarter
otherJob.gsbdev_full.quartzCron = 0 0 2 * * ?