Grouper Users - Open Discussion List

[Dominique Petitpierre <>]

Hello,

For a while I was wondering why the gsh code to trigger a full sync of a single group did not work for me.
I followed carefully the instructions ("Full Sync Provisioner using GrouperMessagingEngine (Faster)"):
https://spaces.at.internet2.edu/display/Grouper/Grouper+Provisioning:+PSPNG#highlighter_687389
https://lists.internet2.edu/sympa/arc/grouper-users/2018-12/msg00038.html

The gsh code seemed correct:

provisioner_name="activedirectory_employee";
group_name="application:testpspng:group1";
gs=GrouperSession.startRootSession();
edu.internet2.middleware.grouperClient.messaging.GrouperMessagingEngine.send(new edu.internet2.middleware.grouperClient.messaging.GrouperMessageSendParam().assignGrouperMessageSystemName(GrouperBuiltinMessagingSystem.BUILTIN_NAME).assignQueueType(edu.internet2.middleware.grouperClient.messaging.GrouperMessageQueueType.queue).assignQueueOrTopicName("pspng_full_sync_" + provisioner_name +"_asap").addMessageBody(group_name));

The grouper-loader.properties had a matching provisioner:

...
changeLog.consumer.activedirectoryemployee.class = edu.internet2.middleware.grouper.pspng.PspChangelogConsumerShim
changeLog.consumer.activedirectoryemployee.type = edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner
...

And the loader daemon was running and had started to read the pspng_full_sync_activedirectory_employee_asap queue:

2020-10-01 02:45:28,764: [FullSyncer(activedirectory_employee)-MessageReaderThread-asap] INFO  FullSyncProvisioner.thread_fullSyncMessageQueueReader(293) -  - FullSyncer(activedirectory_employee) message reader Starting: pspng_full_sync_activedirectory_employee_asap-->asap

The output of the gsh script seemed correct as well:

...
Type help() for instructions
activedirectoryemployee
application:testpspng:group1
edu.internet2.middleware.grouper.GrouperSession: 8db8b312eaad4521ba072474f74d56c9,'GrouperSystem','application'

But there was no sign of a full sync happening in the logs (INFO log level), just the usual lines when gsh is starting:

2020-10-01 20:10:41,039: [main] WARN  GrouperStartup.printConfigOnce(232) -  - Grouper starting up: version: 2.4.0, build date: null, env: test_2.4.0_grouper-loader
grouperPatchStatus read from: /usr/local/grouper-loader/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, 94, 95, 96
pspng patches installed:      0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12
...
subject.properties internalsource id:g:isa
subject.properties groupersource id: g:gsa
subject.properties groupersource id: grouperEntities
# And that's it: no more logged output.

I.e the message seems to be ignored by the queue's message reader.

Note: the other method described in the documentation did not work any better. ("Full Sync Provisioner using FullSyncer (Slower, but also works)").

I had a vague memory that I did succeed in making it work and tried all kinds of changes or sequence of operations, thinking there was something in my context that caused the problem; to no avail.
Until out of desperation I tried to change the name of the provisioner and remove the underline character (activedirectory_employee -> activedirectoryemployee).
After effecting the change everywhere (properties, gsh script, provision_to attribute) and restarting the loader,  the script did succeed in triggering a full sync of a single group:

