Yocto project with systemd - nfs: server not responding, still trying

 

Introduction

This work is sponsored by Reliable Embedded Systems. You can find more information about our training/consulting services here.

Objectives

The goal of this blog post is to walk you through the steps what to do when systemd does not want to boot with a rootfs over NFS by default.



Issue

So let's say you make a brand new image recipe which pulls in many beautiful packages and eventually you need systemd instead of good old sys-v. You try to boot and see:

U-Boot SPL 2020.01 (Jan 06 2020 - 20:56:31 +0000)
Boot device 1
Trying to boot from MMC1
mmc_load_image_raw_sector: mmc block read error


U-Boot 2020.01 (Jan 06 2020 - 20:56:31 +0000)

CPU:   Freescale i.MX6Q rev1.3 996 MHz (running at 792 MHz)
CPU:   Automotive temperature grade (-40C to 125C) at 64C
Reset cause: POR
I2C:   ready
DRAM:  1 GiB
NAND:  1024 MiB
MMC:   FSL_SDHC: 0
Loading Environment from SPI Flash... SF: Detected n25q128a13 with page size 256 Bytes, erase size 4 KiB, total 16 MiB
OK
In:    serial
Out:   serial
Err:   serial
Net:   FEC [PRIME]
Hit any key to stop autoboot:  0
bootfile: imx6q-phytec-mira-rdk-nand/uImage
fdtfile: imx6q-phytec-mira-rdk-nand/uImage-imx6q-phytec-mira-rdk-nand.dtb
FEC Waiting for PHY auto negotiation to complete...... done
Using FEC device
host 192.168.42.107 is alive
Using FEC device
TFTP from server 192.168.42.107; our IP address is 192.168.42.127
Filename 'imx6q-phytec-mira-rdk-nand/uImage'.
Load address: 0x10007fc0
Loading: #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         ##########################################
         9.9 MiB/s
done
Bytes transferred = 10154560 (9af240 hex)
Using FEC device
TFTP from server 192.168.42.107; our IP address is 192.168.42.127
Filename 'imx6q-phytec-mira-rdk-nand/uImage-imx6q-phytec-mira-rdk-nand.dtb'.
Load address: 0x18000000
Loading: ###
         6.5 MiB/s
done
Bytes transferred = 40916 (9fd4 hex)
Booting from nfs uEnv.txt from ext4...
bootargs=console=ttymxc1,115200n8 ip=192.168.42.127:192.168.42.107:192.168.42.254:255.255.255.0:imx6q-phytec-mira-rdk-nand:eth0:off nfsroot=192.168.42.107:/opt/poky/mira-rootfs,v3,tcp noinitrd nohlt panic=1 earlyprintk=ttymxc1,115200n8
## Booting kernel from Legacy Image at 10007fc0 ...
   Image Name:   Linux-5.4.47-custom-ml-virt
   Image Type:   ARM Linux Kernel Image (no loading done) (uncompressed)
   Data Size:    10154496 Bytes = 9.7 MiB
   Load Address: 00000000
   Entry Point:  00000000
   Verifying Checksum ... OK
## Flattened Device Tree blob at 18000000
   Booting using the fdt blob at 0x18000000
   XIP Kernel Image (no loading done)
   Using Device Tree in place at 18000000, end 1800cfd3

