Main loop and IntervalTimer stall for exactly 2^30 CPU cycles, every 2^32 cycles - systick keeps running

J

_jacek_

New member
On a Teensy 4.1 with 16 MB PSRAM, my program freezes for exactly 2^30 CPU cycles (1.789 s at 600 MHz), at intervals that are multiples of 2^32 CPU cycles (7.16 s at 600 MHz). During the stall the main loop and my IntervalTimer stop, but systick keeps counting. The stall lands in whatever code happens to be executing.
The 4:1 ratio between the interval and the stall length, and the fact that both scale exactly with the core clock, make me think this is tied to the 32-bit cycle counter rolling over - but I cannot find where.

The stall length is a fixed number of CPU cycles. Rebuilding at a different core clock scales it exactly:
600 MHz --> stall: 1 788 160 us --> 1.07290 x 10^9
528 MHz --> stall: 2 032 130 us --> 1.07296 x 10^9

Ratio of the two durations: 1.1364. Ratio of the two clocks: 600/528 = 1.1364. The cycle count is essentially 2^30 (1.0737 x 10^9), about 0.07% low.
The interval between stalls is 2^32 cycles or a multiple. Timestamps from two runs at 600 MHz, seconds since start:
run A: 19, 26, 33, 40, 47, 55, 69, 83, 105, 112, 126, 133, 140
run B: 12, 19, 26, 33, 40, 47, 69, 76, 105, 119, 126, 133, 140

Spacing is 7 s or multiples of 7 s. 2^32 / 600e6 = 7.158 s.
At 528 MHz the spacing becomes 8 s (2^32 / 528e6 = 8.133 s):
13, 21, 30, 38, 46, 54, 78, 86, 103, 111, 119, 127, 135, 143

Stall lengths come in multiples: 1.788 s, 3.577 s, occasionally 5.37 s - always an integer multiple of the same quantum.

systick keeps running, my IntervalTimer does not. I measure elapsed time with micros(), which is built on systick_millis_count, so if it reports 1.788 s then the systick ISR must have run ~1788 times. Meanwhile a counter incremented by my own 1 ms IntervalTimer advances only 40-160 times over the same interval.

Raising the IntervalTimer priority from 160 to 32 changed nothing, so this is not preemption by a higher-priority handler.

The stall lands anywhere. I instrumented several call sites; the long delay has been observed inside analogRead(), inside delayMicroseconds(20), and inside a routine decoding a 30x12 pixel sprite from valid data. There is no single function at fault.


Each of these was disabled or bypassed while the rest kept running, and the stalls continued unchanged:
- SD card - accumulated time inside _read is zero during stalls
- PSRAM - a dedicated stress test (64 blocks of 16-256 KB, allocate, free, write and scattered read every iteration, both chips) ran 5 h 40 min / 383 381 iterations with zero stalls, including with the SD card mounted and yield() called every iteration
- I2C touch controller - bus untouched
- ADC - averaging of 4 and 16 give an identical quantum; with analogRead() removed entirely the stall moves elsewhere
- Display - both with DMA (updateScreenAsync) and with blocking updateScreen(), and with transmission skipped entirely
- Audio library and MQS output - not initialised
- USB - stalls occur when powered from a charger with no host attached
- Power supply - no droop visible on a scope, a 4700 uF cap across 3.3 V changes nothing
- Temperature - hottest component on the board reads 36.4 C on a thermal camera

Disabling the audio path and display DMA together made stalls more frequent (every ~7 s instead of every few tens of seconds) and longer (mostly double quanta). That suggests interrupt sources were shortening the stalls rather than causing them.

Setup:
Teensy 4.1, 600 MHz, two IPS6404L PSRAM chips (16 MB), hand-soldered
PlatformIO, framework-arduinoteensy 1.162.0, GCC 15.2.1
-Os -flto -fno-strict-aliasing
Display: ILI9341 over SPI with DMA, 320x240 framebuffer in DMAMEM
SdFat over SDIO (built-in socket)
One IntervalTimer at 1 ms, priority 160
Audio library with AudioPlayQueue -> MQS
The application is a port of a 1990s DOS game; peak heap usage in PSRAM is 8.7 MB

