WDT kicked off by OS_PRINTF

AgentSmithers
Posts: 162
Joined: Sat Apr 01, 2017 1:21 am
Contact:

WDT kicked off by OS_PRINTF

Postby AgentSmithers » Tue Mar 05, 2019 7:45 am

Hi Everyone! I am having quite a strange issue. I am getting the WDT kicked off when calling a function that transverses and calls itself drilling through nodes. About 20-30 times in on calling itself the function enter and then calls system_soft_wdt_feed to reset the WDT and then does a printf to display the address in SPI its reading, however for some reason at the address 70000 (where to starts) it gets to 702e0 (By incremented by sets of 4/8/12 each time) PrintF seems to trigger a WDT. It seems almost like there is a resource that is depleted that is stalling PrintF from returning correctly to print the same address it did 20-30 times before that successfully, Now if I replace it with any other printf function like one to just even display the heap it stops again on the first printf with a variable to fill in. Again, a resource issue more than the WDT? Anyone have any background on the Sysinterals of PrintF so I can narrow down the true issue?

Outlog


FreeHeap!: 21536
data : 0x3ffe8000 ~ 0x3ffe88a0, len: 2208
rodata: 0x3ffe88a0 ~ 0x3ffeebb0, len: 25360
bss : 0x3ffeebb0 ~ 0x3fff5be0, len: 28720
heap : 0x3fff5be0 ~ 0x3fffc000, len: 25632
[ReadSPItableCurrentElement] Reading @ 0x702b0
Completed and skipping 82
[ReadSPItableNextElement]
Binary len: 8
FreeHeap!: 21536
data : 0x3ffe8000 ~ 0x3ffe88a0, len: 2208
rodata: 0x3ffe88a0 ~ 0x3ffeebb0, len: 25360
bss : 0x3ffeebb0 ~ 0x3fff5be0, len: 28720
heap : 0x3fff5be0 ~ 0x3fffc000, len: 25632
[ReadSPItableCurrentElement] Reading @ 0x702bc
Completed and skipping 82
[ReadSPItableNextElement]
Binary len: 8
FreeHeap!: 21536
data : 0x3ffe8000 ~ 0x3ffe88a0, len: 2208
rodata: 0x3ffe88a0 ~ 0x3ffeebb0, len: 25360
bss : 0x3ffeebb0 ~ 0x3fff5be0, len: 28720
heap : 0x3fff5be0 ~ 0x3fffc000, len: 25632
[ReadSPItableCurrentElement] Reading @ 0x702c8
Completed and skipping 82
[ReadSPItableNextElement]
Binary len: 8
FreeHeap!: 21536
data : 0x3ffe8000 ~ 0x3ffe88a0, len: 2208
rodata: 0x3ffe88a0 ~ 0x3ffeebb0, len: 25360
bss : 0x3ffeebb0 ~ 0x3fff5be0, len: 28720
heap : 0x3fff5be0 ~ 0x3fffc000, len: 25632
[ReadSPItableCurrentElement] Reading @ 0x702d4
Completed and skipping 82
[ReadSPItableNextElement]
Binary len: 8
FreeHeap!: 21536
data : 0x3ffe8000 ~ 0x3ffe88a0, len: 2208
rodata: 0x3ffe88a0 ~ 0x3ffeebb0, len: 25360
bss : 0x3ffeebb0 ~ 0x3fff5be0, len: 28720
heap : 0x3fff5be0 ~ 0x3fffc000, len: 25632
[ReadSPItableCurrentElement] Reading @ 0x702e0
Completed and skipping 82
[ReadSPItableNextElement]
Binary len: 8
FreeHeap!: *After a moment HW WDT TRIGGERS on first OS_PRINTF


I even called ets_wdt_disable(); to disable the watch dog and it just sits and hangs on

os_printf("FreeHeap!: %u\r\n", system_get_free_heap_size());

This screams that its not a WDT issue from the normal perspective, It really makes me think it has to do with stack allocation. Howmany times I call one function into another.

[ReadSPItableNextElement]
[HowManyElementsInSPItable]
EOF! Returning 5
[ReadSPItableFirstElement]
[ReadSPItableCurrentElement] Reading @ 0x70004
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70010
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x7001c
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70028
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70034
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70040
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x7004c
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70058
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70064
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70070
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x7007c
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70088
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70094
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x700a0
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x700ac
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x700b8
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x700c4
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x700d0
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x700dc
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x700e8
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x700f4
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70100
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x7010c
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70118
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70124
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70130
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x7013c
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70148
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70154
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70160
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x7016c
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70178
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70184
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70190
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x7019c
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x701a8
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x701b4
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x701c0
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x701cc
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x701d8
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x701e4
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x701f0
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x701fc
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70208
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70214
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70220
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x7022c
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70238
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70244
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70250
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x7025c
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70268
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70274
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70280
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x7028c
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x70298
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x702a4
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x702b0
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x702bc
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x702c8
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x702d4
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x702e0
[ReadSPItableNextElement]
[ReadSPItableCurrentElement] Reading @ 0x


Even after it just sits there with the WDT disabled it never completes. Expected value it should of spit out was 0x702ec

AgentSmithers
Posts: 162
Joined: Sat Apr 01, 2017 1:21 am
Contact:

Re: WDT kicked off by OS_PRINTF

Postby AgentSmithers » Wed Mar 06, 2019 2:43 am

So in my function I only allocate one Variable with the char buffer[4] that remains open and called to itself will then allocate another 4 bytes at a time growing in size until the end of the stack is meet then everything is freed. The issue is coming a bit more clear now after adjusting the buffer from char buffer[4] to char buffer[20]/[40]/[1000] to determine if there is a memory issue and sure enough here are the crash addresses

4 0x702e0
20 0x7028c
40 0x7025c
1000 0x70058

As you can see the crashes are happening closer and closer to 0x70000 due to a memory issue and not a WDT. When PrintF gets invoked the internal system may be trying to allocate space to interpret the string passed and fails to do so, hangs, then the WDT kicks in giving a red herring that a timing issue is in play. The crapping thing is Get Free Heap is displaying 21456 the same number each time I call it within the nested function. I seem to be running out of memory but there are no system calls that I seem to know/have that can indicate how much I actually have left at runtime. Any feedback would be appreciated

PostScript: Anyone knows how to get our Stacksize for Local Var memory allocation, The Heap is for Global Vars correct? so the Heap technically should not adjust in this case but the stack should?

AgentSmithers
Posts: 162
Joined: Sat Apr 01, 2017 1:21 am
Contact:

Re: WDT kicked off by OS_PRINTF

Postby AgentSmithers » Fri Mar 08, 2019 12:28 am

To resolve this, avoid recursive functions. I had to craft a while loop to replace my function call with logic that would emulate the function call within the loop. Instead of the function being able to chunk out 60 or so in the work queue it was able to do several 100 before the chip's WDT actually kicked off (Not a memory allocation issue but a real timing issue).

Who is online

Users browsing this forum: Baidu [Spider] and 9 guests