Starting kernel ...

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.4.47-custom-ml-virt (oe-user@oe-host) (gcc version 9.3.0 (GCC)) #1 SMP Wed Jun 17 14:40:38 UTC 2020
[    0.000000] CPU: ARMv7 Processor [412fc09a] revision 10 (ARMv7), cr=10c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: PHYTEC phyBOARD-Mira Quad Carrier-Board with NAND
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] efi: Getting EFI parameters from FDT:
[    0.000000] efi: UEFI not found.
[    0.000000] cma: Reserved 64 MiB at 0x4c000000
[    0.000000] percpu: Embedded 20 pages/cpu s49356 r8192 d24372 u81920
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 260416
[    0.000000] Kernel command line: console=ttymxc1,115200n8 ip=192.168.42.127:192.168.42.107:192.168.42.254:255.255.255.0:imx6q-phytec-mira-rdk-nand:eth0:off nfsroot=192.168.42.107:/opt/poky/mira-rootfs,v3,tcp noinitrd nohlt panic=1 earlyprintk=ttymxc1,115200n8
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 947832K/1048576K available (14336K kernel code, 1748K rwdata, 5580K rodata, 2048K init, 424K bss, 35208K reserved, 65536K cma-reserved, 196608K highmem)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu:     RCU event tracing is enabled.
[    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=16 to nr_cpu_ids=4.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] L2C-310 errata 752271 769419 enabled
[    0.000000] L2C-310 enabling early BRESP for Cortex-A9
[    0.000000] L2C-310 full line of zeros enabled for Cortex-A9
[    0.000000] L2C-310 ID prefetch enabled, offset 16 lines
[    0.000000] L2C-310 dynamic clock gating enabled, standby mode enabled
[    0.000000] L2C-310 cache controller enabled, 16 ways, 1024 kB
[    0.000000] L2C-310: CACHE_ID 0x410000c7, AUX_CTRL 0x76470001
[    0.000000] random: get_random_bytes called from start_kernel+0x314/0x4e4 with crng_init=0
[    0.000000] Switching to timer-based delay loop, resolution 333ns
[    0.000006] sched_clock: 32 bits at 3000kHz, resolution 333ns, wraps every 715827882841ns
[    0.000023] clocksource: mxc_timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 637086815595 ns
[    0.003315] Console: colour dummy device 80x30
[    0.003367] Calibrating delay loop (skipped), value calculated using timer frequency.. 6.00 BogoMIPS (lpj=30000)
[    0.003380] pid_max: default: 32768 minimum: 301
[    0.003576] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.003592] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.004426] CPU: Testing write buffer coherency: ok
[    0.004457] CPU0: Spectre v2: using BPIALL workaround
[    0.004729] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.005271] Setting up static identity map for 0x10300000 - 0x103000ac
[    0.006855] rcu: Hierarchical SRCU implementation.
[    0.010251] EFI services will not be available.
[    0.010474] smp: Bringing up secondary CPUs ...
[    0.011162] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.011169] CPU1: Spectre v2: using BPIALL workaround
[    0.011958] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.011965] CPU2: Spectre v2: using BPIALL workaround
[    0.012721] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.012730] CPU3: Spectre v2: using BPIALL workaround
[    0.012836] smp: Brought up 1 node, 4 CPUs
[    0.012847] SMP: Total of 4 processors activated (24.00 BogoMIPS).
[    0.012855] CPU: All CPU(s) started in SVC mode.
[    0.013409] devtmpfs: initialized
[    0.020764] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
[    0.020992] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.021013] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.024458] xor: measuring software checksum speed
[    0.119158]    arm4regs  :  1233.600 MB/sec
[    0.219155]    8regs     :   951.200 MB/sec
[    0.319154]    32regs    :  1028.800 MB/sec
[    0.419155]    neon      :   900.400 MB/sec
[    0.419164] xor: using function: arm4regs (1233.600 MB/sec)
[    0.419247] pinctrl core: initialized pinctrl subsystem
[    0.421057] DMI not present or invalid.
[    0.421529] NET: Registered protocol family 16
[    0.424443] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.426949] cpuidle: using governor menu
[    0.427233] CPU identified as i.MX6Q, silicon rev 1.5
[    0.437409] vdd1p1: supplied by regulator-dummy
[    0.437942] vdd3p0: supplied by regulator-dummy
[    0.438481] vdd2p5: supplied by regulator-dummy
[    0.453481] No ATAGs?
[    0.453619] hw-breakpoint: found 5 (+1 reserved) breakpoint and 1 watchpoint registers.
[    0.453632] hw-breakpoint: maximum watchpoint size is 4 bytes.
[    0.457261] imx6q-pinctrl 20e0000.iomuxc: initialized IMX pinctrl driver
[    0.462414] Serial: AMBA PL011 UART driver
[    0.639225] raid6: neonx8   gen()   542 MB/s
[    0.809163] raid6: neonx8   xor()   500 MB/s
[    0.979148] raid6: neonx4   gen()   680 MB/s
[    1.149148] raid6: neonx4   xor()   622 MB/s
[    1.319168] raid6: neonx2   gen()   662 MB/s
[    1.489152] raid6: neonx2   xor()   688 MB/s
[    1.659151] raid6: neonx1   gen()   607 MB/s
[    1.829152] raid6: neonx1   xor()   554 MB/s
[    1.999423] raid6: int32x8  gen()   221 MB/s
[    2.169285] raid6: int32x8  xor()   155 MB/s
[    2.339312] raid6: int32x4  gen()   189 MB/s
[    2.509255] raid6: int32x4  xor()   155 MB/s
[    2.679204] raid6: int32x2  gen()   160 MB/s
[    2.849275] raid6: int32x2  xor()   145 MB/s
[    3.019207] raid6: int32x1  gen()   100 MB/s
[    3.189161] raid6: int32x1  xor()   110 MB/s
[    3.189170] raid6: using algorithm neonx4 gen() 680 MB/s
[    3.189177] raid6: .... xor() 622 MB/s, rmw enabled
[    3.189184] raid6: using neon recovery algorithm
[    3.202687] mxs-dma 110000.dma-apbh: initialized
[    3.204516] AT91: Could not find identification node
[    3.209809] iommu: Default domain type: Translated
[    3.210113] vgaarb: loaded
[    3.211037] SCSI subsystem initialized
[    3.211503] usbcore: registered new interface driver usbfs
[    3.211550] usbcore: registered new interface driver hub
[    3.211621] usbcore: registered new device driver usb
[    3.212906] i2c i2c-0: IMX I2C adapter registered
[    3.213358] i2c i2c-1: IMX I2C adapter registered
[    3.214045] i2c i2c-2: IMX I2C adapter registered
[    3.215154] pps_core: LinuxPPS API ver. 1 registered
[    3.215163] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    3.215184] PTP clock support registered
[    3.215394] EDAC MC: Ver: 3.0.0
[    3.218394] clocksource: Switched to clocksource mxc_timer1
[    3.736055] thermal_sys: Registered thermal governor 'step_wise'
[    3.736463] NET: Registered protocol family 2
[    3.737320] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    3.737354] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    3.737431] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    3.737559] TCP: Hash tables configured (established 8192 bind 8192)
[    3.737679] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    3.737726] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    3.737935] NET: Registered protocol family 1
[    3.738521] RPC: Registered named UNIX socket transport module.
[    3.738531] RPC: Registered udp transport module.
[    3.738537] RPC: Registered tcp transport module.
[    3.738544] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    3.738557] PCI: CLS 0 bytes, default 64
[    3.739355] hw perfevents: no interrupt-affinity property for /pmu, guessing.
[    3.739587] hw perfevents: enabled with armv7_cortex_a9 PMU driver, 7 counters available
[    3.741102] Initialise system trusted keyrings
[    3.741268] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    3.748759] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    3.749426] NFS: Registering the id_resolver key type
[    3.749454] Key type id_resolver registered
[    3.749461] Key type id_legacy registered
[    3.749500] ntfs: driver 2.1.32 [Flags: R/O].
[    3.786114] Key type asymmetric registered
[    3.786126] Asymmetric key parser 'x509' registered
[    3.786179] bounce: pool size: 64 pages
[    3.786224] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
[    3.786234] io scheduler mq-deadline registered
[    3.786242] io scheduler kyber registered
[    3.828711] imx-sdma 20ec000.sdma: Direct firmware load for imx/sdma/sdma-imx6q.bin failed with error -2
[    3.828729] imx-sdma 20ec000.sdma: external firmware not found, using ROM firmware
[    3.876134] Serial: 8250/16550 driver, 5 ports, IRQ sharing enabled
[    3.880243] SuperH (H)SCI(F) driver initialized
[    3.881216] 21e8000.serial: ttymxc1 at MMIO 0x21e8000 (irq = 68, base_baud = 5000000) is a IMX
[    4.724363] printk: console [ttymxc1] enabled
[    4.729367] 21ec000.serial: ttymxc2 at MMIO 0x21ec000 (irq = 69, base_baud = 5000000) is a IMX
[    4.739114] msm_serial: driver initialized
[    4.743444] STMicroelectronics ASC driver initialized
[    4.750270] STM32 USART driver initialized
[    4.771602] brd: module loaded
[    4.783030] loop: module loaded
[    4.787157] at24 2-0050: 4096 byte 24c32 EEPROM, writable, 1 bytes/write
[    4.802419] nand: device found, Manufacturer ID: 0x01, Chip ID: 0xd3
[    4.808809] nand: AMD/Spansion S34ML08G2
[    4.812739] nand: 1024 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 128
[    4.820910] Bad block table found at page 524224, version 0x01
[    4.826872] Bad block table found at page 524160, version 0x01
[    4.834361] gpmi-nand 112000.gpmi-nand: driver registered.
[    4.846066] libphy: Fixed MDIO Bus: probed
[    4.851247] CAN device driver interface
[    4.856284] bgmac_bcma: Broadcom 47xx GBit MAC driver loaded
[    4.865948] pps pps0: new PPS source ptp0
[    4.871085] libphy: fec_enet_mii_bus: probed
[    4.877075] fec 2188000.ethernet eth0: registered PHC device 0
[    4.884076] e1000e: Intel(R) PRO/1000 Network Driver - 3.2.6-k
[    4.889940] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[    4.895915] igb: Intel(R) Gigabit Ethernet Network Driver - version 5.6.0-k
[    4.902897] igb: Copyright (c) 2007-2014 Intel Corporation.
[    4.913690] pegasus: v0.9.3 (2013/04/25), Pegasus/Pegasus II USB Ethernet driver
[    4.921168] usbcore: registered new interface driver pegasus
[    4.926869] usbcore: registered new interface driver asix
[    4.932320] usbcore: registered new interface driver ax88179_178a
[    4.938463] usbcore: registered new interface driver cdc_ether
[    4.944342] usbcore: registered new interface driver smsc75xx
[    4.950158] usbcore: registered new interface driver smsc95xx
[    4.955939] usbcore: registered new interface driver net1080
[    4.961650] usbcore: registered new interface driver cdc_subset
[    4.967602] usbcore: registered new interface driver zaurus
[    4.973241] usbcore: registered new interface driver cdc_ncm
[    4.981809] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    4.988342] ehci-pci: EHCI PCI platform driver
[    4.992841] ehci-platform: EHCI generic platform driver
[    4.998320] ehci-orion: EHCI orion driver
[    5.002553] SPEAr-ehci: EHCI SPEAr driver
[    5.006733] ehci-st: EHCI STMicroelectronics driver
[    5.011801] ehci-exynos: EHCI EXYNOS driver
[    5.016150] ehci-atmel: EHCI Atmel driver
[    5.020341] tegra-ehci: Tegra EHCI driver
[    5.024562] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    5.030779] ohci-pci: OHCI PCI platform driver
[    5.035269] ohci-platform: OHCI generic platform driver
[    5.040744] SPEAr-ohci: OHCI SPEAr driver
[    5.044924] ohci-st: OHCI STMicroelectronics driver
[    5.049995] ohci-atmel: OHCI Atmel driver
[    5.054942] usbcore: registered new interface driver usb-storage
[    5.072489] ci_hdrc ci_hdrc.1: EHCI Host Controller
[    5.077398] ci_hdrc ci_hdrc.1: new USB bus registered, assigned bus number 1
[    5.108400] ci_hdrc ci_hdrc.1: USB 2.0 started, EHCI 1.00
[    5.114523] hub 1-0:1.0: USB hub found
[    5.118322] hub 1-0:1.0: 1 port detected
[    5.128807] i2c /dev entries driver
[    5.146636] imx2-wdt 20bc000.wdog: timeout 60 sec (nowayout=0)
[    5.157921] sdhci: Secure Digital Host Controller Interface driver
[    5.164132] sdhci: Copyright(c) Pierre Ossman
[    5.171007] Synopsys Designware Multimedia Card Interface Driver
[    5.178849] sdhci-pltfm: SDHCI platform and OF driver helper
[    5.185471] sdhci-esdhc-imx 2190000.usdhc: Got CD GPIO
[    5.223080] mmc0: SDHCI controller on 2190000.usdhc [2190000.usdhc] using ADMA
[    5.234340] ledtrig-cpu: registered to indicate activity on CPUs
[    5.241156] usbcore: registered new interface driver usbhid
[    5.246733] usbhid: USB HID core driver
[    5.255432] drop_monitor: Initializing network drop monitor service
[    5.262928] NET: Registered protocol family 10
[    5.268299] Segment Routing with IPv6
[    5.272127] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    5.278644] NET: Registered protocol family 17
[    5.283103] can: controller area network core (rev 20170425 abi 9)
[    5.289371] NET: Registered protocol family 29
[    5.293820] can: raw protocol (rev 20170425)
[    5.298094] can: broadcast manager protocol (rev 20170425 t)
[    5.303782] can: netlink gateway (rev 20190810) max_hops=1
[    5.309679] Key type dns_resolver registered
[    5.315259] ThumbEE CPU extension supported.
[    5.319575] Registering SWP/SWPB emulation handler
[    5.324646] Loading compiled-in X.509 certificates
[    5.332452] Btrfs loaded, crc32c=crc32c-generic
[    5.370290] hctosys: unable to open rtc device (rtc0)
[    5.396508] mmc0: host does not support reading read-only switch, assuming write-enable
[    5.410598] mmc0: new high speed SDHC card at address 0007
[    5.416757] mmcblk0: mmc0:0007 SD04G 3.71 GiB
[    5.424725]  mmcblk0: p1
[    5.481839] Micrel KSZ9031 Gigabit PHY 2188000.ethernet-1:03: attached PHY driver [Micrel KSZ9031 Gigabit PHY] (mii_bus:phy_addr=2188000.ethernet-1:03, irq=POLL)
[   14.968808] fec 2188000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
[   14.978421] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   14.968466] IP-Config: Complete:
[   14.971707]      device=eth0, hwaddr=50:2d:f4:0d:d3:c3, ipaddr=192.168.42.127, mask=255.255.255.0, gw=192.168.42.254
[   14.982258]      host=imx6q-phytec-mira-rdk-nand, domain=, nis-domain=(none)
[   14.989326]      bootserver=192.168.42.107, rootserver=192.168.42.107, rootpath=
[   23.145444] random: fast init done
[   23.150675] VFS: Mounted root (nfs filesystem) readonly on device 0:16.
[   23.158324] devtmpfs: mounted
[   23.163717] Freeing unused kernel memory: 2048K
[   23.218936] Run /sbin/init as init process
[   24.954008] systemd[1]: System time before build time, advancing clock.
[   25.201347] systemd[1]: systemd 244.3+ running in system mode. (-PAM -AUDIT -SELINUX +IMA -APPARMOR -SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN -PCRE2 default-hierarchy=hybrid)
[   25.223623] systemd[1]: Detected architecture arm.

