<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">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"><u></u>
<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">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">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">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">ovmsdev@lists.openvehicles.com</a>><br>
<b>Cc:</b> Derek Caudwell <<a href="mailto:d.caudwell@gmail.com" rel="noreferrer noreferrer" target="_blank">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">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">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">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">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">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">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">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">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">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">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>
<p class="MsoNormal" style="margin-bottom:7.5pt;background:whitesmoke;word-break:break-all"></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>