Log entries for admin copy cache events


Two types of log entries mark admin copy cache events:

  • Admin copy cache event triggered by definition change
  • Admin copy cache event triggered by Group/User change

 Admin copy cache event triggered by definition change

A definition change received for copy cache marks the copy cache event and includes the following parameters:

  • tid - Thread ID
  • user - User who triggers the event

Here is an example of the log entry:

<THRD> <0 > /* Fri Nov 19 2010 11:32:25.1550 */ Defn change received for copycache: tid=3368 user=Demo

CopyCache: CreateNewCache indicates that a new cache must be created, it marks the cache event, and includes the thread ID ( tid ).

Here is an example of the log entry:

<THRD> <0 > /* Fri Nov 19 2010 11:32:25.1550 */ CopyCache: CreateNewCache tid=3368

A definition change might not trigger creation of a new cache if it is received during a delay recache period (see Best-practices-for-preventing-cache-memory-issues). In this case, the existing admin cache is used. This is shown in the following log example:

<THRD> <0 > /* Fri Nov 19 2010 11:32:37.5780 */ CopyCache: existingAdminCache tid=3368

CopyCache Begin marks the beginning of the copy cache event, if a new cache is being created. This event includes the following parameters:

  • cacheID - The cache ID of the current cache
  • rpcCallProc - Remote procedure call value
  • tid - Thread ID
  • rpcid - The unique ID of the remote procedure call
  • numCaches - The current number of caches in the process
  • maxNumCaches - The maximum number of caches allowed for the process, based on the configuration

Here is an example of the log entry:

<THRD> <0 > /* Fri Nov 19 2010 11:32:25.1710 */ CopyCache Begin: cacheId=1 rpcCallProc=8 user="Demo" tid=3368 rpcId=66 numCaches=2 maxNumCaches=2147483647, alloc=0 bytes

CopyCache End marks the end of the copy cache event, and includes the following parameters:

  • new cacheId - The ID of the new cache
  • old cacheId - The ID of the current cache
  • threadCount - The number of threads holding the current cache
  • tids - The IDs of the threads holding the current cache

Here is an example of the log entry:

<THRD> <0 > /* Fri Nov 19 2010 11:32:37.5000 */
CopyCache End: new cacheId=2, old cacheId=1 threadCount=1 tids=3368,alloc=0 bytes, diff=0 bytes

cacheChange Completed indicates the end of the cache change event. Here is an example of the log entry:

<THRD> <0 > /* Fri Nov 19 2010 11:32:37.5780 */ Cache Change Completed: tid=3368

Admin Cache Promoted occurs after the delayRecacheTime has elapsed, and if no more definition changes are queued. This entry logs the completion of the copy cache event, and includes the following parameters:

  • cacheID - The new cache ID
  • cacheIdToFree - The ID of the current cache that is to be released

Here is an example of the log entry:

<THRD> <0 > /* Fri Nov 19 2010 11:33:20.1880 */ Admin Cache Promoted: cacheId=2 rpcCallProc=0 user="NULL" tid=5844 rpcId=0 cacheIdToFree=1

The copy cache event is followed by a FreeServerCache event, as seen in the following example:

<THRD> <0 > /* Fri Nov 19 2010 11:35:53.6760 */ FreeServerCache Begin: cacheId=1 rpcCallProc=0 user="NULL" tid=4864 rpcId=0, alloc=0 bytes
<THRD> <0 /* Fri Nov 19 2010 11:35:54.4260 */ FreeServerCache End: cacheId=1 rpcCallProc=0 user="NULL" tid=4864 rpcId=0, alloc=0 bytes, diff=-0 bytes

For more information about FreeServerCache, see Log-entries-for-free-server-cache-events.

 Admin copy cache event triggered by Group/User change

When a group or user change occurs, a copy cache event is triggered. This event is marked by the Group/User Change Received entry, and includes the following parameters:

  • tid - The thread ID
  • user - The user who triggers the event
  • userOrGroup - Indicates a user or group change
  • groupRecacheIsPending - Indicates that the event is pending based on a previous change.
  • delayRecacheTime - The amount of time this copy cache event will be delayed, based on your configuration
  • Add request to Timer Queue - Indicates the amount of time the copy cache event will be delayed based on the configured delayRecacheTime.
  • Add request to Admin thread - Marks the completed delayRecacheTime .
  • AR_INTERNAL_REQ_GROUP_CHANGED Started - Indicates the start of the copy cache event.

Here is an example of the log entry:

<THRD> <1 > /* Fri Nov 19 2010 11:38:22.1970 */ Group/User Change Received: tid=3164 user=Demo userOrGroup=GROUP groupRecacheIsPending=0 delayRecacheTime=5 , Add request to Timer Queue
<THRD> /* Fri Nov 19 2010 11:38:27.1970 */ GroupChangeRecache: tid=2400 delayRecacheTime=5 lastGroupChangeTime=1290195502, Add request to Admin thread
<THRD> <1 > /* Fri Nov 19 2010 11:38:27.1970 */ PerformInternalRequest: AR_INTERNAL_REQ_GROUP_CHANGED Started, tid=3368

Here is an example of the log entry for the actual copy cache:

<THRD> <1 > /* Fri Nov 19 2010 11:38:27.1970 */ CopyCache: CreateNewCache tid=3368
<THRD> <1 > /* Fri Nov 19 2010 11:38:27.2130 */ CopyCache Begin: cacheId=2 rpcCallProc=10002 user="Demo" tid=3368 rpcId=0 numCaches=2 maxNumCaches=2147483647, alloc=0 bytes
<THRD> <1 > /* Fri Nov 19 2010 11:38:33.7600 */ CopyCache End: new cacheId=3, old cacheId=2 threadCount=1 tids=3368,alloc=0 bytes, diff=0 bytes

After a copy cache event, the group permissions are reloaded from the database. This is indicated with the AR_INTERNAL_REQ_GROUP_CHANGED Completed log entry as shown in the following example:

<THRD> <1 > /* Fri Nov 19 2010 11:38:34.9780 */PerformInternalRequest: AR_INTERNAL_REQ_GROUP_CHANGED Completed, tid=3368
<THRD> <1 > /* Fri Nov 19 2010 11:38:34.9780 */ Cache Change Completed: tid=3368

Admin Cache Promoted occurs after the delayRecacheTime has elapsed, and if no more changes are queued. This entry logs the completion of the copy cache event as shown in the following example:

<THRD> <0 > /* Fri Nov 19 2010 11:39:20.9010 */ Admin Cache Promoted: cacheId=3 rpcCallProc=0 user="NULL" tid=4140 rpcId=0 cacheIdToFree=2

The copy cache event is followed by a FreeServerCache event, as shown in the following example:

<THRD> <0 > /* Fri Nov 19 2010 11:35:53.6760 */ FreeServerCache Begin: cacheId=2 rpcCallProc=0 user="NULL" tid=4864 rpcId=0, alloc=0 bytes
<THRD> <0 /* Fri Nov 19 2010 11:35:54.4260 */ FreeServerCache End: cacheId=2 rpcCallProc=0 user="NULL" tid=4864 rpcId=0, alloc=0 bytes, diff=-0 bytes

For more information about FreeServerCache, see Log-entries-for-free-server-cache-events.


 

Tip: For faster searching, add an asterisk to the end of your partial query. Example: cert*

BMC Helix Innovation Suite 26.1