hping occasionally reports RTT+1s instead of real RTT

[fasaxc]

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.

[jipanyang]

@fasaxc Good catch and nice root cause analysis! Are you going to create a PR to hping for this issue? Hit the same problem. It would be great if you already have code fix to it.