Forum Discussion

Randy_Johnson_1's avatar
Randy_Johnson_1
Icon for Nimbostratus rankNimbostratus
Mar 30, 2010

HTTP REQUEST Event timelines -

Hello, Forum -

 

I'm trying to troubleshoot what I suspect is a client issue by using some creative iRuling -

 

 

We're currently using a basic iRule to write a timestamp on the inbound leg, and a timestamp on the outbound leg.

 

 

when HTTP_REQUEST {

 

set http_request_time [clock clicks -milliseconds]

 

set request_log_line "\

 

[HTTP::request_num],\

 

[IP::remote_addr],\

 

[HTTP::method],\

 

[HTTP::uri]\,

 

[HTTP::host],\

 

[LB::server]\

 

"

 

}

 

when HTTP_RESPONSE {

 

set http_response_time [ clock clicks -milliseconds ]

 

log local0.info "$request_log_line,\

 

[HTTP::status],\

 

[expr $http_response_time - $http_request_time]"

 

}

 

 

However, research indicates that may be a little deceptive in the case where a client has a SLOW internet connection, since the 'HTTP_REQUEST' event is "Triggered when the system fully parses a complete client request header (that is, the method, URI, version, and all headers, not including the body)."

 

Similarly, the HTTP_RESPONSE event is "Triggered when the system parses all of the response status and header lines from the server response."

 

 

So... I guess my question is whehter or not there is an event that occurs when all the body data for a POST is collected ?

 

 

Even more basic... does it matter ? Does the BigIP make a load balancing decision based on the info it receives in a HTTP_REQUEST and open the connection based on that, then sit and wait until it has collected the POST data or 'stream' the POST data to the virtual server ?

 

 

In our case, we suspect that a client has a slow connection, or crappy routing. So, an initial connection is made but that it takes a long time (several seconds) to send the complete POST request through to IIS, where it is processed by our app fairly quickly.

 

 

Logging indicates that our app processes in sub-second times, but that for some specific clients, the overall tranasction time (measured at the LB by the iRule above) takes SUBSTANTIALLY longer than it should, or than other clients' transactions do.

 

 

 

Thanks for any insights !

 

 

 

 

 

 

 

 

 

1 Reply

  • Hi Randy,

     

     

    So... I guess my question is whehter or not there is an event that occurs when all the body data for a POST is collected ?

     

     

     

    You could collect the request payload, and then measure the time delta in HTTP_REQUEST_DATA, but this would add latency and load and skew the results.

     

     

    Even more basic... does it matter ? Does the BigIP make a load balancing decision based on the info it receives in a HTTP_REQUEST and open the connection based on that, then sit and wait until it has collected the POST data or 'stream' the POST data to the virtual server ?

     

     

     

    No, I don't think it matters. I believe that LTM makes a load balancing or persistence decision for most cases with an HTTP VIP based on the TCP or HTTP request headers. Once the headers are parsed and a load balancing decision is made, LTM opens (or re-uses) a server side connection. The exact characteristics for how it sends the TCP data depends on the VIP's TCP profile. But in general, I wouldn't expect much latency in the process of relaying the data.

     

     

    In our case, we suspect that a client has a slow connection, or crappy routing. So, an initial connection is made but that it takes a long time (several seconds) to send the complete POST request through to IIS, where it is processed by our app fairly quickly.

     

     

    Logging indicates that our app processes in sub-second times, but that for some specific clients, the overall tranasction time (measured at the LB by the iRule above) takes SUBSTANTIALLY longer than it should, or than other clients' transactions do.

     

     

     

    I'd suggest capturing tcpdumps and trying to reproduce the issue. This will be the most complete and definitive way to troubleshoot intermittent latency (assuming you can reproduce the issue while capturing the trace). To do so, you can use a trace like:

     

     

    tcpdump -i 0.0 -s 0 -w /var/tmp/test.1.dmp host CLIENT_IP

     

     

    -i 0.0 = all switch interfaces

     

    -s 0 = no snaplength restriction (capture the full packet)

     

    -w = output file

     

    host CLIENT_IP = filter

     

     

    If you're using SNAT, you'll need to filter on the SNAT IP or each pool member to capture both sides of the trace. This will add a lot of data to the trace as you'll be capturing all server side traffic through the VIP.

     

     

    tcpdump -ni 0.0 -s 0 -w /var/tmp/test.1.dmp host CLIENT_IP or host SNAT_IP

     

     

    For details on capturing and analysing tcpdumps, you can check SOL411 on AskF5.com or search online.

     

     

    SOL411: Overview of packet tracing with the tcpdump utility

     

    https://support.f5.com/kb/en-us/solutions/public/0000/400/sol411.html

     

     

    Aaron