Forum Discussion

Jason_Heath_432's avatar
Icon for Nimbostratus rankNimbostratus
May 06, 2011

Is microsecond precision available in an iRule?

I am trying to get to microsecond precision in an iRule I am working on.




Based on reading the Tcl docs that I found a link to on this site ( I would expect "clock microseconds" to have worked. A bit more digging and experimentation after I got an error I would have expected "clock clicks -microseconds" to have worked. After that also triggered an error I started digging through the forums. At this point I'm not sure that microsecond precision is available but I haven't been able to find definitive documentation saying that. I tried to figure out the level of Tcl support that I should expect but have been unable to do so. I'm reasonably certain that I'm on a BigIP 6900 at version 10.2.1.




What I'm ultimately trying to achieve is an iRule that inserts a header named "X-Request-Start" that inserts a value like "t=1304697000869668". The following is what I have right now. There is a bit of debugging/development cruft in this version.






set now t=[clock clicks]


set x_request_start "X-Request-Start"


set big_ip_x_request_start "BigIP-X-Request-Start"



HTTP::header remove $x_request_start


HTTP::header remove $big_ip_x_request_start



HTTP::header insert $x_request_start $now


HTTP::header insert $big_ip_x_request_start $now


HTTP::header insert X-HELLO there






Trimming that down to a focused version of what I'm really after one would get something like






set now t=[clock microseconds]


set x_request_start "X-Request-Start"


HTTP::header remove $x_request_start


HTTP::header insert $x_request_start $now






The Tcl documentation for "clock clicks" states that without "If no -option argument is supplied, returns a high-resolution time value as a system-dependent integer value." I tried that hoping to get microseconds, I instead got a negative value that won't be useful to me.



this value came from an intermediate Apache server that inserted the sort of value I'm trying to achieve






this value from "HTTP::header insert $big_ip_x_request_start $now" above






Can anyone explain what clicks means within an iRule? If I can't get to microseconds, can I get to milliseconds? I tried both "clicks -milliseconds" and "clock milliseconds" and go results that mirrored what I've seen attempting to get microseconds so I don't think milliseconds is available either.


8 Replies

  • microsecond resolution isn't currently possible, but millisecond resolution should work fine for calculating deltas in time:

    set start_time [clock clicks -milliseconds]
     do something else
    log local0. "delta: [expr {[clock clicks -milliseconds] - $start_time}]"

    clock clicks ?-milliseconds? ... This value should only be used for the relative measurement of elapsed time.

    For the current time, I think the best you can get is second resolution.

  • I found an older post which said that microseconds support isn't possible until TCL v8.5. I think there are plans to update the TCL base in iRules from 8.4, but I don't know of any concrete timing for this.



    You could open a case with F5 Support and ask them to open a request for enhancement to support millisecond clock resolution in iRules. If you do, can you reply back with the RFE ID?



    Thanks, Aaron
  • If you use [clock clicks] you get the highest resolution timer value available on the platform with the least overhead possible. Of course that does not represent microseconds, but it can be very useful.
  • hoolio: Have you tried that within an iRule? I'm reasonably sure that I tried that Friday when I was working on this and I don't think the -milliseconds worked either.



    And does anybody know what value it is that clock clicks is returning?


  • spark_86682's avatar
    Historic F5 Account
    On my 10.1.0 box, "clock clicks" returns microseconds. Here's an example:
         set a1 [clock clicks]
         set b1 [clock clicks -milliseconds]
         after 10
         set a2 [clock clicks]
         set b2 [clock clicks -milliseconds]
         after 100
         set a3 [clock clicks]
         set b3 [clock clicks -milliseconds]
         after 1000
         set a4 [clock clicks]
         set b4 [clock clicks -milliseconds]
         log local0. "As: $a1 $a2 $a3 $a4"
         log local0. "Bs: $b1 $b2 $b3 $b4"
         log local0. "a2-a1: [expr $a2 - $a1]  a3-a2: [expr $a3 - $a2]  a4-a3: [expr $a4 - $a3]"
         log local0. "b2-b1: [expr $b2 - $b1]  b3-b2: [expr $b3 - $b2]  b4-b3: [expr $b4 - $b3]"
    and here's what it logs:
     As: -1076552924 -1076543381 -1076442893 -1075443255
     Bs: -426278316 -426278306 -426278206 -426277206
     a2-a1: 9543  a3-a2: 100488  a4-a3: 999638
     b2-b1: 10  b3-b2: 100  b4-b3: 1000
    The microseconds counts each round to the number of milliseconds that we waited, and that were measured.

    The negative numbers are because Tcl is presenting unsigned numbers as signed numbers, but the subtraction math still works out, so don't be fooled by that. However, this also means you won't be able to measure durations of more than 2^31 microseconds, which is about 35 minutes.
  • Colin_Walker_12's avatar
    Historic F5 Account
    Very nice info, thanks Spark. I seem to remember some gotchas regarding trying to get to this level of detail with the clock command, but can't seem to turn up the thread I'm thinking of right now. Anything we should watch out for here? If I find what I'm thinking of I'll post it here.



  • The clock clicks number is not equal to actual microseconds. You need to take into account the processor frequency, and there may be some inaccuracy due to interrupts, etc. In general, I tell people they can think of it as microseconds but the greater the number (difference between first observation and second observation) the greater the skew from accuracy. Imperical testing over a long period using an external time source (known to be accurate) will help prove the case.



    Write an irule that just does an "HTTP::respond 200 content [clock clicks]" and call it every 60 seconds for several days. You'll see the skew for the box in question. When you have an HA pair, you can't assume the processor frequencies are identical either. So you need to check both boxes.