Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Panic when enabling task stack traces #72

Closed
jperkin opened this issue Dec 27, 2021 · 10 comments
Closed

Panic when enabling task stack traces #72

jperkin opened this issue Dec 27, 2021 · 10 comments

Comments

@jperkin
Copy link
Contributor

jperkin commented Dec 27, 2021

I'm porting Hubris to Cortex-M0+ / armv6m so this is likely caused by changes with that architecture, and probably won't be helped by it not fully running yet, but while most commands work great, when requesting stack traces with humility tasks -s I get a panic.

Printing tasks and their registers works fine:

$ humility tasks -r
humility: attached via OpenOCD
system time = 3
ID TASK                 GEN PRI STATE    
 0 jefe                   0   0 recv, notif: bit0 bit1(T+97)
   |
   +--->   R0 = 0x0800a0ec   R1 = 0x00000000   R2 = 0x00000003   R3 = 0x20001580
           R4 = 0x0800a0ec   R5 = 0x00000000   R6 = 0x00000003   R7 = 0x00000000
           R8 = 0x00000000   R9 = 0x00000000  R10 = 0x00000000  R11 = 0x00000001
          R12 = 0x00000000   SP = 0x20001510   LR = 0x080080f9   PC = 0x08009434

 1 rcc_driver             0   1 recv
   |
   +--->   R0 = 0x20001b98   R1 = 0x00000004   R2 = 0x00000000   R3 = 0x20001b9c
           R4 = 0x20001b98   R5 = 0x00000004   R6 = 0x00000000   R7 = 0x00000000
           R8 = 0x00000000   R9 = 0x00000000  R10 = 0x00000000  R11 = 0x00000001
          R12 = 0x00000000   SP = 0x20001bb8   LR = 0x0800c067   PC = 0x0800cc44

 2 gpio_driver            0   2 RUNNING
   |
   +--->   R0 = 0x20001f88   R1 = 0x00000005   R2 = 0x00000000   R3 = 0x20001f90
           R4 = 0x00000000   R5 = 0x00000003   R6 = 0x00000002   R7 = 0x00000005
           R8 = 0x00000000   R9 = 0x00000000  R10 = 0x00000000  R11 = 0x00000001
          R12 = 0x00000000   SP = 0x20001f88   LR = 0x0800e195   PC = 0x0800efcc

 3 user_leds              0   2 wait: reply from gpio_driver/gen0
   |
   +--->   R0 = 0x20002340   R1 = 0x08011734   R2 = 0x00000000   R3 = 0x20002338
           R4 = 0x00020002   R5 = 0x20002338   R6 = 0x00000005   R7 = 0x2000235c
           R8 = 0x00000000   R9 = 0x08011734  R10 = 0x00000000  R11 = 0x00000000
          R12 = 0x00000000   SP = 0x20002360   LR = 0x08010b5d   PC = 0x08010e6e

 4 pong                   0   3 ready
   |
   +--->   R0 = 0x00000000   R1 = 0x00000000   R2 = 0x00000000   R3 = 0x00000000
           R4 = 0x00000000   R5 = 0x00000000   R6 = 0x00000000   R7 = 0x00000000
           R8 = 0x00000000   R9 = 0x00000000  R10 = 0x00000000  R11 = 0x00000000
          R12 = 0x00000000   SP = 0x20002800   LR = 0xffffffff   PC = 0x08012001

 5 idle                   0   5 ready
   |
   +--->   R0 = 0x00000000   R1 = 0x00000000   R2 = 0x00000000   R3 = 0x00000000
           R4 = 0x00000000   R5 = 0x00000000   R6 = 0x00000000   R7 = 0x00000000
           R8 = 0x00000000   R9 = 0x00000000  R10 = 0x00000000  R11 = 0x00000000
          R12 = 0x00000000   SP = 0x20002900   LR = 0xffffffff   PC = 0x08014001

but not when adding -s:

$ humility tasks -rs
humility: attached via OpenOCD
system time = 3
ID TASK                 GEN PRI STATE    
 0 jefe                   0   0 recv, notif: bit0 bit1(T+97)
thread 'main' panicked at 'range end index 2598222598 out of range for slice of length 2048', humility-core/src/hubris.rs:2707:32
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

Backtrace:

$ RUST_BACKTRACE=1 humility tasks -rs
humility: attached via OpenOCD
system time = 3
ID TASK                 GEN PRI STATE    
 0 jefe                   0   0 recv, notif: bit0 bit1(T+97)
