Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

inconsistent logging results when using atomics#160

nihalpasham started this conversation inGeneral
Discussion options

This seems like an odd issue.

I'm using thelog crate to abstract over the (UART-based) logging implementation.log uses atomics under the hood to initialize the global logger. In this case, I'm usingset_logger_racy

pubunsafefnset_logger_racy(logger:&'staticdynLog) ->Result<(),SetLoggerError>{matchSTATE.load(Ordering::SeqCst){UNINITIALIZED =>{LOGGER = logger;STATE.store(INITIALIZED,Ordering::SeqCst);Ok(())}INITIALIZING =>{// This is just plain UB, since we were racing another initialization functionunreachable!("set_logger_racy must not be used with other initialization functions")}        _ =>Err(SetLoggerError(())),}}

set_logger_racy uses an atomic load + store, like in the casepanic_wait. I presume they are lowered to regular load/store operations onaarch64. However, initializing the global logger yields inconsistent results.

  • exception handling andmmu + caching are enabled in all cases.
  • Here's a link to thefull implementation.

Case 1:

  • with the global logger enabled, adding the following piece of code.
let _fat_cache =match ctrlr.populate_fat_cache(&volume){Ok(val) =>{info!("fat cache populated ...")}Err(e) =>{panic!("error populating fat_cache, {:?}", e)}};

In theory, this snippet simply caches the fat table and should have no bearing on our global logger but nonetheless, adding this, results in the system-hanging withoutany exception. What's weird is the call to initialize the global logger is supposed to happen after printing a few more logs. In other words, none of theinfo logs fromkernel_main get printed. It looks like the system simply hangs right afterkernel_init.

--- COM3 is connected. Press Ctrl+] to quit---[1.796213] EMMC: reset card.[1.796240] control1:16143[1.798915] Divisor=63, Freq Set=396825[2.206299] CSD Contents :00400e0032 5b590000ed c87f80 0a4040[2.210115] cemmc_structure=1, spec_vers=0, taac=0x0E, nsac=0x00, tran_speed=0x32,ccc=0x05B5, read_bl_len=0x09, read_bl_partial=0b, write_blk_misalign=0b,read_blk_misalign=0b, dsr_imp=0b, sector_size=0x7F, erase_blk_en=1b[2.229749] CSD2.0: ver2_c_size=0xEFFC, card capacity:31914459136 bytes or31.91GiB[2.237654] wp_grp_size=0x0000000b, wp_grp_enable=0b, default_ecc=00b, r2w_factor=010b, write_bl_len=0x09, write_bl_partial=0b, file_format_grp=0, copy=1b, perm_write_protect=0b, tmp_write_protect=0b, file_format=0b ecc=00b[2.257375] control1:271[2.259895] Divisor=1, Freq Set=25000000[2.266381] EMMC: Bus width set to4[2.267542] EMMC: SD Card Type2 HC,30436Mb, mfr_id:3,'SD:ACLCD', r8.0, mfr_date:1/2017, serial:0xbbce119c, RCA:0xaaaa[2.278659] EMMC2 driver initialized...hangs.....

Case 2:

  • with the global logger enabled but without the above snippet of code, it works as expected. As you can see from the output logs, we print[INFO] logs.