Welcome to Resy virt (Reliable Embedded Systems Virtualization Reference Distro) 3.1.2 (olivegold)!

[   25.311313] systemd[1]: Set hostname to <multi-v7-ml>.
[   25.328023] random: systemd: uninitialized urandom read (16 bytes read)
[   25.334735] systemd[1]: Initializing machine ID from random generator.
[   25.341508] systemd[1]: Installed transient /etc/machine-id file.
[   26.217701] random: systemd: uninitialized urandom read (16 bytes read)
[   26.224574] systemd[1]: system-getty.slice: unit configures an IP firewall, but the local system does not support BPF/cgroup firewalling.
[   26.236962] systemd[1]: (This warning is only shown for the first unit using IP firewalling.)
[   26.248952] systemd[1]: Created slice system-getty.slice.
[  OK  ] Created slice system-getty.slice.
[   26.298651] random: systemd: uninitialized urandom read (16 bytes read)
[   26.306757] systemd[1]: Created slice system-serial\x2dgetty.slice.
[  OK  ] Created slice system-serial\x2dgetty.slice.
[   26.338625] random: systemd: uninitialized urandom read (16 bytes read)
[   26.346554] systemd[1]: Created slice User and Session Slice.
[  OK  ] Created slice User and Session Slice.
[   26.378612] random: systemd: uninitialized urandom read (16 bytes read)
[   26.385539] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[  OK  ] Started Dispatch Password …ts to Console Directory Watch.
[   26.428574] random: systemd: uninitialized urandom read (16 bytes read)
[   26.435454] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[  OK  ] Started Forward Password R…uests to Wall Directory Watch.
[   26.478839] systemd[1]: Reached target Host and Network Name Lookups.
[  OK  ] Reached target Host and Network Name Lookups.
[   26.518592] systemd[1]: Reached target Paths.
[  OK  ] Reached target Paths.
[   26.548635] systemd[1]: Reached target Remote File Systems.
[  OK  ] Reached target Remote File Systems.
[   26.588602] systemd[1]: Reached target Slices.
[  OK  ] Reached target Slices.
[   26.618676] systemd[1]: Reached target Swap.
[  OK  ] Reached target Swap.
[   26.649087] systemd[1]: Listening on initctl Compatibility Named Pipe.
[  OK  ] Listening on initctl Compatibility Named Pipe.
[   26.930833] systemd[1]: Condition check resulted in Journal Audit Socket being skipped.
[   26.941352] systemd[1]: Listening on Journal Socket (/dev/log).
[  OK  ] Listening on Journal Socket (/dev/log).
[   26.979229] systemd[1]: Listening on Journal Socket.
[  OK  ] Listening on Journal Socket.
[   27.020428] systemd[1]: Listening on Network Service Netlink Socket.
[  OK  ] Listening on Network Service Netlink Socket.
[   27.060792] systemd[1]: Listening on udev Control Socket.
[  OK  ] Listening on udev Control Socket.
[   27.098956] systemd[1]: Listening on udev Kernel Socket.
[  OK  ] Listening on udev Kernel Socket.
[   27.139170] systemd[1]: Condition check resulted in Huge Pages File System being skipped.
[   27.152629] systemd[1]: Mounting POSIX Message Queue File System...
         Mounting POSIX Message Queue File System...