thread 'main' panicked at 'range end index 2598222598 out of range for slice of length 2048', humility-core/src/hubris.rs:2707:32
stack backtrace:
   0: rust_begin_unwind
             at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/std/src/panicking.rs:517:5
   1: core::panicking::panic_fmt
             at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/core/src/panicking.rs:100:14
   2: core::slice::index::slice_end_index_len_fail
             at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/core/src/slice/index.rs:41:5
   3: <core::ops::range::Range<usize> as core::slice::index::SliceIndex<[T]>>::index
             at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/core/src/slice/index.rs:240:13
   4: core::slice::index::<impl core::ops::index::Index<I> for [T]>::index
             at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/core/src/slice/index.rs:15:9
   5: <alloc::vec::Vec<T,A> as core::ops::index::Index<I>>::index
             at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/alloc/src/vec/mod.rs:2496:9
   6: humility_core::hubris::HubrisArchive::stack::{{closure}}
             at /System/Volumes/Data/work/git/humility/humility-core/src/hubris.rs:2707:32
   7: humility_core::hubris::HubrisArchive::stack
             at /System/Volumes/Data/work/git/humility/humility-core/src/hubris.rs:2764:25
   8: humility_cmd_tasks::tasks
             at /System/Volumes/Data/work/git/humility/cmd/tasks/src/lib.rs:220:27
   9: humility::cmd::subcommand
             at /System/Volumes/Data/work/git/humility/src/cmd.rs:117:17
  10: humility::main
             at /System/Volumes/Data/work/git/humility/src/main.rs:139:19
  11: core::ops::function::FnOnce::call_once
             at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9c/library/core/src/ops/function.rs:227:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

When running with a reduced app configuration which appears to be running fine (but where I need to halt via gdb before Humility can access over OpenOCD) I also get a hang when trying to add -s:

$ humility tasks -r
humility: attached via OpenOCD
system time = 6000
ID TASK                 GEN PRI STATE    
 0 jefe                   0   0 RUNNING
   |
   +--->   R0 = 0x00000005   R1 = 0x20001414   R2 = 0x00000001   R3 = 0x00000028
           R4 = 0x08009d29   R5 = 0x20001570   R6 = 0x00000000   R7 = 0x20001428
           R8 = 0x00000000   R9 = 0x00000000  R10 = 0x00000000  R11 = 0x00000000
          R12 = 0x00000000   SP = 0x20001414   LR = 0x08008fc3   PC = 0x08008f72

 1 rcc_driver             0   1 recv
   |
   +--->   R0 = 0x20001b98   R1 = 0x00000004   R2 = 0x00000000   R3 = 0x20001b9c
           R4 = 0x20001b98   R5 = 0x00000004   R6 = 0x00000000   R7 = 0x00000000
           R8 = 0x00000000   R9 = 0x00000000  R10 = 0x00000000  R11 = 0x00000001
          R12 = 0x00000000   SP = 0x20001bb8   LR = 0x0800c067   PC = 0x0800cc44

 2 idle                   0   5 ready
   |
   +--->   R0 = 0x20001d00   R1 = 0x20001d00   R2 = 0x00000000   R3 = 0x00000000
           R4 = 0x00000000   R5 = 0x00000000   R6 = 0x00000000   R7 = 0x20001cb0
           R8 = 0x00000000   R9 = 0x00000000  R10 = 0x00000000  R11 = 0x00000000
          R12 = 0x00000000   SP = 0x20001cf8   LR = 0x0800e031   PC = 0x0800e04e
$ humility tasks -rs
humility: attached via OpenOCD
system time = 6000
ID TASK                 GEN PRI STATE    
 0 jefe                   0   0 RUNNING
[...hangs...]

This may be related. I can provide system images on request if required.

@bcantrill
Copy link
Contributor

Interesting! Assuming that humility dump works (which it may well not?) would it be possible to provide a dump of the system in this condition? More generally: what M0+ chip are you using? (It would be great to get formal M0+ support and have a reference board for it.) Hoping that it's the STM32G0 series, I ordered a few eval boards...

@jperkin
Copy link
Contributor Author

jperkin commented Dec 28, 2021

Sure, dump does appear to work, available here: https://us-east.manta.joyent.com/jperkin/public/tmp/hubris.core.1

