hping occasionally reports RTT+1s instead of real RTT

Sometimes hping reports an RTT that is 1000ms larger than all the other values. However, it doesn't actually pause for 1s at that line, it appears that the time is misreported.

      HPING 10.65.1.1 (eth0 10.65.1.1): S set, 40 headers + 0 data bytes
      len=44 ip=10.65.1.1 ttl=63 DF id=0 sport=3000 flags=SA seq=0 win=29200 rtt=3.9 ms
      len=44 ip=10.65.1.1 ttl=63 DF id=0 sport=3000 flags=SA seq=1 win=29200 rtt=1003.7 ms
      len=44 ip=10.65.1.1 ttl=63 DF id=0 sport=3000 flags=SA seq=2 win=29200 rtt=3.4 ms
      len=44 ip=10.65.1.1 ttl=63 DF id=0 sport=3000 flags=SA seq=3 win=29200 rtt=3.0 ms
      len=44 ip=10.65.1.1 ttl=63 DF id=0 sport=3000 flags=SA seq=4 win=29200 rtt=2.7 ms
      len=44 ip=10.65.1.1 ttl=63 DF id=0 sport=3000 flags=SA seq=5 win=29200 rtt=2.3 ms
      len=44 ip=10.65.1.1 ttl=63 DF id=0 sport=3000 flags=SA seq=6 win=29200 rtt=2.0 ms
...

After digging in the codebase, it looks like the problem is this: when storing the timestamp of the outgoing ping, hping does

secs = time(NULL);
usecs = get_usec();

This can fail if the time wraps to the next second between the call to time() and get_usecs().

About to send packet:

clock is at 9.999999s, we read the second part as 9
clock wraps to 1.000000, we read the usec part as 0
record that packet was sent at 9.000000s

Receive response

clock is at 10.001000
read seconds as 10
read usec as 1000

Incorrectly calculate RTT as 10.001000 - 9.000000 = 1.001sec.

Best fix would be to remove the get_usec utility function and call gettimeofday() exactly once and to use the returned tv_sec and tv_usec from the same call.

antirez / hping

hping occasionally reports RTT+1s instead of real RTT #48