boards\bootloaders\rpi4 on  main [!?] is 📦 v0.1.0 via 🦀 v1.61.0-nightly❯terminal-s.exe--- COM3 is connected. Press Ctrl+] to quit---[1.796262] EMMC: reset card.[1.796289] control1:16143[1.798965] Divisor=63, Freq Set=396825[2.206343] CSD Contents :00400e0032 5b590000ed c87f80 0a4040[2.210159] cemmc_structure=1, spec_vers=0, taac=0x0E, nsac=0x00, tran_speed=0x32,ccc=0x05B5, read_bl_len=0x09, read_bl_partial=0b, write_blk_misalign=0b,read_blk_misalign=0b, dsr_imp=0b, sector_size=0x7F, erase_blk_en=1b[2.229792] CSD2.0: ver2_c_size=0xEFFC, card capacity:31914459136 bytes or31.91GiB[2.237698] wp_grp_size=0x0000000b, wp_grp_enable=0b, default_ecc=00b, r2w_factor=010b, write_bl_len=0x09, write_bl_partial=0b, file_format_grp=0, copy=1b, perm_write_protect=0b, tmp_write_protect=0b, file_format=0b ecc=00b[2.257419] control1:271[2.259938] Divisor=1, Freq Set=25000000[2.266424] EMMC: Bus width set to4[2.267586] EMMC: SD Card Type2 HC,30436Mb, mfr_id:3,'SD:ACLCD', r8.0, mfr_date:1/2017, serial:0xbbce119c, RCA:0xaaaa[2.278703] EMMC2 driver initialized...[2.282526] rpi4 version0.1.0[2.285479] Booting on: Raspberry Pi4[2.289128] MMU online. Special regions:[2.292950]0x00080000-0x000acfff|180 KiB| C   RO PX| Kernel code and ROdata[2.301117]0xfe000000-0xff84ffff|24 MiB| Dev RW PXN| Device MMIO[2.308241] Current privilege level: EL1[2.312063] Exception handling state:[2.315625]       Debug:  Masked[2.318752]       SError: Masked[2.321880]       IRQ:    Masked[2.325007]       FIQ:    Masked[2.328135] Architectural timer resolution:18 ns[2.332739] Drivers loaded:[2.335432]1. BCM GPIO[2.338299]2. BCM PL011 UART[2.341687] Chars written:1702[2.344730] [INFO]  create new emmc-fat controller...[2.350462]- rustBoot::fs::controller @ line:202[2.360068] Listing root directory:[2.361587]- Found: SIGNED~1.ITB[2.365795] loading fit-image...[34.285615] loaded fit:62202019 bytes, starting at addr:0x4200000[34.288911] authenticating fit-image...[34.293908] [INFO]  computing"kernel" hash[34.298641]- rustBoot::dt::fit @ line:289[35.404489] [INFO]  computed"kernel" hash: 97dcbff24ad0a60514e31a7a6b34a765681fea81f8dd11e4644f3ec81e1044fb[35.412127]- rustBoot::dt::fit @ line:294[35.416913] [INFO]  kernel integrity consistent with supplied itb...[35.424724]- rustBoot::dt::fit @ line:308[35.429526] [INFO]  computing"fdt" hash[35.434107]- rustBoot::dt::fit @ line:289[35.439856] [INFO]  computed"fdt" hash: 3572783be74511b710ed7fca9b3131e97fd8073c620a94269a4e4ce79d331540[35.449136]- rustBoot::dt::fit @ line:294[35.453920] [INFO]  fdt integrity consistent with supplied itb...[35.461472]- rustBoot::dt::fit @ line:308[35.466274] [INFO]  computing"ramdisk" hash[35.471202]- rustBoot::dt::fit @ line:289[36.713353] [INFO]  computed"ramdisk" hash: f1290587e2155e3a5c2c870fa1d6e3e2252fb0dddf74992113d2ed86bc67f37c[36.721078]- rustBoot::dt::fit @ line:294[36.725862] [INFO]  ramdisk integrity consistent with supplied itb...[36.733762]- rustBoot::dt::fit @ line:308[36.738568] [INFO]  computing"rbconfig" hash[36.743579]- rustBoot::dt::fit @ line:289[36.748367] [INFO]  computed"rbconfig" hash: b16d058c4f09abdb8da98561f3a15d06ff271c38a4655c2be11dec23567fd519[36.759042]- rustBoot::dt::fit @ line:294[36.763825] [INFO]  rbconfig integrity consistent with supplied itb...[36.771813]- rustBoot::dt::fit @ line:308######## ecdsa signature checks out, image is authentic ########[36.808898] relocating kernel to addr:0x2200000[36.832642] relocating initrd to addr:0x200000[36.834200] load rbconfig...[36.837013] patching dtb...[36.840865] relocating dtb to addr:0x4000000first4 entries of FAT_CACHE, [[0,0,0,0], [0,0,0,0],[0,0,0,0],[0,0,0,0]]

Case 3:

  • with the global loggerdisabled, everything works as expected. You can see that the time taken toload the fit-image is much faster (down from 30 seconds to 3 seconds).
