[c-nsp] understanding the IP SLA "icmp-jitter" calculations

Thu Apr 4 08:50:13 EDT 2019

Thanks, ok that makes sense. Right off the bat 300ms just seemed implausible.

So the tap10server is artificially delaying the packets 300ms, so
there is absolutely no way CSR1k could have received it within 1ms.
Unfortunately I can't offer much anything than IP SLA bug.

For additional datapoint you could use UDP echo or jitter and install
https://github.com/cmouse/ip-sla-responder on the server.

On Thu, 4 Apr 2019 at 15:38, Martin T <m4rtntns at gmail.com> wrote:
>
> Hi Saku,
>
> > You quote 'queueing discipline', how do you measure this, is the device fully
> > congested and you expect packets to sit in queue for 300ms?
>
> I'm simply using
> netem(http://manpages.ubuntu.com/manpages/bionic/man8/tc-netem.8.html)
> to introduce the delay.
>
>
> > How far are the devices and what media is between them?
>
> I'm using Cisco CSR 1000v and remote end is the host server. So
> topology is simply following:
>
> csr1000v[Gi1] <-> [tap10]server
>
> Gi1 has 192.168.11.1/24 configured and tap10 has 192.168.11.2/24 configured.
>
>
> > What latency do you see by running simply 'ping x.y.j.k'?
>
> csr1000v#ping 192.168.11.2
> Type escape sequence to abort.
> Sending 5, 100-byte ICMP Echos to 192.168.11.2, timeout is 2 seconds:
> !!!!!
> Success rate is 100 percent (5/5), round-trip min/avg/max = 300/300/301 ms
> csr1000v#
>
>
> Martin
>
>
> On Thu, Apr 4, 2019 at 3:22 PM Saku Ytti <saku at ytti.fi> wrote:
> >
> > Hey Martin,
> >
> > I'd like to understand why do you say 300ms makes sense. You quote
> > 'queueing discipline', how do you measure this, is the device fully
> > congested and you expect packets to sit in queue for 300ms? How far
> > are the devices and what media is between them?
> >
> > What latency do you see by running simply 'ping x.y.j.k'?
> >
> > On Thu, 4 Apr 2019 at 14:59, Martin T <m4rtntns at gmail.com> wrote:
> > >
> > > Hi,
> > >
> > > I configured an icmp-jitter type of IP SLA entry in Cisco CSR1000V
> > > router and enabled IP SLA debug. Following two sequential debug
> > > messages show the sending of the ICMP "Timestamp Request" and
> > > receiving of the ICMP "Timestamp Reply" message:
> > >
> > > *Apr  4 09:55:25.095: IPSLA-OPER_TRACE:OPER:300 Sending ID: 38
> > >
> > > *Apr  4 09:55:25.396: IPSLA-OPER_TRACE:OPER:300 Rev Seq: 1, Id: 38
> > >         STS: 2183208743  RTD: 35723058 STD: 35723058  RTS: 35725395
> > >
> > >
> > > This 2183208743 decimal timestamp(10000010001000010001111100100111 in
> > > binary) is a non-standard
> > > value(https://tools.ietf.org/html/rfc792#page-17) as the most
> > > significant bit is set. 10001000010001111100100111 converts to
> > > 35725095 in decimal, i.e debug output above can be translated into:
> > >
> > > *Apr  4 09:55:25.396: IPSLA-OPER_TRACE:OPER:300 Rev Seq: 1, Id: 38
> > >         STS: 35725095  RTD: 35723058 STD: 35723058  RTS: 35725395
> > >
> > > This means that ICMP "Timestamp Request" reached the destination
> > > -2037(35723058-35725095) milliseconds later. This makes sense because
> > > the system time in destination is set to be bit more than two seconds
> > > behind. Processing in destination took less than a
> > > millisecond(35723058-35723058). ICMP "Timestamp Reply" was sent at
> > > 35723058 and reached the router at 35725395, i.e time difference is
> > > 2337ms. 2037ms is the clock difference and 300ms added by server
> > > egress queue discipline. This 300ms difference can also be seen in
> > > debug messages timestamps, i.e "Apr  4 09:55:25.095" vs "Apr  4
> > > 09:55:25.396". In short, the numbers make perfect sense.
> > >
> > > However, when I check the IP SLA statistics, then it shows that RTT
> > > was 1ms which is clearly wrong:
> > >
> > > IPSLAs Latest Operation Statistics
> > >
> > > IPSLA operation id: 300
> > > Type of operation: icmp-jitter
> > >         Latest RTT: 1 milliseconds
> > > Latest operation start time: 09:55:25 UTC Thu Apr 4 2019
> > > Latest operation return code: OK
> > > RTT Values:
> > >         Number Of RTT: 1                RTT Min/Avg/Max: 1/1/1 milliseconds
> > > Latency one-way time:
> > >         Number of Latency one-way Samples: 0
> > >         Source to Destination Latency one way Min/Avg/Max: 0/0/0 milliseconds
> > >         Destination to Source Latency one way Min/Avg/Max: 0/0/0 milliseconds
> > > Jitter Time:
> > >         Number of SD Jitter Samples: 0
> > >         Number of DS Jitter Samples: 0
> > >         Source to Destination Jitter Min/Avg/Max: 0/0/0 milliseconds
> > >         Destination to Source Jitter Min/Avg/Max: 0/0/0 milliseconds
> > > Over Threshold:
> > >         Number Of RTT Over Threshold: 0 (0%)
> > > Packet Late Arrival: 0
> > > Out Of Sequence: 0
> > >         Source to Destination: 0        Destination to Source 0
> > >         In both Directions: 0
> > > Packet Skipped: 0       Packet Unprocessed: 0
> > > Packet Loss: 0
> > >         Loss Periods Number: 0
> > >         Loss Period Length Min/Max: 0/0
> > >         Inter Loss Period Length Min/Max: 0/0
> > > Number of successes: 1
> > > Number of failures: 0
> > > Operation time to live: Forever
> > >
> > >
> > > 1) Why does "sh ip sla statistics" report 1ms RTT?
> > > 2) Does "icmp-jitter" expect the timestamps to be STS < RTD < STD <
> > > RTS and if not, then no calculations are made?
> > > 3) How practical such measurements are as even a small, few
> > > millisecond time offset in remote host, can screw up the latency
> > > measurement results?
> > >
> > >
> > > thanks,
> > > Martin
> > > _______________________________________________
> > > cisco-nsp mailing list  cisco-nsp at puck.nether.net
> > > https://puck.nether.net/mailman/listinfo/cisco-nsp
> > > archive at http://puck.nether.net/pipermail/cisco-nsp/
> >
> >
> >
> > --
> >   ++ytti

-- 
  ++ytti