[   27.193752] systemd[1]: Mounting Kernel Debug File System...
         Mounting Kernel Debug File System...
[   27.237063] systemd[1]: Mounting Temporary Directory (/tmp)...
         Mounting Temporary Directory (/tmp)...
[   27.270037] systemd[1]: Condition check resulted in Create list of static device nodes for the current kernel being skipped.
[   27.290776] systemd[1]: Started Hardware RNG Entropy Gatherer Daemon.
[  OK  ] Started Hardware RNG Entropy Gatherer Daemon.
[   27.340075] systemd[1]: Starting File System Check on Root Device...
         Starting File System Check on Root Device...
[   27.385751] systemd[1]: Starting Journal Service...
         Starting Journal Service...
[   27.608379] systemd[1]: Condition check resulted in Load Kernel Modules being skipped.
[   27.617133] systemd[1]: Condition check resulted in FUSE Control File System being skipped.
[   27.659097] systemd[1]: Mounting Kernel Configuration File System...
         Mounting Kernel Configuration File System...
[   27.703814] systemd[1]: Starting Apply Kernel Variables...
         Starting Apply Kernel Variables...
[   27.773446] systemd[1]: Starting udev Coldplug all Devices...
         Starting udev Coldplug all Devices...
[   27.823916] systemd[1]: Started Journal Service.
[  OK  ] Started Journal Service.
[  OK  ] Mounted POSIX Message Queue File System.
[  OK  ] Mounted Kernel Debug File System.
[  OK  ] Mounted Temporary Directory (/tmp).
[  OK  ] Started File System Check on Root Device.
[  OK  ] Mounted Kernel Configuration File System.
         Starting Remount Root and Kernel File Systems...
