topic Re: "PRINTF" SRAM Overhead/Stack Overflow in Kinetis Microcontrollers

"PRINTF" SRAM Overhead/Stack Overflow

myke_predko — Tue, 20 Apr 2021 19:43:17 GMT

I'm running my FreeRTOS (with USB CDC) development code on a FRDM-K22F and I've just started seeing something strange. To monitor operations, I periodically "PRINTF" (using the SDK library code) to put out a message. All works well when I run with MCUXpresso debug active.

If I stop the debugger (and optionally remove the USB Cable from the debug port of the Freedom board) which allows the code in the Freedom board continues executing until it encounters a "PRINTF" statement at which point it stops and indicates a Stack Overflow issue.

The "PRINTF" statements are typically only built into the code when I specify the pre-processor symbol SDK_DEBUGCONSOLE=0 and all "PRINTF" instances are surrounded by "#if" statements like:

#if (2 != SDK_DEBUGCONSOLE)
  PRINTF("Done");
#endif

When I remove the "PRINTF" statements by setting SDK_DEBUGCONSOLE=2 the application runs fine, no stack overflows detected regardless of whether or not it is connected to the development PC and whether or not debug is active.

So, I believe the problem is with the PRINTF statements. Now, I've increased the "configTOTAL_HEAP_SIZE" as well as the stack size for the first task that executes a "PRINT" statement but no joy. 25k is the total stacks size used by all the tasks and the total system heap is 36k.

I haven't checked running the code without MCUXpresso Debug active for a week or so, during which I've added a number of tasks and queues and a mutex along with increasing the total number of queues in FreeRTOSConfig.h. - but, as indicated, when MCUXpresso Debug is active, no issues or overflow detected/indicated. Along with that no task's stack is close to it's threshold.

Rather than pouding out different ideas, I'd thought I'd ask if anybody has any thoughts as to where I should look to understand this issue.

Thanx!

Re: "PRINTF" SRAM Overhead/Stack Overflow

ErichStyger — Wed, 21 Apr 2021 03:37:38 GMT

Hi @myke_predko ,

do you print to a serial port or are you using semihosting?

If using semihosting, be aware that without a debugger attached it will cause a hard fault to be handled by your semihosting hard fault handler. It will add to the MSP (interrupt stack) (see https://mcuoneclipse.com/2016/08/28/arm-cortex-m-interrupts-and-freertos-part-3/ if this is new to you). So I suggest to increase the interrupt stack space. In MCUXpresso you can do this in the linker settings (there is a setting for the Stack under 'managed linker script').

I hope this helps,

Erich

Re: "PRINTF" SRAM Overhead/Stack Overflow

myke_predko — Wed, 21 Apr 2021 04:33:19 GMT

Hi @ErichStyger

That's really helpful - I'm using semihosting and the default.

I was aware of the two stack architecture in the Cortex-M but I thought that the task stack (PSP) was used during interrupts and the MSP was used within FreeRTOS to avoid adding to the process's stack data (and also simplify restoring the process's context information).

When I take a look at "Properties"->"C/C++ Build"->"Settings"->"MCU Linker"->"Managed Linker Script" I see:

And when I roll over the "Default" for "Stack", I see:
"Actual size allocated: 4.0kB (0x1000)
Setting to any non-numeric value will result in Default"

Is this what you are suggesting that I change? If so, what value should I put in here?

Finally, any idea why this stack would now have a problem? Looking over the changes, I added:

ADC Interrupt Handler
2x Queues
1x Mutex

I wouldn't think that would significantly add to the amount of memory required by the MSP.

Again, many thanx,

myke

Re: "PRINTF" SRAM Overhead/Stack Overflow

ErichStyger — Wed, 21 Apr 2021 05:52:09 GMT

Hi @myke_predko ,

The PSP and the FreeRTOS stack space is used for the task (without the interrupt stacks). The interrupts are stacked on the MSP: so all variables and and pushed registers of the interrupts will end up on the MSP stack.

I'm not 100% positive if this is really your issue, but as using printf with semihosting without a debugger will trigger a hard fault on top of it, so this might be the thing. Although the hardfault handler itself (if using the one from the SDK) should not use much stack.

I recommend you check the interrupt stack size used with the Image Info:

It does not count in for the interrupt nesting (this is not something this view can account for), but if you know your interrupt priorities you should get an idea about the stack consumed.

And yes: that is the linker setting you showed responsible for the MSP stack size. 4k should be plenty, but who knows what your interrupts are doing?

The other thought I have: do you reset the MSP stack at scheduler start? The NXP SDK standard examples are doing this, and if you have some data present on the MSP stack this will be not good.

See https://mcuoneclipse.com/2019/01/20/freertos-how-to-end-and-restart-the-scheduler/ on that topic.

That's why I have added

configRESET_MSP