Note that for some reason (a limitation of semihosting?) humility only works when the system is stopped, e.g. ^C in gdb. If I try to run any humility command against a running system I get this error:

$ humility dump
humility: attached via OpenOCD
humility: dump failed: apptable at 0x8006c00 does not match archive apptable

The board is an STM NUCLEO-G0B1RE, and my branch is at https://github.com/jperkin/hubris/tree/armv6. It appears to work as expected and I'm currently working on the GPIO driver, but unfortunately with the above issue I'm unable to run the test suite, even after flashing and removing all of the logging so that it runs with semihosting.

@bcantrill
Copy link
Contributor

The NUCLEO-G0B1RE is one of the three M0+ eval boards I ordered, so will have hardware in hand soon! It would be worth getting OpenOCD out of the way entirely to see if that changes behavior (the OpenOCD backend to Humility relies on somewhat shaky foundation in terms of the OpenOCD TCL interface). Without any archive at all, you should be able to run humility probe, for which I would love to see the output! (Also, it would be helpful to store this information in the dump; I'll open an issue on that.)

That said: based on the fact that you have a dump, it appears that they are working properly -- though I do notice from the dump (as you mentioned) that semihosting is enabled. It would be helpful to see humility probe output, but it would appear that the M0+ has no support for ITM, which is unfortunate. (humility test relies upon ITM.) That said: we have generally moved away from ITM as load-bearing because it is flaky even when it works (and it's brittle); recasting the Hubris test suite to not use ITM at all is actually entirely conceivable. (And indeed, the test suite itself entirely predates both HIF and Idol; recasting it in terms of HIF and Idol would allow us to better test the system anyway.) Would love to get @cbiffle's thoughts on that.

And great work on this so far -- and it feels like old times to get a Manta URL to a dump! ;)

@jperkin
Copy link
Contributor Author

jperkin commented Dec 28, 2021

I've been using humility probe quite a bit during bring-up and it's been working great (with #70 applied).

I don't know if I'm doing this right, but with the device flashed and no OpenOCD running (and no HUMILITY_ARCHIVE set), I get:

$ humility probe
humility: probe failed: Probe could not be created

Caused by:
    0: Pipe error
    1: Pipe error

If I fire up openocd and retry it appears to attach (I need to figure out why it's halting, probably due to some missing semihosting bits..):

$ humility probe
humility: attached via OpenOCD
humility:        probe => OpenOCD
humility: probe serial => -
humility:         core => Cortex-M0+
humility: manufacturer => ARM Ltd
humility:         chip => STM32G0x1, revision 0x1000
humility:       status => halted, vector catch, breakpoint, debug halt
humility:  debug units => BPU DWT SCS
humility:          BPU => 0xe0002000
humility:          DWT => 0xe0001000
humility:          SCS => 0xe000e000
humility:   ITM status => absent
humility:           R0 => 0x1        
humility:           R1 => 0x2000036c 
humility:           R2 => 0x13       
humility:           R3 => 0x20001000 
humility:           R4 => 0x1        
humility:           R5 => 0x20000400 
humility:           R6 => 0x0        
humility:           R7 => 0x20000378 
humility:           R8 => 0xffffffff 
humility:           R9 => 0xffffffff 
humility:          R10 => 0xffffffff 
humility:          R11 => 0xffffffff 
humility:          R12 => 0xffffffff 
humility:           SP => 0x20000368 
humility:           LR => 0x8002415  
humility:           PC => 0x8005060  
humility:         xPSR => 0x1000000  
humility:          MSP => 0x20000368 
humility:          PSP => 0xfffffffc 
humility:          SPR => 0x1        

If I fire up gdb and run hubris from there, humility is unable to retrieve register status while the system is running (I'm guessing due to the various debug bits that are missing in ARMv6 compared to ARMv7?):

$ humility probe
humility: attached via OpenOCD
humility:        probe => OpenOCD
humility: probe serial => -
humility:         core => Cortex-M0+
humility: manufacturer => ARM Ltd
humility:         chip => <Unknown STM32 chip 0x0>, revision 0x0
humility:       status => vector catch, breakpoint, debug halt
humility:  debug units => BPU DWT SCS
humility:          BPU => 0xe0002000
humility:          DWT => 0xe0001000
humility:          SCS => 0xe000e000
humility:   ITM status => absent
humility: probe failed: "reg 0": malformed return value: ""

If I then ^C in gdb, humility can connect:

$ humility probe
humility: attached via OpenOCD
humility:        probe => OpenOCD
humility: probe serial => -
humility:         core => Cortex-M0+
humility: manufacturer => ARM Ltd
humility:         chip => STM32G0x1, revision 0x1000
humility:       status => halted, vector catch, breakpoint, debug halt
humility:  debug units => BPU DWT SCS
humility:          BPU => 0xe0002000
humility:          DWT => 0xe0001000
humility:          SCS => 0xe000e000
humility:   ITM status => absent
humility:           R0 => 0x20001d00 
humility:           R1 => 0x20001d00 
humility:           R2 => 0x0        
humility:           R3 => 0x0        
humility:           R4 => 0x0        
humility:           R5 => 0x0        
humility:           R6 => 0x0        
humility:           R7 => 0x20001cb0 
humility:           R8 => 0x0        
humility:           R9 => 0x0        
humility:          R10 => 0x0        
humility:          R11 => 0x0        
humility:          R12 => 0x0        
humility:           SP => 0x20001cb0 
humility:           LR => 0x8016031  
humility:           PC => 0x801604c  
humility:         xPSR => 0x61000000 
humility:          MSP => 0x20000320 
humility:          PSP => 0x20001cb0 
humility:          SPR => 0x0        

It's also worth noting I'm using the latest trunk of openocd as the support for the G0 devices is quite new, 0.11 works but e.g. a bunch of register values are incorrect.

@bcantrill
Copy link
Contributor

I somehow missed #70 -- my apologies! Especially if OpenOCD has some recent changes to support the G0 devices, my guess is that we need to update/fix probe-rs. One experiment worth trying: try latest probe-rs (we are quite a bit behind and on our own branch that has some fixes that we have needed) on its own (that is, without Humility), and see if the tooling that they provide can correctly see the chip. If so, we would want to update our probe-rs (which we truthfully want to do anyway); if not, we will want to add G0 support in probe-rs. (You can also get more information about why Humility is failing to create the probe by running with -v -- as in humility -v probe.)

I would also add that the register values being incorrect may well be the root cause of this actual issue (incorrect stack traces); Humility should clearly not be tossing in this circumstance, but it seems likely that the fix will be to detect that the stack is corrupt and indicate as much.

@jperkin
Copy link
Contributor Author

jperkin commented Dec 28, 2021

Aha, yes, switching over to the latest probe-rs helps, I can now connect when openocd is not running:

$ humility probe
humility: INFO (probe_rs::probe::stlink): Target voltage (VAPP): 3.22 V
humility: attached via ST-Link V2-1
humility:        probe => STLink V2-1, VID 0483, PID 374b
humility: probe serial => 066BFF515754888367193828
humility:         core => Cortex-M0+
humility: manufacturer => ARM Ltd
humility:         chip => <Unknown STM32 chip 0x0>, revision 0x0
humility:       status => executing
humility:  debug units => BPU DWT SCS
humility:          BPU => 0xe0002000
humility:          DWT => 0xe0001000
humility:          SCS => 0xe000e000
humility:   ITM status => absent
humility:           R0 => 0x20001d00 
humility:           R1 => 0x20001d00 
humility:           R2 => 0x0        
humility:           R3 => 0x0        
humility:           R4 => 0x0        
humility:           R5 => 0x0        
humility:           R6 => 0x0        
humility:           R7 => 0x20001cb0 
humility:           R8 => 0x0        
humility:           R9 => 0x0        
humility:          R10 => 0x0        
humility:          R11 => 0x0        
humility:          R12 => 0x0        
humility:           SP => 0x20001cb0 
humility:           LR => 0x8016031  
humility:           PC => 0x801604c  
humility:         xPSR => 0x61000000 
humility:          MSP => 0x20000320 
humility:          PSP => 0x20001cb0 
humility:          SPR => 0x3000000  

Unfortunately I still can't get a tasks output due to the apptable mismatch issue:

$ export HUMILITY_ARCHIVE=/work/git/hubris/target/demo-stm32g0b1-nucleo/dist//build-demo-stm32g0b1-nucleo.zip
$ humility tasks -rslv
humility: INFO (probe_rs::probe::stlink): Target voltage (VAPP): 3.22 V
humility: attached via ST-Link V2-1
humility: tasks failed: apptable at 0x8006bf0 does not match archive apptable

In case it's useful here's the output with -v:

$ humility -v tasks -rslv
humility: loading kernel as object 0
humility: no name found for GOFF 0x00000d4a
humility: no name found for GOFF 0x00008a25
humility: no name found for GOFF 0x0000a3be
humility: no name found for GOFF 0x0001a9c1
humility: no name found for GOFF 0x0001b160
humility: no name found for GOFF 0x0001b1a1
humility: loading jefe as object 1
humility: loading rcc_driver as object 2
humility: no name found for GOFF 0x0000e000 (object 2)
humility: loading hiffy as object 3
humility: no name found for GOFF 0x0000a85a (object 3)
humility: loading idle as object 4
humility: DEBUG (probe_rs::probe::cmsisdap::tools): Searching for CMSIS-DAP probes using libusb
humility: DEBUG (probe_rs::probe::cmsisdap::tools): Found 0 CMSIS-DAP probes using libusb, searching HID
humility: DEBUG (probe_rs::probe::cmsisdap::tools): Found 0 CMSIS-DAP probes total
humility: DEBUG (jaylink): libusb 1.0.24.11584
humility: DEBUG (jaylink): libusb has capability API: true
humility: DEBUG (jaylink): libusb has HID access: false
humility: DEBUG (jaylink): libusb has hotplug support: true
humility: DEBUG (jaylink): libusb can detach kernel driver: false
humility: TRACE (probe_rs::probe::cmsisdap::tools): Attempting to open device matching 0483:374b:066BFF515754888367193828
humility: TRACE (probe_rs::probe::cmsisdap::tools): Trying device Bus 020 Device 014: ID 0483:374b
humility: TRACE (probe_rs::probe::cmsisdap::tools): Trying device Bus 064 Device 005: ID 05ac:026c
humility: TRACE (probe_rs::probe::cmsisdap::tools): Trying device Bus 064 Device 004: ID 05ac:1112
humility: TRACE (probe_rs::probe::cmsisdap::tools): Trying device Bus 064 Device 003: ID 05ac:1107
humility: TRACE (probe_rs::probe::cmsisdap::tools): Trying device Bus 064 Device 002: ID 05ac:9227
humility: TRACE (probe_rs::probe::cmsisdap::tools): Trying device Bus 064 Device 001: ID 05ac:9127
humility: TRACE (probe_rs::probe::cmsisdap::tools): Error getting languages: Pipe
humility: DEBUG (probe_rs::probe::cmsisdap::tools): Attempting to open 0483:374b in CMSIS-DAP v1 mode
humility: DEBUG (probe_rs::probe::stlink::usb_interface): Acquired libusb context.
humility: DEBUG (probe_rs::probe::stlink::usb_interface): Aquired handle for probe
humility: DEBUG (probe_rs::probe::stlink::usb_interface): Active config descriptor: ConfigDescriptor { bLength: 9, bDescriptorType: 2, wTotalLength: 128, bNumInterfaces: 4, bConfigurationValue: 1, iConfiguration: 0, bmAttributes: 128, bMaxPower: 250, extra: None }
humility: DEBUG (probe_rs::probe::stlink::usb_interface): Device descriptor: DeviceDescriptor { bLength: 18, bDescriptorType: 1, bcdUSB: 512, bDeviceClass: 239, bDeviceSubClass: 2, bDeviceProtocol: 1, bMaxPacketSize: 64, idVendor: 1155, idProduct: 14155, bcdDevice: 256, iManufacturer: 1, iProduct: 2, iSerialNumber: 3, bNumConfigurations: 1 }
humility: DEBUG (probe_rs::probe::stlink::usb_interface): Claimed interface 0 of USB device.
humility: DEBUG (probe_rs::probe::stlink::usb_interface): Succesfully attached to STLink.
humility: DEBUG (probe_rs::probe::stlink): Initializing STLink...
humility: TRACE (probe_rs::probe::stlink): Getting current mode of device...
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f5] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 2 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Current device mode: Jtag
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f1] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 6 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): STLink version: (2, 39)
humility: DEBUG (probe_rs::config::registry): Searching registry for chip with name STM32F407VGTx
humility: DEBUG (probe_rs::config::registry): Exact match for chip name: STM32F407VGTx
humility: DEBUG (probe_rs::probe::stlink): attach(Swd)
humility: TRACE (probe_rs::probe::stlink): Getting current mode of device...
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f5] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 2 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Current device mode: Jtag
humility: DEBUG (probe_rs::probe::stlink): Switching protocol to SWD
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f7] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 8 bytes, 0 bytes remaining
humility: INFO (probe_rs::probe::stlink): Target voltage (VAPP): 3.22 V
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 30, a3, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 2 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Successfully initialized SWD.
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 43, 1] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 2 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::ap): Reading register IDR
humility: DEBUG (probe_rs::probe::stlink): Opening AP 0
humility: TRACE (probe_rs::probe::stlink): JTAG_INIT_AP 0
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 4b, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 2 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 45, 0, 0, fc, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 8 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::ap): Read register    IDR, value=0x4770031
humility: DEBUG (probe_rs::architecture::arm::ap): Reading register IDR
humility: DEBUG (probe_rs::probe::stlink): Opening AP 1
humility: TRACE (probe_rs::probe::stlink): JTAG_INIT_AP 1
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 4b, 1] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 2 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 45, 1, 0, fc, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 8 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::ap): Read register    IDR, value=0x0
humility: DEBUG (probe_rs::architecture::arm::ap): Reading register IDR
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 45, 0, 0, fc, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 8 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::ap): Read register    IDR, value=0x4770031
humility: DEBUG (probe_rs::architecture::arm::ap): Reading register BASE
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 45, 0, 0, f8, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 8 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::ap): Read register    BASE, value=0xf0000003
humility: DEBUG (probe_rs::architecture::arm::ap): Reading register BASE2
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 45, 0, 0, f0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 8 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::ap): Read register    BASE2, value=0x0
humility: DEBUG (probe_rs::architecture::arm::ap): Reading register CSW
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 45, 0, 0, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 8 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::ap): Read register    CSW, value=0x3000052
humility: DEBUG (probe_rs::architecture::arm::ap): Writing register CSW, value=CSW { DbgSwEnable: 1, HNONSEC: 1, PROT: 6, CACHE: 3, SPIDEN: 0, _RES0: 0, MTE: 0, Type: 0, Mode: 0, TrinProg: 0, DeviceEn: 0, AddrInc: Single, _RES1: 0, SIZE: U8 }
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 46, 0, 0, 0, 0, 10, 0, 0, e3] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 2 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::ap): Reading register CSW
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 45, 0, 0, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 8 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::ap): Read register    CSW, value=0x3000050
humility: DEBUG (probe_rs::architecture::arm::ap): Writing register CSW, value=CSW { DbgSwEnable: 0, HNONSEC: 0, PROT: 0, CACHE: 3, SPIDEN: 0, _RES0: 0, MTE: 0, Type: 0, Mode: 0, TrinProg: 0, DeviceEn: 1, AddrInc: Single, _RES1: 0, SIZE: U32 }
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 46, 0, 0, 0, 0, 52, 0, 0, 3] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 2 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::communication_interface): HNONSEC supported: false
humility: DEBUG (probe_rs::probe::stlink): AP ApAddress {
    dp: Default,
    ap: 0x0,
}: MemoryAp(MemoryApInformation { address: ApAddress { dp: Default, ap: 0 }, only_32bit_data_size: false, debug_base_address: 4026531840, supports_hnonsec: false })
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e000edf0, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, f0, ed, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::architecture::arm::sequences): Core is already in debug mode, no need to enable it again
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e000edf0, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, f0, ed, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink): write_mem_32bit
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 8, 30, ed, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Wrote 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): USB write done!
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002000, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 0, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002000, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 0, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002008, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 8, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002000, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 0, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e000200c, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, c, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002000, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 0, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002010, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 10, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002000, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 0, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002014, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 14, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: attached via ST-Link V2-1
humility: TRACE (probe_rs::probe::stlink): read_mem_8bit
humility: DEBUG (probe_rs::probe::stlink): Read mem 8 bit, address=08006bf0, length=64
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, c, f0, 6b, 0, 8, 40, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 64 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink): read_mem_8bit
humility: DEBUG (probe_rs::probe::stlink): Read mem 8 bit, address=08006c30, length=64
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, c, 30, 6c, 0, 8, 40, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 64 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink): read_mem_8bit
humility: DEBUG (probe_rs::probe::stlink): Read mem 8 bit, address=08006c70, length=64
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, c, 70, 6c, 0, 8, 40, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 64 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink): read_mem_8bit
humility: DEBUG (probe_rs::probe::stlink): Read mem 8 bit, address=08006cb0, length=64
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, c, b0, 6c, 0, 8, 40, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 64 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink): read_mem_8bit
humility: DEBUG (probe_rs::probe::stlink): Read mem 8 bit, address=08006cf0, length=48
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, c, f0, 6c, 0, 8, 30, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 48 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002000, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 0, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002000, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 0, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002008, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 8, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002000, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 0, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e000200c, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, c, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002000, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 0, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002010, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 10, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002000, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 0, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Read mem 32 bit, address=e0002014, length=4
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 7, 14, 20, 0, e0, 4, 0, 0] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 4 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f2, 3e] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 12 bytes, 0 bytes remaining
humility: TRACE (probe_rs::probe::stlink): Getting current mode of device...
humility: TRACE (probe_rs::probe::stlink::usb_interface): Sending command [f5] to STLink, timeout: 1s
humility: TRACE (probe_rs::probe::stlink::usb_interface): Read 2 bytes, 0 bytes remaining
humility: DEBUG (probe_rs::probe::stlink): Current device mode: Jtag
humility: tasks failed: apptable at 0x8006bf0 does not match archive apptable