[  OK  ] Started Apply Kernel Variables.
[  OK  ] Started Remount Root and Kernel File Systems.
         Starting Flush Journal to Persistent Storage...
         Starting Create System Users...
[   28.324613] systemd-journald[112]: Received client request to flush runtime journal.
[  OK  ] Started Flush Journal to Persistent Storage.
[  OK  ] Started Create System Users.
         Starting Create Static Device Nodes in /dev...
[  OK  ] Started Create Static Device Nodes in /dev.
[  OK  ] Reached target Local File Systems (Pre).
         Mounting /var/volatile...
         Starting udev Kernel Device Manager...
[  OK  ] Mounted /var/volatile.
         Starting Load/Save Random Seed...
[  OK  ] Reached target Local File Systems.
         Starting Rebuild Dynamic Linker Cache...
         Starting Commit a transient machine-id on disk...
         Starting Create Volatile Files and Directories...
[  OK  ] Started Commit a transient machine-id on disk.
[  OK  ] Started udev Kernel Device Manager.
[   30.468467] random: crng init done
[   30.471888] random: 4 urandom warning(s) missed due to ratelimiting
[  OK  ] Started Load/Save Random Seed.
[  OK  ] Started udev Coldplug all Devices.
[  OK  ] Started Create Volatile Files and Directories.
         Starting Run pending postinsts...
         Starting Rebuild Journal Catalog...
         Starting Network Time Synchronization...
         Starting Update UTMP about System Boot/Shutdown...
