NetBSD-Bugs archive

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]

port-i386/60848: Alix fails to boot sometimes after warmstart, very likely due to network initialization



>Number:         60848
>Category:       port-i386
>Synopsis:       Alix fails to boot sometimes after warmstart, very likely due to network initialization
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    port-i386-maintainer
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sun Oct 04 17:00:00 +0000 2026
>Originator:     Ekkehard
>Release:        Netbsd11
>Organization:
>Environment:
NetBSD melone2 11.0 NetBSD 11.0 (GENERIC) #0: Thu Jul 30 15:23:12 UTC 2026  mkrepro%mkrepro.NetBSD.org@localhost:/usr/src/sys/arch/i386/compile/GENERIC i386
>Description:
I configured a PC-Engines Alix with 3 ethernet-ports to boot via pxe/dhcp as headless nfs-root machine. I created a new pxeboot_ia32_com0 to work with com0 at 38400.
In most cases, booting this setup works.
But sometimes when doing a warmstart ("reboot" from the running system), booting hangs when trying to mount the root-filesystem as nfs.

Here is the log from the serial console:
---
PC Engines ALIX.2 v0.99
640 KB Base Memory
261120 KB Extended Memory
Waiting for HDD .....................

01F0 - no drive found !

Intel UNDI, PXE-2.0 (build 082)
Copyright (C) 1997,1998,1999  Intel Corporation
VIA Rhine III Management Adapter v2.43 (2005/12/15)

