Fork us on GitHub Follow us on Facebook Follow us on Twitter

Opened 6 months ago

Closed 6 months ago

#827 closed defect (fixed)

Boot on Raspberry Pi ends prematurely when accessing ramdisk

Reported by: Jakub Jermář Owned by: Martin Decky
Priority: major Milestone: 0.11.1
Component: helenos-build Version: mainline
Keywords: Cc:
Blocker for: Depends on:
See also:

Description

As of current master, the boot on Raspberry Pi ends prematurely as follows. Seems like it cannot access files on the ramdisk. This happens both during a u-boot boot and a direct boot from the SD card.

U-Boot> loady
## Ready for binary (ymodem) download to 0x00200000 at 115200 bps...                                                                                          
CCX)/0(CAN) packets, 29 retries
## Total Size      = 0x001a2d78 = 1715576 Bytes
U-Boot> bootm
## Booting kernel from Legacy Image at 00200000 ...
   Image Name:   HelenOS-0.9.1
   Image Type:   ARM Linux Kernel Image (uncompressed)
   Data Size:    1715512 Bytes = 1.6 MiB
   Load Address: 00008000
   Entry Point:  00008000
   Verifying Checksum ... OK
   Loading Kernel Image ... OK

Starting kernel ...

HelenOS bootloader, release 0.9.1 (Armonia), revision b27553c1c
Built on 2021-03-22 17:56:58 for arm32
Copyright (c) 2001-2019 HelenOS project
Boot loader: 0x00008000 -> 0x00015d38

Memory statistics
 0x00015000|0x00015000: bootstrap stack
 0x00010000|0x00010000: bootstrap page table
 0x00015830|0x00015830: boot info structure
 0x80a08000|0x00a08000: kernel entry point
Boot loader: 0x00008000 -> 0x00015d38
Payload: 0x00015d38 -> 0x001aad38
Kernel load address: 0x00a08000
Kernel start: 0x80a08000
RAM end: 0x01a08000 (16777216 bytes available)

Inflating components ... 
 0x80a08000|0x00a08000: kernel.elf.gz image (494232/148931 bytes)
 0x80a81000|0x00a81000: ns.gz image (110780/51462 bytes)
 0x80a9d000|0x00a9d000: loader.gz image (117256/54739 bytes)
 0x80aba000|0x00aba000: init.gz image (139776/64299 bytes)
 0x80add000|0x00add000: locsrv.gz image (125980/59087 bytes)
 0x80afc000|0x00afc000: rd.gz image (117128/54449 bytes)
 0x80b19000|0x00b19000: vfs.gz image (141556/65105 bytes)
 0x80b3c000|0x00b3c000: logger.gz image (123456/57180 bytes)
 0x80b5b000|0x00b5b000: fat.gz image (187236/87807 bytes)
 0x80b89000|0x00b89000: initrd.img.gz image (4024832/999618 bytes)
Done.
Booting the kernel...
SPARTAN kernel, release 0.9.1 (Armonia), revision b27553c1c
Built on 2021-03-22 17:56:58 for arm32
Copyright (c) 2001-2019 HelenOS project
Detected 1 CPU(s), 196576 KiB free memory
Program loader at 0xc0020000
Kernel console ready (press any key to activate)
RAM disk at 0x00b89000 (size 4024832 bytes)
[init:ns(2)] ns: HelenOS IPC Naming Service
[init:ns(2)] ns: Accepting connections
[init:init(3)] init: HelenOS init
[init:locsrv(4)] loc: HelenOS Location Service
[init:rd(5)] rd: HelenOS RAM disk server
[init:rd(5)] rd: Found RAM disk at 0x00b89000, 4024832 bytes
[init:vfs(6)] vfs: HelenOS VFS server
[init:logger(7)] logger: HelenOS Logging Service
[init:fat(8)] fat: HelenOS FAT file system server
[init:logger(7)] logger: Accepting connections
[init:locsrv(4)] loc: Accepting connections
[init:rd(5)] rd: Accepting connections
[init:vfs(6)] vfs: Accepting connections
[init:fat(8)] fat: Accepting connections
[init:init(3)] init: Root file system mounted on / (fat at bd/initrd)
[init:init(3)] init: Unable to stat /srv/fs/tmpfs
[init:init(3)] init: Unable to stat /srv/fs/exfat
[init:init(3)] init: Unable to stat /srv/fs/cdfs
[init:init(3)] init: Unable to stat /srv/fs/mfs
[init:init(3)] init: Starting /srv/klog
[init:init(3)] init: Error spawning /srv/klog ([EINVAL] Invalid value)
[init:init(3)] init: Starting /srv/fs/locfs
[init:init(3)] init: Error spawning /srv/fs/locfs ([EINVAL] Invalid value)
[init:init(3)] init: Unable to stat /srv/taskmon

Change History (5)

comment:1 Changed 6 months ago by Jakub Jermář

