Openmoko Bug #2320: icmp ping RTT over wifi plotted over time forms a sawtooth wave

Openmoko Public Trac bugs at docs.openmoko.org
Wed Nov 25 22:57:05 CET 2009


#2320: icmp ping RTT over wifi plotted over time forms a sawtooth wave
-----------------------------+----------------------------------------------
 Reporter:  lindi            |          Owner:  openmoko-kernel    
     Type:  defect           |         Status:  new                
 Priority:  normal           |      Milestone:                     
Component:  System Software  |        Version:  unspecified        
 Severity:  normal           |       Keywords:  wifi latency kernel
 Haspatch:  0                |      Blockedby:                     
Estimated:                   |    Patchreview:                     
 Blocking:                   |   Reproducible:  always             
-----------------------------+----------------------------------------------
 icmp ping over wifi seems to show very peculiar delays that increase by
 around 10 ms on every attempt and at some point reset back to 20 ms:

 {{{
 $ ping 192.168.2.1
 64 bytes from 192.168.2.1: icmp_seq=29 ttl=64 time=20.1 ms
 64 bytes from 192.168.2.1: icmp_seq=30 ttl=64 time=40.1 ms
 64 bytes from 192.168.2.1: icmp_seq=31 ttl=64 time=60.1 ms
 64 bytes from 192.168.2.1: icmp_seq=32 ttl=64 time=80.3 ms
 64 bytes from 192.168.2.1: icmp_seq=33 ttl=64 time=90.3 ms
 64 bytes from 192.168.2.1: icmp_seq=34 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=35 ttl=64 time=30.1 ms
 64 bytes from 192.168.2.1: icmp_seq=36 ttl=64 time=50.1 ms
 64 bytes from 192.168.2.1: icmp_seq=37 ttl=64 time=70.1 ms
 64 bytes from 192.168.2.1: icmp_seq=38 ttl=64 time=90.2 ms
 64 bytes from 192.168.2.1: icmp_seq=39 ttl=64 time=109 ms
 64 bytes from 192.168.2.1: icmp_seq=40 ttl=64 time=20.1 ms
 64 bytes from 192.168.2.1: icmp_seq=41 ttl=64 time=40.1 ms
 64 bytes from 192.168.2.1: icmp_seq=42 ttl=64 time=60.1 ms
 64 bytes from 192.168.2.1: icmp_seq=43 ttl=64 time=85.5 ms
 64 bytes from 192.168.2.1: icmp_seq=44 ttl=64 time=104 ms
 64 bytes from 192.168.2.1: icmp_seq=45 ttl=64 time=115 ms
 64 bytes from 192.168.2.1: icmp_seq=46 ttl=64 time=447 ms
 64 bytes from 192.168.2.1: icmp_seq=47 ttl=64 time=770 ms
 64 bytes from 192.168.2.1: icmp_seq=48 ttl=64 time=380 ms
 64 bytes from 192.168.2.1: icmp_seq=49 ttl=64 time=90.2 ms
 64 bytes from 192.168.2.1: icmp_seq=50 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=51 ttl=64 time=30.1 ms
 64 bytes from 192.168.2.1: icmp_seq=52 ttl=64 time=50.1 ms
 64 bytes from 192.168.2.1: icmp_seq=53 ttl=64 time=70.1 ms
 64 bytes from 192.168.2.1: icmp_seq=54 ttl=64 time=90.2 ms
 64 bytes from 192.168.2.1: icmp_seq=55 ttl=64 time=100 ms
 64 bytes from 192.168.2.1: icmp_seq=56 ttl=64 time=21.5 ms
 64 bytes from 192.168.2.1: icmp_seq=57 ttl=64 time=40.1 ms
 64 bytes from 192.168.2.1: icmp_seq=58 ttl=64 time=60.0 ms
 64 bytes from 192.168.2.1: icmp_seq=59 ttl=64 time=80.3 ms
 64 bytes from 192.168.2.1: icmp_seq=60 ttl=64 time=100 ms
 64 bytes from 192.168.2.1: icmp_seq=61 ttl=64 time=120 ms
 64 bytes from 192.168.2.1: icmp_seq=62 ttl=64 time=30.1 ms
 64 bytes from 192.168.2.1: icmp_seq=63 ttl=64 time=50.0 ms
 64 bytes from 192.168.2.1: icmp_seq=64 ttl=64 time=70.1 ms
 64 bytes from 192.168.2.1: icmp_seq=65 ttl=64 time=90.2 ms
 64 bytes from 192.168.2.1: icmp_seq=66 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=67 ttl=64 time=30.1 ms
 64 bytes from 192.168.2.1: icmp_seq=68 ttl=64 time=50.0 ms
 64 bytes from 192.168.2.1: icmp_seq=69 ttl=64 time=60.0 ms
 64 bytes from 192.168.2.1: icmp_seq=70 ttl=64 time=80.3 ms
 64 bytes from 192.168.2.1: icmp_seq=71 ttl=64 time=100 ms
 64 bytes from 192.168.2.1: icmp_seq=72 ttl=64 time=20.1 ms
 64 bytes from 192.168.2.1: icmp_seq=73 ttl=64 time=40.1 ms
 64 bytes from 192.168.2.1: icmp_seq=74 ttl=64 time=60.1 ms
 }}}

 linux is andy-tracking a3587e4ed77974ad
 hardware is gta02v5
 tested with two WLAN APs, one is wrt54gl v1.1 running openwrt svn r18459
 with b43 driver and the other one is unknown.

 Is something buffering the packets?

 Since ping measures RTT I used

 nc -lp1234 -u | perl -e 'use Time::HiRes; $| = 1; while (<>) {
 $l=Time::HiRes::time() - $_; $l*=1000;print "$l\n"; }'
 perl -e 'use Time::HiRes; $| = 1; while (1) { print Time::HiRes::time() .
 "\n"; sleep(1); }' | nc -u 192.168.0.99 1234

 to measure delay from PC to openmoko

 {{{
 12.293959
 12.502098
 12.347841
 11.870050
 11.975908
 11.922026
 12.448931
 11.515045
 12.295866
 11.923933
 11.738920
 11.603022
 11.639023
 11.248970
 26.214981
 11.125946
 11.755848
 10.733032
 11.644983
 11.251116
 11.290932
 11.272812
 11.109018
 11.723185
 11.438990
 11.480951
 11.324072
 11.042976
 11.093998
 10.823870
 14.966869
 18.019819
 }}}

 and openmoko to PC

 {{{
 128.469002
 129.320871
 128.603947
 128.538143
 128.767979
 128.843081
 136.215937
 133.112204
 137.031090
 128.907930
 128.802073
 128.696215
 128.594887
 129.487049
 129.377853
 129.401934
 129.205000
 129.066002
 128.966105
 128.860008
 129.772913
 129.657042
 137.234938
 129.427921
 129.323017
 129.232895
 130.115997
 130.011093
 130.097162
 129.807007
 129.707109
 129.714024
 129.505884
 }}}

 The absolute values mean nothing since the clocks are not entirely in
 sync. However, we can see here that this test does not show the same
 variations as we see with ping. What an earth could be going on here? If I
 ping with shorter interval the delay seems to stick to some value that is
 different on each attempt:

 {{{
 lindi at ginger:~$ ping -i 0.2 192.168.2.1
 PING 192.168.2.1 (192.168.2.1) 56(84) bytes of data.
 64 bytes from 192.168.2.1: icmp_seq=1 ttl=64 time=87.4 ms
 64 bytes from 192.168.2.1: icmp_seq=2 ttl=64 time=90.2 ms
 64 bytes from 192.168.2.1: icmp_seq=3 ttl=64 time=90.1 ms
 64 bytes from 192.168.2.1: icmp_seq=4 ttl=64 time=90.1 ms
 64 bytes from 192.168.2.1: icmp_seq=5 ttl=64 time=90.1 ms
 64 bytes from 192.168.2.1: icmp_seq=6 ttl=64 time=90.1 ms
 64 bytes from 192.168.2.1: icmp_seq=7 ttl=64 time=90.3 ms
 64 bytes from 192.168.2.1: icmp_seq=8 ttl=64 time=90.1 ms
 64 bytes from 192.168.2.1: icmp_seq=9 ttl=64 time=90.0 ms
 64 bytes from 192.168.2.1: icmp_seq=10 ttl=64 time=90.1 ms
 64 bytes from 192.168.2.1: icmp_seq=11 ttl=64 time=90.1 ms
 }}}
 {{{
 lindi at ginger:~$ ping -i 0.2 192.168.2.1
 PING 192.168.2.1 (192.168.2.1) 56(84) bytes of data.
 64 bytes from 192.168.2.1: icmp_seq=1 ttl=64 time=32.1 ms
 64 bytes from 192.168.2.1: icmp_seq=2 ttl=64 time=35.4 ms
 64 bytes from 192.168.2.1: icmp_seq=3 ttl=64 time=35.3 ms
 64 bytes from 192.168.2.1: icmp_seq=4 ttl=64 time=35.3 ms
 64 bytes from 192.168.2.1: icmp_seq=5 ttl=64 time=35.3 ms
 64 bytes from 192.168.2.1: icmp_seq=6 ttl=64 time=35.3 ms
 64 bytes from 192.168.2.1: icmp_seq=7 ttl=64 time=35.3 ms
 64 bytes from 192.168.2.1: icmp_seq=8 ttl=64 time=40.1 ms
 64 bytes from 192.168.2.1: icmp_seq=9 ttl=64 time=40.1 ms
 }}}
 {{{
 lindi at ginger:~$ ping -i 0.2 192.168.2.1
 PING 192.168.2.1 (192.168.2.1) 56(84) bytes of data.
 64 bytes from 192.168.2.1: icmp_seq=1 ttl=64 time=108 ms
 64 bytes from 192.168.2.1: icmp_seq=2 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=3 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=4 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=5 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=6 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=7 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=8 ttl=64 time=105 ms
 64 bytes from 192.168.2.1: icmp_seq=9 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=10 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=11 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=12 ttl=64 time=110 ms
 64 bytes from 192.168.2.1: icmp_seq=13 ttl=64 time=110 ms
 }}}

-- 
Ticket URL: <https://docs.openmoko.org/trac/ticket/2320>
docs.openmoko.org <http://docs.openmoko.org/trac/>
openmoko trac


More information about the openmoko-kernel mailing list