From owner-freebsd-net@FreeBSD.ORG Thu Jan 14 20:49:00 2010 Return-Path: Delivered-To: freebsd-net@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 67AED106566B for ; Thu, 14 Jan 2010 20:49:00 +0000 (UTC) (envelope-from info@je-eigen-domein.nl) Received: from mx2.je-eigen-domein.nl (mx2.je-eigen-domein.nl [85.10.196.86]) by mx1.freebsd.org (Postfix) with ESMTP id AD9A68FC15 for ; Thu, 14 Jan 2010 20:48:59 +0000 (UTC) Received: from ubuntu.localnet (localhost [127.0.0.1]) by mx2.je-eigen-domein.nl (Postfix) with ESMTP id F0190788119; Thu, 14 Jan 2010 21:49:11 +0100 (CET) From: Floris Bos Organization: Maxnet To: pyunyh@gmail.com Date: Thu, 14 Jan 2010 21:48:56 +0100 User-Agent: KMail/1.12.2 (Linux/2.6.31-15-generic; KDE/4.3.2; i686; ; ) References: <201001140140.o0E1e5hr072464@freefall.freebsd.org> <201001142108.02941.info@je-eigen-domein.nl> <20100114201144.GA1228@michelle.cdnetworks.com> In-Reply-To: <20100114201144.GA1228@michelle.cdnetworks.com> MIME-Version: 1.0 Content-Type: Text/Plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Message-Id: <201001142148.56444.info@je-eigen-domein.nl> Cc: freebsd-net@freebsd.org Subject: Re: kern/92090: [bge] bge: watchdog timeout -- resetting X-BeenThere: freebsd-net@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Networking and TCP/IP with FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 14 Jan 2010 20:49:00 -0000 On Thursday 14 January 2010 09:11:44 pm Pyun YongHyeon wrote: > On Thu, Jan 14, 2010 at 09:08:02PM +0100, Floris Bos wrote: > > On Thursday 14 January 2010 06:56:03 pm Pyun YongHyeon wrote: > > > On Thu, Jan 14, 2010 at 04:33:19AM +0100, Floris Bos wrote: > > > > Hi, > > > > > > > > On Thursday 14 January 2010 03:54:52 am Pyun YongHyeon wrote: > > > > > > == > > > > > > bge0: mem 0xdf900000-0xdf90ffff irq 16 at device 0.0 on pci32 > > > > > > == > > > > > > > > > > > > After boot, the network works for about 5 seconds, barely enough time to get an IP by DHCP, and sent a ping or 2. > > > > > > Then network connectivity goes down, and after some time there is a "bge0: watchdog timeout -- resetting" message. > > > > > > > > > > > > Then network works again for 5 seconds, and goes down again. All the time, repeatedly. > > > > > > > > > > > > The system works fine under Ubuntu. So I assume the hardware is ok. > > > > > > > > > > > > > > > > I'm not sure but it looks like you have a BCM5784 controller. What is > > > > > the output of "devinfo -rv | grep phy"? > > > > > > > > == > > > > ukphy0 pnpinfo oui=0x50ef model=0x3a rev=0x4 at phyno=1 > > > > ukphy1 pnpinfo oui=0x50ef model=0x3a rev=0x4 at phyno=1 > > > > == > > > > > > Support for the PHY was added in r202269. > > > Please try again after applying the change. Or you can download > > > sys/dev/mii/miidevs and sys/dev/mii/brgphy.c from HEAD and rebuild > > > kernel. > > > > Fetched the latest source using CVS on another computer, and transferred it to the system concerned by USB stick. > > Rebuild the kernel, but the problem is still there. > > > Would you show me full dmesg output including "watchodg timeout" > messages? === Copyright (c) 1992-2010 The FreeBSD Project. Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 The Regents of the University of California. All rights reserved. FreeBSD is a registered trademark of The FreeBSD Foundation. FreeBSD 9.0-CURRENT #0: Thu Jan 14 20:12:47 CET 2010 root@db3.xxxxxxx.xx:/usr/obj/usr/src/sys/GENERIC amd64 WARNING: WITNESS option enabled, expect reduced performance. Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: Intel(R) Xeon(R) CPU X3430 @ 2.40GHz (2394.00-MHz K8-class CPU) Origin = "GenuineIntel" Id = 0x106e5 Stepping = 5 Features=0xbfebfbff Features2=0x98e3fd AMD Features=0x28100800 AMD Features2=0x1 TSC: P-state invariant real memory = 17179869184 (16384 MB) avail memory = 16533999616 (15768 MB) ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs FreeBSD/SMP: 1 package(s) x 4 core(s) cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 2 cpu2 (AP): APIC ID: 4 cpu3 (AP): APIC ID: 6 ioapic0 irqs 0-23 on motherboard kbd1 at kbdmux0 acpi0: on motherboard acpi0: [ITHREAD] acpi0: Power Button (fixed) Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1008-0x100b on acpi0 acpi_hpet0: iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 14318180 Hz quality 900 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 pcib1: irq 16 at device 3.0 on pci0 pci1: on pcib1 pci0: at device 8.0 (no driver attached) pci0: at device 8.1 (no driver attached) pci0: at device 8.2 (no driver attached) pci0: at device 8.3 (no driver attached) pci0: at device 16.0 (no driver attached) pci0: at device 16.1 (no driver attached) ehci0: mem 0xdfd02000-0xdfd023ff irq 16 at device 26.0 on pci0 ehci0: [ITHREAD] usbus0: EHCI version 1.0 usbus0: on ehci0 pcib2: irq 17 at device 28.0 on pci0 pci16: on pcib2 pcib3: irq 17 at device 28.4 on pci0 pci32: on pcib3 bge0: mem 0xdf900000-0xdf90ffff irq 16 at device 0.0 on pci32 miibus0: on bge0 brgphy0: PHY 1 on miibus0 brgphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-FDX, auto bge0: Ethernet address: f4:ce:46:0f:2a:2c bge0: [FILTER] pcib4: irq 16 at device 28.5 on pci0 pci34: on pcib4 bge1: mem 0xdfa00000-0xdfa0ffff irq 17 at device 0.0 on pci34 miibus1: on bge1 brgphy1: PHY 1 on miibus1 brgphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-FDX, auto bge1: Ethernet address: f4:ce:46:0f:2a:2d bge1: [FILTER] pcib5: irq 18 at device 28.6 on pci0 pci36: on pcib5 vgapci0: mem 0xde000000-0xdeffffff,0xdf800000-0xdf803fff,0xdf000000-0xdf7fffff irq 18 at device 0.0 on pci36 pcib6: irq 19 at device 28.7 on pci0 pci38: on pcib6 ehci1: mem 0xdfd02400-0xdfd027ff irq 23 at device 29.0 on pci0 ehci1: [ITHREAD] usbus1: EHCI version 1.0 usbus1: on ehci1 pcib7: at device 30.0 on pci0 pci48: on pcib7 isab0: at device 31.0 on pci0 isa0: on isab0 atapci0: port 0x1830-0x1837,0x1824-0x1827,0x1828-0x182f,0x1820-0x1823,0x1800-0x181f mem 0xdfd01000-0xdfd017ff irq 18 at device 31.2 on pci0 atapci0: [ITHREAD] atapci0: AHCI v1.30 controller with 6 3Gbps ports, PM supported ata2: on atapci0 ata2: [ITHREAD] ata3: on atapci0 ata3: [ITHREAD] ata4: on atapci0 ata4: [ITHREAD] ata5: on atapci0 ata5: [ITHREAD] pci0: at device 31.3 (no driver attached) acpi_button0: on acpi0 atrtc0: port 0x70-0x71 on acpi0 uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 uart0: [FILTER] cpu0: on acpi0 est0: on cpu0 p4tcc0: on cpu0 cpu1: on acpi0 est1: on cpu1 p4tcc1: on cpu1 cpu2: on acpi0 est2: on cpu2 p4tcc2: on cpu2 cpu3: on acpi0 est3: on cpu3 p4tcc3: on cpu3 orm0: at iomem 0xc0000-0xc7fff,0xc8000-0xc8fff,0xdc000-0xdffff on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 atkbdc0: at port 0x60,0x64 on isa0 atkbd0: irq 1 on atkbdc0 kbd0 at atkbd0 atkbd: unable to set the command byte. atkbd0: [GIANT-LOCKED] atkbd0: [ITHREAD] psm0: unable to set the command byte. ppc0: cannot reserve I/O port range ZFS filesystem version 3 ZFS storage pool version 14 Timecounters tick every 1.000 msec usbus0: 480Mbps High Speed USB v2.0 usbus1: 480Mbps High Speed USB v2.0 ad4: 152627MB at ata2-master UDMA100 SATA 3Gb/s ad6: 152627MB at ata3-master UDMA100 SATA 3Gb/s ad8: 152627MB at ata4-master UDMA100 SATA 3Gb/s ad10: 152627MB at ata5-master UDMA100 SATA 3Gb/s SMP: AP CPU #3 Launched! SMP: AP CPU #1 Launched! SMP: AP CPU #2 Launched! WARNING: WITNESS option enabled, expect reduced performance. ugen1.1: at usbus1ugen0.1: at usbus0 uhub0: on usbus1 uhub1: on usbus0 Root mount waiting for: usbus1 usbus0 uhub0: 2 ports with 2 removable, self powered uhub1: 2 ports with 2 removable, self powered Root mount waiting for: usbus1 usbus0 ugen1.2: at usbus1 uhub2: on usbus1 ugen0.2: at usbus0 uhub3: on usbus0 Root mount waiting for: usbus1 usbus0 uhub3: 6 ports with 6 removable, self powered uhub2: 8 ports with 8 removable, self powered Root mount waiting for: usbus1 usbus0 ugen0.3: at usbus0 ums0: on usbus0 ums0: 8 buttons and [XYZ] coordinates ID=0 ugen1.3: at usbus1 ukbd0: on usbus1 kbd2 at ukbd0 ums1: on usbus1 ums1: 8 buttons and [XYZ] coordinates ID=0 ugen0.4: at usbus0 umass0: on usbus0 umass0: SCSI over Bulk-Only; quirks = 0x0000 Root mount waiting for: usbus0 umass0:0:0:-1: Attached to scbus0 Trying to mount root from zfs:zroot da0 at umass-sim0 bus 0 scbus0 target 0 lun 0 da0: Removable Direct Access SCSI-0 device da0: 40.000MB/s transfers da0: 3839MB (7862911 512 byte sectors: 255H 63S/T 489C) GEOM: da0: partition 1 does not end on a track boundary. lock order reversal: 1st 0xffffff000a372bd8 zfs (zfs) @ /usr/src/sys/kern/vfs_mount.c:1058 2nd 0xffffff000a5bc9f8 devfs (devfs) @ /usr/src/sys/kern/vfs_subr.c:2091 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a _witness_debugger() at _witness_debugger+0x2e witness_checkorder() at witness_checkorder+0x81e __lockmgr_args() at __lockmgr_args+0xd10 vop_stdlock() at vop_stdlock+0x39 VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b _vn_lock() at _vn_lock+0x47 vget() at vget+0x7b devfs_allocv() at devfs_allocv+0x100 devfs_root() at devfs_root+0x48 vfs_donmount() at vfs_donmount+0xfb2 nmount() at nmount+0x63 syscall() at syscall+0x1ae Xfast_syscall() at Xfast_syscall+0xe1 --- syscall (378, FreeBSD ELF64, nmount), rip = 0x8007afeac, rsp = 0x7fffffffdd28, rbp = 0x800a06048 --- bge0: link state changed to UP bge0: link state changed to DOWN bge0: watchdog timeout -- resetting bge0: link state changed to UP bge0: link state changed to DOWN bge0: watchdog timeout -- resetting bge0: link state changed to UP bge0: watchdog timeout -- resetting bge0: link state changed to DOWN bge0: link state changed to UP === Seconds after the link goes up the connectivity is gone, but it takes minutes before it actually shows up as "link state changed to DOWN" in dmesg. According to the log file of the switch the server is connected to, the link goes up and down every 3 seconds or so. == Log Index Message Text Severity Log Time Component Description 1700 <14> Jan 01 09:27:45 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1701 %% Interface 9 is Link Up Info Jan 01 09:27:45 NIM Interface 9 is Link Up 1701 <14> Jan 01 09:27:48 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1702 %% Interface 9 is Link Down Info Jan 01 09:27:48 NIM Interface 9 is Link Down 1702 <14> Jan 01 09:27:51 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1703 %% Interface 9 is Link Up Info Jan 01 09:27:51 NIM Interface 9 is Link Up 1703 <14> Jan 01 09:27:54 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1704 %% Interface 9 is Link Down Info Jan 01 09:27:54 NIM Interface 9 is Link Down 1704 <14> Jan 01 09:27:57 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1705 %% Interface 9 is Link Up Info Jan 01 09:27:57 NIM Interface 9 is Link Up 1705 <14> Jan 01 09:28:00 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1706 %% Interface 9 is Link Down Info Jan 01 09:28:00 NIM Interface 9 is Link Down 1706 <14> Jan 01 09:28:03 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1707 %% Interface 9 is Link Up Info Jan 01 09:28:03 NIM Interface 9 is Link Up 1707 <14> Jan 01 09:28:06 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1708 %% Interface 9 is Link Down Info Jan 01 09:28:06 NIM Interface 9 is Link Down 1708 <14> Jan 01 09:28:09 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1709 %% Interface 9 is Link Up Info Jan 01 09:28:09 NIM Interface 9 is Link Up 1709 <14> Jan 01 09:28:12 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1710 %% Interface 9 is Link Down Info Jan 01 09:28:12 NIM Interface 9 is Link Down 1710 <14> Jan 01 09:28:15 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1711 %% Interface 9 is Link Up Info Jan 01 09:28:15 NIM Interface 9 is Link Up 1711 <14> Jan 01 09:28:17 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1712 %% Interface 9 is Link Down Info Jan 01 09:28:17 NIM Interface 9 is Link Down 1712 <14> Jan 01 09:28:20 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1713 %% Interface 9 is Link Up Info Jan 01 09:28:20 NIM Interface 9 is Link Up 1713 <14> Jan 01 09:28:24 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1714 %% Interface 9 is Link Down Info Jan 01 09:28:24 NIM Interface 9 is Link Down 1714 <14> Jan 01 09:28:26 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1715 %% Interface 9 is Link Up Info Jan 01 09:28:26 NIM Interface 9 is Link Up 1715 <14> Jan 01 09:28:30 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1716 %% Interface 9 is Link Down Info Jan 01 09:28:30 NIM Interface 9 is Link Down 1716 <14> Jan 01 09:28:32 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1717 %% Interface 9 is Link Up Info Jan 01 09:28:32 NIM Interface 9 is Link Up 1717 <14> Jan 01 09:28:36 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1718 %% Interface 9 is Link Down Info Jan 01 09:28:36 NIM Interface 9 is Link Down 1718 <14> Jan 01 09:28:39 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1719 %% Interface 9 is Link Up Info Jan 01 09:28:39 NIM Interface 9 is Link Up 1719 <14> Jan 01 09:28:42 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1720 %% Interface 9 is Link Down Info Jan 01 09:28:42 NIM Interface 9 is Link Down 1720 <14> Jan 01 09:28:45 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1721 %% Interface 9 is Link Up Info Jan 01 09:28:45 NIM Interface 9 is Link Up 1721 <14> Jan 01 09:28:48 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1722 %% Interface 9 is Link Down Info Jan 01 09:28:48 NIM Interface 9 is Link Down 1722 <14> Jan 01 09:28:51 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(619) 1723 %% Interface 9 is Link Up Info Jan 01 09:28:51 NIM Interface 9 is Link Up 1723 <14> Jan 01 09:28:54 197 192.168.2.10-1 NIM[-2137017720]: nim_events.c(665) 1724 %% Interface 9 is Link Down Info Jan 01 09:28:54 NIM Interface 9 is Link Down == Yours sincerly, Floris Bos