On Tue, 5 Jul 2005, Manuel Bouyer wrote:

>> On my router:
>>
>> #  time /sbin/ping -c 5 www.washington.edu
>> PING www.washington.edu (140.142.3.7): 56 data bytes
>> 64 bytes from 140.142.3.7: icmp_seq=0 ttl=57 time=95.812 ms
>> 64 bytes from 140.142.3.7: icmp_seq=1 ttl=57 time=102.938 ms
>> 64 bytes from 140.142.3.7: icmp_seq=2 ttl=57 time=84.297 ms
>> 64 bytes from 140.142.3.7: icmp_seq=3 ttl=57 time=69.290 ms
>> 64 bytes from 140.142.3.7: icmp_seq=4 ttl=57 time=111.203 ms
>>
>> ----www.washington.edu PING Statistics----
>> 5 packets transmitted, 5 packets received, 0.0% packet loss
>> round-trip min/avg/max/stddev = 69.290/92.708/111.203/16.397 ms
>>    10.70s real     0.06s user     3.35s system
>
> What is the system doing for 3.35s for such a light task ? Also, the
> real time should be 5s, not 10s. Does top or systat vm reveal some
> high system CPU usage ?

I didn't really notice that. I did this a few more times (only difference 
was a different NIC and a reboot).

5 packets transmitted, 5 packets received, 0.0% packet loss
round-trip min/avg/max/stddev = 7.389/66.557/103.288/44.764 ms
     3.81s real     1.15s user 42949672.67s system

system time is way off. (The shell's time is from ksh.)


5 packets transmitted, 5 packets received, 0.0% packet loss
round-trip min/avg/max/stddev = 73.813/96.490/120.985/17.926 ms
    19.15s real     3.32s user     0.10s system

19 seconds is slow.

5 packets transmitted, 5 packets received, 0.0% packet loss
round-trip min/avg/max/stddev = 26.357/56.721/94.156/26.613 ms
     8.25s real     0.13s user     3.57s system

And another example:

$ time /sbin/ping -c 5 www.washington.edu
PING www.washington.edu (140.142.3.35): 56 data bytes
64 bytes from 140.142.3.35: icmp_seq=0 ttl=57 time=92.821 ms
64 bytes from 140.142.3.35: icmp_seq=1 ttl=57 time=6450.027 ms
64 bytes from 140.142.3.35: icmp_seq=2 ttl=57 time=114.192 ms
64 bytes from 140.142.3.35: icmp_seq=3 ttl=57 time=-7833.590 ms
64 bytes from 140.142.3.35: icmp_seq=4 ttl=57 time=77.477 ms

----www.washington.edu PING Statistics----
5 packets transmitted, 5 packets received, 0.0% packet loss
round-trip min/avg/max/stddev = -7833.590/-219.815/6450.027/5068.384 ms
    14.35s real     0.93s user     1.76s system

6450 ms can't be correct and the negative number is wrong too.


And some examples to NetBSD:

$ time /sbin/ping -c 5 www.netbsd.org 
PING www.netbsd.org (204.152.190.12): 56 data bytes
64 bytes from 204.152.190.12: icmp_seq=0 ttl=243 time=0.006 ms
64 bytes from 204.152.190.12: icmp_seq=1 ttl=243 time=97.916 ms
64 bytes from 204.152.190.12: icmp_seq=2 ttl=243 time=2465.484 ms
64 bytes from 204.152.190.12: icmp_seq=3 ttl=243 time=1868.607 ms
64 bytes from 204.152.190.12: icmp_seq=4 ttl=243 time=130.104 ms

----www.netbsd.org PING Statistics----
5 packets transmitted, 5 packets received, 0.0% packet loss
round-trip min/avg/max/stddev = 0.006/912.423/2465.484/1165.572 ms
     8.14s real     0.05s user     0.72s system

$ time /sbin/ping -c 5 www.netbsd.org
PING www.netbsd.org (204.152.190.12): 56 data bytes
64 bytes from 204.152.190.12: icmp_seq=0 ttl=243 time=112.385 ms
64 bytes from 204.152.190.12: icmp_seq=1 ttl=243 time=133.724 ms
64 bytes from 204.152.190.12: icmp_seq=2 ttl=243 time=-8930.317 ms
64 bytes from 204.152.190.12: icmp_seq=3 ttl=243 time=194.835 ms
64 bytes from 204.152.190.12: icmp_seq=4 ttl=243 time=260.105 ms

----www.netbsd.org PING Statistics----
5 packets transmitted, 5 packets received, 0.0% packet loss
round-trip min/avg/max/stddev = -8930.317/-1645.854/260.105/4072.546 ms
    12.65s real     4.60s user 42949672.56s system

But from my workstation (with same NetBSD/i386 2.0.2) it behaves good.

top and vmstat don't indicate any load problem.

Here is vmstat during a ping test:

$ vmstat 3 8
  procs    memory      page                       disks      faults 
cpu
  r b w    avm    fre  flt  re  pi   po   fr   sr m0 w0 w1   in   sy  cs us 
sy id
  0 0 0  57368  17592   35   0   0    0    0    0  0  3  0  141  156  17  1 
1 98
  0 0 0  57520  17424   42   0   0    0    0    0  0  0  0  110  128  17  0 
1 99
  0 0 0  57384  17544  155   0   0    0    0    0  0 12  0  120  218  30  3 
3 94
  0 0 0  57384  17544    2   0   0    0    0    0  0  7  0  109   13   4  0 
0 100
  0 0 0  57384  17544    2   0   0    0    0    0  0  0  0  103   13   4  0 
0 100
  0 0 0  57384  17544    2   0   0    0    0    0  0  4  0  108   25   5  0 
1 99
  0 0 0  57528  17388   39   0   0    0    0    0  0  0  0  113   91  13  0 
1 99
  0 0 0  57528  17388    2   0   0    0    0    0  0  0  0  103   16   4  0 
0 100


The following was done while about vmstat was running:

$ time /sbin/ping -c 5 www.washington.edu
PING www.washington.edu (140.142.15.233): 56 data bytes
64 bytes from 140.142.15.233: icmp_seq=0 ttl=57 time=75.781 ms
64 bytes from 140.142.15.233: icmp_seq=1 ttl=57 time=-23781.699 ms
64 bytes from 140.142.15.233: icmp_seq=2 ttl=57 time=99.391 ms
64 bytes from 140.142.15.233: icmp_seq=3 ttl=57 time=30.359 ms
64 bytes from 140.142.15.233: icmp_seq=4 ttl=57 time=123.606 ms

----www.washington.edu PING Statistics----
5 packets transmitted, 5 packets received, 0.0% packet loss
round-trip min/avg/max/stddev = -23781.699/-4690.512/123.606/10672.353 ms
    33.34s real     0.12s user     2.85s system


Here is my dmesg.boot 
http://pilchuck.reedmedia.net/jeremy/tmp-ohc5t8/dmesg.boot

  Jeremy C. Reed

  	  	 	 BSD News, BSD tutorials, BSD links
 	  	 	 http://www.bsdnewsletter.com/