<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
</head>
<body text="#000000" bgcolor="#FFFFFF">
I think the RTOS timer service task starves. It's running on core 0
with priority 1.<br>
<br>
Taks on core 0 sorted by priority:<br>
<br>
<tt>Number of Tasks = 20 Stack: Now Max Total Heap 32-bit
SPIRAM C# PRI</tt><tt><br>
</tt><tt><tt>3FFC84A8 6 Blk ipc0 388 500 1024
7788 0 0 0 24</tt><tt><br>
</tt></tt><tt><tt>3FFC77F0 5 Blk OVMS CanRx 428 428
2048 3052 0 31844 0 23</tt><tt><br>
</tt>3FFAFBF4 1 Blk esp_timer 400 656 4096 35928
644 25804 0 22</tt><tt><br>
</tt><tt><tt>3FFD3240 19 Blk wifi 460 2716 3584
43720 0 20 0 22</tt><tt><br>
</tt>3FFC03C4 2 Blk eventTask 448 1984 4608
104 0 0 0 20</tt><tt><br>
</tt><tt><tt>3FFC8F14 17 Blk tiT 500 2308 3072
6552 0 0 * 18</tt><tt><br>
</tt></tt><tt><tt>3FFE14F0 26 Blk OVMS COrx 456 456
4096 0 0 0 0 7</tt><tt><br>
</tt><tt>3FFE19D4 27 Blk OVMS COwrk 476 476 3072
0 0 0 0 7</tt><tt><br>
</tt>3FFCBC34 12 Blk Tmr Svc 352 928 3072
88 0 0 0 1</tt><tt><br>
</tt><tt>3FFE7708 23 Blk mdns 468 1396 4096
108 0 0 0 1</tt><tt><br>
</tt><br>
I don't think it's our CanRx, as that only fetches and queues CAN
frames, the actual work is done by the listeners. The CO tasks only
run for CANopen jobs, which are few for normal operation.<br>
<br>
That leaves the system tasks, with main suspect -once again- the
wifi blob.<br>
<br>
We need to know how much CPU time the tasks actually use now. I
think I saw some option for this in the FreeRTOS config.<br>
<br>
Regards,<br>
Michael<br>
<br>
<br>
<div class="moz-cite-prefix">Am 06.09.19 um 23:15 schrieb Michael
Balzer:<br>
</div>
<blockquote type="cite"
cite="mid:01014878-5a73-b611-4334-989b8aea76c5@expeedo.de">
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
The workaround is based on the monotonictime being updated per
second, as do the history record offsets.<br>
<br>
Apparently, that mechanism doesn't work reliably. That may be an
indicator for some bigger underlying issue.<br>
<br>
Example log excerpt:<br>
<br>
<tt>2019-09-06 22:07:48.126919 +0200 info main: #173 C MITPROHB
rx msg h
964,0,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:09:03.089031 +0200 info main: #173 C
MITPROHB rx msg h
964,-10,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:09:05.041574 +0200 info main: #173 C
MITPROHB rx msg h
964,-20,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:09:05.052644 +0200 info main: #173 C
MITPROHB rx msg h
964,-30,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:09:05.063617 +0200 info main: #173 C
MITPROHB rx msg h
964,-49,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:09:05.077527 +0200 info main: #173 C
MITPROHB rx msg h
964,-59,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:09:05.193775 +0200 info main: #173 C
MITPROHB rx msg h
964,-70,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:09:13.190645 +0200 info main: #173 C
MITPROHB rx msg h
964,-80,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:09:22.077994 +0200 info main: #173 C
MITPROHB rx msg h
964,-90,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:09:54.590300 +0200 info main: #173 C
MITPROHB rx msg h
964,-109,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:11:10.127054 +0200 info main: #173 C
MITPROHB rx msg h
964,-119,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:11:16.794200 +0200 info main: #173 C
MITPROHB rx msg h
964,-130,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:11:22.455652 +0200 info main: #173 C
MITPROHB rx msg h
964,-140,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:12:49.423412 +0200 info main: #173 C
MITPROHB rx msg h
964,-150,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:12:49.442096 +0200 info main: #173 C
MITPROHB rx msg h
964,-169,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:12:49.461941 +0200 info main: #173 C
MITPROHB rx msg h
964,-179,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:14:39.828133 +0200 info main: #173 C
MITPROHB rx msg h
964,-190,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:14:39.858144 +0200 info main: #173 C
MITPROHB rx msg h
964,-200,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:14:52.020319 +0200 info main: #173 C
MITPROHB rx msg h
964,-210,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:14:54.452637 +0200 info main: #173 C
MITPROHB rx msg h
964,-229,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:15:12.613935 +0200 info main: #173 C
MITPROHB rx msg h
964,-239,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:15:35.223845 +0200 info main: #173 C
MITPROHB rx msg h
964,-250,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:16:09.255059 +0200 info main: #173 C
MITPROHB rx msg h
964,-260,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:17:31.919754 +0200 info main: #173 C
MITPROHB rx msg h
964,-270,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:19:23.366267 +0200 info main: #173 C
MITPROHB rx msg h
964,-289,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:21:57.344609 +0200 info main: #173 C
MITPROHB rx msg h
964,-299,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:23:40.082406 +0200 info main: #31 C
MITPROHB rx msg h
964,-1027,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><tt>2019-09-06 22:25:58.061883 +0200 info main: #31 C
MITPROHB rx msg h
964,-1040,RT-BAT-C,5,86400,2,1,3830,3795,3830,-10,25,25,25,0</tt><tt><br>
</tt><br>
<br>
This shows the ticker was only run 299 times from 22:07:48 to
22:21:57.<br>
<br>
After 22:21:57 the workaround was triggered and did a reconnect.
Apparently during that network reinitialization of 103 seconds,
the per second ticker was run 628 times.<br>
<br>
That can't be catching up on the event queue, as that queue has
only 20 slots. So something strange is going on here.<br>
<br>
Any ideas?<br>
<br>
Regards,<br>
Michael<br>
<br>
<br>
<div class="moz-cite-prefix">Am 06.09.19 um 08:04 schrieb Michael
Balzer:<br>
</div>
<blockquote type="cite"
cite="mid:9ee4a7b5-59a2-a05d-046d-e932b65e3e34@expeedo.de">
<meta http-equiv="Content-Type" content="text/html;
charset=UTF-8">
Mark & anyone else running a V2 server,<br>
<br>
as most cars don't send history records, this also needs the
change to the server I just pushed, i.e. server version 2.4.2.<br>
<br>
<a
href="https://github.com/openvehicles/Open-Vehicle-Monitoring-System/commits/master"
moz-do-not-send="true">https://github.com/openvehicles/Open-Vehicle-Monitoring-System/commits/master</a><br>
<br>
Regards,<br>
Michael<br>
<br>
<br>
<div class="moz-cite-prefix">Am 05.09.19 um 19:55 schrieb
Michael Balzer:<br>
</div>
<blockquote type="cite"
cite="mid:91892018-3ecb-2dc9-b430-e79fe598cc4c@expeedo.de">
<meta http-equiv="Content-Type" content="text/html;
charset=UTF-8">
I've pushed the nasty workaround: the v2 server checks for no
RX over 15 minutes, then restarts the network (wifi &
modem) as configured for autostart.<br>
<br>
Rolled out on my server in edge as 3.2.002-237-ge075f655.<br>
<br>
Please test.<br>
<br>
Regards,<br>
Michael<br>
<br>
<br>
<div class="moz-cite-prefix">Am 05.09.19 um 01:58 schrieb Mark
Webb-Johnson:<br>
</div>
<blockquote type="cite"
cite="mid:D4C2658B-49FB-48CB-A687-9A7325117BC4@webb-johnson.net">
<meta http-equiv="Content-Type" content="text/html;
charset=UTF-8">
<div class="">
<blockquote type="cite" class="">
<div text="#000000" bgcolor="#FFFFFF" class="">Mark, you
can check your server logs for history messages with
ridiculous time offsets:<br class="">
<blockquote class=""><tt class="">[sddexter@ns27
server]$ cat log-20190903 | egrep "rx msg h
[0-9]+,-[0-9]{4}" | wc -l<br class="">
455283</tt></blockquote>
</div>
</blockquote>
<br class="">
</div>
I checked my logs and see 12 vehicles showing this. But, 2
only show this for a debugcrash log (which is expected, I
guess, if the time is not synced at report time). I’ve got 4
cars with the offset > 10,000.
<div class=""><br class="">
</div>
<div class="">Regards, Mark.<br class="">
<div><br class="">
<blockquote type="cite" class="">
<div class="">On 4 Sep 2019, at 4:45 AM, Michael
Balzer <<a href="mailto:dexter@expeedo.de"
class="" moz-do-not-send="true">dexter@expeedo.de</a>>
wrote:</div>
<br class="Apple-interchange-newline">
<div class="">
<meta http-equiv="Content-Type" content="text/html;
charset=UTF-8" class="">
<div text="#000000" bgcolor="#FFFFFF" class="">
Everyone,<br class="">
<br class="">
I've pushed a change that needs some testing.<br
class="">
<br class="">
I had the issue myself now parking at a certain
distance from my garage wifi AP, i.e. on the edge
of "in", after wifi had been disconnected for some
hours, and with the module still connected via
modem. The wifi blob had been trying to connect to
the AP for about two hours.<br class="">
<br class="">
As seen before, the module saw no error, just the
server responses and commands stopped coming in. I
noticed the default interface was still "st1"
despite wifi having been disconnected and modem
connected. The DNS was also still configured for
my wifi network, and the interface seemed to have
an IP address -- but wasn't pingable from the wifi
network.<br class="">
<br class="">
A power cycle of the modem solved the issue
without reboot. So the cause may be in the
modem/ppp subsystem, or it may be related (in some
weird way) to the default interface / DNS setup.<br
class="">
<br class="">
More tests showed the default interface
again/still got set by the wifi blob itself at
some point, overriding our modem prioritization.
The events we didn't handle up to now were
"sta.connected" and "sta.lostip", so I added
these, and the bug didn't show up again since
then. That doesn't mean anything, so we need to
test this.<br class="">
<br class="">
The default interface really shouldn't affect
inbound packet routing of an established
connection, but there always may be strange bugs
lurking in those libs.<br class="">
<br class="">
The change also reimplements the wifi signal
strength reading, as the tests also showed that
still wasn't working well using the CSI callback.
It now seems to be much more reliable.<br class="">
<br class="">
Please test & report. The single module will
be hard to test, as the bug isn't reproducable
easily, but you can still try if wifi / modem
transitions work well.<br class="">
<br class="">
Mark, you can check your server logs for history
messages with ridiculous time offsets:<br class="">
<blockquote class=""><tt class="">[sddexter@ns27
server]$ cat log-20190903 | egrep "rx msg h
[0-9]+,-[0-9]{4}" | wc -l<br class="">
455283</tt><br class="">
</blockquote>
The bug now severely affects the V2 server
performance, as the server is single threaded and
doesn't scale very well to this kind of bulk data
bursts, especially when coming from multiple
modules in parallel. So we really need to solve
this now. Slow reactions or connection drops from
my server lately have been due to this bug. If
this change doesn't solve it, we'll need to add
some reboot trigger on "too many server v2
notification retransmissions" -- or maybe a modem
power cycle will do, that wouldn't discard the
data.<br class="">
<br class="">
Thanks,<br class="">
Michael<br class="">
<br class="">
<br class="">
<div class="moz-cite-prefix">Am 03.09.19 um 07:46
schrieb Mark Webb-Johnson:<br class="">
</div>
<blockquote type="cite"
cite="mid:7A81965B-AD97-4DFC-9768-9A03A74107BA@webb-johnson.net"
class="">
<pre class="moz-quote-pre" wrap="">No problem. We can hold. I won’t commit anything for the next few days (and agree to hold-off on Markos’s pull). Let me know when you are ready.
Regards, Mark.
</pre>
<blockquote type="cite" class="">
<pre class="moz-quote-pre" wrap="">On 3 Sep 2019, at 1:58 AM, Michael Balzer <a class="moz-txt-link-rfc2396E" href="mailto:dexter@expeedo.de" moz-do-not-send="true"><dexter@expeedo.de></a> wrote:
Mark, please wait.
I may just have found the cause for issue #241, or at least something I need to investigate before releasing.
I need to dig into my logs first, and try something.
Regards,
Michael
Am 02.09.19 um 12:23 schrieb Michael Balzer:
</pre>
<blockquote type="cite" class="">
<pre class="moz-quote-pre" wrap="">Nothing open from my side at the moment.
I haven't had the time to look in to Markos pull request, but from a first check also think that's going too deep to be included in this release.
Regards,
Michael
Am 02.09.19 um 04:15 schrieb Mark Webb-Johnson:
</pre>
<blockquote type="cite" class="">
<pre class="moz-quote-pre" wrap="">I think it is well past time for a 3.2.003 release. Things seems table in edge (although some things only partially implemented).
Anything people want to include at the last minute, or can we go ahead and build?
Regards, Mark.
_______________________________________________
OvmsDev mailing list
<a class="moz-txt-link-abbreviated" href="mailto:OvmsDev@lists.openvehicles.com" moz-do-not-send="true">OvmsDev@lists.openvehicles.com</a>
<a class="moz-txt-link-freetext" href="http://lists.openvehicles.com/mailman/listinfo/ovmsdev" moz-do-not-send="true">http://lists.openvehicles.com/mailman/listinfo/ovmsdev</a>
</pre>
</blockquote>
</blockquote>
<pre class="moz-quote-pre" wrap="">--
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
_______________________________________________
OvmsDev mailing list
<a class="moz-txt-link-abbreviated" href="mailto:OvmsDev@lists.openvehicles.com" moz-do-not-send="true">OvmsDev@lists.openvehicles.com</a>
<a class="moz-txt-link-freetext" href="http://lists.openvehicles.com/mailman/listinfo/ovmsdev" moz-do-not-send="true">http://lists.openvehicles.com/mailman/listinfo/ovmsdev</a>
</pre>
</blockquote>
<pre class="moz-quote-pre" wrap="">_______________________________________________
OvmsDev mailing list
<a class="moz-txt-link-abbreviated" href="mailto:OvmsDev@lists.openvehicles.com" moz-do-not-send="true">OvmsDev@lists.openvehicles.com</a>
<a class="moz-txt-link-freetext" href="http://lists.openvehicles.com/mailman/listinfo/ovmsdev" moz-do-not-send="true">http://lists.openvehicles.com/mailman/listinfo/ovmsdev</a>
</pre>
</blockquote>
<br class="">
<pre class="moz-signature" cols="160">--
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
</pre>
</div>
_______________________________________________<br
class="">
OvmsDev mailing list<br class="">
<a href="mailto:OvmsDev@lists.openvehicles.com"
class="" moz-do-not-send="true">OvmsDev@lists.openvehicles.com</a><br
class="">
<a class="moz-txt-link-freetext"
href="http://lists.openvehicles.com/mailman/listinfo/ovmsdev"
moz-do-not-send="true">http://lists.openvehicles.com/mailman/listinfo/ovmsdev</a><br
class="">
</div>
</blockquote>
</div>
<br class="">
</div>
<br>
<fieldset class="mimeAttachmentHeader"></fieldset>
<pre class="moz-quote-pre" wrap="">_______________________________________________
OvmsDev mailing list
<a class="moz-txt-link-abbreviated" href="mailto:OvmsDev@lists.openvehicles.com" moz-do-not-send="true">OvmsDev@lists.openvehicles.com</a>
<a class="moz-txt-link-freetext" href="http://lists.openvehicles.com/mailman/listinfo/ovmsdev" moz-do-not-send="true">http://lists.openvehicles.com/mailman/listinfo/ovmsdev</a>
</pre>
</blockquote>
<br>
<pre class="moz-signature" cols="160">--
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
</pre>
<br>
<fieldset class="mimeAttachmentHeader"></fieldset>
<pre class="moz-quote-pre" wrap="">_______________________________________________
OvmsDev mailing list
<a class="moz-txt-link-abbreviated" href="mailto:OvmsDev@lists.openvehicles.com" moz-do-not-send="true">OvmsDev@lists.openvehicles.com</a>
<a class="moz-txt-link-freetext" href="http://lists.openvehicles.com/mailman/listinfo/ovmsdev" moz-do-not-send="true">http://lists.openvehicles.com/mailman/listinfo/ovmsdev</a>
</pre>
</blockquote>
<br>
<pre class="moz-signature" cols="160">--
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
</pre>
<br>
<fieldset class="mimeAttachmentHeader"></fieldset>
<pre class="moz-quote-pre" wrap="">_______________________________________________
OvmsDev mailing list
<a class="moz-txt-link-abbreviated" href="mailto:OvmsDev@lists.openvehicles.com" moz-do-not-send="true">OvmsDev@lists.openvehicles.com</a>
<a class="moz-txt-link-freetext" href="http://lists.openvehicles.com/mailman/listinfo/ovmsdev" moz-do-not-send="true">http://lists.openvehicles.com/mailman/listinfo/ovmsdev</a>
</pre>
</blockquote>
<br>
<pre class="moz-signature" cols="160">--
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
</pre>
<br>
<fieldset class="mimeAttachmentHeader"></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>
<br>
<pre class="moz-signature" cols="160">--
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
</pre>
</body>
</html>