<html>
  <head>
    <meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
  </head>
  <body text="#000000" bgcolor="#FFFFFF">
    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">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>