Cosmo SP "disappeared"

[rmustacc]

We had an issue where a Rev A Cosmo, BRM22250001, SP basically seemed to disappear after being up for some time. This was in a rack context so there was no way to get probes on it. Here were the observations that we made:

• Fans had spun up to a constant, elevated level that was not commiserate with the I/O workload going on. This was based on the fact that we had a few other Cosmo systems in the same environment. Whether this was a fixed elevated rate or the MAX31790 is unknown.
• The host OS remained up and operational during this time. There was on degradation in host performance for the network stress test that we were performing at that time.
• The device did not reply to any IPCC activity. I issued a basic IPCC ident command.
• The SP was not broadcasting any beacons on the management network.
• We went a step further and confirmed on both switch ports that the link was up and that the counters for data transmitted by the SP did not increase at all.

Unfortunately due to being in a rack environment we don't have any additional information about what happened. This is here for tracking and to see if we see similar failure modes again.

[leftwo]

This was seen again on another cosmo, BRM13250010, that was in cubby 2.
The host itself is up and functioning. I'm able to log into it with pilot.

The SP appears to be gone:

root@oxz_switch0:~# pilot sp ls -x
CUBBY SERIAL      TYPE    IMAGE            IP
0     BRM13250012 cosmo   b0324ed49586f601 fe80::aa40:25ff:fe04:402
1     BRM22250001 cosmo   b0324ed49586f601 fe80::aa40:25ff:fe04:c86
2     -           -       -                -
3     BRM15250002 cosmo   b0324ed49586f601 fe80::aa40:25ff:fe04:2c0
4     -           -       -                -
5     -           -       -                -
6     -           -       -                -
7     BRM27230045 gimlet  019e78cae54ab58c fe80::aa40:25ff:fe04:6c6
8     BRM44220011 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:3c5
9     BRM44220005 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:347
10    BRM42220009 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:3c4
11    BRM42220006 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:181
12    BRM42220057 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:383
13    BRM42220018 gimlet  063400b416b53c88 fe80::aa40:25ff:fe04:1c1
14    BRM42220051 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:185
15    -           -       -                -
16    BRM42220014 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:342
17    BRM42220017 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:182
18    -           -       -                -
19    -           -       -                -
20    -           -       -                -
21    BRM42220031 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:343
22    -           -       -                -
23    BRM42220016 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:385
24    -           -       -                -
25    BRM44220010 gimlet  387887d734554d7f fe80::aa40:25ff:fe04:344
26    -           -       -                -
27    -           -       -                -
28    -           -       -                -
29    -           -       -                -
30    -           -       -                -
31    -           -       -                -
-     BRM44220012 sidecar 0f48d885c5b2a178 fe80::aa40:25ff:fe05:0
-     BRM44220008 sidecar 0f48d885c5b2a178 fe80::aa40:25ff:fe05:401
-     BRM45220004 psc     fca10e319039e017 fe80::aa40:25ff:fe06:107

Packets do not appear to be moving:

root@oxz_switch0:~# faux-mgs --interface=sidecar0 component-details monorail | grep "port: 15"
Jul 17 15:20:23.827 INFO creating SP handle on interface sidecar0, component: faux-mgs
Jul 17 15:20:23.828 INFO initial discovery complete, addr: [fe80::aa40:25ff:fe05:0%78]:11111, interface: sidecar0, socket: control-plane-agent, component: faux-mgs
PortStatus(Ok(PortStatus { port: 15, cfg: PortConfig { mode: Sgmii(Speed100M), dev: (Dev2g5, 7), serdes: (Serdes6g, 7) }, link_status: Up, phy_status: None, counters: PortCounters { rx: PacketCount { multicast: 48696, unicast: 20015891, broadcast: 0 }, tx: PacketCount { multicast: 31650920, unicast: 3257, broadcast: 0 }, link_down_sticky: true, phy_link_down_sticky: false } }))
root@oxz_switch0:~# faux-mgs --interface=sidecar0 component-details monorail | grep "port: 15"
Jul 17 15:20:26.786 INFO creating SP handle on interface sidecar0, component: faux-mgs
Jul 17 15:20:26.787 INFO initial discovery complete, addr: [fe80::aa40:25ff:fe05:0%78]:11111, interface: sidecar0, socket: control-plane-agent, component: faux-mgs
PortStatus(Ok(PortStatus { port: 15, cfg: PortConfig { mode: Sgmii(Speed100M), dev: (Dev2g5, 7), serdes: (Serdes6g, 7) }, link_status: Up, phy_status: None, counters: PortCounters { rx: PacketCount { multicast: 48696, unicast: 20015891, broadcast: 0 }, tx: PacketCount { multicast: 31650978, unicast: 3257, broadcast: 0 }, link_down_sticky: true, phy_link_down_sticky: false } }))