...
subject.properties groupersource id: grouperEntities
2020-10-01 20:28:49,770: [FullSyncer(activedirectoryemployee)-MessageReaderThread-asap] INFO  FullSyncProvisioner.thread_fullSyncMessageQueueReader(352) -  - FullSyncer(activedirectoryemployee)/asap message reader: received and processing 1 messages
2020-10-01 20:28:49,771: [FullSyncer(activedirectoryemployee)-MessageReaderThread-asap] INFO  FullSyncProvisioner.thread_fullSyncMessageQueueReader(380) -  - FullSyncer(activedirectoryemployee) message reader: queuing onto asap queue: Action="application:testpspng:group1|qid=6|Trigger=from" old-format message|ExternalRef=null|AsOf=Oct 1, 2020 8:28:49 PM|QTime=00s|Age=00.001s
2020-10-01 20:28:49,771: [FullSyncer(activedirectoryemployee)-Thread] INFO  FullSyncProvisioner.getNextFullSyncRequest(524) -  - FullSyncer(activedirectoryemployee): Next full-sync request: Action="application:testpspng:group1|qid=6|Trigger=from" old-format message|ExternalRef=null|AsOf=Oct 1, 2020 8:28:49 PM|QTime=00.001s|Age=00.001s
2020-10-01 20:28:49,771: [FullSyncer(activedirectoryemployee)-Thread] INFO  FullSyncProvisioner.thread_manageFullSyncProcessing(248) -  - Starting to process full-sync queue item: Action="application:testpspng:group1|qid=6|Trigger=from" old-format message|ExternalRef=null|AsOf=Oct 1, 2020 8:28:49 PM|QTime=00.001s|Age=00.001s
2020-10-01 20:28:49,810: [FullSyncer(activedirectoryemployee)-Thread] INFO  FullSyncProvisioner.fullSyncGroup(751) -  - FullSyncer(activedirectoryemployee): Starting Full-Sync (from old-format message) of group application:testpspng:group1/#16437(Existing)
...
2020-10-01 20:28:50,118: [FullSyncer(activedirectoryemployee)-Thread] INFO  LdapGroupProvisioner.doFullSync(206) -  - activedirectoryemployee-full: Group application:testpspng:group1/#16437(Existing) has 0 extra values
2020-10-01 20:28:50,118: [FullSyncer(activedirectoryemployee)-Thread] INFO  LdapGroupProvisioner.doFullSync(225) -  - activedirectoryemployee-full: Group application:testpspng:group1/#16437(Existing) has 0 missing values
2020-10-01 20:28:50,118: [FullSyncer(activedirectoryemployee)-Thread] INFO  ProvisioningWorkItem.setStatus(132) -  - Work item handled: ProvisioningWorkItem[done=true,successful=true,msg=Modification complete,
  cmd=FULL_SYNC_GROUP]

Now I am glad that I can test full sync on just one group without resorting to having the provision_to attribute only on that group and do a global full sync.
(And I found in a previous versions of the properties file that I had once a provisioner name without an underline which could explain why I remember that it had worked before.)

But I am worried: If that is the case for the gsh script, may be the various processing that take place during incremental or full sync are also affected by that issue:
i.e. a lot of rescheduling of full sync of groups occur (when there are concurrent changes etc.) and may be some of these use the same messaging mechanism as the gsh script above to put a message in a queue whose name contains the provisioner's name. In which case if that name contains an underline character the message would be ignored and cause the processing to not work as intended.
I did not research that.

But I noticed that quite a few people named a PSPNG provisioner with an underline in it, e.g.:

pspng_activedirectory   https://lists.internet2.edu/sympa/arc/grouper-users/2020-09/msg00044.html
pspng_brancheGrouper    https://lists.internet2.edu/sympa/arc/grouper-users/2020-03/msg00000.html
pspng_activedirectory   https://lists.internet2.edu/sympa/arc/grouper-users/2019-10/msg00030.html
pspng_entitlement       https://lists.internet2.edu/sympa/arc/grouper-users/2019-08/msg00042.html
pspng_iamucla_entl      https://lists.internet2.edu/sympa/arc/grouper-users/2019-08/msg00024.html

And last but not least all the examples in the PSPNG documentation (pspng_groupOfUniqueNames, pspng_posixGroup, pspng_activedirectory):
https://spaces.at.internet2.edu/display/Grouper/Grouper+Provisioning:+PSPNG#GrouperProvisioning:PSPNG-GROUPOFUNIQUENAMES

Hence my questions:

- Am I overlooking something else? (i.e. is there indeed something special in my context that causes the problem?)
- Does the gsh script work for you? (who have a provisioner containing an underline character in its name)
  If yes or no:  with what versions of Grouper and patches?

If it is indeed a bug,
- Does it affect the provisioner's processing? (cf. my worry above)
- and has it been fixed since Grouper 2.4.0,  PSPNG patch 12 (2019/12/22), API patch 96 (2020/03/24)? (I could not find anything related in JIRA or grouper-users)
  (I suspect it did work for Grouper 2.4.0 PSPNG patch 12, API patch 89 (2020/01/10), cf. Yoann Delattre's posts https://lists.internet2.edu/sympa/arc/grouper-users/2020-03/msg00020.html and https://lists.internet2.edu/sympa/arc/grouper-users/2020-03/msg00000.html)

Thanks in advance for your answers and comments!

Regards.

-- 
Mr Dominique Petitpierre, user=Dominique.Petitpierre domain=unige.ch
IT Division, University of Geneva, Switzerland