Date: Fri, 10 Jul 1998 23:32:16 +0300 (EEST) From: jkirma@vulcan.tky.hut.fi To: FreeBSD-gnats-submit@FreeBSD.ORG Subject: misc/7239: ping(8) and traceroute(8) may report erratic round-trip times Message-ID: <199807102032.XAA08920@vulcan.tky.hut.fi>
index | next in thread | raw e-mail
>Number: 7239
>Category: misc
>Synopsis: ping(8) and traceroute(8) may report erratic round-trip times
>Confidential: no
>Severity: non-critical
>Priority: low
>Responsible: freebsd-bugs
>State: open
>Quarter:
>Keywords:
>Date-Required:
>Class: sw-bug
>Submitter-Id: current-users
>Arrival-Date: Fri Jul 10 13:40:01 PDT 1998
>Last-Modified:
>Originator: Jari Kirma
>Organization:
>Release: FreeBSD 2.2.6-STABLE i386
>Environment:
Contents of /var/run/dmesg.boot:
Copyright (c) 1992-1998 FreeBSD Inc.
Copyright (c) 1982, 1986, 1989, 1991, 1993
The Regents of the University of California. All rights reserved.
FreeBSD 2.2.6-STABLE #0: Sun Jun 14 13:54:19 EEST 1998
jkirma@vulcan.tky.hut.fi:/usr/src/sys/compile/VULCAN
CPU: Cyrix 6x86MX (166.28-MHz 686-class CPU)
Origin = "CyrixInstead" Id = 0x600 DIR=0x451 Stepping=0 Revision=4
real memory = 134217728 (131072K bytes)
avail memory = 129503232 (126468K bytes)
Probing for devices on PCI bus 0:
chip0 *generic PCI bridge (vendor=10b9 device=1531 subclass=0)* rev 178 on pci0:
0:0
chip1 *generic PCI bridge (vendor=10b9 device=1533 subclass=1)* rev 180 on pci0:
2:0
vga0 *VGA-compatible display device* rev 48 int a irq 15 on pci0:3:0
pci0:11: ACER Labs, device=0x5229, class=storage (ide) int a irq ?? [no drive
r assigned]
Probing for PnP devices:
CSN 1 Vendor ID: CTL00e4 [0xe4008c0e] Serial 0x056e8049
Probing for devices on the ISA bus:
sc0 at 0x60-0x6f irq 1 on motherboard
sc0: VGA color *4 virtual consoles, flags=0x0*
ed0 at 0x240-0x25f irq 10 maddr 0xc8000 msize 16384 on isa
ed0: address 00:00:c0:83:02:af, type SMC8216T (16 bit)
sio0 at 0x3f8-0x3ff irq 4 on isa
sio0: type 16550A
sio1 at 0x2f8-0x2ff irq 3 on isa
sio1: type 16550A
wdc0 at 0x1f0-0x1f7 irq 14 flags 0x80ff80ff on isa
wdc0: unit 0 (wd0): *ST52520A*, 32-bit, multi-block-16
wd0: 2446MB (5009760 sectors), 4970 cyls, 16 heads, 63 S/T, 512 B/S
wdc0: unit 1 (wd1): *ST3491A-XR*, 32-bit, multi-block-16
wd1: 408MB (836070 sectors), 899 cyls, 15 heads, 62 S/T, 512 B/S
npx0 flags 0x7 on motherboard
npx0: INT 16 interface
sb0 at 0x220 irq 5 drq 1 on isa
sb0: *SoundBlaster 16 4.16*
sbxvi0 at 0x0 drq 5 on isa
sbxvi0: *SoundBlaster 16 4.16*
sbmidi0 at 0x330 on isa
*SoundBlaster MPU-401*
awe0 at 0x620 on isa
AWE32 not found
AWE32: not detected
opl0 at 0x388 on isa
opl0: *Yamaha OPL-3 FM*
Related options at /sys/i386/conf/VULCAN:
# NETWORKING OPTIONS
options INET #Internet communications protocols
pseudo-device ether #Generic Ethernet
pseudo-device loop #Network loopback device
Uptime:
10:35PM up 26 days, 7:53, 14 users, load averages: 0.13, 0.04, 0.01
Other potentially related information:
The host clock is synchronised using xntpd.
>Description:
ping(8) and traceroute(8) produce erratic round-trip times for hosts
closer than 10 ms from the host. Interestingly, the first round-trip
time reported for a host by the process is always correct, and some of
the following responses may be correct.
Pinging loopback device and the host itself produce correct results.
$ ping -c 5 localhost
PING localhost (127.0.0.1): 56 data bytes
64 bytes from 127.0.0.1: icmp_seq=0 ttl=255 time=0.072 ms
64 bytes from 127.0.0.1: icmp_seq=1 ttl=255 time=0.063 ms
64 bytes from 127.0.0.1: icmp_seq=2 ttl=255 time=0.067 ms
64 bytes from 127.0.0.1: icmp_seq=3 ttl=255 time=0.078 ms
64 bytes from 127.0.0.1: icmp_seq=4 ttl=255 time=0.059 ms
--- localhost ping statistics ---
5 packets transmitted, 5 packets received, 0% packet loss
round-trip min/avg/max/stddev = 0.059/0.068/0.078/0.007 ms
$ ping -c 5 vulcan
PING vulcan.tky.hut.fi (130.233.19.89): 56 data bytes
64 bytes from 130.233.19.89: icmp_seq=0 ttl=255 time=0.067 ms
64 bytes from 130.233.19.89: icmp_seq=1 ttl=255 time=0.060 ms
64 bytes from 130.233.19.89: icmp_seq=2 ttl=255 time=0.050 ms
64 bytes from 130.233.19.89: icmp_seq=3 ttl=255 time=0.065 ms
64 bytes from 130.233.19.89: icmp_seq=4 ttl=255 time=0.050 ms
--- vulcan.tky.hut.fi ping statistics ---
5 packets transmitted, 5 packets received, 0% packet loss
round-trip min/avg/max/stddev = 0.050/0.058/0.067/0.007 ms
$ traceroute localhost
traceroute to localhost (127.0.0.1), 30 hops max, 40 byte packets
1 localhost (127.0.0.1) 0.157 ms 0.102 ms 0.061 ms
$ traceroute vulcan
traceroute to vulcan.tky.hut.fi (130.233.19.89), 30 hops max, 40 byte packets
1 vulcan (130.233.19.89) 0.157 ms 0.104 ms 0.092 ms
Pinging another machine in the local network doesn't:
$ ping -c 5 shadow
PING shadow.tky.hut.fi (130.233.19.69): 56 data bytes
64 bytes from 130.233.19.69: icmp_seq=0 ttl=64 time=1.527 ms
64 bytes from 130.233.19.69: icmp_seq=1 ttl=64 time=0.217 ms
64 bytes from 130.233.19.69: icmp_seq=2 ttl=64 time=0.212 ms
64 bytes from 130.233.19.69: icmp_seq=3 ttl=64 time=0.213 ms
64 bytes from 130.233.19.69: icmp_seq=4 ttl=64 time=0.214 ms
--- shadow.tky.hut.fi ping statistics ---
5 packets transmitted, 5 packets received, 0% packet loss
round-trip min/avg/max/stddev = 0.212/0.477/1.527/0.525 ms
$ traceroute -q 10 shadow
traceroute to shadow.tky.hut.fi (130.233.19.69), 30 hops max, 40 byte packets
1 shadow (130.233.19.69) 0.825 ms 0.688 ms 0.709 ms 0.423 ms 0.274 ms 0.268 ms 0.420 ms 0.268 ms 0.267 ms 0.265 ms
But instead, using single query per process invocation produces
correct results!
$ ping -c 1 shadow
PING shadow.tky.hut.fi (130.233.19.69): 56 data bytes
64 bytes from 130.233.19.69: icmp_seq=0 ttl=64 time=0.837 ms
--- shadow.tky.hut.fi ping statistics ---
1 packets transmitted, 1 packets received, 0% packet loss
round-trip min/avg/max/stddev = 0.837/0.837/0.837/0.000 ms
$ ping -c 1 shadow
PING shadow.tky.hut.fi (130.233.19.69): 56 data bytes
64 bytes from 130.233.19.69: icmp_seq=0 ttl=64 time=0.746 ms
--- shadow.tky.hut.fi ping statistics ---
1 packets transmitted, 1 packets received, 0% packet loss
round-trip min/avg/max/stddev = 0.746/0.746/0.746/0.000 ms
$ ping -c 1 shadow
PING shadow.tky.hut.fi (130.233.19.69): 56 data bytes
64 bytes from 130.233.19.69: icmp_seq=0 ttl=64 time=3.142 ms
--- shadow.tky.hut.fi ping statistics ---
1 packets transmitted, 1 packets received, 0% packet loss
round-trip min/avg/max/stddev = 3.142/3.142/3.142/0.000 ms
Machines that are just about 10 ms away seem to give mixed results:
$ ping upper-gw.sunet.se
PING upper-gw.sunet.se (193.10.85.17): 56 data bytes
64 bytes from 193.10.85.17: icmp_seq=0 ttl=247 time=14.634 ms
64 bytes from 193.10.85.17: icmp_seq=1 ttl=247 time=0.240 ms
64 bytes from 193.10.85.17: icmp_seq=2 ttl=247 time=0.233 ms
64 bytes from 193.10.85.17: icmp_seq=3 ttl=247 time=10.068 ms
64 bytes from 193.10.85.17: icmp_seq=4 ttl=247 time=0.236 ms
64 bytes from 193.10.85.17: icmp_seq=5 ttl=247 time=0.245 ms
64 bytes from 193.10.85.17: icmp_seq=6 ttl=247 time=10.073 ms
64 bytes from 193.10.85.17: icmp_seq=7 ttl=247 time=10.069 ms
64 bytes from 193.10.85.17: icmp_seq=8 ttl=247 time=0.264 ms
64 bytes from 193.10.85.17: icmp_seq=9 ttl=247 time=0.233 ms
64 bytes from 193.10.85.17: icmp_seq=10 ttl=247 time=0.235 ms
64 bytes from 193.10.85.17: icmp_seq=11 ttl=247 time=0.293 ms
64 bytes from 193.10.85.17: icmp_seq=12 ttl=247 time=0.237 ms
64 bytes from 193.10.85.17: icmp_seq=13 ttl=247 time=10.061 ms
64 bytes from 193.10.85.17: icmp_seq=14 ttl=247 time=0.239 ms
64 bytes from 193.10.85.17: icmp_seq=15 ttl=247 time=9.981 ms
^C
--- upper-gw.sunet.se ping statistics ---
16 packets transmitted, 16 packets received, 0% packet loss
round-trip min/avg/max/stddev = 0.233/4.209/14.634/5.223 ms
$ traceroute -q 10 upper-gw.sunet.se
traceroute to upper-gw.sunet.se (193.10.80.33), 30 hops max, 40 byte packets
1 trinet-gw (130.233.31.254) 2.491 ms 3.888 ms 0.292 ms 0.262 ms
7.737 ms 0.262 ms 7.790 ms 0.267 ms 0.285 ms 7.739 ms
2 hutnet-sw.hut.fi (130.233.248.254) 1.773 ms 0.274 ms 8.189 ms
0.265 ms 0.264 ms 0.411 ms 0.283 ms 4.922 ms 0.263 ms 0.263 ms
3 hutnet-gw-100m.hut.fi (130.233.0.125) 1.761 ms 0.273 ms 0.263
ms 0.275 ms 0.413 ms 0.267 ms 0.279 ms 0.261 ms 0.264 ms 0.262
ms
4 funet5-hut-a.hut.fi (130.233.0.98) 1.695 ms 0.273 ms 0.282 ms
7.346 ms 0.262 ms 0.411 ms 0.267 ms 0.264 ms 5.094 ms 0.262 ms
5 funet3-a10042-funet5.funet.fi (193.166.187.41) 18.600 ms 0.273
ms 0.264 ms 0.410 ms 5.498 ms 0.262 ms 0.263 ms 0.261 ms 0.261
ms 0.262 ms
6 funet3-a10042-funet5.funet.fi (193.166.187.41) 5.596 ms 0.271 ms
0.265 ms 0.276 ms 4.462 ms 0.268 ms 0.263 ms 0.276 ms 0.263 ms
0.260 ms
7 funet2-fe500-backbone.funet.fi (193.166.4.2) 6.477 ms
funet1-a1002-funet2.funet.fi (128.214.231.13) 7.453 ms 0.437 ms
0.588 ms 0.267 ms 0.263 ms 0.262 ms 0.413 ms 0.265 ms 0.264 ms
8 193.10.252.49 (193.10.252.49) 6.817 ms 8.703 ms 9.415 ms 9.404
ms 9.455 ms 8.860 ms 9.131 ms 9.420 ms 9.427 ms 9.459 ms
9 upper-gw.sunet.se (193.10.252.66) 9.391 ms * 9.526 ms * 0.313
ms * 0.336 ms * 59.553 ms *
Machines further away produce correct results:
$ ping -c 5 freebsd.org
PING freebsd.org (204.216.27.18): 56 data bytes
64 bytes from 204.216.27.18: icmp_seq=0 ttl=236 time=330.886 ms
64 bytes from 204.216.27.18: icmp_seq=1 ttl=236 time=350.094 ms
64 bytes from 204.216.27.18: icmp_seq=2 ttl=236 time=360.079 ms
64 bytes from 204.216.27.18: icmp_seq=3 ttl=236 time=320.086 ms
64 bytes from 204.216.27.18: icmp_seq=4 ttl=236 time=320.070 ms
--- freebsd.org ping statistics ---
5 packets transmitted, 5 packets received, 0% packet loss
round-trip min/avg/max/stddev = 320.070/336.243/360.079/16.195 ms
$ traceroute -q 10 freebsd.org
traceroute to freebsd.org (204.216.27.18), 30 hops max, 40 byte packets
1 trinet-gw (130.233.31.254) 1.087 ms 0.300 ms 0.264 ms 7.120 ms 0.263 ms
0.261 ms 0.421 ms 0.287 ms 5.643 ms 0.262 ms
2 hutnet-sw.hut.fi (130.233.248.254) 0.979 ms 0.678 ms 0.271 ms 0.286 ms
0.262 ms 3.301 ms 0.288 ms 0.265 ms 0.263 ms 0.275 ms
3 hutnet-gw-100m.hut.fi (130.233.0.125) 1.597 ms 0.866 ms 0.796 ms 0.223 m
s 0.411 ms 2.219 ms 0.263 ms 0.262 ms 0.263 ms 0.279 ms
4 funet5-hut-a.hut.fi (130.233.0.98) 1.587 ms 1.084 ms 0.291 ms 0.264 ms
0.261 ms 0.433 ms 0.266 ms 0.263 ms 0.263 ms 0.261 ms
5 funet3-a10042-funet5.funet.fi (193.166.187.41) 6.012 ms 0.708 ms 0.290 ms
0.265 ms 0.410 ms 0.267 ms 0.263 ms 0.263 ms 0.262 ms 4.557 ms
6 funet2-fe500-backbone.funet.fi (193.166.4.2) 2.509 ms 4.907 ms 0.264 ms
0.261 ms 0.411 ms 0.293 ms 0.262 ms 6.559 ms 0.283 ms 0.263 ms
7 funet1-a1002-funet2.funet.fi (128.214.231.13) 1.577 ms 0.274 ms 0.266 ms
0.285 ms 0.410 ms 0.267 ms 5.540 ms 0.262 ms 0.262 ms 7.829 ms
8 193.10.252.49 (193.10.252.49) 9.359 ms 8.400 ms 9.432 ms 9.411 ms 0.297
ms 7.507 ms 9.384 ms 0.285 ms 0.361 ms 8.830 ms
9 us-gw.nordu.net (193.10.252.138) 109.366 ms 99.082 ms 109.376 ms 109.406
ms 106.718 ms 99.408 ms 109.402 ms 109.348 ms 99.423 ms 99.896 ms
10 Teleglobe.net (207.45.216.249) 109.389 ms 99.132 ms 109.402 ms 109.423 m
s 106.676 ms 109.373 ms 99.336 ms 109.420 ms 109.412 ms 109.405 ms
11 gin-nyy-bb1.Teleglobe.net (207.45.201.33) 99.379 ms 109.031 ms 99.393 ms
100.198 ms 100.000 ms 109.382 ms 109.414 ms 109.406 ms 109.391 ms 169.414
ms
12 Teleglobe.net (207.45.223.2) 108.821 ms 109.101 ms 119.418 ms 119.356 ms
109.520 ms 116.651 ms 109.393 ms 119.391 ms 109.421 ms 119.382 ms
13 mae-e-1.e0.crl.com (192.41.177.104) 139.338 ms * 119.677 ms * 139.569 ms
139.386 ms 109.048 ms 149.814 ms 119.372 ms 139.419 ms
14 sfo-vva.x.atm.us.crl.net (165.113.50.65) 359.365 ms 319.888 ms 309.420 ms
349.365 ms * 339.402 ms 289.376 ms 259.390 ms 289.393 ms 319.445 ms
15 E0-CRL-SFO-02-E0X0.US.CRL.NET (165.113.55.2) 329.238 ms 318.816 ms 320.12
9 ms 339.422 ms 339.646 ms 309.319 ms 359.329 ms 339.576 ms 359.410 ms 33
9.309 ms
16 T1-CDROM-00-EX.US.CRL.NET (165.113.118.2) 306.572 ms 339.011 ms 349.364 m
s 337.030 ms 369.337 ms 339.377 ms 369.366 ms 329.382 ms 319.397 ms 349.3
55 ms
17 hub.FreeBSD.ORG (204.216.27.18) 336.701 ms 358.804 ms 429.590 ms 319.359
ms 356.650 ms 299.518 ms 319.219 ms 323.537 ms 345.204 ms 389.333 ms
In the test system, faulty values obviously cluster inside 0.2-0.4 ms
range.
Actual transmission of ICMP datagrams have been measured to happen
within the network.
Based on a rudimentary functionality testing of gettimeofday(2) with
similar delays imposed between the measurements (using usleep(3) or
idle loop), no failure have been noticed. This would suggest something
being wrong in the protocol stack, no matter how eerie it sounds. ;)
>How-To-Repeat:
This bug is as far as I know, unrepeatable. Similar tests were
conducted with another similarily configured FreeBSD 2.2.6 machine,
without any failures.
The problem has appeared sometime during (wild guess) two last weeks
of machine uptime.
>Fix:
Unknown.
>Audit-Trail:
>Unformatted:
To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-bugs" in the body of the message
help
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?199807102032.XAA08920>