NetBSD Problem Report #53390

From tsutsui@ceres.dti.ne.jp  Sun Jun 24 05:53:13 2018
Return-Path: <tsutsui@ceres.dti.ne.jp>
Received: from mail.netbsd.org (mail.netbsd.org [199.233.217.200])
	(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
	(Client CN "mail.NetBSD.org", Issuer "mail.NetBSD.org CA" (not verified))
	by mollari.NetBSD.org (Postfix) with ESMTPS id 08C8F7A16A
	for <gnats-bugs@gnats.NetBSD.org>; Sun, 24 Jun 2018 05:53:13 +0000 (UTC)
Message-Id: <201806240553.w5O5r6eA002325@ceres.dti.ne.jp>
Date: Sun, 24 Jun 2018 14:53:06 +0900 (JST)
From: tsutsui@ceres.dti.ne.jp
Reply-To: tsutsui@ceres.dti.ne.jp
To: gnats-bugs@NetBSD.org
Subject: dhcpcd(8) can't get IP on fxp(4) + inphy(4)
X-Send-Pr-Version: 3.95

>Number:         53390
>Category:       bin
>Synopsis:       dhcpcd(8) can't get IP on fxp(4) + inphy(4)
>Confidential:   no
>Severity:       non-critical
>Priority:       low
>Responsible:    bin-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sun Jun 24 05:55:00 +0000 2018
>Last-Modified:  Fri Mar 20 05:00:01 +0000 2020
>Originator:     Izumi Tsutsui
>Release:        NetBSD 7.1.2
>Organization:
>Environment:
System: NetBSD tpx21 7.1.2 NetBSD 7.1.2 (GENERIC.201803151611Z) i386
Architecture: i386
Machine: i386
>Description:
On an old ThinkPad X21 which has fxp(4) (i82550) + inphy(4)
dhcpcd(8) cannot get IP address.

It reports "carrier lost" and "carrier acquired" again and again
and gets timeout.

---
login: root
Jun 24 23:29:55 tpx21 login: ROOT LOGIN (root) on tty tty00
Last login: Sun Jun 24 23:29:01 2018 on ttyE1
Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005,
    2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2015, 2016, 2017,
    2018 The NetBSD Foundation, Inc.  All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
    The Regents of the University of California.  All rights reserved.

NetBSD 7.1.2 (GENERIC.201803151611Z)

Welcome to NetBSD!

Terminal type is vt100.
We recommend creating a non-root account and using su(1) for root access.
tpx21# dhcpcd
dhcpcd[493]: version 6.7.1 starting
dhcpcd[493]: fxp0: adding address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: DUID 00:01:00:01:20:56:2d:ca:00:03:47:xx:xx:xx
dhcpcd[493]: fxp0: IAID 47:xx:xx:xx
dhcpcd[493]: fxp0: carrier lost
dhcpcd[493]: fxp0: deleting address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: carrier acquired
dhcpcd[493]: fxp0: adding address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: IAID 47:xx:xx:xx
dhcpcd[493]: fxp0: carrier lost
dhcpcd[493]: fxp0: deleting address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: carrier acquired
dhcpcd[493]: fxp0: adding address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: IAID 47:xx:xx:xx
dhcpcd[493]: fxp0: carrier lost
dhcpcd[493]: fxp0: deleting address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: carrier acquired
dhcpcd[493]: fxp0: adding address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: IAID 47:xx:xx:xx
dhcpcd[493]: fxp0: carrier lost
dhcpcd[493]: fxp0: deleting address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: carrier acquired
dhcpcd[493]: fxp0: adding address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: IAID 47:xx:xx:xx
dhcpcd[493]: fxp0: carrier lost
dhcpcd[493]: fxp0: deleting address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: carrier acquired
dhcpcd[493]: fxp0: adding address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: IAID 47:xx:xx:xx
dhcpcd[493]: fxp0: carrier lost
dhcpcd[493]: fxp0: deleting address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: carrier acquired
dhcpcd[493]: fxp0: adding address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: IAID 47:xx:xx:xx
dhcpcd[493]: fxp0: carrier lost
dhcpcd[493]: fxp0: deleting address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: carrier acquired
dhcpcd[493]: fxp0: adding address fe80::bd30:9e9d:956a:9987
dhcpcd[493]: fxp0: IAID 47:xx:xx:xx
dhcpcd[493]: timed out
Jun 24 23:30:33 tpx21 dhcpcd[493]: timed out
dhcpcd[493]: forked to background, child pid 176
tpx21# 
---

fxp(4) and inphy(4) are probed as the following:
---
fxp0 at pci0 dev 10 function 0: i82550 Ethernet (rev. 0x0c)
fxp0: interrupting at irq 11
fxp0: Ethernet address 00:03:47:xx:xx:xx
inphy0 at fxp0 phy 1: i82555 10/100 media interface, rev. 4
inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
---

Full dmesg:
---
Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005,
    2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2015, 2016, 2017,
    2018 The NetBSD Foundation, Inc.  All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
    The Regents of the University of California.  All rights reserved.

NetBSD 7.1.2 (GENERIC.201803151611Z)
total memory = 383 MB
avail memory = 360 MB
kern.module.path=/stand/i386/7.1/modules
mainbus0 (root)
ACPI: RSDP 0xf6ec0 000014 (v00 PTLTD )
ACPI: RSDT 0x17ff5c49 00002C (v01 PTLTD    RSDT   06042250  LTP 00000000)
ACPI: FACP 0x17ffeb65 000074 (v01 IBM    TP-X21   06042250      00000000)
ACPI: DSDT 0x17ff5c75 008EF0 (v01 IBM    TP-X21   06042250 MSFT 0100000C)
ACPI: FACS 0x17fff000 000040
ACPI: BOOT 0x17ffebd9 000027 (v01 PTLTD  $SBFTBL$ 06042250  LTP 00000001)
ACPI: All ACPI Tables successfully acquired
cpu0 at mainbus0: Intel 686-class, 697MHz, id 0x686
acpi0 at mainbus0: Intel ACPICA 20131218
acpiec0 at acpi0 (EC, PNP0C09)
: io 0x62,0x66
acpiec0: using global ACPI lock
MEM (PNP0C01) at acpi0 not configured
acpilid0 at acpi0 (LID, PNP0C0D): ACPI Lid Switch
acpibut0 at acpi0 (SLPB, PNP0C0E): ACPI Sleep Button
acpivga0 at acpi0 (VID): ACPI Display Adapter
acpiout0 at acpivga0 (LCD0, 0x0110): ACPI Display Output Device
acpiout1 at acpivga0 (CRT0, 0x0100): ACPI Display Output Device
SIO (PNP0C02) at acpi0 not configured
attimer1 at acpi0 (TIMR, PNP0100): io 0x40-0x43 irq 0
pcppi1 at acpi0 (SPKR, PNP0800): io 0x61
midi0 at pcppi1: PC speaker
sysbeep0 at pcppi1
FPU (PNP0C04) at acpi0 not configured
pckbc1 at acpi0 (KBD, PNP0303) (kbd port): io 0x60,0x64 irq 1
pckbc2 at acpi0 (MOU, IBM3780) (aux port): irq 12
SPIO (PNP0C02) at acpi0 not configured
FDC (PNP0700) at acpi0 not configured
UART (PNP0501) at acpi0 not configured
LPT (PNP0400) at acpi0 not configured
acpibat0 at acpi0 (BAT0, PNP0C0A-0): ACPI Battery
acpiacad0 at acpi0 (AC, ACPI0003-0): ACPI AC Adapter
HKEY (IBM0068) at acpi0 not configured
acpitz0 at acpi0 (THM0)
apm0 at acpi0: Power Management spec V1.2
ACPI Exception: AE_NOT_FOUND, While evaluating Sleep State [\_S2_] (20131218/hwxface-646)
attimer1: attached to pcppi1
pckbd0 at pckbc1 (kbd slot)
pckbc1: using irq 1 for kbd slot
wskbd0 at pckbd0 mux 1
pms0 at pckbc1 (aux slot)
pckbc1: using irq 12 for aux slot
wsmouse0 at pms0 mux 0
pci0 at mainbus0 bus 0: configuration mode 1
pchb0 at pci0 dev 0 function 0: vendor 0x8086 product 0x7190 (rev. 0x03)
agp0 at pchb0: aperture at 0xf8000000, size 0x4000000
ppb0 at pci0 dev 1 function 0: vendor 0x8086 product 0x7191 (rev. 0x03)
pci1 at ppb0 bus 1
vga0 at pci1 dev 0 function 0: vendor 0x1002 product 0x4c4d (rev. 0x64)
wsdisplay0 at vga0 kbdmux 1
drm at vga0 not configured
pcib0 at pci0 dev 7 function 0: vendor 0x8086 product 0x7110 (rev. 0x02)
piixide0 at pci0 dev 7 function 1: Intel 82371AB IDE controller (PIIX4) (rev. 0x01)
piixide0: primary channel interrupting at irq 14
atabus0 at piixide0 channel 0
piixide0: secondary channel interrupting at irq 15
atabus1 at piixide0 channel 1
uhci0 at pci0 dev 7 function 2: vendor 0x8086 product 0x7112 (rev. 0x01)
uhci0: interrupting at irq 11
usb0 at uhci0: USB revision 1.0
piixpm0 at pci0 dev 7 function 3: vendor 0x8086 product 0x7113 (rev. 0x03)
piixpm0: 24-bit timer
piixpm0: interrupting at SMI, polling
iic0 at piixpm0: I2C bus
cbb0 at pci0 dev 8 function 0: vendor 0x1180 product 0x0476 (rev. 0x80)
cbb1 at pci0 dev 8 function 1: vendor 0x1180 product 0x0476 (rev. 0x80)
fxp0 at pci0 dev 10 function 0: i82550 Ethernet (rev. 0x0c)
fxp0: interrupting at irq 11
fxp0: Ethernet address 00:03:47:xx:xx:xx
inphy0 at fxp0 phy 1: i82555 10/100 media interface, rev. 4
inphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
vendor 0x11c1 product 0x045c (serial communications, generic XT-compat, revision 0x01) at pci0 dev 10 function 1 not configured
clct0 at pci0 dev 11 function 0: vendor 0x1013 product 0x6005 (rev. 0x01)
clct0: interrupting at irq 11
clct0: ac97: Crystal CS4297A codec; headphone, 20 bit DAC, 18 bit ADC, Crystal Semi 3D
clct0: ac97: ext id 0x200<AMAP>
audio0 at clct0: full duplex, playback, capture, independent
isa0 at pcib0
lpt2 at isa0 port 0x3bc-0x3bf irq : polled
com0 at isa0 port 0x3f8-0x3ff irq 4: ns16550a, working fifo
com0: console
fdc0 at isa0 port 0x3f0-0x3f7 irq 6 drq 2
cbb0: interrupting at irq 11
cardslot0 at cbb0
cardbus0 at cardslot0: bus 2
pcmcia0 at cardslot0
cbb1: interrupting at irq 11
cardslot1 at cbb1
cardbus1 at cardslot1: bus 5
pcmcia1 at cardslot1
fd0 at fdc0 drive 0: 1.44MB, 80 cyl, 2 head, 18 sec
acpiacad0: AC adapter online.
uhub0 at usb0: vendor 0x8086 UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
wdc2 at pcmcia1 function 0: <HITACHI, FLASH, 5.0>
wdc2: i/o mapped mode
atabus2 at wdc2 channel 0
uhub1 at uhub0 port 1: vendor 0x0451 General Purpose USB Hub, class 9/0, rev 1.10/1.01, addr 2
wd0 at atabus0 drive 0
wd0: <IBM-DJSA-220>
wd0: 19077 MB, 38760 cyl, 16 head, 63 sec, 512 bytes/sect x 39070080 sectors
umass0 at uhub1 port 1 configuration 1 interface 0
umass0: Generic Mass Storage Device, rev 2.00/3.00, addr 3
scsibus0 at umass0: 2 targets, 1 lun per target
sd0 at scsibus0 target 0 lun 0: <Mass, Storage Device, \001\000\000\001> disk removable
sd0: fabricating a geometry
sd0: 1936 MB, 1936 cyl, 64 head, 32 sec, 512 bytes/sect x 3964928 sectors
sd0: fabricating a geometry
atapibus0 at atabus1: 2 targets
cd0 at atapibus0 drive 0: <HITACHI DVD-ROM GD-S200, , 0034> cdrom removable
wd1 at atabus2 drive 0
wd1: <Hitachi CVM1.3.3>
wd1: 62592 KB, 978 cyl, 4 head, 32 sec, 512 bytes/sect x 125184 sectors
match_bootwedge: unable to read block 4188241 of dev wd1 (22)
match_bootwedge: unable to read block 4188241 of dev sd0 (22)
boot device: wd0
root on wd0a dumps on wd0b
root file system type: ffs
---

I also saw the same problem at least one other fxp(4) based i386 notebook.
 http://dmesgd.nycbug.org/index.cgi?do=view&id=3499

dhclient(8) can get IP address on the same environment.

>How-To-Repeat:
Run dhcpcd(8) on fxp(4) + inphy(4) systems?

>Fix:
dhcpcd is too sensitive against momentary carrier lost during
re-initialization of the fxp(4)?

>Audit-Trail:
From: Martin Husemann <martin@duskware.de>
To: gnats-bugs@NetBSD.org
Cc: 
Subject: Re: bin/53390: dhcpcd(8) can't get IP on fxp(4) + inphy(4)
Date: Sun, 24 Jun 2018 09:38:20 +0200

 The carrier loss is a bug in the driver fxp(4) that should be fixed. This is
 the real issue here.

 You can run dhcpcd with -K or --nolink to make it ignore carrier
 status (like dhcpdclient does).

 Martin

From: Joerg Sonnenberger <joerg@bec.de>
To: gnats-bugs@NetBSD.org
Cc: gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: bin/53390: dhcpcd(8) can't get IP on fxp(4) + inphy(4)
Date: Sun, 24 Jun 2018 17:19:28 +0200

 On Sun, Jun 24, 2018 at 05:55:00AM +0000, tsutsui@ceres.dti.ne.jp wrote:
 > It reports "carrier lost" and "carrier acquired" again and again
 > and gets timeout.

 Can you try running dhcpcd -4? Some drivers decided to do a full PHY
 reset when the multicast filter changes and IPv6 is triggering that case
 a lot.

 Joerg

From: Izumi Tsutsui <tsutsui@ceres.dti.ne.jp>
To: gnats-bugs@NetBSD.org
Cc: martin@duskware.de, tsutsui@ceres.dti.ne.jp
Subject: Re: bin/53390: dhcpcd(8) can't get IP on fxp(4) + inphy(4)
Date: Tue, 26 Jun 2018 00:18:04 +0900

 >  The carrier loss is a bug in the driver fxp(4) that should be fixed. This is
 >  the real issue here.
 >  
 >  You can run dhcpcd with -K or --nolink to make it ignore carrier
 >  status (like dhcpdclient does).

 dhcpcd -K works:

 ---

 tpx21# dhcpcd -K
 dhcpcd[466]: version 6.7.1 starting
 dhcpcd[466]: fxp0: adding address fe80::bd30:9e9d:956a:9987
 dhcpcd[466]: DUID 00:01:00:01:20:56:2d:ca:00:03:47:xx:xx:xx
 dhcpcd[466]: fxp0: IAID 47:xx:xx:xx
 dhcpcd[466]: fxp0: soliciting an IPv6 router
 dhcpcd[466]: fxp0: rebinding lease of 192.168.20.209
 dhcpcd[466]: fxp0: leased 192.168.20.209 for 14159 seconds
 dhcpcd[466]: fxp0: adding host route to 192.168.20.209 via 127.0.0.1
 dhcpcd[466]: fxp0: adding route to 192.168.20.0/24
 dhcpcd[466]: fxp0: adding default route via 192.168.20.1
 dhcpcd[466]: forked to background, child pid 568
 tpx21# 

 ---
 Izumi Tsutsui

From: Izumi Tsutsui <tsutsui@ceres.dti.ne.jp>
To: gnats-bugs@NetBSD.org
Cc: joerg@bec.de, tsutsui@ceres.dti.ne.jp
Subject: Re: bin/53390: dhcpcd(8) can't get IP on fxp(4) + inphy(4)
Date: Tue, 26 Jun 2018 00:20:48 +0900

 >  Can you try running dhcpcd -4? Some drivers decided to do a full PHY
 >  reset when the multicast filter changes and IPv6 is triggering that case
 >  a lot.

 dhcpcd -4 hangs after it acquires carrier:

 ---

 tpx21# dhcpcd -4
 dhcpcd[466]: version 6.7.1 starting
 dhcpcd[466]: DUID 00:01:00:01:20:56:2d:ca:00:03:47:xx:xx:xx
 dhcpcd[466]: fxp0: IAID 47:xx:xx:xx
 dhcpcd[466]: fxp0: carrier lost
 dhcpcd[466]: fxp0: carrier acquired
 ^C^C^C^C^C^C^C^C^C^C^C^C^C^C^C^C^C^Z^Z^Z^Z^Z^Z^Z^Z

 ---
 Izumi Tsutsui

From: Izumi Tsutsui <tsutsui@ceres.dti.ne.jp>
To: gnats-bugs@NetBSD.org
Cc: tsutsui@ceres.dti.ne.jp
Subject: Re: bin/53390: dhcpcd(8) can't get IP on fxp(4) + inphy(4)
Date: Fri, 20 Mar 2020 13:58:43 +0900

 Note dhcpcd(8) can acquire IP address with fxp(4) + nsphy(4)
 on NetBSD/i386 9.0:

 ---
 fxp0 at pci3 dev 10 function 0: Intel i8255x Ethernet (rev. 0x02)
 fxp0: interrupting at ioapic0 pin 22
 fxp0: May need receiver lock-up workaround
 fxp0: Ethernet address xx:xx:xx:xx:xx:xx
 nsphy0 at fxp0 phy 1: DP83840 10/100 media interface, rev. 1
 nsphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
 ---
 Izumi Tsutsui

Home	PR Database Search