[  OK  ] Started Update UTMP about System Boot/Shutdown.
[  OK  ] Started Rebuild Journal Catalog.
[  OK  ] Started Network Time Synchronization.
[  OK  ] Reached target System Time Set.
[  OK  ] Reached target System Time Synchronized.
[  OK  ] Started Run pending postinsts.
[  OK  ] Started Rebuild Dynamic Linker Cache.
         Starting Update is Completed...
[  OK  ] Started Update is Completed.
[  OK  ] Reached target System Initialization.
[  OK  ] Started Daily rotation of log files.
[  OK  ] Started Daily Cleanup of Temporary Directories.
[  OK  ] Reached target Timers.
[  OK  ] Listening on D-Bus System Message Bus Socket.
         Starting sshd.socket.
         Starting Reboot and dump vmcore via kexec...
[  OK  ] Listening on sshd.socket.
[  OK  ] Reached target Sockets.
[  OK  ] Reached target Basic System.
[  OK  ] Started Periodic Command Scheduler.
[  OK  ] Started D-Bus System Message Bus.
[  OK  ] Started Getty on tty1.
         Starting IPv6 Packet Filtering Framework...
         Starting IPv4 Packet Filtering Framework...
[  OK  ] Started Serial Getty on ttyS0.
[  OK  ] Started Serial Getty on ttymxc1.
[  OK  ] Reached target Login Prompts.
         Starting Login Service...
