Calculate time taken for an HTTP request-response

[telsonalva]

Hi All,

Need help with my iRules, basically i am trying to calculate the time take when the F5 receives a request and sends it to the client. This gives me the time for how long the request took on our side before releasing it to the client. However i have seem some descrepancies with certain requests.

Setup:

I have two load balancers, there are two iRules and on each load balancer the time taken is calculated and the value sent as a header back in the response.

The traffic flow is as follows

Internet User -> Load balancer 1 -> Load balancer 2 -> Backend servers

iRule on Load balancer 1:

ltm rule LoadBalancer1 { 
    when HTTP_REQUEST { 
                       
    #Record the time when request event in this iRule is triggered
    set http_request_time [clock clicks -milliseconds]
                        
    }            
	when HTTP_RESPONSE_RELEASE  {
	
	#Record the time when response is ready to be released to the client side
	set http_responserelease_time [clock clicks -milliseconds]
	set time_taken [expr {$http_responserelease_time - $http_request_time}]
	
	#set response headers for client side analysis
	HTTP::header replace "LoadBalancer1-TimeTaken" "$time_taken ms"
	
	#unset the variables
	unset http_responserelease_time http_request_time time_taken
	}
}

iRule on Load balancer 2:

ltm rule LoadBalancer2 { 
    when HTTP_REQUEST { 
                       
    #Record the time when request event in this iRule is triggered
    set http_request_time [clock clicks -milliseconds]
                        
    }            
    when HTTP_RESPONSE_RELEASE  {
	
	#Record the time when response is ready to be released to the client side
	set http_responserelease_time [clock clicks -milliseconds]
	set time_taken [expr {$http_responserelease_time - $http_request_time}]
	
	#set response headers for client side analysis
	HTTP::header replace "LoadBalancer2-TimeTaken" "$time_taken ms"
	
	#unset the variables
	unset http_responserelease_time http_request_time time_taken
     }
}

Problem:

Assuming my above setup is correct, then the value of header LoadBalancer1-TimeTaken should be greater than LoadBalancer2-TimeTaken for each of the HTTP requests sent during a page load.

Though i see this to be true (LoadBalancer1-TimeTaken > LoadBalancer2-TimeTaken) for most of the requests, some requests it is the other way (LoadBalancer2-TimeTaken > LoadBalancer1-TimeTaken) I have noticed this for some javascript files, from my observation it seems consistent for the same javascript files. How is this possible?

[jaikumar_f5]

I use the below snippet for troubleshooting latency stuffs.

when HTTP_REQUEST {
set http_request_time [clock clicks -milliseconds]
}
when HTTP_REQUEST_SEND {
set irule_proc_time [expr {[clock clicks -milliseconds] - $http_request_time}]
}
when HTTP_RESPONSE {
log local0. "Irule-proc-time=$irule_proc_time;Response Time-taken:[expr {[clock clicks -milliseconds] - $http_request_time}]ms"
}

Capture for every URI and its content length, see which is causing time to load longer.

[telsonalva]

Thanks, its the same logic that i have, i do not understand how the time taken on LB1 can be lesser than LB2 when the request flows from LB1->LB2.