Question & Answer
Question
Here are two examples of WebSphere DataPower latency messages:
Mon Sep 19 2011 13:23:40 [latency][info] xmlfirewall (loopback-fw): tid(2809): Latency: 0 1 0 1 1 0 0 1 1 1 1 1 0 0 1 1 [http://[http://127.0.0.1:9999/]]
What are each of the latency arguments in this message?
Answer
These Latency arguments are the timestamps marking when certain events occurred during the life of a completed HTTP transaction.
Each timestamp is expressed in milliseconds (ms) since the transaction began (not additive).
A '0' means that event did not occur and streaming processing can cause the order to change depending on the configuration.
The values reflect the following events respectively: The latencies measure in milliseconds the time since a base latency measurement was taken. Usually, this is at the start of the HTTP transaction.
Please note that the following latency log format is the same for all types of services on DataPower.
The latency log format (numbers are in milliseconds):
| Explanation of Arguments found in the Latency log message | |
| Position | Argument |
| 1 | request header read |
| 2 | request header sent |
| 3 | front side transform begun |
| 4 | front side transform complete |
| 5 | entire request transmitted |
| 6 | front side style-sheet ready |
| 7 | front side parsing complete |
| 8 | response header received |
| 9 | response headers sent |
| 10 | back side transform begun |
| 11 | back side transform complete |
| 12 | response transmitted |
| 13 | back side style-sheet read |
| 14 | back side parsing complete |
| 15 | back side connection attempted |
| 16 | back side connection completed |
Since the arguments above are not additive and mark the timestamps of different events that are not necessarily in order of the transaction execution, it may be useful to understand the "real" order of execution.
The following table shows the execution order of the events in the order they would typically occur during a transaction:
| The "real" execution order of the Latency Arguments for a transaction | |
| Position | Argument |
| 1 | request header read |
| 3 | front side transform begun |
| 7 | front side parsing complete |
| 6 | front side style-sheet ready |
| 4 | front side transform complete |
| 15 | back side connection attempted |
| 16 | back side connection completed |
| 2 | request header sent |
| 5 | entire request transmitted |
| 8 | response headers received |
| 10 | back side transform begun |
| 14 | back side parsing complete |
| 13 | back side style-sheet read |
| 11 | back side transform complete |
| 9 | response headers sent |
| 12 | response transmitted |
There are some variables that may be used for access to certain latency data:
| Names and permissions for variables that are available for latency | |
| Variable name | Permission |
| var://service/time-elapsed | Read-only |
| var://service/time-forwarded | Read-only |
| var://service/time-response-complete | Read-only |
| var://service/time-started | Read-only |
See the Product Documentation Portal for more information about this subject.
Was this topic helpful?
Document Information
Modified date:
08 June 2021
UID
swg21239328