000025333 - How do you interpret the pool log output when the agent is configured for cleartrust.agent.log_pool_option=Both

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

Article Content

Article Number000025333
Applies ToRSA ClearTrust Agent 4.6
IssueHow do you interpret the pool log output when the agent is configured for cleartrust.agent.log_pool_option=Both
Resolution

Here is an example of the log output in the ctagent.log file with the pool logging option enabled.

Information is logged for each pool whenever a pool refresh event occurs.  Some agents, such as IIS and Apache may have more that one pool and may allocate additional pools dynamically.  Each pool will log its own events.  It is not possible to positively identify a specific pool, but the process ID and thread ID, in this example "[9775/12]" are usually unique for a pool.

The first line tells you the time the pool refresh event occurred.  This typically occurs every hour, but may also occur if the aserver list is refreshed manually, for example if a connection is dropped.

The value "updates = 1376" indicates the number of times this pool has been refreshed since it was started, and the last refresh is the time since the last time the aserver list was updated (time is in seconds since 1970, to convert to date use excel format =A3/(60*60*24)+DATE(1970,1,1) ).

The next block gives information on what dispatcher and aserver mode the agent is using. 

connection limit is the value of cleartrust.agent.max_open_connections
the pool mode is one of the following, STANDARD, or DISTRIBUTED with a submode of either ADAPTIVE or ROUNDROBIN
the Dispatcher mode is either STANDARD or DISTRIBUTED
The number of dispatchers matches the value of
The Auth servers: list shows the number of aservers currently reporting to the dispatchers as available, and the number actually connected.

The next section shows all the connected aservers and their statistics.  The aserver marked as <-- current, is the aserver that this pool is currently using (not that important for ROUNDROBIN mode).  The aserver name and port are listed, along with any location class for the aserver.  The list is sorted in order of location class, with aservers not belonging to a particular location class listed at the end.

The statistical information is useful to understand the behavior of the agent, but these numbers need some interpretation. 

Requests - a running total of the number requests since the last pool refresh event.  This number is reset with each pool refresh event. 

failures - a running total of the number of requests that did not return results within a specific time, or returned an error.  Note that this number is not reset with the pool event.  This is an absolute number that is only reset when the agent is restarted.

queued - the report back from the aserver as to the current queue length for a particular aserver.  The agent uses this list in ADAPTIVE DISTRIBUTED mode to determine what aserver to use.  The aserver with the lowest queue length will be used as the next aserver.  (If the queue length is the same, the aserver with the lowest delay will be used.

delay - an estimate of the delay in  microseconds (10^-6 seconds) for that aserver.  This is not an absolute number, but a weighted moving average of the last 8 request times skewed to the most recent requests.  This number is not reset with the pool refresh event but will trend towards the average delay.  This value is used to choose the server with the least delay to us in situations where the queue lengths of all aservers in the pool are the same.

Caches - information on behavior of the Agent cache. (more information required.)

Jan 21, 2007 08:56:10 PM EST - [9775/12] - <Config> - [ct_print_pool_info] - Pool: name = __default__, updates = 1376, last refresh = 1169430970
{
    No connection limit, Currently not refreshing
    Pool mode: distributed, Dispatcher mode: standard
    Dispatchers: 2
    {
        dispatcher1:5608 <-- current
        dispatcher2:5608
    }
    Auth servers: 6, connected: 4
    {
        10.10.10.1:5615@location1 (connected) <-- current
            Requests: 7207, failures: 1041, queued: 1, delay: 7514
        10.10.10.2:5615@location1 (connected)
            Requests: 2, failures: 893, queued: 0, delay: 2136
        10.10.10.3:5615@location1 (connected)
            Requests: 3, failures: 7496, queued: 0, delay: 1847
        10.10.10.4:5615@location1 (connected)
            Requests: 3, failures: 8007, queued: 0, delay: 12995
        10.10.10.5:5615@_NO_AS_CLASS_
            Requests: 0, failures: 0, queued: 0, delay: 0
        10.10.10.6:5615@_NO_AS_CLASS_
            Requests: 0, failures: 0, queued: 0, delay: 0
       
    }
    Caches: 6
    {
        #0: requests: 4395475 hits: 1245210 entries: 10000 size: 10000 TTL: 600 secs
        #1: requests: 3150265 hits: 636250 entries: 43 size: 1000 TTL: 600 secs
        #2: requests: 3607341 hits: 856549 entries: 10000 size: 10000 TTL: 600 secs
        #3: requests: 2750792 hits: 3535 entries: 42 size: 1000 TTL: 600 secs
        #4: requests: 0 hits: 0 entries: 0 size: 10000 TTL: 600 secs
        #5: requests: 4649034 hits: 4544076 entries: 793 size: 10000 TTL: 600 secs
       


See also solution ClearTrust Agent pool logging options shows a large number of failures compared to the number of requests.
Legacy Article IDa33822

Attachments

    Outcomes