<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
</head>
<body text="#000000" bgcolor="#FFFFFF">
No, the 32 bit limit indeed has an effect pretty soon. I had assumed
they are "ticks", but they really are at the timer resolution (see
DebugTasks records).<br>
<br>
Timer resolution is currently 1 MHz, so the counters will cycle over
every 71.6 minutes.<br>
<br>
So if you don't enable the debug.tasks report, the fist manual
report is likely to look strange.<br>
<br>
We can get a checkpoint every five minutes regardless of the report
activation. Or we can add a measurement delay to the command.<br>
<br>
Regards,<br>
Michael<br>
<br>
<br>
<div class="moz-cite-prefix">Am 20.09.19 um 16:16 schrieb Michael
Balzer:<br>
</div>
<blockquote type="cite"
cite="mid:2f66409f-ef10-b513-5674-e0e740169da7@expeedo.de">
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
The percentages are calculated from the time slice counter
differences between two command invocations (or boot), but their
32 bit limit shouldn't have an effect that soon.<br>
<br>
Also strange: your esp_timer SPIRAM allocation…<br>
<br>
Is that a build with toolkit -98?<br>
<br>
Regards,<br>
Michael<br>
<br>
<br>
<div class="moz-cite-prefix">Am 20.09.19 um 03:29 schrieb Mark
Webb-Johnson:<br>
</div>
<blockquote type="cite"
cite="mid:0D4D450E-631F-4A4C-B043-12633A4C7BBF@webb-johnson.net">
<meta http-equiv="Content-Type" content="text/html;
charset=UTF-8">
Strange. Connected to my car, and from ovms_shell asked for
‘module tasks’:
<div class=""><br class="">
</div>
<blockquote style="margin: 0 0 0 40px; border: none; padding:
0px;" class="">
<div class="">
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">ovms>
module tasks</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">...</span></font></div>
</div>
<div class="">
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">Vehicle
Response:</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
Number of Tasks = 17 Stack: Now Max Total
Heap 32-bit SPIRAM C# PRI CPU%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFAFBF4 1 Blk esp_timer 400 656 4096
35944 6442122956 0 22 2%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFBDBBC 2 Blk eventTask 440 1928 4608
140 0 0 0 20 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFBFF00 3 Blk OVMS Events 444 3404 8192
70816 0 21092 1 5 9%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC3300 4 Blk OVMS DukTape 460 9548 12288
188 0 31020 1 3 12%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC4FF4 5 Blk OVMS CanRx 432 832 2048
3144 0 32072 0 23 120%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC5D3C 6 Blk ipc0 392 504 1024
7804 0 0 0 24 2%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC6340 7 Blk ipc1 396 444 1024
12 0 0 1 24 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC8194 10 Rdy IDLE0 416 512 1024
0 0 0 0 0 362%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC872C 11 Rdy IDLE1 408 504 1024
0 0 0 1 0 387%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC94C4 12 Blk Tmr Svc 352 912 3072
88 0 0 0 20 1%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC6794 17 Blk tiT 504 2536 3072
7668 0 0 * 18 6%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFCF3E0 18 Blk OVMS SIMCOM 460 2412 4096
40 0 3892 1 5 1%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFD0C10 19 Blk wifi 460 2716 3584
36356 0 2912 0 22 23%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFDBD70 20 Blk OVMS Vehicle 460 1308 6144
0 0 2336 1 10 95%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFDF0FC 21 Rdy OVMS Console 488 1736 6144
0 0 20 1 5 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFDF64C 22 Blk mdns 472 1576 4096
108 0 0 0 1 1%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFE38F0 35 Rdy OVMS NetMan 1384 2984 8192
144 25180 5004 1 5 3%</span></font></div>
</div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class=""><br
class="">
</span></font></div>
<div class="">
<div class="">
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;"
class="">ovms> module tasks</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;"
class="">...</span></font></div>
</div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">Vehicle
Response:</span></font></div>
</div>
<div class="">
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
Number of Tasks = 17 Stack: Now Max Total
Heap 32-bit SPIRAM C# PRI CPU%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFAFBF4 1 Blk esp_timer 400 656 4096
35944 6442122956 0 22 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFBDBBC 2 Blk eventTask 440 1928 4608
140 0 0 0 20 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFBFF00 3 Blk OVMS Events 444 3404 8192
70816 0 21092 1 5 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC3300 4 Blk OVMS DukTape 460 9548 12288
188 0 23712 1 3 1%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC4FF4 5 Blk OVMS CanRx 432 832 2048
3144 0 32072 0 23 4%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC5D3C 6 Blk ipc0 392 504 1024
7804 0 0 0 24 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC6340 7 Blk ipc1 396 444 1024
12 0 0 1 24 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC8194 10 Rdy IDLE0 416 512 1024
0 0 0 0 0 96%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC872C 11 Rdy IDLE1 408 504 1024
0 0 0 1 0 95%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC94C4 12 Blk Tmr Svc 352 912 3072
88 0 0 0 20 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFC6794 17 Blk tiT 504 2536 3072
7668 0 0 * 18 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFCF3E0 18 Blk OVMS SIMCOM 668 2412 4096
40 0 3892 1 5 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFD0C10 19 Blk wifi 460 2716 3584
36356 0 2912 0 22 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFDBD70 20 Blk OVMS Vehicle 460 1308 6144
0 0 2336 1 10 3%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFDF0FC 21 Blk OVMS Console 552 1736 6144
0 0 20 1 5 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFDF64C 22 Blk mdns 472 1576 4096
108 0 0 0 1 0%</span></font></div>
<div class=""><font class="" face="Andale Mono"><span
style="font-style: normal; font-size: 14px;" class="">
3FFE38F0 35 Rdy OVMS NetMan 1896 3240 8192
400 25180 5392 1 5 0%</span></font></div>
</div>
</blockquote>
<div class="">
<div><br class="">
</div>
<div>The second one is what I normally see, but the first is
bizarre. Any idea what the time frame for the CPU% is?</div>
<div><br class="">
</div>
<div>Regards, Mark</div>
<div><br class="">
</div>
<div>
<blockquote type="cite" class="">
<div class="">
<div text="#000000" bgcolor="#FFFFFF" class="">
<blockquote type="cite" class="">
<blockquote type="cite" class="">
<blockquote type="cite" class="">
<div class="">
<div class="">
<blockquote type="cite" class="">
<div class="">
<div class="">
<blockquote type="cite" class=""> </blockquote>
</div>
</div>
</blockquote>
</div>
</div>
</blockquote>
</blockquote>
<blockquote type="cite"
cite="mid:7a3bb65a-9a54-6f67-c794-4b6f8d4ca2b8@expeedo.de"
class=""> </blockquote>
</blockquote>
<blockquote type="cite"
cite="mid:76a60138-8d46-0703-d9d0-6b2f5daa20da@expeedo.de"
class="">
<blockquote type="cite"
cite="mid:7a3bb65a-9a54-6f67-c794-4b6f8d4ca2b8@expeedo.de"
class=""> </blockquote>
</blockquote>
</div>
</div>
</blockquote>
<div class="">
<div text="#000000" bgcolor="#FFFFFF" class="">
<blockquote type="cite"
cite="mid:7a3bb65a-9a54-6f67-c794-4b6f8d4ca2b8@expeedo.de"
class="">
<blockquote type="cite"
cite="mid:BFED773E-0CFE-4EBB-A3B4-9B44FE4A783D@webb-johnson.net"
class="">
<div class="">
<div class="">
<blockquote type="cite" class="">
<div class="">
<div class="">
<blockquote type="cite" class="">
<blockquote type="cite" class="">On 8
Sep 2019, at 5:43 PM, Michael Balzer
<<a href="mailto:dexter@expeedo.de"
class="" moz-do-not-send="true">dexter@expeedo.de</a>>
wrote:<br class="">
<br class="">
I've pushed some modifications and
improvements to (hopefully) fix the
timer issue or at least be able to
debug it.<br class="">
<br class="">
Some sdkconfig changes are necessary.<br
class="">
<br class="">
The build including these updates is
on my edge release as
3.2.002-258-g20ae554b.<br class="">
<br class="">
Btw: the network restart strategy
seems to mitigate issue #241; I've
seen a major drop on record
repetitions on my server since the
rollout.<br class="">
<br class="">
<br class="">
commit
99e4e48bdd40b7004c0976f51aba9e3da4ecab53<br
class="">
<br class="">
Module: add per task CPU usage
statistics, add task stats history
records<br class="">
<br class="">
To enable CPU usage statistics,
apply the changes to sdkconfig<br
class="">
included. The CPU usage shown by
the commands is calculated against<br
class="">
the last task status retrieved (or
system boot).<br class="">
<br class="">
Command changes:<br class="">
- "module tasks" -- added CPU
(core) usage in percent per task<br
class="">
<br class="">
New command:<br class="">
- "module tasks data" -- output
task stats in history record form<br
class="">
<br class="">
New config:<br class="">
- [module] debug.tasks -- yes
(default) = send task stats every 5
minutes<br class="">
<br class="">
New history record:<br class="">
- "*-OVM-DebugTasks" v1:
<taskcnt,totaltime> + per task:<br
class="">
<tasknum,name,state,stack_now,stack_max,stack_total,<br
class="">
heap_total,heap_32bit,heap_spi,runtime><br class="">
Note: CPU core use percentage =
runtime / totaltime<br class="">
<br class="">
commit
950172c216a72beb4da0bc7a40a46995a6105955<br
class="">
<br class="">
Build config: default timer service
task priority raised to 20<br class="">
<br class="">
Background: the FreeRTOS timer
service shall only be used for very<br
class="">
short and non-blocking jobs. We
delegate event processing to our<br
class="">
events task, anything else in
timers needs to run with high<br
class="">
priority.<br class="">
<br class="">
commit
31ac19d187480046c16356b80668de45cacbb83d<br
class="">
<br class="">
DukTape: add build config for task
priority, default lowered to 3<br
class="">
<br class="">
Background: the DukTape garbage
collector shall run on lower<br
class="">
priority than tasks like SIMCOM
& events<br class="">
<br class="">
commit
e0a44791fbcfb5a4e4cad24c9d1163b76e637b4f<br
class="">
<br class="">
Server V2: use esp_log_timestamp
for timeout detection,<br class="">
add timeout config, limit data
records & size per second<br
class="">
<br class="">
New config:<br class="">
- [server.v2] timeout.rx -- timeout
in seconds, default 960<br class="">
<br class="">
commit
684a4ce9525175a910040f0d1ca82ac212fbf5de<br
class="">
<br class="">
Notify: use esp_log_timestamp for
creation time instead of monotonictime<br
class="">
to harden against timer service
starvation / ticker event drops<br
class="">
<br class="">
<br class="">
Regards,<br class="">
Michael<br class="">
<br class="">
<br class="">
Am 07.09.19 um 10:55 schrieb Michael
Balzer:<br class="">
<blockquote type="cite" class="">I
think the RTOS timer service task
starves. It's running on core 0 with
priority 1.<br class="">
<br class="">
Taks on core 0 sorted by priority:<br
class="">
<br class="">
Number of Tasks = 20 Stack:
Now Max Total Heap 32-bit
SPIRAM C# PRI<br class="">
3FFC84A8 6 Blk ipc0
388 500 1024 7788
0 0 0 24<br class="">
3FFC77F0 5 Blk OVMS CanRx
428 428 2048 3052
0 31844 0 23<br class="">
3FFAFBF4 1 Blk esp_timer
400 656 4096 35928
644 25804 0 22<br class="">
3FFD3240 19 Blk wifi
460 2716 3584 43720
0 20 0 22<br class="">
3FFC03C4 2 Blk eventTask
448 1984 4608 104
0 0 0 20<br class="">
3FFC8F14 17 Blk tiT
500 2308 3072
6552 0 0 * 18<br
class="">
3FFE14F0 26 Blk OVMS COrx
456 456 4096 0
0 0 0 7<br class="">
3FFE19D4 27 Blk OVMS COwrk
476 476 3072 0
0 0 0 7<br class="">
3FFCBC34 12 Blk Tmr Svc
352 928 3072 88
0 0 0 1<br class="">
3FFE7708 23 Blk mdns
468 1396 4096 108
0 0 0 1<br class="">
<br class="">
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 class="">
<br class="">
That leaves the system tasks, with
main suspect -once again- the wifi
blob.<br class="">
<br class="">
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 class="">
<br class="">
Regards,<br class="">
Michael<br class="">
<br class="">
<br class="">
Am 06.09.19 um 23:15 schrieb Michael
Balzer:<br class="">
<blockquote type="cite" class="">The
workaround is based on the
monotonictime being updated per
second, as do the history record
offsets.<br class="">
<br class="">
Apparently, that mechanism doesn't
work reliably. That may be an
indicator for some bigger
underlying issue.<br class="">
<br class="">
Example log excerpt:<br class="">
<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
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<br class="">
<br class="">
<br class="">
This shows the ticker was only run
299 times from 22:07:48 to
22:21:57.<br class="">
<br class="">
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 class="">
<br class="">
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
class="">
<br class="">
Any ideas?<br class="">
<br class="">
Regards,<br class="">
Michael<br class="">
<br class="">
<br class="">
Am 06.09.19 um 08:04 schrieb
Michael Balzer:<br class="">
<blockquote type="cite" class="">Mark
& anyone else running a V2
server,<br class="">
<br class="">
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 class="">
<br class="">
<a
href="https://github.com/openvehicles/Open-Vehicle-Monitoring-System/commits/master"
class=""
moz-do-not-send="true">https://github.com/openvehicles/Open-Vehicle-Monitoring-System/commits/master</a>
<<a
href="https://github.com/openvehicles/Open-Vehicle-Monitoring-System/commits/master"
class=""
moz-do-not-send="true">https://github.com/openvehicles/Open-Vehicle-Monitoring-System/commits/master</a>><br
class="">
<br class="">
Regards,<br class="">
Michael<br class="">
<br class="">
<br class="">
Am 05.09.19 um 19:55 schrieb
Michael Balzer:<br class="">
<blockquote type="cite" class="">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
class="">
<br class="">
Rolled out on my server in
edge as 3.2.002-237-ge075f655.<br
class="">
<br class="">
Please test.<br class="">
<br class="">
Regards,<br class="">
Michael<br class="">
<br class="">
<br class="">
Am 05.09.19 um 01:58 schrieb
Mark Webb-Johnson:<br class="">
<blockquote type="cite"
class="">
<blockquote type="cite"
class="">Mark, you can
check your server logs for
history messages with
ridiculous time offsets:<br
class="">
[sddexter@ns27 server]$
cat log-20190903 | egrep
"rx msg h
[0-9]+,-[0-9]{4}" | wc -l<br
class="">
455283<br class="">
</blockquote>
<br class="">
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.<br
class="">
<br class="">
Regards, Mark.<br class="">
<br class="">
<blockquote type="cite"
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>
<<a
href="mailto:dexter@expeedo.de"
class=""
moz-do-not-send="true">mailto:dexter@expeedo.de</a>>>
wrote:<br class="">
<br 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="">
[sddexter@ns27 server]$
cat log-20190903 | egrep
"rx msg h
[0-9]+,-[0-9]{4}" | wc -l<br
class="">
455283<br class="">
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="">
Am 03.09.19 um 07:46
schrieb Mark Webb-Johnson:<br
class="">
<blockquote type="cite"
class="">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.<br
class="">
<br class="">
Regards, Mark.<br
class="">
<br class="">
<blockquote type="cite"
class="">On 3 Sep
2019, at 1:58 AM,
Michael Balzer <<a
href="mailto:dexter@expeedo.de" class="" moz-do-not-send="true">dexter@expeedo.de</a>>
<<a
href="mailto:dexter@expeedo.de"
class=""
moz-do-not-send="true">mailto:dexter@expeedo.de</a>>
wrote:<br class="">
<br class="">
Mark, please wait.<br
class="">
<br class="">
I may just have found
the cause for issue
#241, or at least
something I need to
investigate before
releasing.<br class="">
<br class="">
I need to dig into my
logs first, and try
something.<br class="">
<br class="">
Regards,<br class="">
Michael<br class="">
<br class="">
<br class="">
Am 02.09.19 um 12:23
schrieb Michael
Balzer:<br class="">
<blockquote
type="cite" class="">Nothing
open from my side at
the moment.<br
class="">
<br class="">
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.<br
class="">
<br class="">
Regards,<br class="">
Michael<br class="">
<br class="">
<br class="">
Am 02.09.19 um 04:15
schrieb Mark
Webb-Johnson:<br
class="">
<blockquote
type="cite"
class="">I think
it is well past
time for a 3.2.003
release. Things
seems table in
edge (although
some things only
partially
implemented).<br
class="">
<br class="">
Anything people
want to include at
the last minute,
or can we go ahead
and build?<br
class="">
<br class="">
Regards, Mark.<br
class="">
<br class="">
</blockquote>
</blockquote>
</blockquote>
</blockquote>
</blockquote>
</blockquote>
</blockquote>
</blockquote>
</blockquote>
</blockquote>
</blockquote>
</blockquote>
</div>
</div>
</blockquote>
</div>
</div>
</blockquote>
<br class="">
<pre class="moz-signature" cols="144">--
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26</pre>
</blockquote>
</div>
</div>
</div>
</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">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>