to FreeRTOS to configure this. So check if you reset it,e.g.

So depending on this you have more (or less) usage of the MSP.

I hope this helps,

Erich

Re: "PRINTF" SRAM Overhead/Stack Overflow

bobpaddock — Wed, 21 Apr 2021 17:30:23 GMT

There is a really obscure bug in printf that requires the stack to be aligned on 64 bit boundaries (8 bytes).
The bug usually shows itself when trying to print 64-bit numbers.

In most non-RTOS systems the stack is placed at the end of memory which would be on a 64 bit boundary, so the bug goes unnoticed.

Are all of the RTOS stacks on a 64 bit boundary?

[I edited this to correctly say 64-bit, not byte as when I initially posted.]

Re: "PRINTF" SRAM Overhead/Stack Overflow

myke_predko — Wed, 21 Apr 2021 17:11:30 GMT

Hi @bobpaddock

I just looked at the .map file for the current as well as past versions of code. The end of memory generally looks like below, noting that the it is aligned on a four byte (32 bit) boundary. I don't print (or even use) any 64 bit numbers.

.heap 0x0000000020006388 0x1000
0x0000000020006388 _pvHeapStart = .
0x0000000020007388 . = (. + _HeapSize)
*fill* 0x0000000020006388 0x1000 
0x0000000020007388 . = ALIGN (0x4)
0x0000000020007388 _pvHeapLimit = .
0x0000000000001000 _StackSize = 0x1000

.heap2stackfill
0x0000000020007388 0x1000
0x0000000020008388 . = (. + _StackSize)
*fill* 0x0000000020007388 0x1000

.stack 0x000000002000f000 0x0
0x000000002000f000 _vStackBase = .
0x000000002000f000 . = ALIGN (0x4)
0x0000000020010000 _vStackTop = (. + _StackSize)
0x0000000000000000 _image_start = LOADADDR (.text)
0x0000000000027120 _image_end = (LOADADDR (.data) + SIZEOF (.data))
0x0000000000027120 _image_size = (_image_end - _image_start)

Thank you for the comment.

Re: "PRINTF" SRAM Overhead/Stack Overflow

myke_predko — Wed, 21 Apr 2021 18:30:53 GMT

Hi @ErichStyger

I'm going to answer your post in two parts.

The first is on the MSP reset. In your screenshots, it looks like the first MSP set up is done in "prvPortStartFirstTask" which is called by the "xPortStartScheduler" method which was called by "vTaskStartScheduler".

Looking through the project source, other than the setup in "prvPortStartFirstTask", MSP isn't accessed except in the CMSIS library code.

I made the change to the code that you recommended in your reply:

With no change in the operating behaviour.

Next, I tried taking out the MSP reset in "prvPortStartFirstTask" all together (as discssed in your article):

With again no change in behaviour.

So, I'm restoring port.c (where "prvPortStartFirstTask" and the MSP setup/reset occurs) on the assumption that this isn't the issue.

Re: "PRINTF" SRAM Overhead/Stack Overflow

myke_predko — Wed, 21 Apr 2021 19:36:18 GMT

Hi @ErichStyger

Well no luck with changing the stack value - I doubled the "Default" value to 0x2000 (4k) and I get the same behaviour.

I looked at the Call Graph for a previous build (which works without any issues) and the only difference I can see is the "ADC_IRQHandler" which is in the new project and not in the old as you can see here:

I'm a bit surprised the ADC Handler has a call depth of 8 levels - I'm using the SDK code which appears to be fairly inefficient - right @mjbcswitzerland ?

So, any suggestions on what to look at next? Maybe I'm not changing the right Property?

Re: "PRINTF" SRAM Overhead/Stack Overflow

ErichStyger — Thu, 22 Apr 2021 04:29:34 GMT

Hi @myke_predko ,

can you share a picture of that ADC0 interrupt handler in the image info unfolded to see all the dependencies?

I'm wondering why it is not able to show the stack used unless it is implemented in assembly?

Erich

Re: "PRINTF" SRAM Overhead/Stack Overflow

ErichStyger — Thu, 22 Apr 2021 04:46:22 GMT

Hi @myke_predko ,

ok, I think it it was at least worth trying.

Erich

Re: "PRINTF" SRAM Overhead/Stack Overflow

myke_predko — Thu, 22 Apr 2021 04:51:32 GMT

Hi @ErichStyger

No worries. I'm always game to learn sometthing new as well as try different things.

myke

Re: "PRINTF" SRAM Overhead/Stack Overflow

ErichStyger — Thu, 22 Apr 2021 04:54:54 GMT

Hi @myke_predko ,

ok, just checked an example on my side (FRDM-K22F adc16 interrupt example from the SDK):

I get that huge call stack because of the assert and the associated printf().

