Debugging Firmware Logs on Raspberry Pi 4 via Serial Port

Third Season Running Flagship Video Course: ARM64 Architecture and Programming Launched on October 1, 2020Led by Ben, with hands-on practice and numerous experiments waiting for you!

Firmware on Raspberry Pi 4

Debugging Firmware Logs on Raspberry Pi 4 via Serial Port

Those who have played with Raspberry Pi know that there are several firmware files that need to be copied to the MicroSD card. These firmware files include the following:

  1. bootcode.bin: Bootloader. When the Raspberry Pi is powered on, the CPU is in a reset state, and the GPU is responsible for starting the system. The GPU first runs the firmware (BootROM code) stored inside the chip, reads the bootcode.bin file from the MicroSD card, and loads and runs the bootloader in bootcode.bin. The bootloader for Raspberry Pi 4B is already embedded in the SPI Boot EEPROM.

  2. start4.elf: GPU firmware on Raspberry Pi 4. The bootcode.bin bootloader retrieves the GPU firmware from the MicroSD card, loads the firmware, and starts the GPU.

  3. start.elf: GPU firmware on Raspberry Pi 3.

  4. config.txt: Configuration file. After the GPU starts, it reads the configuration file config.txt, reads the Linux kernel image (such as kernel8.img, etc.) and kernel running parameters, then loads the kernel image into shared memory and starts the CPU, which exits the reset state and begins running the Linux kernel.

The official Raspberry Pi documentation mentions that setting uart_2ndstage to 1 in the config.txt configuration file will enable the second-stage loader (start4.elf firmware) to print debug log information to the serial port.

uart_2ndstage
Setting uart_2ndstage=1 causes the second-stage loader
 (bootcode.bin on devices prior to the Raspberry Pi 4,
 or the boot code in the EEPROM for Raspberry Pi 4 devices)
 and the main firmware (start*.elf) to output diagnostic
 information to UART0.

We tried setting uart_2ndstage to 1 in the config.txt configuration file, but start4 still only prints one line and does not output the debug log.

Starting start4.elf

After this line is printed, there is a pause of several seconds before the Linux kernel logs appear. Therefore, to facilitate debugging of BenOS, we need to find a way to print the debug log of start4.elf to the serial port.

Enable Debug Logs for start.elf

We learned from the Raspberry Pi official website that the SPI BootRom firmware released on August 20, 2020, supports this feature, and it also requires the latest start4.elf firmware, released on September 3, 2020. Next, we will guide you on how to update the firmware on Raspberry Pi 4.

  1. Download the latest Raspberry Pi OS; it must be Raspberry Pi OS, not a third-party Raspberry Pi OS, such as Ubuntu for Raspberry Pi. Domestic users can download it from Tsinghua University mirror.

https://mirrors.tuna.tsinghua.edu.cn/raspberry-pi-os-images/raspios_arm64/images/raspios_arm64-2020-08-24/

After downloading, use a burning tool to write the image to the MicroSD card. On Windows, you can use Win32DiskImager software for burning, and on Linux, you can use the dd command.

  1. Edit the config.txt configuration file in the boot partition of the MicroSD card, adding two lines to this file.

uart_2ndstage=1
enable_uart=1
  1. Insert the MicroSD card back into Raspberry Pi 4 and power it on.

  2. Configure the Wi-Fi on Raspberry Pi 4. You can use the configuration tool on the Raspberry Pi.

$ sudo raspi-config

Select “Network Options” to configure the Wi-Fi password and other settings.

Debugging Firmware Logs on Raspberry Pi 4 via Serial Port

  1. Update the software packages. The SPI BootRom firmware on Raspberry Pi 4 is in the rpi-eeprom package, and the second-stage firmware start4.elf is in the raspberrypi-bootloader package. After updating these two packages, the latest BootRom firmware will be automatically written to the SPI EEPROM, and start4.elf will be updated to the boot partition of the MicroSD. It’s best to update all system packages.

sudo apt update
sudo apt full-upgrade
sudo reboot

After the update is complete, we reboot the machine. We can see the long-awaited debug logs for start4.elf.

Starting start4.elf @ 0xfec00200 partition 0