It turns out that his problem shows already with 0.9.1 when built with the current toolchain (but not in the released 0.9.1). On the current master the problem goes away for a static build. With RTLD_DEBUG enabled, I get the following boot:

HelenOS bootloader, release 0.9.1 (Armonia), revision b27553c1c
Built on 2021-03-22 22:17:30 for arm32
Copyright (c) 2001-2019 HelenOS project
Boot loader: 0x00008000 -> 0x00015d38

Memory statistics
 0x00015000|0x00015000: bootstrap stack
 0x00010000|0x00010000: bootstrap page table
 0x00015830|0x00015830: boot info structure
 0x80a08000|0x00a08000: kernel entry point
Boot loader: 0x00008000 -> 0x00015d38
Payload: 0x00015d38 -> 0x0016ed38
Kernel load address: 0x00a08000
Kernel start: 0x80a08000
RAM end: 0x01a08000 (16777216 bytes available)

Inflating components ... 
 0x80a08000|0x00a08000: kernel.elf.gz image (415344/122432 bytes)
 0x80a6e000|0x00a6e000: ns.gz image (77528/39458 bytes)
 0x80a81000|0x00a81000: loader.gz image (84992/43473 bytes)
 0x80a96000|0x00a96000: init.gz image (102604/51212 bytes)
 0x80ab0000|0x00ab0000: locsrv.gz image (91936/46979 bytes)
 0x80ac7000|0x00ac7000: rd.gz image (83752/42527 bytes)
 0x80adc000|0x00adc000: vfs.gz image (103600/51794 bytes)
 0x80af6000|0x00af6000: logger.gz image (89224/45052 bytes)
 0x80b0c000|0x00b0c000: fat.gz image (145984/73230 bytes)
 0x80b30000|0x00b30000: initrd.img.gz image (3661312/887287 bytes)
Done.
Booting the kernel...
SPARTAN kernel, release 0.9.1 (Armonia), revision b27553c1c
Built on 2021-03-22 22:17:30 for arm32
Copyright (c) 2001-2019 HelenOS project
Detected 1 CPU(s), 458720 KiB free memory
Program loader at 0xc0017000
RAM disk at 0x00b30000 (size 3661312 bytes)
Kernel console ready (press any key to activate)
[init:ns(2)] ns: HelenOS IPC Naming Service
[init:ns(2)] ns: Accepting connections
[init:init(3)] init: HelenOS init
[init:locsrv(4)] loc: HelenOS Location Service
[init:rd(5)] rd: HelenOS RAM disk server
[init:rd(5)] rd: Found RAM disk at 0x00b30000, 3661312 bytes
[init:vfs(6)] vfs: HelenOS VFS server
[init:logger(7)] logger: HelenOS Logging Service
[init:fat(8)] fat: HelenOS FAT file system server
[init:logger(7)] logger: Accepting connections
[init:locsrv(4)] loc: Accepting connections
[init:vfs(6)] vfs: Accepting connections
[init:rd(5)] rd: Accepting connections
[init:fat(8)] fat: Accepting connections
[init:init(3)] init: Root file system mounted on / (fat at bd/initrd)
[init:init(3)] init: Unable to stat /srv/fs/tmpfs
[init:init(3)] init: Unable to stat /srv/fs/exfat
[init:init(3)] init: Unable to stat /srv/fs/cdfs
[init:init(3)] init: Unable to stat /srv/fs/mfs
[init:init(3)] init: Starting /srv/klog
[loader(9)] Load dynamically linked program.
[loader(9)] Parse program .dynamic section at 0x00101b24
[loader(9)] memset
[loader(9)] pass 1
[loader(9)] tag=1 ptr=0x1 val=1
[loader(9)] tag=15 ptr=0x143 val=323
[loader(9)] tag=4 ptr=0x100094 val=1048724
[loader(9)] tag=5 ptr=0x1002d4 val=1049300
[loader(9)] tag=6 ptr=0x100144 val=1048900
[loader(9)] tag=10 ptr=0x14f val=335
[loader(9)] tag=11 ptr=0x10 val=16
[loader(9)] tag=21 ptr=0x0 val=0
[loader(9)] tag=3 ptr=0x101bcc val=1055692
[loader(9)] tag=2 ptr=0xa8 val=168
[loader(9)] tag=20 ptr=0x11 val=17
[loader(9)] tag=23 ptr=0x10043c val=1049660
[loader(9)] tag=17 ptr=0x100424 val=1049636
[loader(9)] tag=18 ptr=0x18 val=24
[loader(9)] tag=19 ptr=0x8 val=8
[loader(9)] str_tab=0x1002d4, soname_idx=0x0, soname=0x1002d4
[loader(9)] soname=''
[loader(9)] rpath='$ORIGIN/lib'
[loader(9)] hash=0x100094
[loader(9)] dt_rela=0x0
[loader(9)] dt_rela_sz=0x0
[loader(9)] dt_rel=0x100424
[loader(9)] dt_rel_sz=0x18
[loader(9)] pass 2
[loader(9)] needed:'libc.so.0'
[loader(9)] prog tdata at 0x00000000 size 0, tbss size 0
[loader(9)] Load all program dependencies
[loader(9)] module_load_deps('[program]')
[loader(9)] [program] needs libc.so.0
[loader(9)] module_find('libc.so.0')
[loader(9)] m = 0x70134140
[loader(9)] filename:'/lib/libc.so.0'
[loader(9)] Failed to load '/lib/libc.so.0'
[init:init(3)] init: Error spawning /srv/klog ([EINVAL] Invalid value)
[init:init(3)] init: Starting /srv/fs/locfs
[loader(10)] Load dynamically linked program.
[loader(10)] Parse program .dynamic section at 0x00103f8c
[loader(10)] memset
[loader(10)] pass 1
[loader(10)] tag=1 ptr=0x1 val=1
[loader(10)] tag=15 ptr=0x3a9 val=937
[loader(10)] tag=4 ptr=0x100094 val=1048724
[loader(10)] tag=5 ptr=0x1005a4 val=1050020
[loader(10)] tag=6 ptr=0x100214 val=1049108
[loader(10)] tag=10 ptr=0x3b5 val=949
[loader(10)] tag=11 ptr=0x10 val=16
[loader(10)] tag=21 ptr=0x0 val=0
[loader(10)] tag=3 ptr=0x104034 val=1065012
[loader(10)] tag=2 ptr=0x1b0 val=432
[loader(10)] tag=20 ptr=0x11 val=17
[loader(10)] tag=23 ptr=0x10096c val=1050988
[loader(10)] tag=17 ptr=0x10095c val=1050972
[loader(10)] tag=18 ptr=0x10 val=16
[loader(10)] tag=19 ptr=0x8 val=8
[loader(10)] str_tab=0x1005a4, soname_idx=0x0, soname=0x1005a4
[loader(10)] soname=''
[loader(10)] rpath='$ORIGIN/lib'
[loader(10)] hash=0x100094
[loader(10)] dt_rela=0x0
[loader(10)] dt_rela_sz=0x0
[loader(10)] dt_rel=0x10095c
[loader(10)] dt_rel_sz=0x10
[loader(10)] pass 2
[loader(10)] needed:'libc.so.0'
[loader(10)] prog tdata at 0x00000000 size 0, tbss size 0
[loader(10)] Load all program dependencies
[loader(10)] module_load_deps('[program]')
[loader(10)] [program] needs libc.so.0
[loader(10)] module_find('libc.so.0')
[loader(10)] m = 0x70134140
[loader(10)] filename:'/lib/libc.so.0'
[loader(10)] Failed to load '/lib/libc.so.0'
[init:init(3)] init: Error spawning /srv/fs/locfs ([EINVAL] Invalid value)
[init:init(3)] init: Unable to stat /srv/taskmon

