NetBSD-Bugs archive

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

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



The following reply was made to PR port-i386/60848; it has been noted by GNATS.

From: Andrius V <vezhlys%gmail.com@localhost>
To: gnats-bugs%netbsd.org@localhost
Cc: 
Subject: Re: port-i386/60848: Alix fails to boot sometimes after warmstart,
 very likely due to network initialization
Date: Fri, 9 Oct 2026 09:15:55 +0300

 On Tue, Oct 6, 2026 at 1:01=E2=80=AFPM Andrius V <vezhlys%gmail.com@localhost> wrote:
 >
 > On Sun, Oct 4, 2026 at 8:00=E2=80=AFPM netbsd%lissners.de@localhost via gnats
 > <gnats-admin%netbsd.org@localhost> wrote:
 > >
 > > >Number:         60848
 > > >Category:       port-i386
 > > >Synopsis:       Alix fails to boot sometimes after warmstart, very lik=
 ely 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 2=
 026  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/dh=
 cp 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]=3D0x17c5a7c
 > > [   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 ri=
 ghts 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/compi=
 le/GENERIC
 > > [   1.0000000] total memory =3D 255 MB
 > > [   1.0000000] avail memory =3D 227 MB
 > > [   1.0000040] mainbus0 (root)
 > > [   1.0000040] Firmware Error (ACPI): A valid RSDP was not found (20241=
 212/tbxfroot-383)
 > > acpi_probe: failed to initialize tables
 > > [   1.0000040] ACPI Error: Could not remove SCI handler (20241212/evmis=
 c-424)
 > > [   1.0000040] cpu0 at mainbus0
 > > [   1.0000040] ACPI Error: AE_BAD_PARAMETER, Thread 3243335680 could no=
 t acquire Mutex [ACPI_MTX_Tables] (0x2) (20241212/utmutex-434)
 > > [   1.0000040] ACPI Error: Mutex [ACPI_MTX_Tables] (0x2) is not acquire=
 d, cannot release (20241212/utmutex-475)
 > > [   1.0000040] cpu0: Geode(TM) Integrated Processor by AMD PCS, id 0x5a=
 2
 > > [   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 Br=
 idge (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 Contro=
 ller (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 Con=
 troller (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 structur=
 es
 > > [   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 F=
 IFO
 > > [   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), c=
 lass 9/0, rev 1.00/1.00, addr 1
 > > [   1.2180982] uhub1 at usb1: NetBSD (0x0000) EHCI root hub (0x0000), c=
 lass 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=3D51
 > > [  47.8764193] Supported file systems: mfs lfs ffs ext2fs nfs umap proc=
 fs 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 =3D 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-syste=
 m, 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=3Dlissner.home
 > > [  52.7771070] nfs_boot: my_addr=3D192.168.10.8
 > > [  52.7893228] nfs_boot: my_mask=3D255.255.240.0
 > > [  52.8018160] nfs_boot: gateway=3D192.168.10.2
 > > [  58.8118575] root on papaya:/srv/diskless/netbsd0/root
 > > [  58.8310180] root file system type: nfs
 > > [  58.8422158] kern.module.path=3D/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 =3D 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.18606=
 4145, 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 DHCPDIS=
 COVER 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.1=
 68.10.8 filename netbsd0/root/netbsd
 > > 2026-10-04T18:23:03.087076+02:00 papaya in.tftpd[21403]: RRQ from 192.1=
 68.10.8 filename netbsd0/root/netbsd
 > > 2026-10-04T18:23:24.748493+02:00 papaya in.tftpd[21404]: RRQ from 192.1=
 68.10.8 filename netbsd0/root/netbsd
 > > 2026-10-04T18:23:48.175746+02:00 papaya in.tftpd[21405]: RRQ from 192.1=
 68.10.8 filename netbsd0/root/netbsd
 > > 2026-10-04T18:24:09.792481+02:00 papaya in.tftpd[21406]: RRQ from 192.1=
 68.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 lin=
 ux 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; con=
 sole is not always connected.
 > >
 > > Doing cold-start (happened often enough before pxe-booting worked) did =
 not show this behaviour.
 > >
 >
 > Hi,
 >
 > I will try to reproduce in a coming days with the hardware I have
 > (using if_vr interface).
 >
 > Since, I've seen forced reset, I modified a code a bit in that place
 > to print if reset failed and make it slightly more optimized.
 >
 > I don't think so it will help to resolve the issue but at least it can
 > confirm that forced reset succeeds. Do you see this message on every
 > failure?
 >
 > Another test which you can do is to comment out `if (i =3D=3D VR_TIMEOUT)
 > {` condition and always use force reset to see if it helps.
 >
 > If it does, my biggest suspicion is that detachment/stopping code
 > leaves invalid or stale state which hinders initialization after a
 > warm reboot.
 > I would likely need to compare it with the Linux code.
 >
 > Regards,
 > Andrius V
 
 Hi,
 
 Just wanted to update that I managed to reproduce the issue, however
 it happens too rarely for me to properly debug.
 So, I can't promise I will find a fast solution, but I will be
 investigating for a while.
 How often does it actually happen to you? For me I can barely hit this
 issue in multiple reboots.
 If I do it may repeat once or twice, but once it's gone, it is close
 to impossible to reproduce again.
 



Home | Main Index | Thread Index | Old Index