[  OK  ] Started Reboot and dump vmcore via kexec.
[  OK  ] Started IPv6 Packet Filtering Framework.
[  OK  ] Started IPv4 Packet Filtering Framework.
[  OK  ] Reached target Network (Pre).
         Starting Connection service...
         Starting Network Service...
[  OK  ] Started Connection service.
[   45.298462] vddpu: disabling
[   45.301366] flexcan1-reg: disabling
[   45.304859] mPCIe_1V5: disabling
[   45.308091] usb_otg_vbus: disabling
[  219.618433] nfs: server 192.168.42.107 not responding, still trying
[  219.618437] nfs: server 192.168.42.107 not responding, still trying
[  219.618483] nfs: server 192.168.42.107 not responding, still trying
[  226.258843] nfs: server 192.168.42.107 not responding, still trying
[  226.265409] nfs: server 192.168.42.107 not responding, still trying
[  226.271781] nfs: server 192.168.42.107 not responding, still trying
[  244.489021] nfs: server 192.168.42.107 not responding, still trying
[  250.568673] nfs: server 192.168.42.107 not responding, still trying

Hmm the NFS died along the way? No shell? Should I add this to my list "why I don't like systemd"? It's 2020 and even I tend to believe that systemd might be usable in the meantime.

Now what?