I grepped the core and libraries for ARM_DWT_CYCCNT and every use I found follows the safe while (ARM_DWT_CYCCNT - begin < cycles) pattern. micros() in delay.c looks correct too - it clamps the fraction and uses unsigned subtraction.

Questions:
- Is there anything in the core, in SdFat, or in the FlexSPI/PSRAM support that would stop the main loop and PIT timers while leaving systick running, for a duration tied to the cycle counter?
- Could a PIT/GPT timer be gated or reloaded in a way that produces a 2^30-cycle gap?
- Has anyone seen stalls synchronised to the 32-bit cycle counter rollover on the i.MX RT1062?

Happy to run further tests - I have the board instrumented with per-stage timing and a set of compile-time switches to cut out each subsystem.
 
_jacek_ said:
Raising the IntervalTimer priority from 160 to 32 changed nothing, so this is not preemption by a higher-priority handler.
Click to expand...
Not necessarily. All of the IntervalTimers share the same interrupt.

It's not possible for the CPU to simply "stall" on an instruction while the clock is still running. Either something is tying it up or you're measuring the cycles incorrectly.
 
Thanks for advice - these are good points, especially about the shared PIT interrupt. I'll add a GPIO toggle in the main loop so I can watch it on a scope. Also I'll sample NVIC_IABR and IPSR from a GPT2 interrupt at priority 0, so if something is tying up the CPU I should see which handler is active.
 
Just to make sure I first answer the original question, there's nothing in the libraries which would be expected to cause this sort of perfectly sync'd 25% duty cycle stall. Many people have used those libraries in all sorts of ways, and indeed a wide variety of issues have come up (and by now the main libraries are quire mature), but over the nearly 7 years since Teensy 4.0 released, this is the first time I can recall hearing of a 2^30 cycle stall happening every 2^32 cycles.

My gut feeling is there's probably some software explanation for this stall. The hardware shouldn't have anything that causes such a stall.

But to talk of the hardware anyway, keep in mind not all clock cycles are created equal. PIT / IntervalTimer run from the peripheral clock, which defaults to 150 MHz. SysTick and ARM_DWT_CYCCNT run from the CPU clock, which defaults to 600 MHz. If you're thinking of everything running from the same clock, maybe this 4X difference in clock speeds has a role in the results you're seeing?

Maybe I'm a bit confused by your question, but I see names ARM_DWT_CYCCNT and "systick" mentioned perhaps interchangably. These are separate timers. Both run at CPU speed which defaults to 600 MHz. SysTick is a 24 bit timer that counts down (not incrementing), which by default is configured with automatic reload to a specific value when it reachs 0, so it causes an interrupt every 1 millisecond. That interrupt routine updates the software counter for millis() and other Arduino API time stuff.

ARM_DWT_CYCCNT is a 32 bit timer which counts up to 0xFFFFFFFF and automatically rolls over to 0. It does not have any interrupt capability. ARM_DWT_CYCCNT doesn't have any sort of configurable reload like SysTick does. ARM_DWT_CYCCNT always counts up to 0xFFFFFFFF.

Not sure if this hardware info helped, or just added more complexity?

Again, my gut feeling is something on the software side. These libraries are very mature, but who knows, maybe you've found a previously unknown issue? It could be anything. Disabling interrupts from within other interrupts when various libraries are called from those interrupts gives a lot of complex ways things can go wrong. If the problem really is within the libraries, I'm afraid the only viable path is shaving your program down to a minimum example which reproduce the issue, ideally with "known quantity" Arduino IDE rather than PlatformIO where everything can be configured differently.
 
Thank you — and let me start by correcting my own post, because two of the things I reported as ruled out were measured wrong.

"Audio library and MQS output — not initialised" was false. My switch only skipped my own init function. The Audio library objects are static, so their constructors ran at startup and the MQS DMA was active throughout. Every "no audio" test I reported was meaningless — which is exactly why they all came back "no change".

