<!DOCTYPE html>
<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
</head>
<body>
Michael,<br>
<br>
did you notice the Leaf is special in polling two buses (1 & 2)
by default? No other vehicle does that. Possibly some sort of
deadlock situation with interleaved bus responses?<br>
<br>
Any frame dropped is an indicator for something bad happening, as
that means there's already a rather long backlog = response
processing is too slow.<br>
<br>
On alerting when the queue grows, see `OvmsDuktape::EventScript()`
-- I added an alert there for this situation, when the Duktape queue
grows larger than 10 entries. But you probably should restrict the
actual log message creation e.g. using a modulo 10 check.<br>
<br>
Maybe Derek can provide a CAN log catching the specific overflow
case along with the system log? That should show which frames lead
to the processing delay.<br>
<br>
Regards,<br>
Michael<br>
<br>
<br>
<div class="moz-cite-prefix">Am 06.05.24 um 01:45 schrieb Michael
Geddes:<br>
</div>
<blockquote type="cite"
cite="mid:CAH0p7uJWJLQ_002yrpCmJGRUkzqE106VfVH=2o-NEUqgsTbGzw@mail.gmail.com">
<meta http-equiv="content-type" content="text/html; charset=UTF-8">
<div dir="ltr">
<div dir="auto">I realise that I was only using the standard
cable to test - which probably is not sufficient - I haven't
looked closely at how the Leaf OBD to Db9 cable is different
from standard.<br>
</div>
<div dir="auto"><br>
</div>
<div dir="auto">Ah, my bad out the queue length. We are
definitely queueing more messages though. From my log of
when the overflow happened, the poller was in state 0 which
means OFF - ie nothing was being sent!!</div>
<div dir="auto"><br>
</div>
<div dir="auto">I'll look at the TX message thing - opt in
sounds good - though it shouldn't be playing that much of a
part here as the TXs are infrequent in this case (or zero when
the leaf is off or driving) - On the ioniq 5 when I'm using
the HUD - I'm polling quite frequently - multiple times per
second and that seems to be fine!.</div>
<div dir="auto"><br>
</div>
<div dir="auto">I did find an issue with the throttling .. but
it would still mostly apply the throttling where it matters,
so again, it shouldn't be the problem (also, we aren't
transmitting in the leaf case).</div>
<div dir="auto">
<div dir="auto">
<div dir="auto"><br>
</div>
<div dir="auto">The change I made to the logging of RX
messages showed how many in a row were dropped... and it
was mostly 1 only in a run - which means even if it is a
short time between - that means that the drops are being
interleaved by at least one success!</div>
<div><br>
</div>
<div>Sooo.. I'm still wondering what is going on. Some
things I'm going to try:</div>
<div><br>
</div>
<div>* If the number of messages on the Can bus (coming in
through RX) means that the queue is slowly getting longer
and not quite catching up, then making the queue longer
will help it last longer... but only pushes the problem
down the road.</div>
<div> - Add 'current queue length' to the poller status
information to see if this is indeed the case? </div>
<div> - Add some kind of alert when the queue reaches a %
full?</div>
<div>* Once you start overflowing and getting overflow log
messages, I wonder if this is then contributing to the
problem.</div>
<div> - Push the overflow logging into Poller Task which
can look at how many drops occurred since last received
item.</div>
<div>* Split up the flags for the poller messages into 2:<br>
</div>
<div> - Messages that are/could be happening in the TX/RX
tasks</div>
<div> - Other noisy messages that always happen in the
poller task.</div>
<div><br>
</div>
<div>Thoughts on what else we might measure to figure out
what is going on?<br>
</div>
<div><br>
</div>
<div>//.ichael</div>
<div><br>
</div>
</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Sun, 5 May 2024, 19:29
Michael Balzer via OvmsDev, <<a
href="mailto:ovmsdev@lists.openvehicles.com"
target="_blank" moz-do-not-send="true"
class="moz-txt-link-freetext">ovmsdev@lists.openvehicles.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote"
style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div> Michael,<br>
<br>
the queue size isn't in bytes, it's in messages:<br>
<br>
<blockquote type="cite"><font face="monospace"> * @param
uxQueueLength The maximum number of items that the
queue can contain.<br>
*<br>
* @param uxItemSize The number of bytes each item in
the queue will require.</font></blockquote>
<br>
Also, from the time stamps in Dereks log excerpt, there
were quite some dropped frames in that time window -- at
least 23 frames in 40 ms, that's bad.<br>
<br>
Queue sizes are currently:<br>
<br>
<font face="monospace">CONFIG_OVMS_HW_CAN_RX_QUEUE_SIZE=60<br>
CONFIG_OVMS_VEHICLE_CAN_RX_QUEUE_SIZE=60</font><br>
<br>
The new poller now channels all TX callbacks through the
task queue additionally to RX and commands. So setting the
queue size to be larger than the CAN RX queue size seems
appropriate.<br>
<br>
Nevertheless, an overflow with more than 60 waiting
messages still indicates some too long processing time in
the vehicle task.<br>
<br>
TX callbacks previously were done directly in the CAN
context, and no current vehicle overrides the empty
default handler, so this imposed almost no additional
overhead. By requiring a queue entry for each TX callback,
this feature now has a potentially high impact for all
vehicles. If passing these to the task is actually
necessary, it needs to become an opt-in feature, so only
vehicles subscribing to the callback actually need to cope
with that additional load & potential processing
delays involved.<br>
<br>
Regards,<br>
Michael<br>
<br>
<br>
<div>Am 05.05.24 um 11:59 schrieb Michael Geddes via
OvmsDev:<br>
</div>
<blockquote type="cite">
<div dir="auto">OK.
<div dir="auto"><br>
</div>
<div dir="auto">I did some logging changes to confirm
that it's only _just_ getting overwhelmed..ie
dropping 1 (or occasionally 2) RX frames in a row
but then picking the next ones up...</div>
<div dir="auto"><br>
</div>
<div dir="auto">So increasing the queue size (I
doubled it but maybe that was excessive) seems to do
the trick. I think the queue size is in bytes and
the queue packet size has increased at least a
little bit.</div>
<div dir="auto"><br>
</div>
<div dir="auto">Michael </div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Sat, 4 May 2024,
09:24 Michael Geddes, <<a
href="mailto:frog@bunyip.wheelycreek.net"
rel="noreferrer" target="_blank"
moz-do-not-send="true"
class="moz-txt-link-freetext">frog@bunyip.wheelycreek.net</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote"
style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div dir="ltr">Hey Derek,
<div><br>
<div>I do have a friend with a Leaf in his EV
collection, so I can try grab some more info
from his car and work out exactly what (tf) is
going on.</div>
</div>
<div><br>
</div>
<div>//.</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Sat, 4 May
2024 at 08:13, <<a
href="mailto:frog@bunyip.wheelycreek.net"
rel="noreferrer noreferrer" target="_blank"
moz-do-not-send="true"
class="moz-txt-link-freetext">frog@bunyip.wheelycreek.net</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote"
style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div>
<div lang="EN-AU">
<div>
<p class="MsoNormal"><span
style="font-size:11pt">HI Derek,</span></p>
<p class="MsoNormal"><span
style="font-size:11pt">For a start,
I’m very sorry that the ovms put your
car in limp mode. That’s quite bad.</span></p>
<p class="MsoNormal"><span
style="font-size:11pt"> </span></p>
<p class="MsoNormal"><span
style="font-size:11pt">Just FYI those
overflows that you have copied are
about receiving and not sending
information, so maybe the poller
thread is being overwhelmed or stalled
somehow.</span></p>
<p class="MsoNormal"><span
style="font-size:11pt"> </span></p>
<p class="MsoNormal"><span
style="font-size:11pt">I’ve been
looking at the code and wondered if
you have the ‘can write’ flag set to
true or not? (Though it shouldn’t
make that much difference)</span></p>
<p class="MsoNormal"><span
style="font-size:11pt"> </span></p>
<p class="MsoNormal"><span
style="font-size:11pt">Even if it were
somehow mistakenly polling (ie in the
wrong pollstate), it should not be
doing it that frequently – (at most
once a minute). And the poll throttle
would still be on 1 per second.. so
that should put a limit on sends..
and so it is really worrying that
somehow that is not happening :/</span></p>
<p class="MsoNormal"><span
style="font-size:11pt"> </span></p>
<p class="MsoNormal"><span
style="font-size:11pt">If you have
more logs that you send me that don’t
just include that particular overflow
message that would be good. Did it
crash/reboot? Maybe it crashed
repeatedly?</span></p>
<p class="MsoNormal"><span
style="font-size:11pt"> </span></p>
<p class="MsoNormal"><span
style="font-size:11pt">//.ichael</span></p>
<p class="MsoNormal"><span
style="font-size:11pt"> </span></p>
<div
style="border-right:none;border-bottom:none;border-left:none;border-top:1pt solid rgb(225,225,225);padding:3pt 0cm 0cm">
<p class="MsoNormal"><b><span
style="font-size:11pt;font-family:Calibri,sans-serif" lang="EN-US">From:</span></b><span
style="font-size:11pt;font-family:Calibri,sans-serif" lang="EN-US">
OvmsDev <<a
href="mailto:ovmsdev-bounces@lists.openvehicles.com"
rel="noreferrer noreferrer"
target="_blank"
moz-do-not-send="true"
class="moz-txt-link-freetext">ovmsdev-bounces@lists.openvehicles.com</a>>
<b>On Behalf Of </b>Derek Caudwell
via OvmsDev<br>
<b>Sent:</b> Friday, May 3, 2024
6:54 PM<br>
<b>To:</b> OVMS Developers <<a
href="mailto:ovmsdev@lists.openvehicles.com" rel="noreferrer noreferrer"
target="_blank"
moz-do-not-send="true"
class="moz-txt-link-freetext">ovmsdev@lists.openvehicles.com</a>><br>
<b>Cc:</b> Derek Caudwell <<a
href="mailto:d.caudwell@gmail.com"
rel="noreferrer noreferrer"
target="_blank"
moz-do-not-send="true"
class="moz-txt-link-freetext">d.caudwell@gmail.com</a>><br>
<b>Subject:</b> Re: [Ovmsdev] OVMS
Poller module/singleton</span></p>
</div>
<p class="MsoNormal"> </p>
<div>
<div>
<p class="MsoNormal">Hi Michael,</p>
</div>
<div>
<p class="MsoNormal"> </p>
</div>
<p class="MsoNormal">When running
firmware <span
style="font-size:10pt;font-family:"Cascadia Mono";color:rgb(0,34,0)">3.3.004-74-gbd4e7196
on my Nissan Leaf I suspect (but
can't be 100% sure as it's only been
24h without fault) the new poller
caused the car to throw the attached
faults from overloading the can bus
whilst driving. The fault was
sufficient to send the car into limp
mode and could not be driven until
cleared with LeafSpy. Ovms should
not be polling in the driving state,
so I'm not sure why the poller is
overflowing.</span></p>
<div>
<p class="MsoNormal"> </p>
</div>
<div>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Cascadia Mono";color:rgb(0,34,0)">The
ovms log repeats this overflow in
rapid succession right before the
failure occurred. I have since
reverted to an earlier version and
it might be advisable for
other Leaf owners to do so until
the new poller is fully
operational.</span></p>
<div>
<p class="MsoNormal"> </p>
</div>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.316 NZST I (36847486)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.316 NZST I (36847486)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.316 NZST I (36847486)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.326 NZST I (36847496)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.326 NZST I (36847496)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.326 NZST I (36847496)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.326 NZST I (36847496)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.326 NZST I (36847496)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.326 NZST I (36847496)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.326 NZST I (36847496)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.326 NZST I (36847496)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.336 NZST I (36847506)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.336 NZST I (36847506)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.336 NZST I (36847506)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.336 NZST I (36847506)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.346 NZST I (36847516)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.346 NZST I (36847516)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.346 NZST I (36847516)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.346 NZST I (36847516)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.356 NZST I (36847526)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.356 NZST I (36847526)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.356 NZST I (36847526)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<p class="MsoNormal"><span
style="font-size:10pt;font-family:"Courier New";color:black">2024-05-02
12:22:28.356 NZST I (36847526)
vehicle-poll: Poller[Frame]: Task
Queue Overflow</span><span
style="font-size:11pt;font-family:Calibri,sans-serif"></span></p>
<div>
<p class="MsoNormal"><span
style="font-size:11pt;font-family:Calibri,sans-serif;color:black"> </span><span
style="font-size:10pt;font-family:"Cascadia Mono";color:rgb(0,34,0)"> </span></p>
</div>
</div>
</div>
<p class="MsoNormal"> </p>
<div>
<div>
<p class="MsoNormal">On Fri, 3 May
2024 at 05:40, Michael Balzer via
OvmsDev <<a
href="mailto:ovmsdev@lists.openvehicles.com" rel="noreferrer noreferrer"
target="_blank"
moz-do-not-send="true"
class="moz-txt-link-freetext">ovmsdev@lists.openvehicles.com</a>>
wrote:</p>
</div>
<blockquote
style="border-top:none;border-right:none;border-bottom:none;border-left:1pt solid rgb(204,204,204);padding:0cm 0cm 0cm 6pt;margin-left:4.8pt;margin-right:0cm">
<div>
<p class="MsoNormal"
style="margin-bottom:12pt">A task
may delete itself by calling
vTaskDelete(NULL) as the final
statement, and that's normally a
better way to shutdown a task, if
you can signal the task it should
terminate. Deleting a task from
outside may always result in
resources taken by the task not
being freed, as the task gets
terminated wherever it just is.<br>
<br>
As the vehicle task also needs to
access vehicle data memory,
vehicle destruction should not
begin until the task has finished,
otherwise a task job already
running while the vehicle
destruction takes place may run
into an illegal memory access
(access after free). Keep in mind,
destructors are executed bottom
up, so waiting for the task
shutdown within the destructor
won't help.<br>
<br>
Also, I think
"MyCan.DeregisterCallback(TAG)" in
ShuttingDown() is now obsolete.<br>
<br>
Regards,<br>
Michael<br>
<br>
</p>
<div>
<p class="MsoNormal">Am 02.05.24
um 15:23 schrieb Michael Geddes:</p>
</div>
<blockquote
style="margin-top:5pt;margin-bottom:5pt">
<div>
<p class="MsoNormal">Thanks. </p>
<div>
<p class="MsoNormal"> </p>
</div>
<div>
<p class="MsoNormal">On that
race condition... do you
think we are better to just
delete the task or I saw
one recommendation that</p>
</div>
<div>
<p class="MsoNormal">We can
delete it outside the while
loop in the task itself! </p>
</div>
<div>
<p class="MsoNormal"> </p>
</div>
<div>
<p class="MsoNormal">//.ichael </p>
</div>
</div>
<p class="MsoNormal"> </p>
<div>
<div>
<p class="MsoNormal">On Tue,
30 Apr 2024, 17:46 Michael
Balzer via OvmsDev, <<a
href="mailto:ovmsdev@lists.openvehicles.com" rel="noreferrer noreferrer"
target="_blank"
moz-do-not-send="true"
class="moz-txt-link-freetext">ovmsdev@lists.openvehicles.com</a>>
wrote:</p>
</div>
<blockquote
style="border-top:none;border-right:none;border-bottom:none;border-left:1pt solid rgb(204,204,204);padding:0cm 0cm 0cm 6pt;margin-left:4.8pt;margin-right:0cm">
<div>
<p class="MsoNormal"
style="margin-bottom:12pt">OK,
understood & merged,
thanks for the quick
fix/workaround.<br>
<br>
I'll ask the Twizy driver
to test this.<br>
<br>
Regards,<br>
Michael<br>
<br>
PS: side note: there's a
shutdown race condition
arising from `while
(!m_is_shutdown)` in the
new
`OvmsVehicle::VehicleTask()`:
if the task receives a
message while
m_is_shutdown already has
been set, it will exit the
loop and return from the
task function, which isn't
allowed. I think FreeRTOS
will abort in that case.<br>
<br>
<br>
</p>
<div>
<p class="MsoNormal">Am
30.04.24 um 08:55
schrieb Michael Geddes:</p>
</div>
<blockquote
style="margin-top:5pt;margin-bottom:5pt">
<div>
<p class="MsoNormal">No
it will start the poll
thread of the poller
fine for those that
don't use it. That's
the last commit.... so
that should be
covered. When the
callback is registered
the thread is force
started. </p>
<div>
<p class="MsoNormal"> </p>
</div>
<div>
<p class="MsoNormal"> </p>
</div>
<div>
<p class="MsoNormal">This
is not to say that
what you are
suggesting isn't a
better way
forward... just that
it should work.</p>
</div>
<div>
<p class="MsoNormal"> </p>
</div>
<div>
<p class="MsoNormal">Michael </p>
<div>
<p class="MsoNormal"> </p>
</div>
<p class="MsoNormal"
style="margin-bottom:12pt"> </p>
<div>
<div>
<p
class="MsoNormal">On Tue, 30 Apr 2024, 14:51 Michael Balzer via OvmsDev,
<<a
href="mailto:ovmsdev@lists.openvehicles.com" rel="noreferrer noreferrer"
target="_blank" moz-do-not-send="true" class="moz-txt-link-freetext">ovmsdev@lists.openvehicles.com</a>>
wrote:</p>
</div>
<blockquote
style="border-top:none;border-right:none;border-bottom:none;border-left:1pt solid rgb(204,204,204);padding:0cm 0cm 0cm 6pt;margin-left:4.8pt;margin-right:0cm">
<div>
<p
class="MsoNormal" style="margin-bottom:12pt">Michael,<br>
<br>
(taking this
back to the
list, as other
developers may
have helpful
ideas or
suggestions)<br>
<br>
from a first
check, your
new patch (PR
#1008) won't
help for
vehicles that
don't use the
poller, like
the generic
DBC vehicle or
the Fiat 500
(plus possibly
non-public
third party
vehicles). As
the poller is
normally
compiled in,
these would
need a run
time switch to
re-enable the
vehicle task,
or more
suitably
default into
that
configuration
and switch to
the poller
task only when
the poller
gets
initialized.<br>
<br>
How about
moving the
task back into
the vehicle
class, but
keeping your
task message
extensions
while doing
so, and adding
a way for the
poller to hook
into the task?
The dedicated
vehicle task
is an
essential part
of the vehicle
framework, but
I do remember
some occasions
where a
general way to
pass custom
messages to
the vehicle
task would
have been
helpful to use
the task for
more than CAN
processing.<br>
<br>
If the poller
shall become
avaible as a
separate
service that
can be used
without any
vehicle
instance
(currently not
a defined use
case), the
construct of a
CAN processor
task that can
be extended
for custom
messages (or a
message
processor task
that can
subscribe to
CAN frames)
could be
factored out
into a
dedicated
class or
template. The
poller could
then create
his own
instance of
that class, if
it cannot hook
into an
existing one.<br>
<br>
Btw, in case
you're not
aware of this,
FreeRTOS also
provides queue
sets (<a
href="https://www.freertos.org/RTOS-queue-sets.html"
rel="noreferrer noreferrer" target="_blank" moz-do-not-send="true"
class="moz-txt-link-freetext">https://www.freertos.org/RTOS-queue-sets.html</a>).
We haven't
used them in
the OVMS yet,
but they could
be useful,
especially if
message unions
become large
or tasks shall
be able to
dynamically
subscribe to
different
message
sources.<br>
<br>
Regards,<br>
Michael<br>
<br>
</p>
<div>
<p
class="MsoNormal">Am 30.04.24 um 01:20 schrieb Michael Geddes:</p>
</div>
<blockquote
style="margin-top:5pt;margin-bottom:5pt">
<div>
<div>
<div>
<p
class="MsoNormal">It might be worth reverting, but, I've got a patch
suggestion
that I'll push
up which will
let me know if
I understand
everything and
which might
provide a
solution.</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">If this isn't going to work then revert. (P/R coming)</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">While the poller was still a part of the vehicle class
it was
probably still
all ok. The
poller had
taken over
what I assume
you are
talking about
as the
vehicle task.
A call-back
fromthe poller
was calling
IncomingPollRxFrame
which was then
coming from
the (now)
poller task
(is that
correct?)</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">While we have OVMS_COMP_POLLER config defined, we
could just use
the poller
task to
provide the
IncomingPollRxFrame
call-back from
the poller
(was vehicle?)
task.</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">The problem is when OVMS_COMP_POLLER is undefined, we
need an
alternate
(maybe we
could use the
'Event' loop
then) which is
when I hacked
that bad
solution.</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">//.ichael</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal" style="margin-bottom:12pt">I was thinking though that
because
everything is
being queued
we could
divert some
calls into the
car </p>
<div>
<div>
<p
class="MsoNormal">On Mon, 29 Apr 2024, 18:58 Michael Balzer, <<a
href="mailto:dexter@expeedo.de" rel="noreferrer noreferrer"
target="_blank" moz-do-not-send="true" class="moz-txt-link-freetext">dexter@expeedo.de</a>>
wrote:</p>
</div>
<blockquote
style="border-top:none;border-right:none;border-bottom:none;border-left:1pt solid rgb(204,204,204);padding:0cm 0cm 0cm 6pt;margin-left:4.8pt;margin-right:0cm">
<div>
<p
class="MsoNormal" style="margin-bottom:12pt">Michael,<br>
<br>
I've found a
severe design
flaw with your
poller change.
Sorry, I
should have
seen that
before, and
shouldn't have
merged this.<br>
<br>
You have moved
the standard
CAN frame
processing
from the
vehicle task
into the CAN
task by
changing the
vehicle from a
CAN listener
to a CAN
callback
processor.
That will
break all kind
of things,
vehicles like
the Twizy,
Smart and many
others rely on
frame
processing
being done in
the dedicated
vehicle task.<br>
<br>
This
especially
induces issues
regarding CAN
processing
capacity, as
the vehicles
rely on having
a separate
context and
not needing to
decouple
complex
processing of
incoming
frames. So
this will
degrade the
CAN processing
performance
seriously in
many cases,
where
additional
steps
involving file
or network I/O
need to be
done.<br>
<br>
So this needs
to be changed
back.<br>
<br>
I assumed you
introduced a
new dedicated
poller task
but kept the
vehicle task
intact. From
your naming
(OvmsVehicle::IncomingPollRxFrame),
it seems you
misinterpreted
the vehicle
task's purpose
as only being
used for
polling.<br>
<br>
I assume this
isn't a small
change…? If so
we should
revert the
poller merge,
to avoid
having a
defunctional
edge build
state until
the fix.<br>
<br>
<br>
Secondly:
logging is
generally
expensive
regardless of
the log level
control and
log channels
enabled. Any
log message
needs to be
queued to the
log system, so
involves a
lock and a
potential wait
state (for the
queue) &
resulting
context switch
(= minimum
delay of 10
ms).
Therefore,
logging must
be avoided as
far as
possible in
any time
critical
context, and
is forbidden
under some
circumstances,
e.g. in a
timer callback
(see FreeRTOS
docs on this).
The log system
load
multiplies
with connected
web clients or
enabled file
logging and
enabled debug
/ verbose
level logging
-- that
quickly
becomes too
much, usually
triggering the
task watchdog.<br>
<br>
Your logging
of nearly all
bus events
passing
to/from the
poller
(especially
the log entry
in
Queue_PollerFrame)
becomes an
issue on any
vehicle that
has high
frequency
running
process data
frames on the
bus, like the
Twizy or
Smart. As a
counter
measure, I've
just added a
runtime
control for
all the
poller's
verbose
logging (by
default now
off), and
changed some
debug level
logs to
verbose. Not
sure if I've
catched all
that may need
to be silenced
by default.
Please check
all your log
calls and
place them
under the new
"trace"
control flag
wherever
appropriate.<br>
<br>
This won't
help avoiding
issues with
process data
frame buses
though.<br>
<br>
<br>
Shall I revert
the poller
merge for now?<br>
<br>
Regards,<br>
Michael<br>
<br>
<br>
</p>
<div>
<p
class="MsoNormal">Am 29.04.24 um 06:18 schrieb Michael Geddes:</p>
</div>
<blockquote
style="margin-top:5pt;margin-bottom:5pt">
<div>
<p
class="MsoNormal">Btw I included the log changes in the p/r which is a
few small
commits for
the poller. </p>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">//.</p>
</div>
</div>
<p
class="MsoNormal"> </p>
<div>
<div>
<p
class="MsoNormal">On Mon, 29 Apr 2024, 07:20 Michael Geddes, <<a
href="mailto:frog@bunyip.wheelycreek.net" rel="noreferrer noreferrer"
target="_blank" moz-do-not-send="true" class="moz-txt-link-freetext">frog@bunyip.wheelycreek.net</a>>
wrote:</p>
</div>
<blockquote
style="border-top:none;border-right:none;border-bottom:none;border-left:1pt solid rgb(204,204,204);padding:0cm 0cm 0cm 6pt;margin-left:4.8pt;margin-right:0cm">
<div>
<p
class="MsoNormal">Hey Michael, </p>
<div>
<p
class="MsoNormal">I've got to work now (it's Monday), but I suspect
those 'giving
up' are from
unsolicited
messages on
the bus.</p>
</div>
<div>
<p
class="MsoNormal">I can re-order things so that the message will likely
be 'dropped
(no poll
entry)' rather
than the
time-out
message. </p>
</div>
<div>
<p
class="MsoNormal">And make it a verbose log.</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">//.ichael </p>
</div>
</div>
<p
class="MsoNormal"> </p>
<div>
<div>
<p
class="MsoNormal">On Mon, 29 Apr 2024 at 00:25, Michael Balzer <<a
href="mailto:dexter@expeedo.de" rel="noreferrer noreferrer"
target="_blank" moz-do-not-send="true" class="moz-txt-link-freetext">dexter@expeedo.de</a>>
wrote:</p>
</div>
<blockquote
style="border-top:none;border-right:none;border-bottom:none;border-left:1pt solid rgb(204,204,204);padding:0cm 0cm 0cm 6pt;margin-left:4.8pt;margin-right:0cm">
<div>
<p
class="MsoNormal" style="margin-bottom:12pt">Michael,<br>
<br>
forwarding the
Twizy logs to
you directly,
as they
contain the
user location.<br>
<br>
He has just
verified it's
the new
version, he
says the
module stops
responding as
soon as he
turns on the
Twizy.<br>
<br>
His
description of
his actions is
a bit
ambiguous, and
it seems he
didn't enable
logging to the
file
persistently.<br>
<br>
According to
the server,
these were the
version boot
times:<br>
<br>
2024-04-28
15:30:56
0
3.3.004-32-g125e0841/ota_0/edge
(build idf
v3.3.4-849-g6e214dc335
Apr 26 2024
19:16:50)<br>
2024-04-28
16:21:08
0
3.3.004-32-g125e0841/ota_0/edge
(build idf
v3.3.4-849-g6e214dc335
Apr 26 2024
19:16:50)<br>
2024-04-28
16:38:33
0
3.3.004-63-gf3595561/ota_1/edge
(build idf
v3.3.4-849-g6e214dc335
Apr 27 2024
07:44:50)<br>
2024-04-28
16:40:57
0
3.3.004-63-gf3595561/ota_1/edge
(build idf
v3.3.4-849-g6e214dc335
Apr 27 2024
07:44:50)<br>
2024-04-28
16:43:14
0
3.3.004-63-gf3595561/ota_1/edge
(build idf
v3.3.4-849-g6e214dc335
Apr 27 2024
07:44:50)<br>
2024-04-28
16:46:39
0
3.3.004-63-gf3595561/ota_1/edge
(build idf
v3.3.4-849-g6e214dc335
Apr 27 2024
07:44:50)<br>
2024-04-28
16:54:44
0
3.3.004-32-g125e0841/ota_0/edge
(build idf
v3.3.4-849-g6e214dc335
Apr 26 2024
19:16:50)<br>
<br>
Attached is
also his crash
debug log --
a2ll doesn't
tell much
about what
happened, but
maybe you get
an idea from
this.<br>
<br>
After the boot
at 16:46,
there are
immediately
lots of these
messages:<br>
<br>
2024-04-28
16:46:33.792
CEST D (39042)
vehicle-poll:
Poller: Queue
PollerFrame()<br>
2024-04-28
16:46:33.792
CEST D (39042)
vehicle-poll:
[1]Poller:
Incoming -
giving up<br>
<br>
Regards,<br>
Michael<br>
<br>
</p>
<div>
<p
class="MsoNormal">Am 28.04.24 um 16:44 schrieb Michael Geddes:</p>
</div>
<blockquote
style="margin-top:5pt;margin-bottom:5pt">
<div>
<p
class="MsoNormal">Ah. OK. </p>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">I could try to fix the vin thing using the new way of
doing it and
get rid of a
semaphore? </p>
</div>
<div>
<p
class="MsoNormal">It would at least identify the problem possibly?</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">Michael </p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
</div>
<p
class="MsoNormal"> </p>
<div>
<div>
<p
class="MsoNormal">On Sun, 28 Apr 2024, 22:32 Michael Balzer via OvmsDev,
<<a
href="mailto:ovmsdev@lists.openvehicles.com" rel="noreferrer noreferrer"
target="_blank" moz-do-not-send="true" class="moz-txt-link-freetext">ovmsdev@lists.openvehicles.com</a>>
wrote:</p>
</div>
<blockquote
style="border-top:none;border-right:none;border-bottom:none;border-left:1pt solid rgb(204,204,204);padding:0cm 0cm 0cm 6pt;margin-left:4.8pt;margin-right:0cm">
<div>
<p
class="MsoNormal" style="margin-bottom:12pt">Not sure if that's the
problem, but
I've found a
different
behaviour with
the new
PollSetState()
implementation.<br>
<br>
The old
version only
did anything
if the new
state actually
was different
from the
previous one.
The Twizy
relies on this
behaviour,
calling
PollSetState()
from the per
second ticker
(see
OvmsVehicleRenaultTwizy::ObdTicker1).<br>
<br>
The new
implementation
apparently
always sends
the PollState
command to the
task, and that
in turn always
at least locks
the poller
mutex. Not
sure if/how
that could
cause the
observed
issues, but it
definitely
adds quite
some
(unnecessary?)
lock/unlock
operations.<br>
<br>
<br>
</p>
<div>
<p
class="MsoNormal">Am 28.04.24 um 16:05 schrieb Michael Balzer via
OvmsDev:</p>
</div>
<blockquote
style="margin-top:5pt;margin-bottom:5pt">
<p
class="MsoNormal" style="margin-bottom:12pt">The Twizy uses the poller
to query the
VIN (once) and
DTCs (every 10
seconds while
driving), see
rt_obd2.cpp.<br>
<br>
It also has
its own
version of the
OBD single
request
(OvmsVehicleRenaultTwizy::ObdRequest),
which was the
precursor for
the
generalized
version. This
is used by
custom/user
Twizy plugins
and scripts to
access ECU
internals.<br>
<br>
The Twizy
doesn't use
IncomingPollRxFrame,
but the
Twizy's
IncomingPollReply
handler will
log any poll
responses it
doesn't know
about, so that
could lead to
a lot of log
output if
something goes
wrong there.<br>
<br>
</p>
<div>
<p
class="MsoNormal">Am 28.04.24 um 15:49 schrieb Michael Geddes via
OvmsDev:</p>
</div>
<blockquote
style="margin-top:5pt;margin-bottom:5pt">
<div>
<div>
<p
class="MsoNormal">AFAICT the twizzy doesn't use the poller list at all.
So is it
missing a
call-back or
something??</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">I can see a potential problem with IncomingPollRxFrame
being called
twice as much
as it should
be but only
when there is
a poll list.
Maybe
commenting out
this would do
it. (I can
find another
away to get
this called on
the thread I
want). This
might be the
problem with
the smarted</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal"><span style="font-family:"Courier New"">void
OvmsVehicle::OvmsVehicleSignal::IncomingPollRxFrame(canbus* bus,
CAN_frame_t
*frame, bool
success)<br>
{<br>
//if
(Ready())<br>
//
m_parent->IncomingPollRxFrame(frame,
success);<br>
}</span></p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">//.</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<p
class="MsoNormal"> </p>
<div>
<div>
<p
class="MsoNormal">On Sun, 28 Apr 2024 at 21:10, Michael Balzer via
OvmsDev <<a
href="mailto:ovmsdev@lists.openvehicles.com" rel="noreferrer noreferrer"
target="_blank" moz-do-not-send="true" class="moz-txt-link-freetext">ovmsdev@lists.openvehicles.com</a>>
wrote:</p>
</div>
<blockquote
style="border-top:none;border-right:none;border-bottom:none;border-left:1pt solid rgb(204,204,204);padding:0cm 0cm 0cm 6pt;margin-left:4.8pt;margin-right:0cm">
<div>
<p
class="MsoNormal" style="margin-bottom:12pt">There may also be an issue
with the
Renault Twizy,
I've received
a report of a
user who is
using the edge
builds, that
the latest
build wouldn't
work.<br>
<br>
He reports all
kinds of
errors and
warnings
signaled by
the car during
driving, and
switching back
to the
previous build
fixed the
issues.<br>
<br>
I've asked him
to provide a
debug log
excerpt if
possible.<br>
<br>
Regards,<br>
Michael<br>
<br>
</p>
<div>
<p
class="MsoNormal">Am 28.04.24 um 14:29 schrieb Michael Geddes via
OvmsDev:</p>
</div>
<blockquote
style="margin-top:5pt;margin-bottom:5pt">
<div>
<div>
<p
class="MsoNormal">OK. That's bad.</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">Does the reading work in general?</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">Is it just the writing commands?</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">Raise a ticket on github and tag me in and we can
address it
that way.</p>
</div>
<div>
<p
class="MsoNormal"> </p>
</div>
<div>
<p
class="MsoNormal">Michael</p>
</div>
<div>
<p
class="MsoNormal"> </p>
<div>
<div>
<p
class="MsoNormal">On Sun, 28 Apr 2024, 19:49 Thomas Heuer via OvmsDev,
<<a
href="mailto:ovmsdev@lists.openvehicles.com" rel="noreferrer noreferrer"
target="_blank" moz-do-not-send="true" class="moz-txt-link-freetext">ovmsdev@lists.openvehicles.com</a>>
wrote:</p>
</div>
<blockquote
style="border-top:none;border-right:none;border-bottom:none;border-left:1pt solid rgb(204,204,204);padding:0cm 0cm 0cm 6pt;margin-left:4.8pt;margin-right:0cm">
<div>
<div>
<p
class="MsoNormal"><span style="font-size:11pt" lang="DE">Hi,</span><span
lang="DE"></span></p>
<p
class="MsoNormal"><span style="font-size:11pt" lang="DE"> </span><span
lang="DE"></span></p>
<p
class="MsoNormal"><span style="font-size:11pt" lang="EN-GB">The new
poller code
doesn't seem
to work
properly with
the smarted.</span><span
lang="DE"></span></p>
<div
style="border:1pt solid rgb(204,204,204);padding:7pt">
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">D
(218831)
vehicle-poll:
[1]PollerNextTick(PRI): cycle complete for ticker=215</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">V
(218831)
vehicle-poll:
Standard Poll
Series: List
reset</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">D
(218831)
vehicle-poll:
PollSeriesList::NextPollEntry[!v.standard]: ReachedEnd</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">V
(218831)
vehicle-poll:
[1]PollerSend:
Poller Reached
End</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">D
(219691)
vehicle-poll:
Poller: Queue
PollerFrame()</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">D
(219691)
vehicle-poll:
Poller: Queue
PollerFrame()</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">V
(219691)
vehicle-poll:
Pollers:
FrameRx(bus=2)</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">D
(219691)
vehicle-poll:
Poller: Queue
PollerFrame()</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">V
(219691)
vehicle-poll:
Pollers:
FrameRx(bus=2)</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">V
(219691)
vehicle-poll:
Pollers:
FrameRx(bus=2)</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">D
(219691)
vehicle-poll:
Poller: Queue
PollerFrame()</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><b><span
style="font-size:10pt;font-family:"Cascadia Mono";color:rgb(0,34,0)"
lang="EN-GB">OVMS#</span></b><span
style="font-size:10pt;font-family:"Cascadia Mono";color:rgb(0,34,0)"
lang="EN-GB"> </span><span
style="font-size:9pt;font-family:"Cascadia Mono";color:white;background:rgb(51,51,51)"
lang="EN-GB">unlock
22</span><span
style="font-size:10pt;font-family:"Cascadia Mono";color:rgb(0,34,0)"
lang="EN-GB"><br>
Vehicle
unlocked</span><span
lang="DE"></span></p>
<p
class="MsoNormal"
style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"><span
style="font-size:8.5pt;font-family:"Cascadia Mono";color:gray"
lang="EN-GB">V
(219691)
vehicle-poll:
Pollers:
FrameRx(bus=2)</span><span
lang="DE"></span></p>
</div>
</div>
</div>
</blockquote>
</div>
</div>
</div>
</blockquote>
</div>
</blockquote>
</div>
</div>
</blockquote>
</blockquote>
</div>
</blockquote>
</div>
</blockquote>
</div>
</blockquote>
</div>
</blockquote>
</div>
</blockquote>
</div>
</blockquote>
</div>
</div>
</div>
</div>
</blockquote>
</div>
</blockquote>
</div>
</div>
</div>
</blockquote>
</div>
</blockquote>
</div>
</blockquote>
</div>
</blockquote>
</div>
</div>
</div>
</div>
</blockquote>
</div>
</blockquote>
</div>
</blockquote>
</div>
</blockquote>
</div>
</div>
</blockquote>
<br>
<pre class="moz-signature" cols="72">--
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26</pre>
</body>
</html>