000011918 - AxM 6.X: how to determine if an eserver cache flush event has occured and been sent to the aserver

Document created by RSA Customer Support Employee on Jun 14, 2016Last modified by RSA Customer Support Employee on Apr 21, 2017
Version 2Show Document
  • View in full screen mode

Article Content

Article Number000011918
Applies ToRSA Access Manager 6.X (all datastores, all releases)
IssueAxM 6.X: how to determine if an eserver cache flush event has occured and been sent to the aserver
Password change events are not being flushed from the aserver cache
Resolution

Here is a very simple log trace from both servers that shows a password update using the adminAPI change password command against user1.  It occurs at 10:07:56

In the eserver.out you see the following.   It shows the cache flush event being queued at 10:07:56:682 and then immediately sent.  It also shows the item that will be poisoned.

10:07:56:682 [*] [DataUpdateEventDispatcher] - Notify listener of event: sirrus.api.server.CacheFlushListener

10:07:56:682 [*] [DataUpdateEventDispatcher] - Enqueue cache flush event: UPDATE for UniqueIdentifier (Data Store Type: LDAP Store ID: Testv1 Class Identifier: 16) DN:  "uid=user1,ou=People,dc=rsasecurity,dc=com", tid: Thread[APIClientProxy-0,5,main]

The aserver.out shows the event received at 10:07:56:713.  It then shows the item that will be poisoned.

10:07:56:713 [*] [MuxWorker-5] - FunctionMapping.createObjectFromFunctionNode(): about to invoke method public java.util.Map sirrus.authserver.TCPServerAPIAdaptor.clearServerCaches(java.util.Map,java.util.Map) on 2 args

10:07:56:713 [*] [MuxWorker-5] - Fire DataUpdateEvent, type: UPDATE object: UniqueIdentifier (Data Store Type: LDAP Store ID: Testv1 Class Identifier: 16) DN:  "uid=user1,ou=People,dc=rsasecurity,dc=com"

The eserver.out actually has more detail that may be important.  After the cache flush event is queued there could be a configurable delay while it waits for the database to replicate.  The debug shows this interaction.  It shows the opening of the connection to the aserver, and the closing.   There could be multiple aservers in this list.  This example only shows one.

10:07:56:760 [*] [QueueDispatcher] - Process queued object: Queue delay time has expired, processing object immediately

10:07:56:760 [*] [QueueDispatcher] - Processing cache flush event: UPDATE for UniqueIdentifier (Data Store Type: LDAP Store ID: Testv1 Class Identifier: 16) DN:  "uid=user1,ou=People,dc=rsasecurity,dc=com", tid: Thread[APIClientProxy-0,5,main]

10:07:56:760 [*] [QueueDispatcher] - Cache flush attempt: 1

10:07:56:760 [*] [QueueDispatcher] - AuthServerConnection: started command . Now have 1 active commands

10:07:56:760 [*] [QueueDispatcher] - SEND MSG: DATA_MSG

10:07:56:760 [*] [APIClientProxy-0] - Logging out user=administrator with role=Default Administrative Role, group=Default Administrative Group

10:07:56:760 [*] [APIClientProxy-0] - LogEventDispatcher: current log level is 20 event's log level is 30

10:07:56:776 [*] [MuxStreamReader-0] - MSG: DATA_MSG

10:07:56:776 [*] [QueueDispatcher] - Removing MuxStreamBundle

10:07:56:776 [*] [QueueDispatcher] - AuthServerConnection: command finished. Now have 0 active commands.

Legacy Article IDa54960

Attachments

    Outcomes