FWIW there's a small patch required to get building against the latest probe-rs, the core_index value is clearly bogus but I couldn't find docs on it and just wanted to get it building for now:

diff --git a/humility-core/src/core.rs b/humility-core/src/core.rs
index e4301cd..3905318 100644
--- a/humility-core/src/core.rs
+++ b/humility-core/src/core.rs
@@ -142,7 +142,7 @@ impl Core for ProbeCore {
         use probe_rs::architecture::arm::swo::SwoConfig;
 
         let config = SwoConfig::new(0).set_baud(2_000_000);
-        self.session.setup_swv(&config)?;
+        self.session.setup_swv(1000 as usize, &config)?;
 
         /*
          * Because the probe can have sticky errors, we perform one read
@@ -937,7 +937,7 @@ pub fn attach(mut probe: &str, chip: &str) -> Result<Box<dyn Core>> {
              * debug probe because something else has already attached to it;
              * we pull this error out to yield a more actionable suggestion!
              */
-            if let Err(probe_rs::DebugProbeError::USB(Some(ref err))) = res {
+            if let Err(probe_rs::DebugProbeError::Usb(Some(ref err))) = res {
                 if let Some(rcode) = err.downcast_ref::<rusb::Error>() {
                     if *rcode == rusb::Error::Busy {
                         bail!(

@jperkin
Copy link
Contributor Author

jperkin commented Dec 28, 2021

I just noticed in the verbose output that the chip id is incorrect:

humility: DEBUG (probe_rs::config::registry): Searching registry for chip with name STM32F407VGTx
humility: DEBUG (probe_rs::config::registry): Exact match for chip name: STM32F407VGTx

Looking at the probe-rs support in https://github.com/probe-rs/probe-rs/blob/master/probe-rs/targets/STM32G0_Series.yaml I can't see the STM32G0B1RE listed so will see if adding it and specifying the correct HUMILITY_CHIP helps.

@bcantrill
Copy link
Contributor

The app table mismatch is very surprising -- that should really only show up when the archive does not match what's on the flash. What does humility apptable show, and does that match what's in the kernel binary that's loaded?

@bcantrill
Copy link
Contributor

As it turns out, there were many problems here.

  • First, the apptable mismatch is (apparently) because if the G0 is not halted, reads will return zero (which is what you observed in your first comment). This is a bit unsporting (it would be nice if the read failed instead of giving bogus data), but it's also not entirely unreasonable in that reads on a non-halted MCU are likely going to have unexpected results. I have fixed Humility to halt the core before a read if it isn't already halted.

  • The stack unwinding is broken for two reasons. The first (and simplest) is that there are no FP registers on ARMv6-m -- but we assume that there are when we adjust the stack to reflect pushed registers on a system call, resulting in an incorrect stack pointer (and the out of bound accesses). It further didn't help that this error wasn't handled really crisply (or at all), resulting in a panic instead of an error.

  • The second reason is a bit gnarlier: in addition to not having floating point registers, ARMv6-M is very limited as to its ability to push registers. As a result, the manual register save that we perform in the syscall stubs is not one push instruction but (often) two -- with registers movement to stage R8-R11 into the registers that can be pushed (R7 and lower). Fixing this is a little more involved, and necessitated being smarter about how we're interpreting the instruction text more generally.

Fixing all of these problems, we have stack traces! Output from the original dump:

$ humility: attached to dump
system time = 34056
ID TASK                 GEN PRI STATE    
 0 jefe                   0   0 recv, notif: bit0 bit1(T+44)
   |
   +--->  0x200014f0 0x080112bc userlib::sys_recv_stub
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:336
          0x200015b8 0x08010112 userlib::sys_recv
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:283
          0x200015b8 0x08010112 userlib::sys_recv_open
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:239
          0x200015b8 0x08010124 main
                     @ /System/Volumes/Data/work/git/hubris/task/jefe/src/main.rs:98
          0x200015b8 0x08010030 _start
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:1219

 1 rcc_driver             0   1 recv
   |
   +--->  0x20001b90 0x08014c44 userlib::sys_recv_stub
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:336
          0x20001bb8 0x08014058 userlib::sys_recv
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:283
          0x20001bb8 0x08014058 userlib::hl::recv
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/hl.rs:83
          0x20001bb8 0x08014058 userlib::hl::recv_without_notification
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/hl.rs:121
          0x20001bb8 0x08014066 main
                     @ /System/Volumes/Data/work/git/hubris/drv/stm32g0-rcc/src/main.rs:103
          0x20001bb8 0x08014030 _start
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:1219

 2 hiffy                  0   3 notif: bit0(T+195)
   |
   +--->  0x200044f8 0x08009774 userlib::sys_recv_stub
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:336
          0x20004528 0x080097f2 userlib::sys_recv
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:283
          0x20004528 0x080097f2 userlib::sys_recv_closed
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:264
          0x20004528 0x080097e6 userlib::hl::sleep_until
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/hl.rs:610
          0x20004528 0x08009800 userlib::hl::sleep_for
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/hl.rs:635
          0x200047b8 0x080082f6 main
                     @ /System/Volumes/Data/work/git/hubris/task/hiffy/src/main.rs:110
          0x200047b8 0x08008030 _start
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:1219

 3 idle                   0   5 RUNNING
   |
   +--->  0x20001cb8 0x0801604c cortex_m::asm::inline::__wfi
                     @ /Users/jperkin/.cargo/registry/src/github.com-1ecc6299db9ec823/cortex-m-0.7.3/src/../asm/inline.rs:181
          0x20001cb8 0x0801604c cortex_m::asm::wfi
                     @ /Users/jperkin/.cargo/registry/src/github.com-1ecc6299db9ec823/cortex-m-0.7.3/src/asm.rs:54
          0x20001cb8 0x0801604c main
                     @ /System/Volumes/Data/work/git/hubris/task/idle/src/main.rs:13
          0x20001cb8 0x08016030 _start
                     @ /System/Volumes/Data/work/git/hubris/sys/userlib/src/lib.rs:1219

I am going to get the Humility side of this fixed, but I would like to see the Cortex-M0+ support integrated into Hubris. (I have some minor delta on this to allow for semihosting to only be used for panicking; I will submit that as a PR to your fork.)

Thank you for all of your work on both the M0+ and RISC-V!

@cbiffle
Copy link
Contributor

cbiffle commented Jan 17, 2022

Eventually we'll want to add support for the M0+ MTB (micro trace buffer), which is much closer to the ETM-replacement on the STM32H7 and is a lot more suited to Humility than ITM. However, neither the STM32G0 under discussion here, nor the STM32L0 I have, appear to have implemented MTB, rendering it somewhat moot. :-(

bcantrill added a commit that referenced this issue Jan 18, 2022
This work contains work done as part of Gimlet bringup, including Idol
support for Humility.  Improvements:

- Incorporation of Idol support in Humility, allowing for both
  programmatic and command line interface calls of Idol-specified
  operations.  See "humility hiffy" documentation for details.

- Addition of a new "humility sensors" command that consumes data from
  the Hubris `sensor` task (if present).

- Addition of a new "humility dashboard" command that consumes sensor
  data and provides a single captive, graphical interface showing
  sensor values over time.

- Fixes a bevy of issues around Cortex-M0+; see #72 for details.

- Fixes #52 to clarify that "humility itm" really needs an archive --
  and documented "humility itm" to indicate that it really shouldn't
  be used unless absolutely necessary.

- Add the ability for "humility rencm" to process output gleaned from
  running Renesas configuration software

- Some refactoring and additional command documentation
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants