DEVHIDE
Login Or Sign up

Yocto init hangs on Banana Pi: How to debug?

151 Views Asked by At

in Yocto (branch mickledore for poky and all layers) I build core-image-minimal for MACHINE ?= "bananapi-m2-zero". I flashed it to a µSD card and it starts but then it hangs somewhere in runlevel 5. My questions:

  1. Whats's the best debug strategy I should follow?
  2. What's the best way to make inittab to spawn nothing but a serial console (so that I hopefully get a working starting point and can activate other scripts later on one by one.)
  3. How can I determine, whether an initscript hangs or something else prevents logging in? (When I take the SD card the kernel prints complains, so it seems to be running.)

I'm using following layers:

BBLAYERS ?= " \
  /home/magnus/poky/meta \
  /home/magnus/poky/meta-poky \
  /home/magnus/poky/meta-yocto-bsp \
  /home/magnus/poky/meta-openembedded/meta-oe \
  /home/magnus/poky/meta-openembedded/meta-python \
  /home/magnus/poky/meta-sunxi \
  "

Boot ends with following lines, even when waiting 30 min nothing new appears:

[    4.571532] udevd[130]: starting eudev-3.2.11
[    5.077202] EXT4-fs (mmcblk0p2): re-mounted. Quota mode: disabled.
INIT: Entering runlevel: 5
Configuring network interfaces... ip: SIOCGIFFLAGS: No such device
Starting syslogd/klogd: done

Complete boot process:

U-Boot SPL 2023.01-g62e2ad1 (Jan 09 2023 - 16:07:33 +0000)
DRAM: 512 MiB
Trying to boot from MMC1


U-Boot 2023.01-g62e2ad1 (Jan 09 2023 - 16:07:33 +0000) Allwinner Technology

CPU:   Allwinner H3 (SUN8I 1680)
Model: Banana Pi BPI-M2-Zero
DRAM:  512 MiB
Core:  60 devices, 17 uclasses, devicetree: separate
WDT:   Not starting watchdog@1c20ca0
MMC:   mmc@1c0f000: 0, mmc@1c10000: 1
Loading Environment from FAT... Unable to read "uboot.env" from mmc0:1... 
In:    serial
Out:   serial
Err:   serial
Net:   No ethernet found.
Hit any key to stop autoboot:  0 
switch to partitions #0, OK
mmc0 is current device
Scanning mmc 0:1...
Found U-Boot script /boot.scr
714 bytes read in 1 ms (697.3 KiB/s)
## Executing script at 43100000
25365 bytes read in 3 ms (8.1 MiB/s)
Failed to load 'zImage'
Failed to load 'boot/zImage'
5175240 bytes read in 216 ms (22.8 MiB/s)
zimage: Bad magic!
## Booting kernel from Legacy Image at 42000000 ...
   Image Name:   Linux-6.1.9
   Image Type:   ARM Linux Kernel Image (uncompressed)
   Data Size:    5175176 Bytes = 4.9 MiB
   Load Address: 40008000
   Entry Point:  40008000
   Verifying Checksum ... OK
## Flattened Device Tree blob at 43000000
   Booting using the fdt blob at 0x43000000
Working FDT set to 43000000
   Loading Kernel Image
   Loading Device Tree to 49ff6000, end 49fff314 ... OK
Working FDT set to 49ff6000

