Example 8: Snapshots
A snapshot provides a brief dump of the current statistics associated with all the dispatcher components. All timing statistics reflect elapsed time, not CPU time.
A housekeeping thread wakes up at intervals specified by the Trace Interval setting in the Server Manager, and it travels the entire tree, depth first, producing a SNAPSHOT log record for each node in the tree.
The order of dispatchers in a snapshot is not significant. It depends on some internal data structures and may change over time. The order of slaves listed under their dispatcher is not significant. This also depends on internal data structures and may change over time.
The following example shows a snapshot produced when the SPO had two dispatchers (D1 and D2) with one slave owned by each dispatcher (S1 under D1, and S2 under D2).
2007/10/04_13:36:00.452 SNAPSHOT: DispatcherMgr
TotalClients: 1
CurDispatchers: 2
ReservedSlaveQuota: 4
TotalSlaves: 2
2007/10/04_13:36:00.452 SNAPSHOT: D1
cnt min max avg
QueueUse/Depth: 67 0 0 0
QueueWait: 0ms 0ms 0ms
CurSlaves: 1
ClientRefs: 0
2007/10/04_13:36:00.452 SNAPSHOT: S1
cnt min max avg
QueueUse/Depth: 34 0 0 0
QueueWait: 0ms 0ms 0ms
Initiates: 1 563ms 563ms 563ms
Call4GLs: 33 0ms 16ms 0ms
ASOTrxCount: 33
2007/10/04_13:36:00.452 SNAPSHOT: D2
cnt min max avg
QueueUse/Depth: 5 0 0 0
QueueWait: 0ms 0ms 0ms
CurSlaves: 1
ClientRefs: 0
2007/10/04_13:36:00.452 SNAPSHOT: S2
cnt min max avg
QueueUse/Depth: 3 0 0 0
QueueWait: 0ms 0ms 0ms
Initiates: 1 547ms 547ms 547ms
Call4GLs: 2 0ms 16ms 8ms
ASOTrxCount: 2
The Dispatcher Manager snapshot shows the total number of clients currently connected to the SPO, the number of dispatchers, and the total number of slaves. ReservedSlaveQuota reflects the number of slaves that would exist if all the current dispatchers created their maximum configured number of slaves. (A dispatcher reserves its full slave quota when it is created, before it attempts to create any slaves. This helps to ensure that dynamic slave creation cannot fail due to the limit on the total numbers of slaves in the system.)
A dispatcher snapshot shows the dispatcher queue use count (the number of times the dispatcher lock was obtained) and the queue depth statistics (minimum, maximum, and average number of threads waiting in the queue at the time the lock was released). It also shows the queue wait statistics (minimum, maximum, and average number of milliseconds that threads had to wait before obtaining the dispatcher lock). Because the dispatching process is quick, there is rarely any contention for the dispatcher lock, and dispatcher queue depth and queue waits are usually close to zero. The dispatcher snapshot also includes the current number of slaves owned by the dispatcher, and the number of clients that have initiated with that dispatcher's signature.
A slave snapshot shows the slave queue statistics (similar to the dispatcher snapshot) and statistics regarding the Initiate and Call4GL requests that slave has processed. The slave queue statistics will vary widely, depending on how quickly your application can process its SCP calls inside the ASO. The Initiate and Call4GL statistics show the count of calls, and the minimum, maximum, and average number of milliseconds taken to process the calls.
Sometimes a Call4GL request causes a stopped slave to be restarted implicitly. The thread processing the Call4GL will first do an implicit Initiate of the ASO, and that restart will be reflected in the Initiate statistics. The time taken for the implicit Initiate is also added to the statistics for that Call4GL, since the total elapsed time (including the implicit Initiate) is what an end user would see as the cost of that particular Call4GL call.
Note: Locks are sometimes obtained for internal housekeeping purposes, and therefore the total queue use count for a slave may be higher than the sum of the Initiate and Call4GL counts. Also, call durations may be recorded as zero if they are shorter than the granularity of the timer (which is about 10 milliseconds on a typical machine).
The Initiate and Call4GL statistics are cumulative over the lifetime of the slave object. The ASO transaction count reflects only the number of Call4GL requests processed by the current ASO instance, and it is reset to zero each time the slave is stopped.