boards\bootloaders\rpi4 on  main [!?] is 📦 v0.1.0 via 🦀 v1.61.0-nightly❯terminal-s.exe--- COM3 is connected. Press Ctrl+] to quit---[1.771731] EMMC: reset card.[1.771759] control1:16143[1.774434] Divisor=63, Freq Set=396825[2.181818] CSD Contents :00400e0032 5b590000ed c87f80 0a4040[2.185634] cemmc_structure=1, spec_vers=0, taac=0x0E, nsac=0x00, tran_speed=0x32,ccc=0x05B5, read_bl_len=0x09, read_bl_partial=0b, write_blk_misalign=0b,read_blk_misalign=0b, dsr_imp=0b, sector_size=0x7F, erase_blk_en=1b[2.205267] CSD2.0: ver2_c_size=0xEFFC, card capacity:31914459136 bytes or31.91GiB[2.213172] wp_grp_size=0x0000000b, wp_grp_enable=0b, default_ecc=00b, r2w_factor=010b, write_bl_len=0x09, write_bl_partial=0b, file_format_grp=0, copy=1b, perm_write_protect=0b, tmp_write_protect=0b, file_format=0b ecc=00b[2.232893] control1:271[2.235413] Divisor=1, Freq Set=25000000[2.241898] EMMC: Bus width set to4[2.243060] EMMC: SD Card Type2 HC,30436Mb, mfr_id:3,'SD:ACLCD', r8.0, mfr_date:1/2017, serial:0xbbce119c, RCA:0xaaaa[2.254177] EMMC2 driver initialized...[2.258000] rpi4 version0.1.0[2.260954] Booting on: Raspberry Pi4[2.264602] MMU online. Special regions:[2.268425]0x00080000-0x000abfff|176 KiB| C   RO PX| Kernel code and ROdata[2.276591]0xfe000000-0xff84ffff|24 MiB| Dev RW PXN| Device MMIO[2.283715] Current privilege level: EL1[2.287537] Exception handling state:[2.291099]       Debug:  Masked[2.294227]       SError: Masked[2.297354]       IRQ:    Masked[2.300482]       FIQ:    Masked[2.303609] Architectural timer resolution:18 ns[2.308214] Drivers loaded:[2.310907]1. BCM GPIO[2.313774]2. BCM PL011 UART[2.317162] Chars written:1702[2.465278] fat cache populated ...[2.465793] Listing root directory:[2.470188]- Found: SIGNED~1.ITB[2.474394] loading fit-image...[5.893780] loaded fit:62202019 bytes, starting at addr:0x4200000[5.897076] authenticating fit-image...######## ecdsa signature checks out, image is authentic ########[7.400849] relocating kernel to addr:0x2200000[7.424647] relocating initrd to addr:0x200000[7.426205] load rbconfig...[7.429017] patching dtb...[7.432870] relocating dtb to addr:0x4000000first4 entries of FAT_CACHE, [[248,255,255,15], [255,255,255,255], [255,255,255,15], [255,255,255,15]]

Any idea why this could be happening? Am I missing something specific to the rpi4?

You must be logged in to vote

Replies: 1 comment 10 replies

Comment options

I don’t know your EMMC driver, and it is also not part of the tutorials here.

To me, this looks more like something races between your emmc driver init and this fat_cache snippet than with the logging. If you have caching enabled anyways then there should be no issue with the atomics.

You must be logged in to vote
10 replies
@andre-richter
Comment options

I don’t know if it has to do with the problem, but your current layout.ld is erroneous.

code_end_exclusive is aligned 4KiB (PAGE_SIZE), and then there’s a gap and then data starts 64KiB aligned.

@nihalpasham
Comment options

I guess it was worth a try - used a 64KiB page-size to ensure there are no gaps between__code_end_exclusive and start of .data section.

still get the same result.