Starting kernel ...

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 6.1.9 (oe-user@oe-host) (arm-poky-linux-gnueabi-gcc (GCC) 12.3.0, GNU ld (GNU Binutils) 2.40.0.20230703) #1 SMP Wed Feb  1 07:38:58 UTC 2023
[    0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: Banana Pi BPI-M2-Zero
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000040000000-0x000000005fffffff]
[    0.000000]   HighMem  empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000040000000-0x000000005fffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000005fffffff]
[    0.000000] psci: probing for conduit method from DT.
[    0.000000] psci: Using PSCI v0.1 Function IDs from DT
[    0.000000] percpu: Embedded 12 pages/cpu s18260 r8192 d22700 u49152
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 130048
[    0.000000] Kernel command line: console=ttyS0,115200 console=tty1 root=/dev/mmcblk0p2 rootwait panic=10
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes, linear)
[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off
[    0.000000] Memory: 507088K/524288K available (8192K kernel code, 835K rwdata, 1720K rodata, 1024K init, 284K bss, 17200K reserved, 0K cma-reserved, 0K 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 restricting CPUs from NR_CPUS=8 to nr_cpu_ids=4.
[    0.000000]  Tracing variant of Tasks RCU enabled.
[    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] GIC: Using split EOI/Deactivate mode
[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.
[    0.000000] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns
[    0.000000] arch_timer: cp15 timer(s) running at 24.00MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x588fe9dc0, max_idle_ns: 440795202592 ns
[    0.000002] sched_clock: 56 bits at 24MHz, resolution 41ns, wraps every 4398046511097ns
[    0.000015] Switching to timer-based delay loop, resolution 41ns
[    0.000332] Console: colour dummy device 80x30
[    0.000730] printk: console [tty1] enabled
[    0.000792] Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=240000)
[    0.000828] pid_max: default: 32768 minimum: 301
[    0.001044] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.001083] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.001871] CPU: Testing write buffer coherency: ok
[    0.002363] /cpus/cpu@0 missing clock-frequency property
[    0.002415] /cpus/cpu@1 missing clock-frequency property
[    0.002445] /cpus/cpu@2 missing clock-frequency property
[    0.002474] /cpus/cpu@3 missing clock-frequency property
[    0.002497] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.003408] cblist_init_generic: Setting adjustable number of callback queues.
[    0.003456] cblist_init_generic: Setting shift to 2 and lim to 1.
[    0.003619] Setting up static identity map for 0x40100000 - 0x40100060
[    0.003798] rcu: Hierarchical SRCU implementation.
[    0.003819] rcu:     Max phase no-delay instances is 1000.
[    0.004608] smp: Bringing up secondary CPUs ...
[    0.015726] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.026929] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.038059] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.038159] smp: Brought up 1 node, 4 CPUs
[    0.038232] SMP: Total of 4 processors activated (192.00 BogoMIPS).
[    0.038253] CPU: All CPU(s) started in HYP mode.
[    0.038266] CPU: Virtualization extensions available.
[    0.039037] devtmpfs: initialized
[    0.044431] VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5
[    0.044714] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.044762] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.045068] pinctrl core: initialized pinctrl subsystem
[    0.046606] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.047025] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.047963] thermal_sys: Registered thermal governor 'step_wise'
[    0.048341] cpuidle: using governor menu
[    0.048558] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.048588] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.053126] platform 1c0c000.lcd-controller: Fixing up cyclic dependency with 1100000.mixer
[    0.055984] platform 1ee0000.hdmi: Fixing up cyclic dependency with 1c0c000.lcd-controller
[    0.058879] platform connector: Fixing up cyclic dependency with 1ee0000.hdmi
[    0.067891] cryptd: max_cpu_qlen set to 1000
[    0.069989] SCSI subsystem initialized
[    0.070516] usbcore: registered new interface driver usbfs
[    0.070581] usbcore: registered new interface driver hub
[    0.070635] usbcore: registered new device driver usb
[    0.070740] pps_core: LinuxPPS API ver. 1 registered
[    0.070760] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <[email protected]>
[    0.070797] PTP clock support registered
[    0.072063] clocksource: Switched to clocksource arch_sys_counter
[    0.081011] NET: Registered PF_INET protocol family
[    0.081330] IP idents hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.082871] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear)
[    0.082939] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.082977] TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear)
[    0.083036] TCP bind hash table entries: 4096 (order: 4, 65536 bytes, linear)
[    0.083270] TCP: Hash tables configured (established 4096 bind 4096)
[    0.083415] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.083480] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.083719] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    0.084638] RPC: Registered named UNIX socket transport module.
[    0.084679] RPC: Registered udp transport module.
[    0.084696] RPC: Registered tcp transport module.
[    0.084709] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.086227] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 5 counters available
[    0.087560] Initialise system trusted keyrings
[    0.087842] workingset: timestamp_bits=30 max_order=17 bucket_order=0
[    0.094140] NFS: Registering the id_resolver key type
[    0.094247] Key type id_resolver registered
[    0.094265] Key type id_legacy registered
[    0.094655] Key type asymmetric registered
[    0.094683] Asymmetric key parser 'x509' registered
[    0.094841] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
[    0.094872] io scheduler mq-deadline registered
[    0.094890] io scheduler kyber registered
[    0.158547] Serial: 8250/16550 driver, 8 ports, IRQ sharing disabled
[    0.163501] usbcore: registered new interface driver usb-storage
[    0.164864] ehci-platform 1c1a000.usb: EHCI Host Controller
[    0.164955] ehci-platform 1c1a000.usb: new USB bus registered, assigned bus number 1
[    0.165130] sun6i-rtc 1f00000.rtc: registered as rtc0
[    0.165151] ehci-platform 1c1a000.usb: irq 36, io mem 0x01c1a000
[    0.165224] sun6i-rtc 1f00000.rtc: setting system clock to 2018-03-09T12:37:07 UTC (1520599027)
[    0.165275] ohci-platform 1c1a400.usb: Generic Platform OHCI controller
[    0.165319] ohci-platform 1c1a400.usb: new USB bus registered, assigned bus number 2
[    0.165418] sun6i-rtc 1f00000.rtc: RTC enabled
[    0.165426] ohci-platform 1c1a400.usb: irq 37, io mem 0x01c1a400
[    0.165808] i2c_dev: i2c /dev entries driver
[    0.166713] sunxi-wdt 1c20ca0.watchdog: Watchdog enabled (timeout=16 sec, nowayout=0)
[    0.168080] usbcore: registered new interface driver usbhid
[    0.168111] usbhid: USB HID core driver
[    0.168833] NET: Registered PF_INET6 protocol family
[    0.170307] Segment Routing with IPv6
[    0.170410] In-situ OAM (IOAM) with IPv6
[    0.170503] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    0.171226] NET: Registered PF_PACKET protocol family
[    0.171367] Key type dns_resolver registered
[    0.171481] Registering SWP/SWPB emulation handler
[    0.173841] registered taskstats version 1
[    0.173915] Loading compiled-in X.509 certificates
[    0.179304] sun8i-h3-pinctrl 1c20800.pinctrl: initialized sunXi PIO driver
[    0.180977] sun8i-h3-r-pinctrl 1f02c00.pinctrl: initialized sunXi PIO driver
[    0.181364] sun8i-h3-pinctrl 1c20800.pinctrl: supply vcc-pa not found, using dummy regulator
[    0.182505] printk: console [ttyS0] disabled
[    0.202754] 1c28000.serial: ttyS0 at MMIO 0x1c28000 (irq = 137, base_baud = 1500000) is a U6_16550A
[    0.212090] ehci-platform 1c1a000.usb: USB 2.0 started, EHCI 1.00
[    0.222068] printk: console [ttyS0] enabled
[    0.229957] hub 1-0:1.0: USB hub found
[    0.235915] sun8i-h3-pinctrl 1c20800.pinctrl: supply vcc-pg not found, using dummy regulator
[    0.243118] hub 1-0:1.0: 1 port detected
[    0.269538] 1c28400.serial: ttyS1 at MMIO 0x1c28400 (irq = 138, base_baud = 1500000) is a U6_16550A
[    0.273810] hub 2-0:1.0: USB hub found
[    0.279820] sun8i-h3-r-pinctrl 1f02c00.pinctrl: supply vcc-pl not found, using dummy regulator
[    0.286010] hub 2-0:1.0: 1 port detected
[    0.292076] sun8i-h3-pinctrl 1c20800.pinctrl: supply vcc-pf not found, using dummy regulator
[    0.298163] sunxi-mmc 1c10000.mmc: allocated mmc-pwrseq
[    0.305750] sunxi-mmc 1c0f000.mmc: Got CD GPIO
[    0.334658] sunxi-mmc 1c10000.mmc: initialized, max. request size: 16384 KB
[    0.364676] sunxi-mmc 1c0f000.mmc: initialized, max. request size: 16384 KB
[    1.132599] Waiting for root device /dev/mmcblk0p2...
[    1.176694] mmc0: host does not support reading read-only switch, assuming write-enable
[    1.187343] mmc0: new high speed SDHC card at address 5048
[    1.199561] mmcblk0: mmc0:5048 SD32G 29.7 GiB 
[    1.207840]  mmcblk0: p1 p2
[    1.244964] EXT4-fs (mmcblk0p2): orphan cleanup on readonly fs
[    1.250971] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Quota mode: disabled.
[    1.252497] mmc1: new high speed SDIO card at address 0001
[    1.260028] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.273362] devtmpfs: mounted
[    1.283349] Freeing unused kernel image (initmem) memory: 1024K
[    1.322329] Run /sbin/init as init process
[    1.969760] udevd[129]: starting version 3.2.11
[    4.532065] random: crng init done
[    4.571532] udevd[130]: starting eudev-3.2.11
[    5.077202] EXT4-fs (mmcblk0p2): re-mounted. Quota mode: disabled.
INIT: Entering runlevel: 5
Configuring network interfaces... ip: SIOCGIFFLAGS: No such device
Starting syslogd/klogd: done

