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>
next in thread | raw e-mail | index | archive | help
>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
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?199807102032.XAA08920>