MESS:00:00:05.630001:0: arasan: arasan_emmc_open
MESS:00:00:05.803154:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:05.806352:0: brfs: File read: 1789 bytes
MESS:00:00:05.834684:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:05.843900:0: brfs: File read: 1789 bytes
MESS:00:00:06.325273:0: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
MESS:00:00:06.332523:0: *** Restart logging
MESS:00:00:06.337819:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
MESS:00:00:06.347118:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
MESS:00:00:06.353048:0: HDMI0: hdmi_pixel_encoding: 300000000
MESS:00:00:06.358516:0: HDMI1: hdmi_pixel_encoding: 300000000
MESS:00:00:06.368733:0: dtb_file 'bcm2711-rpi-4-b.dtb'
MESS:00:00:06.377978:0: brfs: File read: /mfs/sd/bcm2711-rpi-4-b.dtb
MESS:00:00:06.381224:0: Loading 'bcm2711-rpi-4-b.dtb' to 0x100 size 0xb96f
MESS:00:00:06.400028:0: brfs: File read: 47471 bytes
MESS:00:00:06.414733:0: brfs: File read: /mfs/sd/overlays/overlay_map.dtb
MESS:00:00:06.472806:0: brfs: File read: 1423 bytes
MESS:00:00:06.477908:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:06.480832:0: dtparam: audio=on
MESS:00:00:06.493443:0: brfs: File read: 1789 bytes
MESS:00:00:06.509298:0: brfs: File read: /mfs/sd/overlays/vc4-fkms-v3d.dtbo
MESS:00:00:06.529750:0: Loaded overlay 'vc4-fkms-v3d'
MESS:00:00:06.574805:0: brfs: File read: 1238 bytes
MESS:00:00:06.579822:0: brfs: File read: /mfs/sd/cmdline.txt
MESS:00:00:06.582401:0: Read command line from file 'cmdline.txt':
MESS:00:00:06.588273:0: 'console=serial0,115200 console=tty1 root=PARTUUID=2b2231e3-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait plymouth.ignore-serial-consoles'
MESS:00:00:07.648530:0: brfs: File read: 153 bytes
MESS:00:00:08.864766:0: brfs: File read: /mfs/sd/kernel8.img
MESS:00:00:08.867324:0: Loading 'kernel8.img' to 0x80000 size 0xec4200
MESS:00:00:08.873585:0: Device tree loaded to 0x2eff4100 (size 0xbead)
MESS:00:00:08.880030:0: uart: Set PL011 baud rate to 103448.300000 Hz
MESS:00:00:08.888893:0: uart: Baud rate change done...
MESS:00:00:08.890915:0:[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]
[    0.000000] Linux version 5.4.51-v8+ (dom@buildbot) (gcc version 5.4.0 20160609 (Ubuntu/Linaro 5.4.0-6ubuntu1~16.04.9)) #1333 SMP PREEMPT Mon Aug 10 16:58:35 BST 2020
[    0.000000] Machine model: Raspberry Pi 4 Model B Rev 1.2

Above is the log for booting the Linux kernel. Next, we will copy the bin file of the BenOS experimental code to the MicroSD card.

Starting start4.elf @ 0xfec00200 partition 0

MESS:00:00:05.264585:0: arasan: arasan_emmc_open
MESS:00:00:05.421982:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:05.424859:0: brfs: File read: 493 bytes
MESS:00:00:05.453548:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:05.462417:0: brfs: File read: 493 bytes
MESS:00:00:05.943690:0: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
MESS:00:00:05.950942:0: *** Restart logging
MESS:00:00:05.956330:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
MESS:00:00:05.965627:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
MESS:00:00:05.971561:0: HDMI0: hdmi_pixel_encoding: 300000000
MESS:00:00:05.977028:0: HDMI1: hdmi_pixel_encoding: 300000000
MESS:00:00:05.987254:0: dtb_file 'bcm2711-rpi-4-b.dtb'
MESS:00:00:05.997023:0: brfs: File read: /mfs/sd/bcm2711-rpi-4-b.dtb
MESS:00:00:06.000269:0: Loading 'bcm2711-rpi-4-b.dtb' to 0x100 size 0xb96f
MESS:00:00:06.019176:0: brfs: File read: 47471 bytes
MESS:00:00:06.110001:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:06.118301:0: brfs: File read: 493 bytes
MESS:00:00:06.122231:0: brfs: File read: /mfs/sd/cmdline.txt
MESS:00:00:06.125361:0: Read command line from file 'cmdline.txt':
MESS:00:00:06.131256:0: 'logdev=ttyS1'
MESS:00:00:07.167549:0: brfs: File read: 13 bytes
MESS:00:00:07.179048:0: brfs: File read: /mfs/sd/benos4.bin
MESS:00:00:07.181512:0: Loading 'benos4.bin' to 0x80000 size 0x4b30
MESS:00:00:07.187507:0: Device tree loaded to 0x2eff4200 (size 0xbd33)
MESS:00:00:07.193841:0: uart: Set PL011 baud rate to 103448.300000 Hz
MESS:00:00:07.202824:0: uart: Baud rate change done...
Booting at EL2
              Booting at EL1
                            Welcome BenOS!
printk init done
<0x800880> func_c
BenOS image layout:
  .text.boot: 0x00080000 - 0x000800d8 (   216 B)
       .text: 0x000800d8 - 0x00083ad8 ( 14848 B)
     .rodata: 0x00083ad8 - 0x000842fe (  2086 B)
       .data: 0x000842fe - 0x000846d0 (   978 B)
        .bss: 0x00084b30 - 0x000a4f40 (132112 B)
test and: p=0x2
test or: p=0x3
test andnot: p=0x1
el = 1
test_asm_goto: a = 1
Bad mode for Sync Abort handler detected, far:0x80002 esr:0x96000061 - DABT (current EL)
ESR info:
  ESR = 0x96000061
  Exception class = DABT (current EL), IL = 32 bits
  Data abort:
  SET = 0, FnV = 0
  EA = 0, S1PTW = 0
  CM = 0, WnR = 1
  DFSC = Alignment fault

Above is the log for booting BenOS, where the following logs are helpful for our debugging.

MESS:00:00:07.179048:0: brfs: File read: /mfs/sd/benos4.bin
MESS:00:00:07.181512:0: Loading 'benos4.bin' to 0x80000 size 0x4b30
MESS:00:00:07.187507:0: Device tree loaded to 0x2eff4200 (size 0xbd33)

The logs above tell us that the firmware read the benos4.bin from the SD card, where benos4.bin is the binary file of BenOS we wrote, and it was loaded to address 0x80000. This information is very helpful for debugging BenOS.

Third Season Flagship Video Course: ARM64 Architecture and Programming, launched on October 1, 2020.

Debugging Firmware Logs on Raspberry Pi 4 via Serial Port

Launch Address:

Taobao Store: shop115683645.taobao.com

Preview of the Third Season Video:

https://space.bilibili.com/277836343/channel/detail?cid=149997

Leave a Comment