From the host, this ipcc command hangs:

BRM13250010 # /usr/platform/oxide/bin/ipcc ident

[mkeeter]

We tested with 32d0f37 overnight on Thursday-Friday (7/17-18). This commit includes two changes:

• Tasks are clamped to restart no faster than 20 Hz
• The chassis LED is flashed (by user_leds), instead of being statically on

Overnight, one machine hit the SP stall; a second machine stalled midday. One machine stopped with the LED on, and the other with the LED off. This tells us that the SP hasn't been reset (because it's still holding the chassis LED GPIO line), and that V3P3_SYS_A2 and V5P0_SYS_A2 are both still good.

It's surprising that the LEDs stopped flashing: user_leds is at priority 2, and the kernel will run it when its timer notification fires (even if a higher-priority task is in a spin loop). Equal-or-higher priority tasks are hash_driver (also priority 2), sys and packrat (both priority 1), and jefe (supervisor, priority 0). We could try rearranging things so that user_leds is the only task at priority 2, moving packrat and hash_driver above it.

One theory was a stack overflow in the kernel, which is hard to detect and produces a hard fault. We noticed that the STM32H7 does not actually hook the HardFault handler, instead falling back to the handler in cortex_m_rt. Artificially lowering kernel stack size produced a full-system lockup on the bench. However, I experimented with stack watermarks (96b2ce0), and found that Cosmo has 512 bytes of stack margin, which seems generous. It's possible that a different hard fault is responsible for locking up the CPU, and Laura has staged debug tools in #2163

Before testing Laura's stuff, we wanted to try moving LED flashing into the kernel's SysTick interrupt (f7699d0). The idea here was to see whether the kernel was still running. Unfortunately, this has stubbornly refused to hang after 72+ hours. I don't understand why this would have fixed things!

[mkeeter]

Here's the diff (removing changes to non-cosmo files):

diff --git a/Cargo.lock b/Cargo.lock
index 123cc241df..4c8a0debfd 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -3484,6 +3484,7 @@
  "ron",
  "serde",
  "ssmarshal",
+ "stm32h7",
  "syn 2.0.98",
  "unwrap-lite",
  "zerocopy 0.8.25",
diff --git a/app/cosmo/Cargo.toml b/app/cosmo/Cargo.toml
index 0114246070..566e798806 100644
--- a/app/cosmo/Cargo.toml
+++ b/app/cosmo/Cargo.toml
@@ -7,6 +7,7 @@
 [features]
 traptrace = ["ringbuf"]
 dump = ["kern/dump"]
+kern-debug-led = ["kern/debug-led-pc6"]
 
 [dependencies]
 cortex-m = { workspace = true }
diff --git a/app/cosmo/base.toml b/app/cosmo/base.toml
index c6dd4a311c..fc58f69d4d 100644
--- a/app/cosmo/base.toml
+++ b/app/cosmo/base.toml
@@ -7,7 +7,7 @@
 [kernel]
 name = "cosmo"
 requires = {flash = 32768, ram = 8192}
-features = ["dump"]
+features = ["dump", "kern-debug-led"]
 
 [mmio]
 peripheral-region = "fmc_nor_psram_bank_1"