"systick vs ARM_DWT_CYCCNT" — you're right that I conflated them. To restate: elapsed time came from micros(), i.e. the SysTick-driven millisecond counter plus a cycle-counter fraction. The counter that stopped was my own 1 ms PIT IntervalTimer, on the 150 MHz peripheral clock. So the observation is: micros() advances normally through the stall while the PIT interrupt and the main loop do not.

Your point about the 4× clock ratio is well taken and I have not ruled it out. The 25% duty cycle may be an artifact of comparing counters on two different clocks rather than something real.

The stall itself is real, though. Following jmarsh's suggestion I toggled a GPIO in the main loop and watched it on a scope. It goes flat for the duration, so this isn't a micros() measurement artifact.

I sampled the interrupted PC from a GPT2 interrupt at priority 0, reading it out of the exception stack frame rather than IPSR (thanks jmarsh — IPSR would indeed have just shown GPT2).

During a stall the PC sits at a fixed address for hundreds of milliseconds, and NVIC_IABR shows one interrupt active besides my own GPT2. addr2line resolved it to AudioOutputMQS::isr().

So I replaced the Audio library with a minimal MQS driver of my own. The stalls got worse, not better — my driver had a misconfigured clock and was requesting DMA far too often. With the library restored, the picture went back to what it was. So the library is not at fault; the profiler was showing me where the stall catches the CPU, not what causes it.

Worth stating plainly, because it explains the contradictions in my earlier posts: this program moves data between three memories — ITCM, OCRAM2 and PSRAM — and several of my diagnostic switches changed which memory things landed in, not just whether a subsystem ran.

Turning off sound effects, for example, dropped peak PSRAM use from 8.7 MB to 2.6 MB and freed several kB of OCRAM2 heap. Two variables at once. Several of my "A doesn't matter" conclusions were drawn from tests like that.

I've since added a startup line that dumps every switch, so at least each log is self-documenting.

The one dependency that holds up
Allocations in PSRAM start at the bottom of the region. If I allocate a dummy block first, everything the game uses shifts upward. Same total usage, same configuration, only the addresses differ:

PSRAM dummy block sizeStalls in one intro run (1.8s)Double-length stalls (3.6 s)
none194
2 MB217
4 MB110
8 MB (low memory build)00

The 8 MB row is from a build with sound effects disabled, so it isn't directly comparable to the others — but a full intro, menu, save and load with no stalls at all was something I hadn't seen in days of testing.

This is not a clean threshold, which argues against a bad solder joint on one chip. It also doesn't match the stress test, which hammered both chips for almost 6 hours with zero stalls — but that test allocates one large region and never touches the small-allocation path.

I have observed a new symptom, which possibly is related to previous issues. With effect conversion disabled, the first extmem_malloc() the program makes never returns. The board sits there; a GPIO-toggle loop confirms the main loop is stopped. With effect conversion enabled — i.e. after PSRAM has already been used heavily — the same allocation succeeds.
I don't have an explanation yet, but it's the same subsystem the address dependency points at, so I'm chasing it before drawing any more conclusions.

I'll fix the hanging allocation first, then re-run the whole switch matrix now that each log records its own configuration. After that, a minimal Arduino IDE sketch as you suggested — I agree PlatformIO adds variables I can't fully account for.

Thanks for the hardware details. The note that ARM_DWT_CYCCNT has no interrupt capability and no configurable reload killed a hypothesis I was still carrying around.
 
I took a quick look at the code. There are indeed a few issues in startup.c (e.g., a missing “;” and an alignment problem with the MPU (!! see above)). I didn’t look into it any further.
 
I guess that narrows it down a bit - something is trying to access non-existent memory (with a non-faulting operation like pre-fetch, cache flush/invalidate, etc.) and it blocks the CPU until the FlexSPI memory access times out.
Changing the value of AHBBUSWAIT in FLEXSPI2_MCR1 would confirm it if it affects the "stall" duration.
 
Last edited:
Fixed. Thank you all - @Mcu32 for recognising it immediately and pointing at the old thread, @jmarsh for the FlexSPI timeout explanation, and @PaulStoffregen for the hardware details that ruled out several of my wrong guesses.

