IBM Support

Latency messages in DataPower appliance

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://:9999/foo/test.xml] Fri Feb 16 2012 13:04:27 [latency][info] xmlfirewall(TestLogging): tid(2075615): Latency: 0 0 0 0 1 0 0 1 0 0 0 1 0 0 0 0 [[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
PositionArgument
1request header read
2request header sent
3front side transform begun
4front side transform complete
5entire request transmitted
6front side style-sheet ready
7front side parsing complete
8response header received
9response headers sent
10back side transform begun
11back side transform complete
12response transmitted
13back side style-sheet read
14back side parsing complete
15back side connection attempted
16back 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
PositionArgument
1request header read
3front side transform begun
7front side parsing complete
6front side style-sheet ready
4front side transform complete
15back side connection attempted
16back side connection completed
2request header sent
5entire request transmitted
8response headers received
10back side transform begun
14back side parsing complete
13back side style-sheet read
11back side transform complete
9response headers sent
12response 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-elapsedRead-only
var://service/time-forwardedRead-only
var://service/time-response-completeRead-only
var://service/time-startedRead-only

See the Product Documentation Portal for more information about this subject.

[{"Product":{"code":"SS9H2Y","label":"IBM DataPower Gateways"},"Business Unit":{"code":"BU053","label":"Cloud & Data Platform"},"Component":"General","Platform":[{"code":"PF009","label":"Firmware"}],"Version":"4.0.2;5.0.0;6.0.0;6.0.1","Edition":"Edition Independent","Line of Business":{"code":"LOB15","label":"Integration"}}]

Document Information

Modified date:
15 June 2018

UID

swg21239328