<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
</head>
<body>
<div class="moz-cite-prefix">Some news...</div>
<div class="moz-cite-prefix"><br>
</div>
<p>My issue was caused because of course I made a mistake with the
way of registering my metrics Listener.</p>
<p>I used the following code (see my previous post) in the
constructor:<br>
</p>
<p><font face="monospace"> +
MyMetrics.RegisterListener(IDTAG.c_str(), "*",
std::bind(&canlog::MetricListener, this, _1));</font></p>
<div class="moz-cite-prefix">and for the destructor:</div>
<div class="moz-cite-prefix"><font face="monospace"> +
MyMetrics.DeregisterListener(IDTAG.c_str());</font></div>
<div class="moz-cite-prefix"><font face="monospace"><br>
</font></div>
<div class="moz-cite-prefix">I had to use IDTAG because this class
has multiple instances.</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix">The issue is passing <font
face="monospace">IDTAG.c_str()</font> as a parameter ; because<font
face="monospace"> MyMetrics.RegisterListener</font> stores the
value of this <font face="monospace">const char* </font>parameter
and uses it 1) as an immutable parameter and 2) as a value.<br>
</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix">Of course this does not work with my
first way to call <font face="monospace">MyMetrics.RegisterListener</font>
:</div>
<div class="moz-cite-prefix">
<ul>
<li> the memory buffer returned by <font face="monospace">IDTAG.c_str()</font>
has no more existence after exiting the constructor, so this
lead to memory corruption.</li>
<li>when calling <font face="monospace">IDTAG.c_str()</font>
again in the destructor, there is absolutely no chance that
this <font face="monospace">c_str() </font>call returns the
same memory address as the call in the constructor, so the
value comparison will never work.<br>
</li>
</ul>
</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix">I rewrote the code this way by adding a
new member (<font face="monospace">m_idtag</font>) to the class:</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix"><font face="monospace">@
vehicle/OVMS.V3/components/can/src/canlog.cpp:352 @
canlog::canlog(const char* type, std::string format,
canformat::canformat_serve_<br>
m_dropcount = 0;<br>
m_filtercount = 0;<br>
<br>
+ m_idtag = strdup(IDTAG.c_str());<br>
+<br>
using std::placeholders::_1;<br>
using std::placeholders::_2;<br>
MyEvents.RegisterEvent(IDTAG, "*",
std::bind(&canlog::EventListener, this, _1, _2));<br>
+ if (NULL != m_idtag)<br>
+ {<br>
+ MyMetrics.RegisterListener(m_idtag, "*",
std::bind(&canlog::MetricListener, this, _1));<br>
+ }<br>
+ else<br>
+ {<br>
+ ESP_LOGE(TAG,"Cannot allocate memory - not registering
metrics listener");<br>
+ }<br>
<br>
int queuesize = MyConfig.GetParamValueInt("can",
"log.queuesize",100);<br>
m_queue = xQueueCreate(queuesize, sizeof(CAN_log_message_t));<br>
@ vehicle/OVMS.V3/components/can/src/canlog.cpp:374 @
canlog::canlog(const char* type, std::string format,
canformat::canformat_serve_<br>
canlog::~canlog()<br>
{<br>
MyEvents.DeregisterEvent(IDTAG);<br>
+ if (NULL != m_idtag)<br>
+ {<br>
+ MyMetrics.DeregisterListener(m_idtag);<br>
+ free((void*)m_idtag);<br>
+ }<br>
<br>
if (m_task)<br>
{</font></div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix">Another option is to change <font
face="monospace">MyMetrics.RegisterListener</font> so that it
store *a copy* of the parameter, and does string comparison
instead of a value comparison:</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix"><font face="monospace">modified:
vehicle/OVMS.V3/main/ovms_metrics.cpp<br>
────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────<br>
@ vehicle/OVMS.V3/main/ovms_metrics.cpp:1019 @ void
OvmsMetrics::RegisterListener(const char* caller, const char*
name, MetricC<br>
return;<br>
}<br>
<br>
+ const char * caller_copy = (const char *)strdup(caller);<br>
+<br>
+ if (NULL == caller_copy)<br>
+ {<br>
+ ESP_LOGE(TAG, "Problem registering metric %s for caller %s
- insufficient memory",name,caller);<br>
+ return;<br>
+ }<br>
+<br>
MetricCallbackList *ml = k->second;<br>
- ml->push_back(new MetricCallbackEntry(caller,callback));<br>
+ ml->push_back(new
MetricCallbackEntry(caller_copy,callback));<br>
}<br>
<br>
void OvmsMetrics::DeregisterListener(const char* caller)<br>
@ vehicle/OVMS.V3/main/ovms_metrics.cpp:1041 @ void
OvmsMetrics::DeregisterListener(const char* caller)<br>
while (itc!=ml->end())<br>
{<br>
MetricCallbackEntry* ec = *itc;<br>
- if (ec->m_caller == caller)<br>
+ if (strcmp(ec->m_caller, caller) == 0)<br>
{<br>
+ free((char *)ec->m_caller);<br>
itc = ml->erase(itc);<br>
delete ec;<br>
}</font></div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix">I've tested both approaches and they
both solve my issue : no more crashes and memory corruption.<br>
</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix">The second one is more "risky" (as it
potentially impacts everyone) but I think that it should not cause
much regression.</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix">Let me know what you think - should I
make a PR for this second approach ?<br>
</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix">Regards,<br>
</div>
<div class="moz-cite-prefix"><br>
</div>
<div class="moz-cite-prefix">Le 16/11/2022 à 22:45, Ludovic LANGE a
écrit :<br>
</div>
<blockquote type="cite"
cite="mid:3fd667f5-34b9-4928-2e4f-31ff5389d8ab@lange.nom.fr">
<meta http-equiv="content-type" content="text/html; charset=UTF-8">
<p>Dear list,</p>
<p>You may remember that I'm trying to enhance the "datalogger"
side of OVMS - in different ways.<br>
</p>
<p>One facet of this endeavour is to have (CAN) logs that also
incorporate other data coming from OVMS. In particular, I'd like
to have GNSS (GPS) data in the same log as my CAN data.<br>
</p>
<p>My first try is to slightly alter `<font face="monospace">canlog.cpp</font>`
and add the ability to `<font face="monospace">LogInfo</font>`
some chosen metrics, in the same spirit of the already logged
subset of events. (With CRTD format, it appears as comments)<br>
</p>
<p>While doing this, I'm facing multiple crashes that are somehow
strange:</p>
<ul>
<li>The crashes only occur when closing the logs (`<font
face="monospace">can log stop</font>`), never when logging<br>
</li>
<li>The cause of the crash is not always the same (<font
face="monospace">LoadProhibited</font>, <font
face="monospace">InstrFetchProhibited</font>)</li>
<li>Sometimes the PC is impacted / overwritten</li>
</ul>
<p>The crashes seems to always occur in a window of 20s after the
`<font face="monospace">can log stop</font>` command (In general
it's immediate, but sometime can take some more seconds).<br>
</p>
<p>(It lead me also to discover that the feature of our version of
esp-idf that resolves the memory addresses in the serial output
- `make monitor` - is broken, and that it's better to use GDB
for that)</p>
<p>While I am doing my homework and try to solve this, I wanted to
share it here also to see if you already encountered this and/or
if my changes are not done properly / not on the right OS task /
etc.... - for which I lack background and experience. (In the
process I think I found a non-freed variable, but it's not
causing my issue - cf
<a class="moz-txt-link-freetext"
href="https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/pull/774"
moz-do-not-send="true">https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/pull/774</a>
)<br>
</p>
<p>Here are the changes - you'll see that the crash do occur as
soon as I `<font face="monospace">LogInfo</font>` something -
after the log has been closed.<br>
</p>
<hr width="100%" size="2">
<p><font face="monospace">modified:
vehicle/OVMS.V3/components/can/src/canlog.cpp<br>
────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────<br>
@ vehicle/OVMS.V3/components/can/src/canlog.cpp:355 @
canlog::canlog(const char* type, std::string format,
canformat::canformat_serve_<br>
using std::placeholders::_1;<br>
using std::placeholders::_2;<br>
MyEvents.RegisterEvent(IDTAG, "*",
std::bind(&canlog::EventListener, this, _1, _2));<br>
+ MyMetrics.RegisterListener(IDTAG.c_str(), "*",
std::bind(&canlog::MetricListener, this, _1));<br>
<br>
int queuesize = MyConfig.GetParamValueInt("can",
"log.queuesize",100);<br>
m_queue = xQueueCreate(queuesize,
sizeof(CAN_log_message_t));<br>
@ vehicle/OVMS.V3/components/can/src/canlog.cpp:365 @
canlog::canlog(const char* type, std::string format,
canformat::canformat_serve_<br>
canlog::~canlog()<br>
{<br>
MyEvents.DeregisterEvent(IDTAG);<br>
+ MyMetrics.DeregisterListener(IDTAG.c_str());<br>
<br>
if (m_task)<br>
{<br>
@ vehicle/OVMS.V3/components/can/src/canlog.cpp:441 @ void
canlog::EventListener(std::string event, void* data)<br>
LogInfo(NULL, CAN_LogInfo_Event, event.c_str());<br>
}<br>
<br>
+void canlog::MetricListener(OvmsMetric* metric) {<br>
+ std::string name = metric->m_name;<br>
+ ESP_LOGI(TAG,"MetricListener - enter : %s",
name.c_str());<br>
+ if (startsWith(name, "v.p.gps") || (name == "v.p.latitude")
|| (name == "v.p.longitude") || (name == "v.p.altitude") ||
(name == "v.p.direction") || (name == "v.p.satcount") || (name
== "m.net.wifi.sq") || (name == "m.freeram")) {<br>
+ std::string metric_text = "metric: " + name;<br>
+ ESP_LOGI(TAG,"MetricListener - keep : %s",
metric_text.c_str());<br>
+ LogInfo(NULL, CAN_LogInfo_Event, metric_text.c_str());<br>
+ }<br>
+}<br>
+<br>
const char* canlog::GetType()<br>
{<br>
return m_type;</font></p>
<p><br>
</p>
<p>Note: <font face="monospace">"m.net.wifi.sq" / "m.freeram"</font>
are providing debugging data, so that I can quickly receive
metrics after the boot. Not what I'm interested in for the final
version of course, and the list will be configurable.<font
face="monospace"><br>
</font></p>
<hr width="100%" size="2">
<p>Here are some example of panic handler infos:</p>
<p><font face="monospace">Guru Meditation Error: Core 1 panic'ed
(LoadProhibited). Exception was unhandled.<br>
Core 1 register dump:<br>
PC : 0x400d95f8 PS : 0x00060830 A0 :
0x8030d32c A1 : 0x3ffc4980 <br>
A2 : 0x3ffeb5a8 A3 : 0x00000000 A4 :
0xfefefefe A5 : 0x3ffb5200 <br>
A6 : 0x3f805e78 A7 : 0x000000fe A8 :
0x800d95f0 A9 : 0x3ffc4930 <br>
A10 : 0x3ffeb5a8 A11 : 0x00000000 A12 :
0x00000009 A13 : 0x73c80b46 <br>
A14 : 0x3ffc4930 A15 : 0x3f8b4164 SAR :
0x00000004 EXCCAUSE: 0x0000001c <br>
EXCVADDR: 0xfefeff2e LBEG : 0x4008abe4 LEND :
0x4008ac00 LCOUNT : 0xffffffff <br>
<br>
ELF file SHA256: eb3e5ce8f67640c8<br>
<br>
Backtrace: 0x400d95f8:0x3ffc4980 0x4030d329:0x3ffc49e0
0x4012122d:0x3ffc4a00 0x40121296:0x3ffc4a60
0x40120e6e:0x3ffc4a80 0x400ede1f:0x3ffc4aa0
0x400eed41:0x3ffc4ae0 0x400ecdc9:0x3ffc4b00
0x4011c5b6:0x3ffc4b40 0x4011c7b6:0x3ffc4b70
0x4011c8d8:0x3ffc4be0 0x0<br>
</font></p>
<p><br>
</p>
<p><font face="monospace">0x400d95f8</font> is exactly the address
of the call to <font face="monospace">LogInfo</font> in my
changes:</p>
<p><font face="monospace">(gdb) list *0x400d95f8<br>
0x400d95f8 is in canlog::MetricListener(OvmsMetric*)
(vehicle/OVMS.V3/components/can/src/canlog.cpp:447).<br>
442 std::string name = metric->m_name;<br>
443 ESP_LOGI(TAG,"MetricListener - enter : %s",
name.c_str());<br>
444 if (startsWith(name, "v.p.gps") || (name ==
"v.p.latitude") || (name == "v.p.longitude") || (name ==
"v.p.altitude") || (name == "v.p.direction") || (name ==
"v.p.satcount") || (name == "m.net.wifi.sq") || (name ==
"m.freeram")) {<br>
445 std::string metric_text = "metric: " + name;<br>
446 ESP_LOGI(TAG,"MetricListener - keep : %s",
metric_text.c_str());<br>
<b>447 LogInfo(NULL, CAN_LogInfo_Event,
metric_text.c_str());</b><br>
448 }<br>
449 }<br>
450 <br>
<br>
</font></p>
<p>0xfefe / 0xfefefefe seems related to some of the Heap Memory
Debugging options I've activated (Cf
<a class="moz-txt-link-freetext"
href="https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-reference/system/heap_debug.html"
moz-do-not-send="true">https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-reference/system/heap_debug.html</a>
) and seems to indicate a possible use-after-free issue. I'll
look to debug in that direction.<br>
</p>
<p><br>
</p>
<p>Another version (before Heap Memory Debugging activated) did
that from time to time:<br>
</p>
<hr width="100%" size="2"><font face="monospace">Guru Meditation
Error: Core 0 panic'ed (InstrFetchProhibited). Exception was
unhandled.<br>
Core 0 register dump:<br>
PC : 0x00008100 PS : 0x00060530 A0 :
0x802f0cf0 A1 : 0x3ffd0f00 <br>
A2 : 0x3ffeb214 A3 : 0x00008100 A4 :
0x402f1df8 A5 : 0x00000000 <br>
A6 : 0x00000003 A7 : 0x3ffb556c A8 :
0x800d9540 A9 : 0x3ffd0ee0 <br>
A10 : 0x3ffeb214 A11 : 0x00000000 A12 :
0x00000009 A13 : 0x3f8b4a24 <br>
A14 : 0xffffffff A15 : 0x40404040 SAR :
0x00000018 EXCCAUSE: 0x00000014 <br>
EXCVADDR: 0x00008100 LBEG : 0x4008a848 LEND :
0x4008a864 LCOUNT : 0xffffffff <br>
<br>
ELF file SHA256: f4d0c43aa48ef759<br>
<br>
Backtrace: 0x00008100:0x3ffd0f00 0x402f0ced:0x3ffd0fb0
0x4011c56d:0x3ffd0fd0 0x4011c5c6:0x3ffd1020
0x4011c24a:0x3ffd1040 0x4014f51d:0x3ffd1060
0x4014f953:0x3ffd1080 0x4014e6e3:0x3ffd11d0
0x4014ef16:0x3ffd1210 0x4014f001:0x3ffd1230
0x4014f119:0x3ffd1260 0x4014e889:0x3ffd1290
0x4014e9ed:0x3ffd1310 0x4014ebf9:0x3ffd13f0</font><br>
<br>
<hr width="100%" size="2">
<p><br>
</p>
<p>Thanks for any hint or advices you may want to share.</p>
<p>Regards,<br>
</p>
<br>
<fieldset class="moz-mime-attachment-header"></fieldset>
<pre class="moz-quote-pre" wrap="">_______________________________________________
OvmsDev mailing list
<a class="moz-txt-link-abbreviated" href="mailto:OvmsDev@lists.openvehicles.com">OvmsDev@lists.openvehicles.com</a>
<a class="moz-txt-link-freetext" href="http://lists.openvehicles.com/mailman/listinfo/ovmsdev">http://lists.openvehicles.com/mailman/listinfo/ovmsdev</a>
</pre>
</blockquote>
<p><br>
</p>
<div id="grammalecte_menu_main_button_shadow_host" style="width:
0px; height: 0px;"></div>
</body>
</html>