`transceivers` / QSFP FPGA hang on Berlin Sidecar

In the Berlin environment, we noticed that the host couldn't get MAC addresses from the SP on switch1 (BRM42220082 is the relevant scrimlet).

After a few false leads, it turned out that we could talk to control-plane-agent fine, but transceivers (which reports MAC addresses to the host) was stuck.

Sampling a few times, we appear to be stuck in this loop:

root@oxz_switch1:~# /tmp/humility-0.12.0-probless --archive /tmp/21f65cb23eaacf2a847f905cd443daf05d85ef6717a255ef28ae0cef23a99432.switch_sp-sidecar-c-1.0.37.tar.gz --ip fe80::aa40:25ff:fe05:1f00%sidecar0 tasks -sl transceivers
humility: connecting to fe80::aa40:25ff:fe05:1f00%38
humility: reading tasks remotely; state may not be consistent
system time = unavailable-via-net
ID TASK                       GEN PRI STATE
16 transceivers                 0   6 notif: bit31(T=93631248)
   |
   +--->  0x2404c7c8 0x0807f9dc userlib::sys_recv_stub
                     @ /hubris/sys/userlib/src/lib.rs:368
          0x2404c810 0x0807fa64 userlib::sys_get_timer
                     @ /hubris/sys/userlib/src/lib.rs:1130
          0x2404c810 0x0807fa3c userlib::hl::sleep_until
                     @ /hubris/sys/userlib/src/hl.rs:425
          0x2404c810 0x0807fa64 userlib::hl::sleep_for
                     @ /hubris/sys/userlib/src/hl.rs:459
          0x2404c840 0x080784b2 drv_sidecar_front_io::transceivers::Transceivers::get_i2c_status_and_read_buffer
          0x2404d000 0x0807c4f8 <core::result::Result<T,E> as core::ops::try_trait::Try>::branch
                     @ /rustc/c52c23b6f44cd19718721a5e3b2eeb169e9c96ff/library/core/src/result.rs:1985
          0x2404d000 0x0807c4f8 main
                     @ /hubris/drv/transceivers-server/src/main.rs:619

root@oxz_switch1:~# /tmp/humility-0.12.0-probless --archive /tmp/21f65cb23eaacf2a847f905cd443daf05d85ef6717a255ef28ae0cef23a99432.switch_sp-sidecar-c-1.0.37.tar.gz --ip fe80::aa40:25ff:fe05:1f00%sidecar0 tasks -sl transceivers
humility: connecting to fe80::aa40:25ff:fe05:1f00%38
humility: reading tasks remotely; state may not be consistent
system time = unavailable-via-net
ID TASK                       GEN PRI STATE
16 transceivers                 0   6 notif: bit31(T=93710054)
   |
   +--->  0x2404c7c8 0x0807f9dc userlib::sys_recv_stub
                     @ /hubris/sys/userlib/src/lib.rs:368
          0x2404c810 0x0807fa64 userlib::sys_get_timer
                     @ /hubris/sys/userlib/src/lib.rs:1130
          0x2404c810 0x0807fa3c userlib::hl::sleep_until
                     @ /hubris/sys/userlib/src/hl.rs:425
          0x2404c810 0x0807fa64 userlib::hl::sleep_for
                     @ /hubris/sys/userlib/src/hl.rs:459
          0x2404c840 0x080784b2 drv_sidecar_front_io::transceivers::Transceivers::get_i2c_status_and_read_buffer
          0x2404d000 0x0807c4f8 <core::result::Result<T,E> as core::ops::try_trait::Try>::branch
                     @ /rustc/c52c23b6f44cd19718721a5e3b2eeb169e9c96ff/library/core/src/result.rs:1985
          0x2404d000 0x0807c4f8 main
                     @ /hubris/drv/transceivers-server/src/main.rs:619

Looking at the FPGA task, we're repeating the same SPI message over and over:

root@oxz_switch1:~# /tmp/humility-0.12.0-probless --archive /tmp/21f65cb23eaacf2a847f905cd443daf05d85ef6717a255ef28ae0cef23a99432.switch_sp-sidecar-c-1.0.37.tar.gz --ip fe80::aa40:25ff:fe05:1f00%sidecar0 ringbuf ecp5_front_io
humility: connecting to fe80::aa40:25ff:fe05:1f00%38
humility: ring buffer drv_fpga_devices::ecp5::__RINGBUF in ecp5_front_io:
humility: ring buffer drv_fpga_server::__RINGBUF in ecp5_front_io:
humility: ring buffer drv_stm32h7_spi_server_core::__RINGBUF in ecp5_front_io:
   TOTAL VARIANT
