Sawtooth ping RTT on RPi

[Ian Lepore]

On Wed, 2013-05-08 at 20:44 +1000, Peter Jeremy wrote:
> On 2013-May-08 03:12:43 -0700, Adrian Chadd <adrian at freebsd.org> wrote:
> >yup, that looks like two almost-but-not-in-sync sampling periods (one
> >being poll, one being ping) beating against each other.
> 
> That seems like a reasonable hypothesis.
> 
> >Is the USB stuff being polled?
> 
> I'm not sure.  I don't think so.  dmesg says:
> 
> dwcotg0: <DWC OTG 2.0 integrated USB controller> mem 0x20980000-0x2099ffff irq 17 on simplebus0
> usbus0 on dwcotg0
> smsc0: <vendor 0x0424 product 0xec00, rev 2.00/2.00, addr 3> on usbus0
> ue0: <USB Ethernet> on smsc0
> 
> So there's an interrupt available and nothing else is using irq 17.
> And systat shows that the interrupt rate on irq 17 goes up with
> network traffic (though it idles at ~500 interrupts/sec - which seems
> excessive).
> 

Just to make all of this even more confusing, my RPi results always look
like this with kern.hz set to one of 100, 500, 1000, 2500:

  PING revolution.hippie.lan (172.22.42.240): 56 data bytes
  64 bytes from 172.22.42.240: icmp_seq=0 ttl=64 time=7.739 ms
  64 bytes from 172.22.42.240: icmp_seq=1 ttl=64 time=10.130 ms
  64 bytes from 172.22.42.240: icmp_seq=2 ttl=64 time=10.115 ms
  64 bytes from 172.22.42.240: icmp_seq=3 ttl=64 time=10.146 ms
  
However, with kern.hz=250, I get this:

  PING revolution.hippie.lan (172.22.42.240): 56 data bytes
  64 bytes from 172.22.42.240: icmp_seq=0 ttl=64 time=5.839 ms
  64 bytes from 172.22.42.240: icmp_seq=1 ttl=64 time=8.169 ms
  64 bytes from 172.22.42.240: icmp_seq=2 ttl=64 time=8.156 ms
  64 bytes from 172.22.42.240: icmp_seq=3 ttl=64 time=8.145 ms

And with kern.hz=333, it looks like this:

  PING revolution.hippie.lan (172.22.42.240): 56 data bytes
  64 bytes from 172.22.42.240: icmp_seq=0 ttl=64 time=6.757 ms
  64 bytes from 172.22.42.240: icmp_seq=1 ttl=64 time=9.126 ms
  64 bytes from 172.22.42.240: icmp_seq=2 ttl=64 time=9.208 ms
  64 bytes from 172.22.42.240: icmp_seq=3 ttl=64 time=9.252 ms

Very strange.  No matter what kern.hz is set to, I always get a shorter
time on the first packet, and then after that the variance from one
packet to the next is always within about 100us.  

My other arm systems running -current don't behave like this.

-- Ian