bin/53390: dhcpcd(8) can't get IP on fxp(4) + inphy(4)

To: gnats-admin%netbsd.org@localhost,netbsd-bugs%netbsd.org@localhost
Subject: bin/53390: dhcpcd(8) can't get IP on fxp(4) + inphy(4)
From: tsutsui%ceres.dti.ne.jp@localhost
Date: Sun, 24 Jun 2018 05:55:00 +0000 (UTC)
>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
>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)?
Follow-Ups:
- Re: bin/53390: dhcpcd(8) can't get IP on fxp(4) + inphy(4)
  - From: Joerg Sonnenberger
Prev by Date: Re: misc/52840 (syslogd doesn't start when unbound is enabled)
Next by Date: Re: bin/53390: dhcpcd(8) can't get IP on fxp(4) + inphy(4)
Previous by Thread: Re: misc/52840 (syslogd doesn't start when unbound is enabled)
Next by Thread: Re: bin/53390: dhcpcd(8) can't get IP on fxp(4) + inphy(4)
Indexes:
Home | Main Index | Thread Index | Old Index