Re: 7.3.1-rc2 does not recognize network interface

David Brooke <[email protected]> Mon, 8 Jul 2024 17:53:59 +0100 (BST)
Newsgroups gmane.linux.leaf.user
Message-ID <[email protected]>
> On 08/07/2024 14:34 BST David Brooke <[email protected]> wrote:
> 
>  
> > On 06/07/2024 12:30 BST KP.Kirchdoerfer <[email protected]> wrote:
> > 
> >  
> > Am Mittwoch, 3. Juli 2024, 18:30:29 CEST schrieb David Brooke:
> > > Hi,
> > > 
> > > > On 04/06/2024 14:20 BST KP.Kirchdoerfer <[email protected]> wrote:
> > > > 
> > > > 
> > > > Hi;
> > > > 
> > > > Am Dienstag, 4. Juni 2024, 08:59:39 CEST schrieb Dirk Gfrörer:
> > > > > Hello,
> > > > > 
> > > > > tried to update one of our apu4 PC Engines boxes to 7.3.1-rc2 using the
> > > > > Bering-uClibc_7.3.1-rc2_x86_64_syslinux_serial115200.tar.gz image.
> > > > > 
> > > > > This failed since the network interfaces were no longer recognized.
> > > > > Reverting back to rc1 made the network interfaces appear again. Have not
> > > > > yet understood on what goes wrong, but maybe someone else is also having
> > > > > this issue.
> > > > 
> > > > It does work here with APU2 and igb network driver (automatically
> > > > detected).
> > > > 
> > > > If you're issue persists I'll look again next week.
> > > > 
> > > > kp
> > > 
> > > I am seeing the same issue today with 7.3.1_x86_64 on an APU2.
> > > 
> > > Seems to be intermittent / inconsistent though:
> > > * Reboot and it says can't find eth0/1/2
> > > * Reboot again and it *can* find those but *not* e.g. ppp0
> > > * Reboot again and it's back to not finding eth0/1/2
> > > 
> > > I wonder if it's right on the limit of a timeout for module loading???
> > > (Is it the 3-second usb_wait, set in syslinux/syslinux.cfg, for this?)
> > > 
> > 
> > Odd; I'm running it successfully on an APU4 and also tested the image with 
> > qemu.
> 
> Odd indeed! :-) When it works, everything is fine - and I've been running
> 7.3.1 successfully for a few days now (without rebooting). But then I do a
> reboot and it fails to find the network interfaces. When I reboot a second
> time - *with the **exact** same configuration* - it works fine again.
> 
> (Changing usb_wait didn't help; I've had that set to 4 when it failed, and 
> 2 when it works.)
> 
> > What does dmesg show when you are booting? (see below how it looks here)
> 
> I've now got the dmesg output captured for a 'good' and a 'bad' boot.
> These are identical until after the 'u32 classifier' lines - which I
> believe are the result of loading cls_u32, specified near the end of
> /etc/modules. Is that a clue? Looking at repo/init.d/root.loadmodules
> there's an attempt to unmount the squashfs as soon as /etc/modules
> has been processed.
> 
> dmesg output from a 'good' boot:
> 
> ...
> [   17.801213] 8021q: 802.1Q VLAN Support v1.8
> [   17.866368] u32 classifier
> [   17.866384]     Performance counters on
> [   17.866387]     input device check on
> [   17.866390]     Actions configured
> [   17.941866] igb: loading out-of-tree module taints kernel.
> [   17.956580] igb: Intel(R) Gigabit Ethernet Linux Driver - version 5.15.6
> [   17.956588] igb: Copyright(c) 2007 - 2023 Intel Corporation.
> ...  (Many more igb lines, omitted)
> [   18.100447] igb 0000:03:00.0: Using MSI-X interrupts. 1 rx queue(s), 1 tx queue(s)
> [   19.117966] sp5100_tco: SP5100/SB800 TCO WatchDog Timer Driver
> [   19.118339] sp5100-tco sp5100-tco: Using 0xfed80b00 for watchdog MMIO address
> [   19.118510] sp5100-tco sp5100-tco: initialized. heartbeat=60 sec (nowayout=0)
> [   19.139035] piix4_smbus 0000:00:14.0: SMBus Host Controller at 0xb00, revision 0
> [   19.139055] piix4_smbus 0000:00:14.0: Using register 0x02 for SMBus port selection
> [   19.139329] piix4_smbus 0000:00:14.0: Auxiliary SMBus Host Controller at 0xb20
> [   19.263714] EDAC amd64: MCT channel count: 1
> [   19.264013] EDAC MC0: Giving out device to module amd64_edac controller F16h_M30h: DEV 0000:00:18.3 (INTERRUPT)
> [   19.264054] EDAC amd64: F16h_M30h detected (node 0).
> [   19.264059] EDAC MC: DCT0 chip selects:
> [   19.264063] EDAC amd64: MC: 0:  4096MB 1:     0MB
> [   19.264070] EDAC amd64: MC: 2:     0MB 3:     0MB
> [   19.264076] EDAC amd64: MC: 4:     0MB 5:     0MB
> [   19.264081] EDAC amd64: MC: 6:     0MB 7:     0MB
> [   19.264086] EDAC MC: DCT1 chip selects:
> [   19.264089] EDAC amd64: MC: 0:     0MB 1:     0MB
> [   19.264094] EDAC amd64: MC: 2:     0MB 3:     0MB
> [   19.264098] EDAC amd64: MC: 4:     0MB 5:     0MB
> [   19.264103] EDAC amd64: MC: 6:     0MB 7:     0MB
> [   19.264107] EDAC amd64: using x4 syndromes.
> [   19.264144] EDAC PCI0: Giving out device to module amd64_edac controller EDAC PCI controller: DEV 0000:00:18.2 (POLLED)                          
> [   19.264183] AMD64 EDAC driver v3.5.0
> [   19.630869] acpi_cpufreq: overriding BIOS provided _PSD data
> [   23.910792] EXT4-fs (sda3): unmounting filesystem.
> [   23.919071] Adding 104444k swap on /dev/zram0.  Priority:100 extents:1 across:104444k SS
> 
> 
> dmesg output from a 'bad' boot:
> 
> ...
> [   17.803206] 8021q: 802.1Q VLAN Support v1.8
> [   17.868978] u32 classifier
> [   17.869023]     Performance counters on
> [   17.869026]     input device check on
> [   17.869028]     Actions configured
> [   17.899170] EXT4-fs (sda3): unmounting filesystem.
> [   17.908144] Adding 104444k swap on /dev/zram0.  Priority:100 extents:1 across:104444k SS
> 
> So it's not only the igb modules that are missing; some others fail to load too.
> It's as if the module auto-loading just stops too soon.
> 
> The text on the serial console is the same in both cases:
> 
> LOADMODULES: identified device /dev/sda3
> LOADMODULES: Mounting squashes with modules...
> LOADMODULES: found modules.sqfs on /mnt1
> [   16.399684] /dev/loop0: Can't open blockdev
> LOADMODULES: loading modules from /etc/modules
> LOADMODULES: Unmounting /mnt1
> LOADMODULES: Removing /mnt1
> 
> (I always get that /dev/loop0 'blockdev' message, which seems to just be a
> warning.)
> 
> > Maybe it's worth testing the kernel module for igb, we are suing the out-of-
> > tree from Intel and/or a kernel version without UEFI support (which has been 
> > added in 7.3.1-rc2.
> 
> I don't think that will help, since the issue isn't specific to the igb module.
> 
> Having reviewed the root.loadmodules script, my hunch is that the unmount
> of the squashfs is happening before the auto-loading has finished. Maybe the
> loop with a 'sleep 3' gets (un)lucky sometimes? I note there's a VERBOSE2
> variable which will create more output; I'll give that a try when I get chance.
> 

The extra debug output to the serial console with VERBOSE2 set would appear to
confirm my hunch.

When the module auto-loading stops too early:

LOADMODULES: Waiting for module loading...
LOADMODULES: PKGPATH: /dev/sda3:ext4
LOADMODULES: identified device /dev/sda3
LOADMODULES: Mounting /dev/sda3 on /mnt1
LOADMODULES: Mounted /dev/sda3 on /mnt1
LOADMODULES: The following mountpoints were created: /mnt1
LOADMODULES: Mounting squashfs with modules...
LOADMODULES: found modules.sqfs on /mnt1
[   16.342129] /dev/loop0: Can't open blockdev
LOADMODULES: loading modules from /etc/modules
LOADMODULES: /sbin/modprobe pppoe
LOADMODULES: /sbin/modprobe softdog
LOADMODULES: /sbin/modprobe ipv6
LOADMODULES: /sbin/modprobe 8021q
LOADMODULES: /sbin/modprobe ifb
LOADMODULES: /sbin/modprobe act_police
LOADMODULES: /sbin/modprobe cls_fw
LOADMODULES: /sbin/modprobe cls_flow
LOADMODULES: /sbin/modprobe sch_tbf
LOADMODULES: /sbin/modprobe sch_prio
LOADMODULES: /sbin/modprobe sch_ingress
LOADMODULES: /sbin/modprobe cls_u32
LOADMODULES: /sbin/modprobe sch_htb
LOADMODULES: /sbin/modprobe sch_sfq
LOADMODULES: looping to unmount /lib/modules/6.1.64-x86_64
LOADMODULES: Unmounting /mnt1
LOADMODULES: Removing /mnt1

When the module auto-loading happens normally:

LOADMODULES: Waiting for module loading...
LOADMODULES: PKGPATH: /dev/sda3:ext4
LOADMODULES: identified device /dev/sda3
LOADMODULES: Mounting /dev/sda3 on /mnt1
LOADMODULES: Mounted /dev/sda3 on /mnt1
LOADMODULES: The following mountpoints were created: /mnt1
LOADMODULES: Mounting squashfs with modules...
LOADMODULES: found modules.sqfs on /mnt1
[   16.361295] /dev/loop0: Can't open blockdev
LOADMODULES: loading modules from /etc/modules
LOADMODULES: /sbin/modprobe pppoe
LOADMODULES: /sbin/modprobe softdog
LOADMODULES: /sbin/modprobe ipv6
LOADMODULES: /sbin/modprobe 8021q
LOADMODULES: /sbin/modprobe ifb
LOADMODULES: /sbin/modprobe act_police
LOADMODULES: /sbin/modprobe cls_fw
LOADMODULES: /sbin/modprobe cls_flow
LOADMODULES: /sbin/modprobe sch_tbf
LOADMODULES: /sbin/modprobe sch_prio
LOADMODULES: /sbin/modprobe sch_ingress
LOADMODULES: /sbin/modprobe cls_u32
LOADMODULES: /sbin/modprobe sch_htb
LOADMODULES: /sbin/modprobe sch_sfq
LOADMODULES: looping to unmount /lib/modules/6.1.64-x86_64
LOADMODULES: looping to unmount /lib/modules/6.1.64-x86_64   <--
LOADMODULES: looping to unmount /lib/modules/6.1.64-x86_64   <--
LOADMODULES: Unmounting /mnt1
LOADMODULES: Removing /mnt1

The difference (marked <--) is that, when all the modules are loaded, it
takes 3 attempts (with a sleep of 3 seconds between) to satisfy the
criteria for 'looping to unmount' whereas when only some of the modules
are loaded, the unmount of /lib/modules/6.1.64-x86_64 succeeds at the
first attempt.

This is the relevant section of repo/initrd/root.loadmodules (installed
as /var/lib/lrpkg/root.loadmodules):

  # umount the squashfs
  loop_counter=0
  while [ $loop_counter -lt 15 ]
  do
          [ "$VERBOSE2" ] && Lecho "looping to unmount /lib/modules/$KVER"
          umount /lib/modules/$KVER > /dev/null 2>&1
          [ -z "$(grep /lib/modules/$KVER /proc/mounts)" ] && break
          sleep 3             
  done

For some reason, the 'umount' is succeeding before module auto-loading has
completed - but only sometimes, and only for some installations (and only
on APU boards, it seems).

dMb

> dMb
> 
> > kp
> >


------------------------------------------------------------------------
leaf-user mailing list: [email protected]
https://lists.sourceforge.net/lists/listinfo/leaf-user
Support Request -- http://leaf-project.org/