<!DOCTYPE html>
<html>
<head>
<meta http-equiv="content-type" content="text/html; charset=UTF-8">
</head>
<body>
Everyone,<br>
<br>
from the crash reports
(<a class="moz-txt-link-freetext" href="https://ovms.dexters-web.de/firmware/developer/">https://ovms.dexters-web.de/firmware/developer/</a>), most remaining
crashes seem to be caused by heap corruptions.<br>
<br>
Not all heap corruptions are easily detectable from the backtrace
analysis, and the component or action causing the corruption isn't
detectable at all that way. So I've added a debug option to enable a
regular heap integrity check ever 5 minutes, with the module sending
an alert notification when a corruption has been detected. Example:<br>
<br>
<blockquote type="cite"><font face="monospace">Heap corruption
detected; reboot advised ASAP!<br>
Please forward including task records and system log:<br>
<br>
CORRUPT HEAP: Bad tail at 0x3f8e44f0 owner 0x3ffea9bc. Expected
0xbaad5678 got 0xbaad5600</font><br>
</blockquote>
<br>
I also added a final heap integrity check to our crash handler, so
the crash debug records should now show exactly which crashes
occurred with a corrupted heap.<br>
<br>
In combination with the system log and the task log, that should
give us some more opportunities to narrow down the cause(s).<br>
<br>
I've also added task ownershop to the heap corruption report. Note,
this needs my latest additions to our esp-idf fork, so take care to
pull these before building.<br>
<br>
Be aware, task ownership of corrupted blocks doesn't necessarily
tell about the task doing the corruption. If the tail canary is
compromised, and no other block located before that block is
compromised, it *may* be that task doing the out of bounds write.
But it may also be a use after free of some previous owner. So take
task ownership with a grain of salt.<br>
<br>
The corruptions are most probably caused by some unclean shutdown of
a component or by an undetected race conditions within a shutdown
procedure. The heap seems to be stable on modules with standard
configurations and components not being started & shut down on a
regular base. The heap corruptions are especially present now with
Smart (SQ) vehicles -- as the Smart doesn't keep the 12V battery
charged from the main battery, most Smart users probably use the
power management to shut down Wifi and/or modem while parking.<br>
<br>
So our main focus should be on analysing what happens before the
corruption. Ask users reporting heap corruptions to provide their
system logs, and possibly also their task logs. To encourage
enabling these, I've added the config to the web UI
(Config→Notifications).<br>
<br>
<br>
Once you can reproduce (!) the corruption, heap tracing might
provide some more insight as to where exactly the corruption occurs.<br>
<br>
Heap tracing means recording all memory allocations and frees. This
adds a recording layer on top of the heap functions, so comes with
some cost, even when inactive. CPU overhead is low, but stack
overhead may be an issue, so I think we should not enable heap
tracing by default for now, but rather use a debug build
specifically in cases we think heap tracing might help.<br>
<br>
To enable heap tracing on some user device, I've reworked the
ESP-IDF heap tracing to enable remote execution and to also include
the task handles performing the allocations and deallocations.<br>
<br>
To enable heap tracing for a build:<br>
<br>
<blockquote type="cite">
<ul class="simple"
style="box-sizing: border-box; margin: 0px 0px 24px; padding: 0px; list-style: disc; line-height: 24px; color: rgb(64, 64, 64); font-family: Lato, proxima-nova, "Helvetica Neue", Arial, sans-serif; font-size: 16px; font-style: normal; font-variant-ligatures: normal; font-variant-caps: normal; font-weight: 400; letter-spacing: normal; orphans: 2; text-align: start; text-indent: 0px; text-transform: none; widows: 2; word-spacing: 0px; -webkit-text-stroke-width: 0px; white-space: normal; background-color: rgb(252, 252, 252); text-decoration-thickness: initial; text-decoration-style: initial; text-decoration-color: initial;">
<li
style="box-sizing: border-box; list-style: disc; margin-left: 24px;">Under<span> </span><code
class="docutils literal notranslate"
style="box-sizing: border-box; font-family: SFMono-Regular, Menlo, Monaco, Consolas, "Liberation Mono", "Courier New", Courier, monospace; font-size: 12px; white-space: nowrap; max-width: 100%; background: rgb(255, 255, 255); border: 1px solid rgb(225, 228, 229); padding: 2px 5px; color: rgb(231, 76, 60); overflow-x: auto;"><span
class="pre" style="box-sizing: border-box;">make</span><span> </span><span
class="pre" style="box-sizing: border-box;">menuconfig</span></code>,
navigate to<span> </span><code
class="docutils literal notranslate"
style="box-sizing: border-box; font-family: SFMono-Regular, Menlo, Monaco, Consolas, "Liberation Mono", "Courier New", Courier, monospace; font-size: 12px; white-space: nowrap; max-width: 100%; background: rgb(255, 255, 255); border: 1px solid rgb(225, 228, 229); padding: 2px 5px; color: rgb(231, 76, 60); overflow-x: auto;"><span
class="pre" style="box-sizing: border-box;">Component</span><span> </span><span
class="pre" style="box-sizing: border-box;">settings</span></code><span> </span>-><span> </span><code
class="docutils literal notranslate"
style="box-sizing: border-box; font-family: SFMono-Regular, Menlo, Monaco, Consolas, "Liberation Mono", "Courier New", Courier, monospace; font-size: 12px; white-space: nowrap; max-width: 100%; background: rgb(255, 255, 255); border: 1px solid rgb(225, 228, 229); padding: 2px 5px; color: rgb(231, 76, 60); overflow-x: auto;"><span
class="pre" style="box-sizing: border-box;">Heap</span><span> </span><span
class="pre" style="box-sizing: border-box;">Memory</span><span> </span><span
class="pre" style="box-sizing: border-box;">Debugging</span></code><span> </span>and
set<span> </span><a class="reference internal"
href="https://docs.espressif.com/projects/esp-idf/en/v3.3/api-reference/kconfig.html#config-heap-tracing"
style="box-sizing: border-box; color: rgb(41, 128, 185); text-decoration: none; cursor: pointer;"><span
class="std std-ref" style="box-sizing: border-box;">CONFIG_HEAP_TRACING</span></a>.</li>
</ul>
</blockquote>
<br>
There's also an option to set the number of stack backtrace frames.
Tracing with two frames is mostly useless in our (C++) context, as
it will normally only show some inner frames of the allocator. I've
tried raising that to 5, and got an immediate crash in the mdns
component. I assume raising the depth will need raising some stack
sizes. If you find a good compromise, please report.<br>
<br>
Heap tracing will work best in a reduced configuration. In normal
operation, my module fills a 500 records buffer within seconds. The
buffer is a FIFO, so will always contain the latest n allocations,
and the last entry in the dump is the newest one.<br>
<br>
Reduced example dump:<br>
<br>
<blockquote type="cite"><font face="monospace">OVMS# mod trace dump<br>
Heap tracing started/resumed at ccount 0x1c70b453 = logtime
19415<br>
1000 allocations trace (1000 entry buffer)<br>
258 bytes (@ 0x3fffb3a8) allocated CPU 1 task 0x3ffc92e8 ccount
0x89074e74 caller 0x4031d4f0:0x4031f553<br>
freed task 0x3ffc92e8 by 0x4031d514:0x4031f595<br>
201 bytes (@ 0x3f8e92f4) allocated CPU 1 task 0x3fff2290 ccount
0x89218bbc caller 0x40131b12:0x4014633c<br>
freed task 0x3fff2290 by 0x402c4634:0x402cb14d<br>
112 bytes (@ 0x3ffebc80) allocated CPU 1 task 0x3ffee918 ccount
0x8a25d47c caller 0x4029b455:0x4017a5dc<br>
freed task 0x3ffee918 by 0x4029b744:0x4017a5dc<br>
112 bytes (@ 0x3ffebc80) allocated CPU 1 task 0x3ffee918 ccount
0x8db89c40 caller 0x4029b455:0x4017a5dc<br>
freed task 0x3ffee918 by 0x4029b744:0x4017a5dc<br>
12 bytes (@ 0x3f85d0d4) allocated CPU 1 task 0x3ffdfcd0 ccount
0x8fccdfd8 caller 0x40131b12:0x4014633c<br>
freed task 0x3ffdfcd0 by 0x402c4634:0x401e0a04<br>
[…]<br>
12 bytes (@ 0x3f85d0d4) allocated CPU 1 task 0x3ffdfcd0 ccount
0x3cf429f4 caller 0x40131b12:0x4014633c<br>
freed task 0x3ffdfcd0 by 0x402c4634:0x401e0a04<br>
112 bytes (@ 0x3ffebc80) allocated CPU 1 task 0x3ffee918 ccount
0x3fe1a0bc caller 0x4029b455:0x4017a5dc<br>
229 bytes alive in trace (3/1000 allocations)<br>
total allocations 1207 total frees 3356<br>
(NB: Buffer has overflowed; so trace data is incomplete.)</font></blockquote>
<br>
"ccount" is the ESP32 CCOUNT register (CPU cycles), so provides an
orientation on when the allocation occurred.<br>
<br>
<br>
Some more basics on heap debugging are also covered here:
<a class="moz-txt-link-freetext" href="https://docs.espressif.com/projects/esp-idf/en/v3.3/api-reference/system/heap_debug.html">https://docs.espressif.com/projects/esp-idf/en/v3.3/api-reference/system/heap_debug.html</a><br>
<br>
Regards,<br>
Michael<br>
<br>
<pre class="moz-signature" cols="72">--
Michael Balzer * Am Rahmen 5 * D-58313 Herdecke
Fon 02330 9104094 * Handy 0176 20698926</pre>
</body>
</html>