The cause was, that startup.c configures the MPU region for FlexSPI2 as 32 MB:
Code: 
SCB_MPU_RBAR = 0x70000000 | REGION(i++);  // FlexSPI2
SCB_MPU_RASR = MEM_CACHE_WBWA | READWRITE | NOEXEC | SIZE_32M;

My board has 16 MB of PSRAM. So everything from 0x71000000 to 0x71FFFFFF is marked accessible and cacheable, with nothing behind it.
The Cortex-M7 is free to speculatively prefetch anywhere inside a defined region. When it reaches past 0x71000000, FlexSPI2 gets a request no device answers, and the CPU stalls on the bus until the controller times out - exactly as jmarsh described.

To fix that I reprogrammed that one region at the top of setup(), before any PSRAM access, rather than editing the core:
Code: 
#define MPU_REGION_FLEXSPI2  9   /* counted from the order in startup.c */

__asm__ volatile ("dmb" ::: "memory");
SCB_MPU_CTRL = 0;

SCB_MPU_RBAR = 0x70000000
             | SCB_MPU_RBAR_REGION(MPU_REGION_FLEXSPI2)
             | SCB_MPU_RBAR_VALID;

SCB_MPU_RASR = SCB_MPU_RASR_TEX(1) | SCB_MPU_RASR_C | SCB_MPU_RASR_B
             | SCB_MPU_RASR_AP(3) | SCB_MPU_RASR_XN
             | SCB_MPU_RASR_SIZE(23)      /* 16 MB, not 32 */
             | SCB_MPU_RASR_ENABLE;

SCB_MPU_CTRL = SCB_MPU_CTRL_ENABLE;
__asm__ volatile ("dsb" ::: "memory");
__asm__ volatile ("isb" ::: "memory");

One hour of continuous play, no stalls. Before the change they came every few tens of seconds.

Why this took me so long - in case it helps someone else:
Every symptom pointed somewhere else, and each wrong trail looked convincing:
* The profiler pointed at whatever was running. Sampling the interrupted PC from a high-priority timer showed AudioOutputMQS::isr(), so I replaced the Audio library with my own MQS driver. Stalls got worse - my driver had a misconfigured clock. The profiler was showing me where the stall caught the CPU, not what caused it.
* Disabling subsystems one at a time never helped, because a speculative prefetch doesn't care what code is executing. Audio, display DMA, SD, touch, I2C, USB - each was ruled out individually, and each conclusion was correct and useless.
* -flto made half my measurements meaningless. Adding one Serial.println moved 39,250 bytes across 636 locations with an identical memory report. I spent a long time comparing builds that differed in ways I hadn't accounted for. If you're chasing something layout-sensitive, switch your diagnostic flags to runtime variables so the binary stays identical - that one change turned noise into a clean result for me.
* The ADC connection was real but indirect. analogRead() calls yield() while waiting for conversion. My game loop polls a joystick up to 10,000 times per second, so yield() ran that often, executing library code and vastly increasing the chance of a prefetch landing outside real memory. Disabling the ADC made stalls disappear entirely - which looked like the answer, and wasn't.
* It was episodic. Two consecutive runs of the same binary gave 7 stalls and 0. Single-run comparisons were worthless; I needed 20-minute runs before anything held up.

Diagnostics that actually were useful:
* GPIO toggled in the main loop, watched on a scope. Proved the stall was real and not a micros() artifact. Nothing else could have settled that.
* A ring buffer of markers with timestamps, instead of a single "where am I" variable. Detection lags the stall by tens of milliseconds, so a single variable is always overwritten by the time it is read.
* Sampling NVIC_IABR and the interrupted PC from a GPT2 interrupt at priority 0 - a separate peripheral, not sharing a vector with PIT.

Suggestion: would it be worth sizing the FlexSPI2 MPU region from external_psram_size in startup.c? Boards with 8 MB have 24 MB of phantom cacheable space, 16 MB boards have 16 MB of it, and the failure is silent - no fault, no CrashReport, just a CPU that stops for 1.79 s in an arbitrary place.

Happy to test a patch if anyone wants to put one together.
 
You must log in or register to reply here.
Back
Top