comment:2 Changed 6 months ago by Jiri Svoboda

I cannot reproduce the issue (in Qemu with latest ew.py) despite rebuilding the OS with the latest toolchain freshly built with toolchain.sh arm32:

[jirka@omelette build-rpi]$ /usr/local/cross/bin/arm-helenos-ld --version
GNU ld (GNU Binutils) 2.31.1
Copyright (C) 2018 Free Software Foundation, Inc.
This program is free software; you may redistribute it under the terms of
the GNU General Public License version 3 or (at your option) a later version.
This program has absolutely no warranty.
[jirka@omelette build-rpi]$ /usr/local/cross/bin/arm-helenos-gcc --version
arm-helenos-gcc (GCC) 8.2.0
Copyright (C) 2018 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

comment:3 Changed 6 months ago by Jakub Jermář

Component: helenos/unspecifiedhelenos-build
Owner: set to Martin Decky

Turns out that with python3, the tools/mkfat.py script builds initrd.img which is missing several subdirectories, including app/ and lib/. This makes the boot process not find /lib/libc.so.0 and manifests as this bug.

It is not clear why it only happens with the Raspberry Pi config though.

comment:4 Changed 6 months ago by Jakub Jermář

The problem seems to originate in the mkfat.py script, which misbehaves with Python3.

More specifically, in function fat_lchar I had to apply the following path in order to get a correct image:

diff --git a/tools/mkfat.py b/tools/mkfat.py
index 0e519b192..ad3647558 100755
--- a/tools/mkfat.py
+++ b/tools/mkfat.py
@@ -192,8 +192,8 @@ def fat_lchars(name):
        filtered = False
 
        for char in name.encode('ascii', 'replace').upper():
-               if char in lchars:
-                       filtered_name += char
+               if chr(char) in lchars:
+                       filtered_name += str.encode(chr(char))
                else:
                        filtered_name += b'_'
                        filtered = True

Without the patch, name would be always thought of as containing invalid characters and thus a LFN would be created in all cases. This somehow results in the initrd.img being incorrect.

comment:5 Changed 6 months ago by Jakub Jermář

Resolution: fixed
Status: newclosed
Note: See TracTickets for help on using tickets.