Could it be that in your case the assert gets triggered? but only in the case it triggers the printf() would be executed. I would disable that assert to give it a try. Or replace it with a check turning on a LED if it fails,then you know if it is really that assert.

I hope this helps,

Erich

Re: "PRINTF" SRAM Overhead/Stack Overflow

myke_predko — Thu, 22 Apr 2021 05:01:58 GMT

@ErichStyger

Here's the interrupt handler:

and here's the sensor value variable declare:

So, as coded, up to eight interrupt sources can be used and stored in an array. I just looked at the assembly code (below) and I don't see anything that I would be extreme. I also followed the code through "ADC16_GetChannelConversionValue" and there is only one subroutine call in the method which means that the depth of this interrupt service routine should be "3" and not the "8" produced by the Call Graph (I guess I don't understand how it works).

ADC0_IRQHandler:
0000205c: push {r3, r4, r7, lr}
0000205e: add r7, sp, #0
62 adcpollConversionDoneFlag = TRUE;
00002060: ldr r3, [pc, #32] ; (0x2084 <ADC0_IRQHandler+40>)
00002062: movs r2, #1
00002064: str r2, [r3, #0]
64 adcpollSensorValue[adcpollActive] = ADC16_GetChannelConversionValue(ADC0_ADC16_BASE
00002066: ldr r3, [pc, #32] ; (0x2088 <ADC0_IRQHandler+44>)
00002068: ldr r4, [r3, #0]
0000206a: movs r1, #0
0000206c: ldr r0, [pc, #28] ; (0x208c <ADC0_IRQHandler+48>)
0000206e: bl 0x2030 <ADC16_GetChannelConversionValue>
00002072: mov r3, r0
00002074: ldr r2, [pc, #24] ; (0x2090 <ADC0_IRQHandler+52>)
00002076: str.w r3, [r2, r4, lsl #2]
879 __ASM volatile ("dsb 0xF":::"memory");
0000207a: dsb sy
880 }
0000207e: nop 
71 }
00002080: nop 
00002082: pop {r3, r4, r7, pc}
00002084: mvns r4, r4
00002086: subs r7, r7, #7
00002088: mvns r0, r5
0000208a: subs r7, r7, #7
0000208c: add sp, #0
0000208e: ands r3, r0
00002090: mvns r4, r0
00002092: subs r7, r7, #7

Thoughts or places where you see issues?

myke

Re: "PRINTF" SRAM Overhead/Stack Overflow

ErichStyger — Thu, 22 Apr 2021 05:08:22 GMT

Hi @myke_predko ,

the depth of this interrupt service routine should be "3" and not the "8" produced by the Call Graph (I guess I don't understand how it works).

It counts how many functions are called to the max and stacked up. Could you share the image as I did for that depth unfolded? Are there any printf() in it?

If it is as on my SDK example, the ADC16_GetChannelConversionValue adds up to the number of calls because of that assert in it.

Erich

Re: "PRINTF" SRAM Overhead/Stack Overflow

myke_predko — Thu, 22 Apr 2021 05:07:47 GMT

Hi @ErichStyger

So, other than the ADC value being stored in an array, our code is basically identical

I expanded the Call Graph and have the same results as you do.

When I check the assert, ChannelGroup is zero (ADC0) and FSL_FEATURE_ADC16_CONVERSION_CONTROL_COUNT is 2, so no issues with assert not being true.

myke

Re: "PRINTF" SRAM Overhead/Stack Overflow

ErichStyger — Thu, 22 Apr 2021 05:11:40 GMT

Hi @myke_predko ,

I would comment out that assert and give it a try if it makes a difference.

Erich

Re: "PRINTF" SRAM Overhead/Stack Overflow

myke_predko — Thu, 22 Apr 2021 05:13:06 GMT

@ErichStyger

Here is the Call Graph Fully Expanded.

No PRINTFs in it.

myke

Re: "PRINTF" SRAM Overhead/Stack Overflow

myke_predko — Thu, 22 Apr 2021 05:17:21 GMT

Hi @ErichStyger

I commented out the assert and tried it.

No differences in operation.

Re: "PRINTF" SRAM Overhead/Stack Overflow

ErichStyger — Thu, 22 Apr 2021 05:18:37 GMT

No PRINTFs in it.

Outsch! Even worse, you have file I/O in it (writing to a file) :-(.

Your assert must be pretty fancy

Erich

Re: "PRINTF" SRAM Overhead/Stack Overflow

ErichStyger — Thu, 22 Apr 2021 05:23:05 GMT

Hi @myke_predko ,

I would set the NDEBUG define in the project settings to disable all these asserts to see if it makes any difference. Your assert is very concerning to me: in case of a triggering it it most likely will immediately overflow any stack unless you have many KBytes available for it: doing File I/O is huge (both from stack usage and code size).

Just to be sure: you are running the 'debug' and not the 'release' version on the target, right?

Erich