/* SPDX-License-Identifier: MIT OR Apache-2.0** Copyright (c)2018-2021 Andre Richter<andre.o.richter@gmail.com>*/PAGE_SIZE= 64K;PAGE_MASK= PAGE_SIZE-1;__rpi_phys_dram_start_addr=0;/* The physical address at which the the kernel binary will be loaded by the Raspberry's firmware */__rpi_phys_binary_load_addr = 0x80000;ENTRY(__rpi_phys_binary_load_addr)/* Flags: *     4 == R *     5 == RX *     6 == RW * * Segments are marked PT_LOAD below so that the ELF file provides virtual and physical addresses. * It doesn't mean all of them need actually be loaded.*/PHDRS{    segment_boot_core_stack PT_LOAD FLAGS(6);    segment_code            PT_LOAD FLAGS(5);    segment_data            PT_LOAD FLAGS(6);}SECTIONS{.=  __rpi_phys_dram_start_addr;/************************************************************************************************ Boot Core Stack***********************************************************************************************/    .boot_core_stack (NOLOAD) :    {/*   ^*//*| stack*/.+= __rpi_phys_binary_load_addr;/*| growth*//*| direction*/        __boot_core_stack_end_exclusive= .;/*|*/    } :segment_boot_core_stack    ASSERT((.& PAGE_MASK)==0,"End of boot core stack is not page aligned")/************************************************************************************************ Code+ ROData+ Global Offset Table***********************************************************************************************/    __code_start= .;    .text :    {        KEEP(*(.text._start))*(.text._start_arguments)/* Constants (or staticsin Rust speak) read by _start().*/*(.text._start_rust)/* The Rust entry point*/*(.text*)/* Everythingelse, add all other input .text sections (i.e.from other                                   input object files) to our main binary.*/    } :segment_code    .rodata : ALIGN(8) {*(.rodata*) } :segment_code    .got    : ALIGN(8) {*(.got)     } :segment_code.= ALIGN(PAGE_SIZE);    __code_end_exclusive= .;/************************************************************************************************Data+ BSS***********************************************************************************************/    .data : {*(.data*) } :segment_data/* align .data to a 64KiB boundary.*//* As we enable the MMU and set the paging granularity to 64KiB.*//* So, theend of`code+ ro` section and start ofdata section needs to be 64KiB aligned.*//* Section is zeroedin pairs of u64. Align start andend to16 bytes*/    .bss (NOLOAD): ALIGN(16)    {        __bss_start= .;*(.bss*);.= ALIGN(16);        __bss_end_exclusive= .;    } :segment_data/* not a section that's loaded into memory, we just need to allocate as many zeroed bytes.*/}

grepped the symbol table for__code_end_exclusive, it looks right.

npashi@DESKTOP-M9O6B7J:/mnt/c/Users/Nil/devspace/rust/projects/rustBoot/boards/bootloaders/rpi4$ readelf-s ../../target/aarch64-unknown-none-softfloat/release/kernel| grep __code*1581:00000000000800000 NOTYPE  GLOBALDEFAULT1 __code_start1582: 00000000000b00000 NOTYPE  GLOBALDEFAULT3 __code_end_exclusive

and assembly for the .data section

Disassembly of section .data:00000000000b0000 <log::LOGGER.1>:   b0000:000a735000000000                       Ps......00000000000b0008 <rustBoot_hal::rpi::rpi4::bsp::global::GPIO>:   b0008:fe20000000000000                       .. .....00000000000b0010 <rustBoot_hal::rpi::rpi4::bsp::global::PL011_UART>:   b0010:fe201000000000000000000000000000     .. ................00000000000b0028 <rustBoot_hal::rpi::rpi4::bsp::drivers::emmc::EMMC_CARD>:...   b0068:000abc370000000000000001000000007..................
@andre-richter
Comment options

What happens if you define your own static atomic and cmp_exchange it during boot?

@andre-richter
Comment options

You need to get an idea where you are actually hanging.

If you can’t get hold of a hw debugger, try something like implementing IRQ support, and periodically interrupt yourself and print ELR_EL1 to understand where the CPU was.

You could set the timer compare value register and then kick off counting with timer IRQ enabled (see time.rs in the tutorials). In the ISR, reset the timer again to get infinite periodic IRQs.

@nihalpasham
Comment options

Yep, that's the only option I have left. I'll circle back when I'm in possession of hw debugger. Hopefully soon.

Sign up for freeto join this conversation on GitHub. Already have an account?Sign in to comment
Category
General
Labels
None yet
2 participants
@nihalpasham@andre-richter
[8]ページ先頭
©2009-2025 Movatter.jp