What I tried so far: I made logging writing to SD card rather ramdisk, expected new info, but was the same as I already had on serial line. Launched a custom script (detached with &) in an initscript, expected it to run infinitely but got only 4 prints:

while (true)
do
    echo "Hello World"
    usleep 3000
done
yocto init.d inittab
Original Q&A
1

There are 1 best solutions below

0
HappyDonkey On

By instrumenting the init.d scripts with various echo commands and making them more and more verbose (set -v), I came to the feeling that the system itself runs fine but we lose connection suddenly during initialization.

So, I wrote the following test program and deployed it as /sbin/init:

#include <fcntl.h>
#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>

#define TTYCOUNT 5

int main() {
  for (;;) {
    int consoles[TTYCOUNT];
    consoles[0] = open("/dev/tty", O_RDWR);
    consoles[1] = open("/dev/tty0", O_RDWR);
    consoles[2] = open("/dev/tty1", O_RDWR);
    consoles[3] = open("/dev/ttyS0", O_RDWR);
    consoles[4] = open("/dev/ttyS1", O_RDWR);

    for (int i = 0; i < TTYCOUNT; i++) {
      if (consoles[i]) {
        char str[] = "0 Hello world\r\n";
        str[0] += i;
        write(consoles[i], str, 15);
        close(consoles[i]);
      }
    }
    sleep(1);
  }
}

As a compiler, I tried Yocto SDK and arm-linux-gnueabihf-gcc (with -static); both worked fine and, as the result, the system printed "3 Hello world" on serial line. Therefore, I adjusted the getty line in /etc/inittab from 1:12345:respawn:/sbin/getty 38400 tty1 to 1:12345:respawn:/sbin/getty 115200 ttyS0.

I have a working system now where I can login. The next step will be to adjust this in Yocto config.

Related Questions in YOCTO

Related Questions in INIT.D

Related Questions in INITTAB

Trending Questions

Popular # Hahtags

javascript python java c# php android html jquery c++ css ios sql mysql r reactjs

Popular Questions

.

Copyright © 2021 Jogjafile Inc.