Forum Discussion

RSpangler_17032's avatar
RSpangler_17032
Icon for Nimbostratus rankNimbostratus
Mar 24, 2017

Response time iRule error

Hello,   So I'm trying to implement code that will capture request and response times between the F5 and the backend servers. I found this spinet of code here, iRule Response time, and I'm trying t...
devops
iRules
LTM
Jeremy_Church_3's avatar
Jeremy_Church_3
Icon for Cirrus rankCirrus

If your goal is to simply check the server's response time to a request, I'm including a small snippet of what I have done in the past.

Probably the best time to capture the actual response time is between HTTP_REQUEST_SEND and HTTP_RESPONSE.

 

ltm profile statistics DELAY_STAT {
    field1 total
    field2 webtest_total
    field3 webtest_slow
    field4 webtest_fast
}

ltm rule LOG-Delay {
    when RULE_INIT {
     what is a slow response in milliseconds
    set static::slow_response 2000
}
when HTTP_REQUEST_SEND {
    STATS::incr DELAY_STAT total
    clientside {
        if {[string tolower [HTTP::host]] contains "onpoint342labupgrade2013"} {
            STATS::incr DELAY_STAT webtest_total
            set URL [string tolower [HTTP::host]][HTTP::uri]
            set SENT [clock clicks -milliseconds]
        }
    }
}
when HTTP_RESPONE {
     exit event if variable is not set
    if {![info exists SENT]} { return }

    set TIME [expr {[clock clicks -milliseconds] - $SENT}]
    if {$TIME >= $static::slow_response} {
        STATS::incr DELAY_STAT webtest_slow
        log local0. "[HTTP::status]: Client [IP::client_addr]; \
        Server [IP::server_addr]:[TCP::server_port]; URL ${URL}; Time ${TIME}ms"
    } else {
        STATS::incr DELAY_STAT webtest_fast
    }
    unset SENT URL TIME
}
}

 

As long as HTTP pipelining is not being used, and hopefully it's not, this would be fine.

Notes

  1. If you expect a lot of logging, I recommend using HSL instead of the log command.
  2. I'm not logging every bit of information, you can add as needed.
  3. You should check out the request logging profile on the F5. It may be able to accomplish what you are looking for without an iRule, though I don't think you can control which URLs it is logging.
  4. I added STATS to track all/slow/fast requests. You would need to add the stats profile to the virtual server for it to work. In the past, I have found it handy to see how many requests were fast vs slow at a glance. Additional STATS fields can be added fairly easily to track other things without requiring you to sift through log messages.
  5. The delay between HTTP_REQUEST_SEND and HTTP_RESPONSE may not include the total response time. The HTTP_RESPONSE event fires when the F5 has received the complete HTTP header, which is not always the same as the response contents.
RSpangler_17032's avatar
RSpangler_17032
Icon for Nimbostratus rankNimbostratus
Apr 03, 2017

OK, I found how to setup the Request Logging but it doesn't seem to be working for me. I know I'm not doing something right just haven't figured it out yet.

I do have the iRule working but now I'm trying to figure out how I can get it to only log for the URL that I want and not every URL that comes through the VS. do you have an idea how I can accomplish this?

This is the iRule I am using:

 

when HTTP_REQUEST {
    set CLIENT_ADDR [IP::client_addr]
    set XFF [HTTP::header X-Forwarded-For]
    set ID "[TCP::local_port][expr { int(100000000 * rand()) }]"
    set REQUEST_RECEIVE [clock clicks -milliseconds]
    set HST "[HTTP::host]"
    set URI "[HTTP::uri]"
}


when HTTP_REQUEST_SEND {
    set REQUEST_SEND [clock clicks -milliseconds]
    set REQUEST_WAIT [expr {$REQUEST_SEND - $REQUEST_RECEIVE}]
    log local0. "SRC:$CLIENT_ADDR  XFF:$XFF ID:$ID HST:$HST'/'$URI"
}

when HTTP_RESPONSE {
    set RESPONSE_TIME [expr {[clock clicks -milliseconds] - $REQUEST_SEND}]
    log local0. "SRC:$CLIENT_ADDR XFF:$XFF ID:$ID HST:$HST$URI - HTTP[HTTP::status] $RESPONSE_TIME\ms/$REQUEST_WAIT\ms [LB::server addr]"
}

 

I want to somehow tell this to log only if the URL is ex. website1.com log if it is website2.com ignore as they will both come into the same VS on the F5.