CLIENT MAC ADDR: 00 0D B9 15 22 14
CLIENT IP: 192.168.10.8  MASK: 255.255.240.0  DHCP IP: 192.168.10.6
GATEWAY IP: 192.168.10.2


  \\-__,------,___.
   \\        __,---`  NetBSD/x86 PXE Boot
    \\       `---,_.  Revision 5.2 (Sun Oct  4 14:23:18 UTC 2026)
     \\-,_____,.---`
      \\
       \\
        \\

Press return to boot now, any other key for boot menu
booting netbsd - starting in 0 seconds.
PXE BIOS Version 2.1
Using PCI device at bus 0 device 9 function 0
Ethernet address 00:0d:b9:15:22:14
20607664+593992+745400 [990792+947152+1036453]=0x17c5a7c
[   1.0000000] Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003,
[   1.0000000]     2004, 2005, 2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013,
[   1.0000000]     2014, 2015, 2016, 2017, 2018, 2019, 2020, 2021, 2022, 2023,
[   1.0000000]     2024, 2025, 2026
[   1.0000000]     The NetBSD Foundation, Inc.  All rights reserved.
[   1.0000000] Copyright (c) 1982, 1986, 1989, 1991, 1993
[   1.0000000]     The Regents of the University of California.  All rights reserved.

[   1.0000000] NetBSD 11.0 (GENERIC) #0: Thu Jul 30 15:23:12 UTC 2026
[   1.0000000]  mkrepro%mkrepro.NetBSD.org@localhost:/usr/src/sys/arch/i386/compile/GENERIC
[   1.0000000] total memory = 255 MB
[   1.0000000] avail memory = 227 MB
[   1.0000040] mainbus0 (root)
[   1.0000040] Firmware Error (ACPI): A valid RSDP was not found (20241212/tbxfroot-383)
acpi_probe: failed to initialize tables
[   1.0000040] ACPI Error: Could not remove SCI handler (20241212/evmisc-424)
[   1.0000040] cpu0 at mainbus0
[   1.0000040] ACPI Error: AE_BAD_PARAMETER, Thread 3243335680 could not acquire Mutex [ACPI_MTX_Tables] (0x2) (20241212/utmutex-434)
[   1.0000040] ACPI Error: Mutex [ACPI_MTX_Tables] (0x2) is not acquired, cannot release (20241212/utmutex-475)
[   1.0000040] cpu0: Geode(TM) Integrated Processor by AMD PCS, id 0x5a2
[   1.0000040] cpu0: node 0, package 0, core 0, smt 0
[   1.0000040] pci0 at mainbus0 bus 0: configuration mode 1
[   1.0000040] pchb0 at pci0 dev 1 function 0: AMD Geode LX Host-PCI Bridge (rev. 0x33)
[   1.0000040] glxsb0 at pci0 dev 1 function 2: RNG AES
[   1.0000040] vr0 at pci0 dev 9 function 0: VIA Technologies VT6105M (Rhine III) 10/100 Ethernet (rev. 0x96)
[   1.0000040] vr0: interrupting at irq 10
[   1.0000040] vr0: Ethernet address 00:0d:b9:15:22:14
[   1.0000040] ukphy0 at vr0 phy 1: OUI 0x0002c6, model 0x0034, rev. 3
[   1.0000040] ukphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
[   1.0000040] vr1 at pci0 dev 10 function 0: VIA Technologies VT6105M (Rhine III) 10/100 Ethernet (rev. 0x96)
[   1.0000040] vr1: interrupting at irq 11
[   1.0000040] vr1: Ethernet address 00:0d:b9:15:22:15
[   1.0000040] ukphy1 at vr1 phy 1: OUI 0x0002c6, model 0x0034, rev. 3
[   1.0000040] ukphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
[   1.0000040] vr2 at pci0 dev 11 function 0: VIA Technologies VT6105M (Rhine III) 10/100 Ethernet (rev. 0x96)
[   1.0000040] vr2: interrupting at irq 12
[   1.0000040] vr2: Ethernet address 00:0d:b9:15:22:16
[   1.0000040] ukphy2 at vr2 phy 1: OUI 0x0002c6, model 0x0034, rev. 3
[   1.0000040] ukphy2: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
[   1.0000040] gcscpcib0 at pci0 dev 15 function 0: AMD CS5536 PCI-ISA Bridge (rev. 0x03)
[   1.0057994] gcscpcib0: Watchdog Timer via MFGPT0, GPIO
[   1.0057994] gpio0 at gcscpcib0: 32 pins
[   1.0057994] viaide0 at pci0 dev 15 function 2: AMD CS5536 IDE Controller (rev. 0x01)
[   1.0057994] viaide0: primary channel interrupting at irq 14
[   1.0057994] atabus0 at viaide0 channel 0
[   1.0057994] viaide0: secondary channel ignored (disabled)
[   1.0057994] ohci0 at pci0 dev 15 function 4: AMD CS5536 OHCI USB Controller (rev. 0x02)
[   1.0057994] ohci0: interrupting at irq 15
[   1.0057994] ohci0: OHCI version 1.0, legacy support
[   1.0057994] usb0 at ohci0: USB revision 1.0
[   1.0057994] gcscehci0 at pci0 dev 15 function 5: AMD CS5536 EHCI USB Controller (rev. 0x02)
[   1.0057994] gcscehci0: interrupting at irq 15
[   1.0057994] gcscehci0: 1 companion controller, 4 ports: ohci0
[   1.0057994] gcscehci0: Using DMA subregion for control data structures
[   1.0057994] usb1 at gcscehci0: USB revision 2.0
[   1.0057994] isa0 at gcscpcib0
[   1.0057994] com0 at isa0 port 0x3f8-0x3ff irq 4: ns16550a, 16-byte FIFO
[   1.0057994] com0: console
[   1.0057994] attimer0 at isa0 port 0x40-0x43
[   1.0057994] pcppi0 at isa0 port 0x61
[   1.0057994] midi0 at pcppi0: PC speaker
[   1.0057994] sysbeep0 at pcppi0
[   1.0057994] isapnp0 at isa0 port 0x279
[   1.0057994] attimer0: attached to pcppi0
[   1.0057994] WARNING: system needs entropy for security; see entropy(7)
[   1.1900868] uhub0 at usb0: NetBSD (0x0000) OHCI root hub (0x0000), class 9/0, rev 1.00/1.00, addr 1
[   1.2180982] uhub1 at usb1: NetBSD (0x0000) EHCI root hub (0x0000), class 9/0, rev 2.00/1.00, addr 1
[   1.2500849] entropy: ready
[   1.7500904] swwdog0: software watchdog initialized
[   1.7667646] WARNING: 1 error while detecting hardware; check system log.
[   1.7867928] boot device: vr0
[   1.7953523] root on vr0
[   1.8026381] nfs_boot: trying DHCP/BOOTP
[  19.8203658] nfs_boot: timeout...
[  24.8204446] nfs_boot: timeout...
[  29.8205195] nfs_boot: timeout...
[  34.8205982] nfs_boot: trying RARP (and RPC/bootparam)
[  34.8505981] vr0: using force reset command.
[  47.8607989] revarp failed, error=51
[  47.8764193] Supported file systems: mfs lfs ffs ext2fs nfs umap procfs overlay null kernfs fdesc union tmpfs puffs ptyfs ntfs msdos efs cd9660 coda
[  47.9112556] no file system for vr0
[  47.9255498] cannot mount root, error = 79
[  47.9380282] root device (default vr0):
---

After that it's waiting at the console for inputs.
Just pressing enter several times (root device, dump device, file-system, init) booting continues:
---
[  47.9380282] root device (default vr0):
[  48.0934634] dump device:
[  49.0017294] file system (default generic):
[  49.7203006] root on vr0
[  49.7271053] nfs_boot: trying DHCP/BOOTP
[  52.7417650] nfs_boot: DHCP next-server: 192.168.10.6
[  52.7643841] nfs_boot: my_domain=lissner.home
[  52.7771070] nfs_boot: my_addr=192.168.10.8
[  52.7893228] nfs_boot: my_mask=255.255.240.0
[  52.8018160] nfs_boot: gateway=192.168.10.2
[  58.8118575] root on papaya:/srv/diskless/netbsd0/root
[  58.8310180] root file system type: nfs
[  58.8422158] kern.module.path=/stand/i386/11.0/modules
[  58.8575345] init path (default /sbin/init):
[  59.8588760] init: trying /sbin/init
Sun Oct  4 16:26:39 -00 2026
Not checking /: fs_passno = 0 in /etc/fstab
Setting sysctl variables:
ddb.onpanic: 1 -> 0
Starting file system checks:
[  61.2919464] papaya:/srv/diskless/netbsd0/root: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1791131203.186064145 1791131203.186064145, mtime 1791131203.186064145 1791131203.186064145)
Loaded entropy from /var/db/entropy-file.
Waiting for entropy...done
Setting tty flags.
Starting network.
Hostname: melone2
IPv6 mode: host
Configuring network interfaces:.
Adding interface aliases:.
add net default: gateway 192.168.10.2
Waiting for duplicate address detection to finish...
Building databases: dev, utmp, utmpx.
Starting syslogd.
Mounting all file systems...
Clearing temporary files.
Creating a.out runtime link editor directory cache.
Checking quotas: done.
/etc/rc: WARNING: No swap space configured!
/etc/rc.d/swap2 exited with code 1
Starting virecover.
Checking for core dump...
savecore: no core dump (no dumpdev)
Creating /var/run/munin...
Starting local daemons:.
Updating motd.
Starting ntpd.
Starting powerd.
Starting sshd.
Starting postfix.
postfix/postlog: starting the Postfix mail system
Starting munin_node.
Starting inetd.
Starting cron.
The following components reported failures:
    /etc/rc.d/swap2
See /var/run/rc.log for more information.
Sun Oct  4 18:27:07 CEST 2026

NetBSD/i386 (melone2) (constty)

login: 

---

The log of the tftp/dhcp-server (a linux machine) shows several DHCPDISCOVER and DHCPOFFER lines after the kernel has been requested several times:
---
2026-10-04T18:23:03.082995+02:00 papaya in.tftpd[21402]: RRQ from 192.168.10.8 filename netbsd0/root/netbsd
2026-10-04T18:23:03.087076+02:00 papaya in.tftpd[21403]: RRQ from 192.168.10.8 filename netbsd0/root/netbsd
2026-10-04T18:23:24.748493+02:00 papaya in.tftpd[21404]: RRQ from 192.168.10.8 filename netbsd0/root/netbsd
2026-10-04T18:23:48.175746+02:00 papaya in.tftpd[21405]: RRQ from 192.168.10.8 filename netbsd0/root/netbsd
2026-10-04T18:24:09.792481+02:00 papaya in.tftpd[21406]: RRQ from 192.168.10.8 filename netbsd0/root/netbsd
2026-10-04T18:24:45.696587+02:00 papaya dhcpd[18181]: DHCPDISCOVER from 00:0d:b9:15:22:14 via eth0
2026-10-04T18:24:45.696601+02:00 papaya dhcpd[18181]: DHCPOFFER on 192.168.10.8 to 00:0d:b9:15:22:14 via eth0
2026-10-04T18:24:46.696637+02:00 papaya dhcpd[18181]: DHCPDISCOVER from 00:0d:b9:15:22:14 via eth0
2026-10-04T18:24:46.696672+02:00 papaya dhcpd[18181]: DHCPOFFER on 192.168.10.8 to 00:0d:b9:15:22:14 via eth0
2026-10-04T18:24:48.696964+02:00 papaya dhcpd[18181]: DHCPDISCOVER from 00:0d:b9:15:22:14 via eth0
2026-10-04T18:24:48.696993+02:00 papaya dhcpd[18181]: DHCPOFFER on 192.168.10.8 to 00:0d:b9:15:22:14 via eth0
2026-10-04T18:24:51.697545+02:00 papaya dhcpd[18181]: DHCPDISCOVER from 00:0d:b9:15:22:14 via eth0
2026-10-04T18:24:51.697559+02:00 papaya dhcpd[18181]: DHCPOFFER on 192.168.10.8 to 00:0d:b9:15:22:14 via eth0
2026-10-04T18:24:55.698425+02:00 papaya dhcpd[18181]: DHCPDISCOVER from 00:0d:b9:15:22:14 via eth0
2026-10-04T18:24:55.698499+02:00 papaya dhcpd[18181]: DHCPOFFER on 192.168.10.8 to 00:0d:b9:15:22:14 via eth0
2026-10-04T18:25:00.708539+02:00 papaya dhcpd[18181]: DHCPDISCOVER from 00:0d:b9:15:22:14 via eth0
2026-10-04T18:25:00.709251+02:00 papaya dhcpd[18181]: DHCPOFFER on 192.168.10.8 to 00:0d:b9:15:22:14 via eth0
2026-10-04T18:25:05.709148+02:00 papaya dhcpd[18181]: DHCPDISCOVER from 00:0d:b9:15:22:14 via eth0
2026-10-04T18:25:05.709162+02:00 papaya dhcpd[18181]: DHCPOFFER on 192.168.10.8 to 00:0d:b9:15:22:14 via eth0
2026-10-04T18:25:10.710081+02:00 papaya dhcpd[18181]: DHCPDISCOVER from 00:0d:b9:15:22:14 via eth0
2026-10-04T18:25:10.710096+02:00 papaya dhcpd[18181]: DHCPOFFER on 192.168.10.8 to 00:0d:b9:15:22:14 via eth0
---

The same machine does not show this behaviour when using Linux (but linux does not support the Alix any longer, so I need a replacement ...)
>How-To-Repeat:
Just reboot several times.
Sometimes it happens at the 3rd attemt, sometimes it takes some more.

>Fix:
continuing on the serial console works. but this is not satisfying; console is not always connected.

Doing cold-start (happened often enough before pxe-booting worked) did not show this behaviour.




Home | Main Index | Thread Index | Old Index