* Track down the I²C lag. The "- 0" markers are the number of milliseconds a log output to serial took, so also convienently show when the log did its output to serial. It doesn't seem like logging is the problem here. Each write -> stopped is sub-milliscend, but write -> write has a millisecond lag. But the weirdest thing is the "i2c data" bit, which is where the main loop has pulled the I²C data from its ring bufffer. From previous logs (not shown) the time at the end of pulling from the ring buffer is the same at the start. So somewhere there's at least 1ms being lost between the stopped event and the start of the main loop. This may need to wait for a logic analyzer to get more accurate timings. In the mean-time we can add number-of-calls counters and time-inside logs from interrupt handlers that we can dump every second or so to try and figure out where the clock cycles are going. #+BEGIN [0] TRACE ble::rtc -- setting up clock [0] TRACE ble::rtc -- set prescaler! [0] INFO ble::uarte1 -- setting up dma: p: 20000008, maxcnt: 128 [0] INFO ble::uarte1 -- rxstarted - 0[2] INFO ble -- - 0Bootstrap complete. - 0 [11121] TRACE ble::i2c -- i²c write [11121] TRACE ble::i2c -- write done [11121] TRACE ble::i2c -- i²c stopped: 2 - 0[11122] TRACE ble::i2c -- i²c write [11122] TRACE ble::i2c -- write done [11122] TRACE ble::i2c -- i²c stopped: 8 - 0[11125] INFO ble -- i2c data - 0[11138] TRACE ble::i2c -- i²c write [11138] TRACE ble::i2c -- write done [11138] TRACE ble::i2c -- i²c stopped: 2 - 0[11139] TRACE ble::i2c -- i²c write [11139] TRACE ble::i2c -- write done [11139] TRACE ble::i2c -- i²c stopped: 8 - 0[11141] INFO ble -- - 0i2c data - 0 #+END * Maybe swap from UARTE1 to UART for trinket transmission. It's very difficult to get stuff out of the UARTE until its DMA buffer is full, but the trinket is sending us logs of variable sizes that we'd like to see immediately. UART0 and UARTE0 share the same address. I don't see a UART1 instance. Maybe send console logs on UARTE1 and use UART0 for trinket serial comms?