diff --git a/sys/kern/Cargo.toml b/sys/kern/Cargo.toml
index 89074e8e13..0222199207 100644
--- a/sys/kern/Cargo.toml
+++ b/sys/kern/Cargo.toml
@@ -10,6 +10,7 @@
 cortex-m = { workspace = true }
 serde = { workspace = true }
 ssmarshal = { workspace = true }
+stm32h7 = { workspace = true, optional = true }
 zerocopy = { workspace = true }
 zerocopy-derive = { workspace = true }
 
@@ -37,6 +38,7 @@
 [features]
 dump = []
 nano = []
+debug-led-pc6 = ["dep:stm32h7"]
 
 [lib]
 test = false
diff --git a/sys/kern/src/arch/arm_m.rs b/sys/kern/src/arch/arm_m.rs
index b00a516ab7..7a1e18837f 100644
--- a/sys/kern/src/arch/arm_m.rs
+++ b/sys/kern/src/arch/arm_m.rs
@@ -1044,6 +1044,17 @@
         let t0 = TICKS[0].load(Ordering::Relaxed);
         let t1 = TICKS[1].load(Ordering::Relaxed);
 
+        #[cfg(feature = "debug-led-pc6")]
+        if t0 % 500 == 0 {
+            let gpioc = unsafe { &*stm32h7::stm32h753::GPIOC::ptr() };
+            gpioc.moder.modify(|_, w| w.moder6().output());
+            if (t0 / 500) & 1 == 0 {
+                gpioc.odr.modify(|_, w| w.odr6().high());
+            } else {
+                gpioc.odr.modify(|_, w| w.odr6().low());
+            }
+        }
+
         // Advance the kernel's notion of time by adding 1. Laboriously.
         let (t0, t1) = if let Some(t0p) = t0.checked_add(1) {
             // Incrementing t0 did not roll over, no need to update t1.

With the added code, SysTick looks like this:

08003e68 <SysTick>:
 8003e68:   b5f0        push    {r4, r5, r6, r7, lr}
 8003e6a:   af03        add r7, sp, #12
 8003e6c:   e92d 0ff8   stmdb   sp!, {r3, r4, r5, r6, r7, r8, r9, sl, fp}
 8003e70:   4d3b        ldr r5, [pc, #236]  ; (8003f60 <SysTick+0xf8>)
 8003e72:   2101        movs    r1, #1
 8003e74:   e8d5 0f4f   ldrexb  r0, [r5]
 8003e78:   e8c5 1f42   strexb  r2, r1, [r5]
 8003e7c:   2a00        cmp r2, #0
 8003e7e:   d1f9        bne.n   8003e74 <SysTick+0xc>
 8003e80:   2800        cmp r0, #0
 8003e82:   f3bf 8f5f   dmb sy
 8003e86:   d165        bne.n   8003f54 <SysTick+0xec>
 8003e88:   4836        ldr r0, [pc, #216]  ; (8003f64 <SysTick+0xfc>)
 8003e8a:   f44f 73fa   mov.w   r3, #500    ; 0x1f4
 8003e8e:   6881        ldr r1, [r0, #8]
 8003e90:   f8d0 a00c   ldr.w   sl, [r0, #12]
 8003e94:   fbb1 f2f3   udiv    r2, r1, r3
 8003e98:   fb02 1313   mls r3, r2, r3, r1
 8003e9c:   b95b        cbnz    r3, 8003eb6 <SysTick+0x4e>
 8003e9e:   4b32        ldr r3, [pc, #200]  ; (8003f68 <SysTick+0x100>)
 8003ea0:   2601        movs    r6, #1
 8003ea2:   681c        ldr r4, [r3, #0]
 8003ea4:   f366 340d   bfi r4, r6, #12, #2
 8003ea8:   601c        str r4, [r3, #0]
 8003eaa:   695c        ldr r4, [r3, #20]
 8003eac:   f362 1486   bfi r4, r2, #6, #1
 8003eb0:   f084 0240   eor.w   r2, r4, #64 ; 0x40
 8003eb4:   615a        str r2, [r3, #20]

I don't see any changes in the prelude versus the old version; we're still saving the same set of registers. Here's the beginning of the version without LED blinking, which is the same other than different offsets.

08003e68 <SysTick>:
 8003e68:   b5f0        push    {r4, r5, r6, r7, lr}
 8003e6a:   af03        add r7, sp, #12
 8003e6c:   e92d 0ff8   stmdb   sp!, {r3, r4, r5, r6, r7, r8, r9, sl, fp}
 8003e70:   4d31        ldr r5, [pc, #196]  ; (8003f38 <SysTick+0xd0>)
 8003e72:   2101        movs    r1, #1
 8003e74:   e8d5 0f4f   ldrexb  r0, [r5]
 8003e78:   e8c5 1f42   strexb  r2, r1, [r5]
 8003e7c:   2a00        cmp r2, #0
 8003e7e:   d1f9        bne.n   8003e74 <SysTick+0xc>
 8003e80:   2800        cmp r0, #0
 8003e82:   f3bf 8f5f   dmb sy
 8003e86:   d152        bne.n   8003f2e <SysTick+0xc6>
 8003e88:   482c        ldr r0, [pc, #176]  ; (8003f3c <SysTick+0xd4>)

[mkeeter]

Thanks to Alan and Bryan, we have reverted to the 32d0f37 and attached a debugger to BRM22250001.

Now, we wait...

matt@alfred ~ () $ pfexec humility -p1fc9:0143:4ZQNLXC4KLURU -a /staff/dock/rack2/cosmo/sp-image/build-cosmo-a-dev-32d0f376.zip tasks
humility: attached to 1fc9:0143:4ZQNLXC4KLURU via CMSIS-DAP
system time = 482909
ID TASK                       GEN PRI STATE
 0 jefe                         0   0 recv, notif: fault timer(T+91)
 1 net                          0   5 recv, notif: eth-irq(irq61) wake-timer(T+447)
 2 sys                          0   1 recv, notif: exti-wildcard-irq(irq6/irq7/irq8/irq9/irq10/irq23/irq40)
 3 spi2_driver                  0   3 recv
 4 spi3_driver                  0   3 recv
 5 i2c_driver                   0   3 recv
 6 packrat                      0   1 recv
 7 thermal                      0   8 recv, notif: timer(T+430)
 8 power                        0   8 recv, notif: timer(T+720)
 9 hiffy                        0   7 notif: bit31(T+231)
10 cosmo_seq                    0   7 recv, notif: timer(T+4)
11 ignition_flash               0   7 recv
12 spartan7_loader              0   4 recv
13 hash_driver                  0   2 recv
14 hf                           0   6 recv, notif: timer
15 update_server                0   3 recv
16 sensor                       0   4 recv
17 host_sp_comms                0   9 recv, notif: jefe-state-change usart-irq(irq71) multitimer control-plane-agent
18 udpecho                      0   6 notif: socket
19 udpbroadcast                 0   6 notif: bit31(T+387)
20 control_plane_agent          0   8 recv, notif: usart-irq(irq37) socket timer
21 sprot                        0   4 recv
22 validate                     0   5 recv
23 vpd                          0   4 recv
24 user_leds                    0   2 recv, notif: timer(T+95)
25 dump_agent                   0   6 recv, notif: socket
26 spd                          0   7 recv, notif: timer(T+248)
27 auxflash                     0   3 recv
28 idle                         0  15 RUNNING
29 udprpc                       0   6 notif: socket
30 fmc_demo                     0   6 recv, notif: socket

This is also available as the cosmo-rack2-debug Humility target.

[leftwo]

After running for ~24 hours, Cosmo 0, BRM13250012 lost the SP at Tue Jul 22 07:27:45 UTC 2025
The other three Cosmo sleds continued to operate as normal.

[leftwo]

After running for ~20 hours, Cosmo 0, BRM13250012, lost the SP at Wed Jul 23 05:02:25 UTC 2025,
That was maybe 20 hours after starting.
The other three Cosmo sleds continued to operate as normal.