RPi-Distro / pi-gen

Tool used to create the official Raspberry Pi OS images
BSD 3-Clause "New" or "Revised" License
2.62k stars 1.64k forks source link

Something known that current generated bullseye image is not starting #608

Closed capiman closed 2 years ago

capiman commented 2 years ago

We have an bullseye image of 29.04. and of 04.04./05.04. We let it run/want to start it on CM4. The image from 29.04. is working without problems. The image from 04.04./05.04. is not working anymore.

On serial debug log I see only:

` [ 1.773982] brcm-pcie fd500000.pcie: link down [ 1.947363] hub 2-0:1.0: config failed, hub doesn't have any ports! (err -19) [ 10.115767] reboot: Restarting system [ 1.773872] brcm-pcie fd500000.pcie: link down [ 1.947361] hub 2-0:1.0: config failed, hub doesn't have any ports! (err -19)

Cannot open access to console, the root account is locked. See sulogin(8) man page for more details.

Press Enter to continue. `

Looks like even kernel is not started at all.

Comparing build logfile I see that e.g. that

Unpacking raspberrypi-bootloader (1:1.20220308-2) ... Selecting previously unselected package raspberrypi-kernel. Preparing to unpack .../raspberrypi-kernel_1%3a1.20220308-2_armhf.deb ...

changed to

Unpacking raspberrypi-bootloader (1:1.20220331-1) ... Selecting previously unselected package raspberrypi-kernel. Preparing to unpack .../raspberrypi-kernel_1%3a1.20220331-1_armhf.deb ...

Has someone seen something similar?

Perhaps something to do with a change from Debian 11.2 to 11.3?

I will test if buster is working in next hours and let you know.

capiman commented 2 years ago

I meanwhile reduced the config.txt to a minimum, but still same problem:

` [cm4]

Enable host mode on the 2711 built-in XHCI USB controller.

This line should be removed if the legacy DWC2 controller is required

(e.g. for USB device mode) or if USB support is not required.

otg_mode=1

[pi4]

Run as fast as firmware / board allows

arm_boost=1

[all]

Enable UART

enable_uart=1 `

I added

uart_2ndstage=1

and got the following output:

` Read start4.elf bytes 2241824 hnd 0x00000000 Read fixup4.dat bytes 5352 hnd 0x00000000 Firmware: e5a963efa66a1974127860b42e913d2374139ff5 Mar 24 2022 13:19:26 0x00b03140 0x00000000 0x00000fff MEM GPU: 76 ARM: 948 TOTAL: 1024 Starting start4.elf @ 0xfec00200 partition 0 +

MESS:00:00:03.011392:0: arasan: arasan_emmc_open MESS:00:00:03.198443:0: brfs: File read: /mfs/sd/config.txt MESS:00:00:03.201258:0: brfs: File read: 328 bytes MESS:00:00:03.255245:0: HDMI0:EDID error reading EDID block 0 attempt 0 MESS:00:00:03.264761:0: HDMI0:EDID error reading EDID block 0 attempt 1 MESS:00:00:03.274268:0: HDMI0:EDID error reading EDID block 0 attempt 2 MESS:00:00:03.283782:0: HDMI0:EDID error reading EDID block 0 attempt 3 MESS:00:00:03.293291:0: HDMI0:EDID error reading EDID block 0 attempt 4 MESS:00:00:03.302805:0: HDMI0:EDID error reading EDID block 0 attempt 5 MESS:00:00:03.312312:0: HDMI0:EDID error reading EDID block 0 attempt 6 MESS:00:00:03.321826:0: HDMI0:EDID error reading EDID block 0 attempt 7 MESS:00:00:03.331336:0: HDMI0:EDID error reading EDID block 0 attempt 8 MESS:00:00:03.340849:0: HDMI0:EDID error reading EDID block 0 attempt 9 MESS:00:00:03.345347:0: HDMI0:EDID giving up on reading EDID block 0 MESS:00:00:03.370800:0: HDMI1:EDID error reading EDID block 0 attempt 0 MESS:00:00:03.380315:0: HDMI1:EDID error reading EDID block 0 attempt 1 MESS:00:00:03.389824:0: HDMI1:EDID error reading EDID block 0 attempt 2 MESS:00:00:03.399337:0: HDMI1:EDID error reading EDID block 0 attempt 3 MESS:00:00:03.408844:0: HDMI1:EDID error reading EDID block 0 attempt 4 MESS:00:00:03.418358:0: HDMI1:EDID error reading EDID block 0 attempt 5 MESS:00:00:03.427867:0: HDMI1:EDID error reading EDID block 0 attempt 6 MESS:00:00:03.437381:0: HDMI1:EDID error reading EDID block 0 attempt 7 MESS:00:00:03.446889:0: HDMI1:EDID error reading EDID block 0 attempt 8 MESS:00:00:03.456404:0: HDMI1:EDID error reading EDID block 0 attempt 9 MESS:00:00:03.460905:0: HDMI1:EDID giving up on reading EDID block 0 MESS:00:00:03.467047:0: brfs: File read: /mfs/sd/config.txt MESS:00:00:03.471588:0: gpioman: gpioman_get_pin_num: pin DISPLAY_SDA not defined MESS:00:00:03.478484:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined MESS:00:00:03.506560:0: gpioman: gpioman_get_pin_num: pin FLASH_0_ENABLE not defined MESS:00:00:03.511192:0: gpioman: gpioman_get_pin_num: pin FLASH_0_INDICATOR not defined MESS:00:00:03.518934:0: gpioman: gpioman_get_pin_num: pin FLASH_0_ENABLE not defined MESS:00:00:03.526383:0: gpioman: gpioman_get_pin_num: pin FLASH_0_INDICATOR not defined MESS:00:00:04.022234:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined MESS:00:00:04.027873:0: *** Restart logging MESS:00:00:04.030516:0: brfs: File read: 328 bytes MESS:00:00:04.040513:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 0 MESS:00:00:04.050548:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 1 MESS:00:00:04.060586:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 2 MESS:00:00:04.070616:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 3 MESS:00:00:04.080654:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 4 MESS:00:00:04.090687:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 5 MESS:00:00:04.100724:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 6 MESS:00:00:04.110755:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 7 MESS:00:00:04.120792:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 8 MESS:00:00:04.130824:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 9 MESS:00:00:04.135853:0: hdmi: HDMI0:EDID giving up on reading EDID block 0 MESS:00:00:04.146478:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 0 MESS:00:00:04.156510:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 1 MESS:00:00:04.166547:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 2 MESS:00:00:04.176578:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 3 MESS:00:00:04.186615:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 4 MESS:00:00:04.196647:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 5 MESS:00:00:04.206684:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 6 MESS:00:00:04.216714:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 7 MESS:00:00:04.226752:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 8 MESS:00:00:04.236785:0: hdmi: HDMI0:EDID error reading EDID block 0 attempt 9 MESS:00:00:04.241813:0: hdmi: HDMI0:EDID giving up on reading EDID block 0 MESS:00:00:04.247412:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead MESS:00:00:04.261202:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 0 MESS:00:00:04.271242:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 1 MESS:00:00:04.281275:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 2 MESS:00:00:04.291312:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 3 MESS:00:00:04.301342:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 4 MESS:00:00:04.311379:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 5 MESS:00:00:04.321411:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 6 MESS:00:00:04.331449:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 7 MESS:00:00:04.341478:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 8 MESS:00:00:04.351517:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 9 MESS:00:00:04.356540:0: hdmi: HDMI1:EDID giving up on reading EDID block 0 MESS:00:00:04.367163:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 0 MESS:00:00:04.377201:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 1 MESS:00:00:04.387233:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 2 MESS:00:00:04.397270:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 3 MESS:00:00:04.407300:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 4 MESS:00:00:04.417337:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 5 MESS:00:00:04.427369:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 6 MESS:00:00:04.437407:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 7 MESS:00:00:04.447436:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 8 MESS:00:00:04.457474:0: hdmi: HDMI1:EDID error reading EDID block 0 attempt 9 MESS:00:00:04.462497:0: hdmi: HDMI1:EDID giving up on reading EDID block 0 MESS:00:00:04.468095:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead MESS:00:00:04.476860:0: HDMI0: hdmi_pixel_encoding: 300000000 MESS:00:00:04.482332:0: HDMI1: hdmi_pixel_encoding: 300000000 MESS:00:00:04.488270:0: gpioman: gpioman_get_pin_num: pin CAMERA_0_I2C_PORT not defined MESS:00:00:04.499790:0: dtb_file 'bcm2711-rpi-cm4.dtb' MESS:00:00:04.507352:0: brfs: File read: /mfs/sd/bcm2711-rpi-cm4.dtb MESS:00:00:04.510600:0: Loading 'bcm2711-rpi-cm4.dtb' to 0x100 size 0xcbcc MESS:00:00:04.530265:0: brfs: File read: 52172 bytes MESS:00:00:04.539530:0: brfs: File read: /mfs/sd/overlays/overlay_map.dtb MESS:00:00:04.615064:0: brfs: File read: 1783 bytes MESS:00:00:04.618237:0: brfs: File read: /mfs/sd/config.txt MESS:00:00:04.640048:0: brfs: File read: 328 bytes MESS:00:00:04.642286:0: brfs: File read: /mfs/sd/cmdline.txt MESS:00:00:04.647145:0: Read command line from file 'cmdline.txt': MESS:00:00:04.653010:0: 'console=serial0,115200 console=tty1 root=PARTUUID=d4e0c687-02 rootfstype=ext4 fsck.repair=yes rootwait quiet cgroup_enable=cpuset cgroup_enable=memory cgroup_memory=1 swapaccount=1' MESS:00:00:04.766643:0: brfs: File read: 181 bytes MESS:00:00:05.399449:0: brfs: File read: /mfs/sd/kernel7l.img MESS:00:00:05.402088:0: Loading 'kernel7l.img' to 0x8000 size 0x6af760 MESS:00:00:05.408345:0: Device tree loaded to 0x2eff2e00 (size 0xd1c9) MESS:00:00:05.416304:0: uart: Set PL011 baud rate to 103448.300000 Hz MESS:00:00:05.423656:0: uart: Baud rate change done... MESS:00:00:05.425678:0:[ 1.732187] brcm-pcie fd500000.pcie: link down [ 1.732801] bcm2708_fb soc:fb: Unable to determine number of FBs. Disabling driver. [ 1.905448] hub 2-0:1.0: config failed, hub doesn't have any ports! (err -19)

Cannot open access to console, the root account is locked. See sulogin(8) man page for more details.

Press Enter to continue.

`

The lines

MESS:00:00:05.416304:0: uart: Set PL011 baud rate to 103448.300000 Hz MESS:00:00:05.423656:0: uart: Baud rate change done... MESS:00:00:05.425678:0:[ 1.732187] brcm-pcie fd500000.pcie: link down [ 1.732801] bcm2708_fb soc:fb: Unable to determine number of FBs.

look like it is aborting some functionality or silently crashing...?

In command line I had

console=serial0,115200 console=tty1 ...

But removing these 2 console entries does not change behaviour.

Any idea what it could be?

XECDesign commented 2 years ago

I'm not really following the issue. I don't know how the image is set up or what the expected behaviour is. You said the kernel doesn't start, but you've posted output from the kernel. I'm not seeing evidence of a crash or anything specific not working there.

capiman commented 2 years ago

It looks like our adapted init=xxx sequence makes the problem. When we skip init=xxx then it boots. Perhaps there were changes in this area from 28.03. to 04.04.? Can I somehow see more debug output from this area if something fails? Can I somehow see which file are included in initramfs and if it changes? Is https://github.com/raspberrypi/linux the right place to see/find such info?

XECDesign commented 2 years ago

Hmm. You could extract the initramfs file and compare the content that way. Are you using one though? I'm not seeing one being loaded in the output you've posted.

What is meant to happen? Is it meant to auto-login as root? Are your changes public anywhere?

In general the github issue trackers are for specific issues and the forum is for general tech support. Since it doesn't looks like there's a problem with pi-gen or the linux kernel, the forum is probably the best place.

capiman commented 2 years ago

Can you tell me, where to find initramfs file in pi-gen/Raspberry Pi environment? I don't find an init. file in /boot. Is it contained in kernel? Or as part of RootFs?

XECDesign commented 2 years ago

We don't use initramfs for the official Raspberry Pi OS images. Everything loads directly from the root partition.

capiman commented 2 years ago

Perhaps my wording is not correct. I am talking about

/usr/lib/raspi-config/init_resize.sh

which is called via cmdline

init=/usr/lib/raspi-config/init_resize.sh

We are doing something similar, which now makes problems on bullseye since end of March. We are installing our own partition with certain size.

XECDesign commented 2 years ago

Ah, got it. The init= option specifies that instead of running systemd, you want to run a custom script instead. initramfs, on the other hand, is a minimal rootfs loaded into memory that linux sees first. initramfs can be used to do things like repair filesystems, load modules not compiled into the kernel and so on, before switching to the real rootfs.

I can't think of anything specific that might have changed that would break things. Without knowing what your script looks like, it's hard to tell what might be happening.

capiman commented 2 years ago

Further comparing the two images, I saw that debian was changed from 12.2 to 12.3

One of the changes is:

Demote systemd-timesyncd from Depends to Recommends. This avoids a dependency cycle between systemd and systemd-timesyncd and thus makes dist upgrades more predictable and robust. It also allows minimal, systemd based containers where no NTP client is strictly necessary. To ensure that systemd-timesyncd is installed in a default installation created by d-i, bump its priority to standard. (Closes: #986651, #993947)

We do

sed -i /lib/systemd/system/systemd-timesyncd.service -e 's/PrivateDevices=yes/PrivateDevices=no/;s/PrivateTmp=yes/PrivateTmp=no/'

in our resize script.

So it could be that this line fails, script execution is not removed from cmdline and called again on next start, where it fails again.

XECDesign commented 2 years ago

Yeah I think you've figured it out.

That should've been fixed by https://github.com/RPi-Distro/pi-gen/commit/226b479f8d32919c9fe36dd5b4c20c02682f8180

If you rebuild from with that commit included, it should hopefully work for you again.