[c-nsp] Cisco IOS ping utility reports lower RTT than possible

[adamv0025 at netconsultings.com]

> Martin T
> Sent: Friday, May 3, 2019 11:14 AM
> 
> Hi Octavio,
> 
> instead of a two-card laptop I used the available ports in server named
"svr",
> but in principle I built the setup you described:
> 
> CISCO1921[Gi0/0] <-> [eno1]test-br[eno2] <-> [eno3]svr
> 
> "test-br" is a two-port Linux bridge in "svr" server. Now when I execute
"ping
> 10.66.66.1 source 10.66.66.2" in Cisco router, then the results are
following:
> 
> CISCO1921#ping 10.66.66.1 source 10.66.66.2 Type escape sequence to abort.
> Sending 5, 100-byte ICMP Echos to 10.66.66.1, timeout is 2 seconds:
> Packet sent with a source address of 10.66.66.2 !!!!!
> Success rate is 100 percent (5/5), round-trip min/avg/max = 8/9/12 ms
> CISCO1921#
> 
> As seen above, minimum measurement was 8ms and average was 9ms. On
> the other hand, packet capture done on eno2 clearly shows that each ICMP
> "echo request" message receives a ICMP "echo reply" with >10ms delay as it
> should:
> 
> svr$ sudo tcpdump -ttt -nei eno2 icmp
> tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
> listening on eno2, link-type EN10MB (Ethernet), capture size 262144 bytes
>  00:00:00.000000 50:0f:80:a5:03:a0 > 3c:a8:2a:1e:f3:da, ethertype IPv4
> (0x0800), length 114: 10.66.66.2 > 10.66.66.1: ICMP echo request, id
60632,
> seq 0, length 80
>  00:00:00.010201 3c:a8:2a:1e:f3:da > 50:0f:80:a5:03:a0, ethertype IPv4
> (0x0800), length 114: 10.66.66.1 > 10.66.66.2: ICMP echo reply, id 60632,
seq
> 0, length 80
>  00:00:00.000431 50:0f:80:a5:03:a0 > 3c:a8:2a:1e:f3:da, ethertype IPv4
> (0x0800), length 114: 10.66.66.2 > 10.66.66.1: ICMP echo request, id
60632,
> seq 1, length 80
>  00:00:00.010165 3c:a8:2a:1e:f3:da > 50:0f:80:a5:03:a0, ethertype IPv4
> (0x0800), length 114: 10.66.66.1 > 10.66.66.2: ICMP echo reply, id 60632,
seq
> 1, length 80
>  00:00:00.000382 50:0f:80:a5:03:a0 > 3c:a8:2a:1e:f3:da, ethertype IPv4
> (0x0800), length 114: 10.66.66.2 > 10.66.66.1: ICMP echo request, id
60632,
> seq 2, length 80
>  00:00:00.010199 3c:a8:2a:1e:f3:da > 50:0f:80:a5:03:a0, ethertype IPv4
> (0x0800), length 114: 10.66.66.1 > 10.66.66.2: ICMP echo reply, id 60632,
seq
> 2, length 80
>  00:00:00.000328 50:0f:80:a5:03:a0 > 3c:a8:2a:1e:f3:da, ethertype IPv4
> (0x0800), length 114: 10.66.66.2 > 10.66.66.1: ICMP echo request, id
60632,
> seq 3, length 80
>  00:00:00.010184 3c:a8:2a:1e:f3:da > 50:0f:80:a5:03:a0, ethertype IPv4
> (0x0800), length 114: 10.66.66.1 > 10.66.66.2: ICMP echo reply, id 60632,
seq
> 3, length 80
>  00:00:00.000332 50:0f:80:a5:03:a0 > 3c:a8:2a:1e:f3:da, ethertype IPv4
> (0x0800), length 114: 10.66.66.2 > 10.66.66.1: ICMP echo request, id
60632,
> seq 4, length 80
>  00:00:00.010136 3c:a8:2a:1e:f3:da > 50:0f:80:a5:03:a0, ethertype IPv4
> (0x0800), length 114: 10.66.66.1 > 10.66.66.2: ICMP echo reply, id 60632,
seq
> 4, length 80
> 
> Cisco IOS ping command inserts the timestamp into the payload of the ICMP
> "echo request" message and at least it seems to increment it, i.e that
part
> seems to be fine.
> 
> 
So how should I interpret the above tcpdump output please?
Is it that for seq0 the request was spotted at time 000000 and reply was
spotted at 010201 = ~10ms later.
And then for seq1 the request was spotted at time 000431 and reply was
spotted at 010165 = ~9ms later.
But if that's the case then how should I interpret seq2, 3 and 4 which all
were spotted before second request at time 000431 please? I'm confused. 

adam