283276834 WaitISR
191326918 Tx
191326918 Rx
47831753 Start(write)
46054995 Start(read)
 NDX LINE      GEN    COUNT PAYLOAD
  37  469    55120        1 Tx(0x0)
  38  533    55120        2 WaitISR(0x10012)
  39  503    55120        1 Rx(0x30)
  40  359    55120        1 Start(write, (0x3, 0x0))
  41  469    55120        1 Tx(0x1)
  42  469    55120        1 Tx(0x2)
  43  469    55120        1 Tx(0x8)
  44  533    55120        2 WaitISR(0x30012)
  45  503    55120        1 Rx(0x0)
  46  533    55120        1 WaitISR(0x20012)
  47  503    55120        1 Rx(0x0)
  48  533    55120        1 WaitISR(0x1301a)
  49  503    55120        1 Rx(0x0)
  50  359    55120        1 Start(read, (0x0, 0x1))
  51  469    55120        1 Tx(0x0)
  52  533    55120        2 WaitISR(0x10012)
  53  503    55120        1 Rx(0x30)
  54  359    55120        1 Start(write, (0x3, 0x0))
  55  469    55120        1 Tx(0x1)
  56  469    55120        1 Tx(0x2)
  57  469    55120        1 Tx(0x8)
  58  533    55120        2 WaitISR(0x30012)
  59  503    55120        2 Rx(0x0)
  60  533    55120        1 WaitISR(0x10012)
  61  503    55120        1 Rx(0x0)
  62  359    55120        1 Start(read, (0x0, 0x1))
  63  469    55120        1 Tx(0x0)
   0  533    55121        2 WaitISR(0x10012)
   1  503    55121        1 Rx(0x30)
   2  359    55121        1 Start(write, (0x3, 0x0))
   3  469    55121        1 Tx(0x1)
   4  469    55121        1 Tx(0x2)
   5  469    55121        1 Tx(0x8)
   6  533    55121        1 WaitISR(0x30012)
   7  533    55121        1 WaitISR(0x22017)
   8  503    55121        3 Rx(0x0)
   9  359    55121        1 Start(read, (0x0, 0x1))
  10  469    55121        1 Tx(0x0)
  11  533    55121        2 WaitISR(0x10012)
  12  503    55121        1 Rx(0x30)
  13  359    55121        1 Start(write, (0x3, 0x0))
  14  469    55121        1 Tx(0x1)
  15  469    55121        1 Tx(0x2)
  16  469    55121        1 Tx(0x8)
  17  533    55121        2 WaitISR(0x30012)
  18  503    55121        1 Rx(0x0)
  19  533    55121        1 WaitISR(0x22017)
  20  503    55121        2 Rx(0x0)
  21  359    55121        1 Start(read, (0x0, 0x1))
  22  469    55121        1 Tx(0x0)
  23  533    55121        2 WaitISR(0x10012)
  24  503    55121        1 Rx(0x30)
  25  359    55121        1 Start(write, (0x3, 0x0))
  26  469    55121        1 Tx(0x1)
  27  469    55121        1 Tx(0x2)
  28  469    55121        1 Tx(0x8)
  29  533    55121        2 WaitISR(0x30012)
  30  503    55121        2 Rx(0x0)
  31  533    55121        1 WaitISR(0x10012)
  32  503    55121        1 Rx(0x0)
  33  359    55121        1 Start(read, (0x0, 0x1))
  34  469    55121        1 Tx(0x0)
  35  533    55121        1 WaitISR(0x10012)
  36  503    55121        1 Rx(0x30)

We're sending [0x01, 0x02, 0x08] and receiving 0x30. The transmitted message is decoded as [ReadOp::Read, QSFP_PORT0_STATUS (0x208)], and the returned byte is BUSY | WDATA_FIFO_EMPTY.

Hubris could be more robust here, but it seems like the FPGA has gotten stuck, which isn't great. The hold on Berlin was extended through Monday, so it should still be like this when @Aaron-Hartwig gets back.