Try the basics:

Maybe we could get some more useful info out of systemd?

https://freedesktop.org/wiki/Software/systemd/Debugging/

I am not sure you'll get anything useful out of this experiments, except for satisfying your curiousity.

The same image with sys-v instead of systemd boots happily - hmm?

It can't be that systemd is not able to boot with a rootfs over NFS. Can it be? Let's first also check if we got the kernel config setting right, maybe something is missing there, or some new version of systemd or even worse some CVE patch (just updated dunfell from 3.1.1 to 3.1.2) applied to systemd requires some new config options? I remember the times where I had to change kernel config options to get systemd to work. But this should be pretty stable now. Right?

systemd destroys your network connection:

For reasons I hope I don't need to understand the problem happens because systemd-networkd tries to get an IP address via DHCP (possibly changing the IP address of the target on the specific network interface, which happends to be eth.network in my case). It releases the current IP address to get a new one, which is not such a great idea if the rootfs is mounted over NFS.

One possible solution:

What we can try to do is tell systemd-networkd only to release the IP address if the string "nfsroot" does not appear on the "KernelCommandLine".

Since our kernel command line looks like this:

root@multi-v7-ml:/# cat /proc/cmdline 
console=ttymxc1,115200n8 ip=192.168.42.11:192.168.42.1:192.168.42.254:255.255.255.0:imx6q-phytec-mira-rdk-nand:eth0:off nfsroot=192.168.42.1:/opt/poky/mira-rootfs,v3,tcp noinitrd nohlt panic=1 earlyprintk=ttymxc1,115200n8
root@multi-v7-ml:/# 

We have good chances that this might work.

As a quick hack I found something on the Internet, which did not quite work out of the box, but was a good starting point. It tells systemd via a bbappend to install also the packages networkd and resolved, which is fine.

But it also tries to install custom en.network, eth.network and wlan.network files via a systemd-conf bbappend.

This does not quite work since systemd already installs eth.network, unfortunately without the fix we need.

So we just use good old trusty sed in a recipe and hack eth.network by adding the line we want after the line with the following content: "Name=eth*".

sed -i '/Name=eth*/a KernelCommandLine=!nfsroot' ${D}${sysconfdir}/systemd/network/eth.network

Another flaw might be a similar issue with wlan.network possibly colliding with another layer, which tries to install it as well. Do we really want to boot over nfs via a wireless network?

Here is my systemd bbappend file. Here the systemd-conf bbappend.

Conclusion

Apparently not booting with a rootfs over NFS with systemd is a "known issue" and here is one solution to fix it. With this fix I'm happily booting various boards over (wired network) NFS. Feel free to utilize my layer by grabbing it from here and let please me know if you come up with a better solution.

Comments

Popular posts from this blog

Yocto: BitBake and Dependencies - e.g. One recipe to use output of another recipe

Yocto: kernel modules not showing up in the rootfs

Compiler tunes benchmarks with the Yocto Project