[Ovmsdev] OVMS Poller module/singleton

Michael Balzer dexter at expeedo.de
Fri Jun 14 14:44:53 HKT 2024


Sorry, I know I'm behind with PRs.

I'll try to find some time this weekend.

Regards,
Michael


Am 14.06.24 um 08:31 schrieb Michael Geddes via OvmsDev:
> Was this all good?  I want to make sure I get to the bottom of this 
> whole issue asap!
>
> https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/pull/1018 
>
>
> Was there something else you needed me to work on to make sure this 
> all works for all supported cars?
>
> //.ichael
>
> On Sun, 26 May 2024 at 21:15, Michael Balzer via OvmsDev 
> <ovmsdev at lists.openvehicles.com> wrote:
>
>     OK, I see now why it wouldn't send the notification: the V2 & V3
>     server register for notifications up to COMMAND_RESULT_NORMAL =
>     1024 characters.
>
>     The report quickly becomes larger than 1024 characters, so the
>     notifications no longer get sent via the server connectors.
>
>     You need to either reduce the size, split the report, or use data
>     notifications instead.
>
>     On the reset value init: for my float targeting smoothing helper
>     class for the UpMiiGo, I implemented a gradual ramp up from 1 to
>     the requested sample size. You can do something similar also with
>     powers of 2. IOW, yes, initialization from the first values
>     received is perfectly OK.
>
>     Regards,
>     Michael
>
>
>     Am 26.05.24 um 14:35 schrieb Michael Geddes:
>>
>>     It _/should/_ already be sending a report on charge stop.
>>
>>     MyEvents.RegisterEvent(TAG, "vehicle.charge.stop",
>>     std::bind(&OvmsPollers::VehicleChargeStop, this, _1, _2));
>>
>>     Reset on charge start/vehicle on is a good idea.
>>
>>     A question – would it be silly if the first value after a reset,
>>     rather than using 0 average to start with, if the average got set
>>     to the initial value?  I’m in 2 minds about it. It would make the
>>     average more useful quicker.
>>
>>     //.ichael
>>
>>     On Sun, 26 May 2024, 19:39 Michael Balzer via OvmsDev,
>>     <ovmsdev at lists.openvehicles.com> wrote:
>>
>>         As the averages quickly decline when idle, an automatic
>>         report should probably also be sent on charge stop.
>>
>>         Also, I think you should automatically reset the timer
>>         statistics on drive & charge start.
>>
>>         First stats from charging my UpMiiGo:
>>
>>         Type           | count  | Utlztn | Time
>>                        | per s  | [‰]    | [ms]
>>         ---------------+--------+--------+---------
>>         Poll:PRI    Avg|    1.00|   0.723| 0.716
>>                    Peak|        |   1.282| 3.822
>>         ---------------+--------+--------+---------
>>         Poll:SRX    Avg|    7.72|   1.246| 0.184
>>                    Peak|        |   3.128| 1.058
>>         ---------------+--------+--------+---------
>>         RxCan1[7ae] Avg|    2.48|   0.915| 0.362
>>                    Peak|        |   1.217| 1.661
>>         ---------------+--------+--------+---------
>>         RxCan1[7cf] Avg|    4.76|   1.928| 0.397
>>                    Peak|        |   2.317| 2.687
>>         ---------------+--------+--------+---------
>>         RxCan1[7ed] Avg|    3.38|   1.251| 0.327
>>                    Peak|        |   8.154| 12.273
>>         ---------------+--------+--------+---------
>>         RxCan1[7ee] Avg|    0.21|   0.066| 0.297
>>                    Peak|        |   0.225| 1.690
>>         ---------------+--------+--------+---------
>>         TxCan1[744] Avg|    1.49|   0.022| 0.011
>>                    Peak|        |   0.032| 0.095
>>         ---------------+--------+--------+---------
>>         TxCan1[765] Avg|    3.89|   0.134| 0.027
>>                    Peak|        |   0.155| 0.113
>>         ---------------+--------+--------+---------
>>         TxCan1[7e5] Avg|    2.32|   0.038| 0.013
>>                    Peak|        |   0.295| 0.084
>>         ---------------+--------+--------+---------
>>         TxCan1[7e6] Avg|     1  0.21|   0.002| 0.008
>>                    Peak|        |   0.010| 0.041
>>         ---------------+--------+--------+---------
>>         Cmd:State   Avg|    0.00|   0.000| 0.007
>>                    Peak|        |   0.005| 0.072
>>         ===============+========+========+=========
>>               Total Avg|   27.46|   6.324| 2.349
>>
>>
>>         Overall healthy I'd say, but let's see how it compares.
>>
>>         7ed is the BMS, the peak time is probably related to the
>>         extended cell data logging -- I've enabled log intervals for
>>         both cell voltages & temperatures.
>>
>>         Regards,
>>         Michael
>>
>>         Am 26.05.24 um 08:42 schrieb Michael Balzer via OvmsDev:
>>
>>             The notification works on my devices, it only has a
>>             garbled per mille character -- see attached screenshot.
>>             The same applies to the mail version:
>>
>>
>>                 Poller timing is: on
>>
>>                 Type           | count  | Utlztn | Time
>>
>>                                 | per s  | [‰]    | [ms]
>>
>>                 ---------------+--------+--------+---------
>>
>>                 Poll:PRI    Avg|    0.25|   0.119|    0.382
>>
>>                             Peak|        |   0.513|    0.678
>>
>>                 ---------------+--------+--------+---------
>>
>>                 RxCan1[597] Avg|    0.01|   0.004|    0.021
>>
>>                             Peak|        |   0.000|    0.338
>>
>>                 ---------------+--------+--------+---------
>>
>>                 RxCan1[59b] Avg|    0.01|   0.011|    0.053
>>
>>                             Peak|        |   0.000|    0.848
>>
>>                 ---------------+--------+--------+---------
>>
>>                 Cmd:State   Avg|    0.01|   0.002|    0.012
>>
>>                             Peak|        |   0.000|    0.120
>>
>>                 ===============+========+========+=========
>>
>>                        Total Avg|    0.28|   0.135|    0.468
>>
>>
>>             The encoding is a general issue. The character encoding
>>             for text messages via V2/MP is quite old & clumsy, it's
>>             got an issue with the degree celcius character as well.
>>             We previously tried to keep all text messages within the
>>             SMS safe character set (which e.g. lead to writing just
>>             "C" instead of "°C"). I'd say we should head towards
>>             UTF-8 now. If we ever refit SMS support, we can recode on
>>             the fly.
>>
>>             Regarding not seeing the notification on your phone:
>>
>>             a) Check your notification subtype/channel filters on the
>>             module. See
>>             https://docs.openvehicles.com/en/latest/userguide/notifications.html#suppress-notifications
>>
>>             b) Check your notification vehicle filters on the phone
>>             (menu on notification tab): if you enabled the vehicle
>>             filter, it will add the messages of not currently
>>             selected vehicles to the list only, but not raise a
>>             system notification. (Applies to the Android App, no idea
>>             about the iOS version)
>>
>>             Regards,
>>             Michael
>>
>>             Am 26.05.24 um 06:32 schrieb Michael Geddes:
>>
>>                 Hi,
>>
>>                 I'm trying to finalise this now .. and one last thing
>>                 is that I don't get the report coming to my mobile.
>>                 I'm using the command:
>>
>>                 MyNotify.NotifyString("info", "poller.report",
>>                 buf.c_str());
>>
>>                 Where the buffer string is just the same as the
>>                 report output.  Should I be using some other format
>>                 or command?
>>
>>                 I get "alert" types (like the ioniq5 door-open alert)
>>                 fine to my mobile.
>>
>>                 Michael.
>>
>>                 On Sun, 19 May 2024, 12:51 Michael Balzer via
>>                 OvmsDev, <ovmsdev at lists.openvehicles.com> wrote:
>>
>>                     A builtin web UI for this seems a bit over the
>>                     top. Builtin web config pages should focus on
>>                     user features, this is clearly a feature only
>>                     needed during/for the development/extension of a
>>                     vehicle adapter. Development features in the web
>>                     UI are confusing for end users.
>>
>>                     If persistent enabling/disabling is done by a
>>                     simple config command (e.g. "config set can
>>                     poller.trace on"), that's also doable by users.
>>
>>                     Regards,
>>                     Michael
>>
>>                     Am 19.05.24 um 02:06 schrieb Michael Geddes:
>>
>>                         I was so focused on how I calculated the
>>                         value that I totally missed that ‰ would be a
>>                         better description.  I could also use the 
>>                         system 'Ratio' unit... so % or ‰.
>>
>>                         I'll make space to put 'Avg' on the row.  Was
>>                         trying to limit the width for output on a
>>                         mobile.  I agree it would make it easier to
>>                         understand.
>>
>>                         Totals also makes sense.
>>
>>                         Should I make this a configuration that can
>>                         be set on the web-page?   I'd probably use a
>>                         configuration change notification so that the
>>                         very bit setting is sync'd with the
>>                         'configuration' value.
>>
>>                         //.ichael
>>
>>                         On Sat, 18 May 2024, 14:05 Michael Balzer,
>>                         <dexter at expeedo.de> wrote:
>>
>>                                 I'm not sure whether the 'max' should
>>                                 be the maximum of the smoothed
>>                                 value.. or the maximum of the raw value.
>>
>>
>>                             It should normally be the maximum of the
>>                             raw value I think, the maximum of the
>>                             smoothed value cannot tell about how bad
>>                             the processing of an ID can become.
>>
>>                             The naming in the table is a bit
>>                             confusing I think. (besides: I've never
>>                             seen "ave" as the abbreviation for average)
>>
>>                             If I understand you correctly, "time ms
>>                             per s" is the time share in per mille, so
>>                             something in that direction would be more
>>                             clear, and "length ms" would then be
>>                             "time [ms]".
>>
>>                             The totals for all averages in the table
>>                             foot would also be nice.
>>
>>                             Maybe "Ave" (or avg?) also should be
>>                             placed on the left, as the "peak" label
>>                             now suggests being the peak of the average.
>>
>>                             Btw, keep in mind, not all "edge" users /
>>                             testers are developers (e.g. the Twizy
>>                             driver I'm in contact with), collecting
>>                             stats feedback for vehicles from testers
>>                             should be straight forward. Maybe add a
>>                             data/history record, sent automatically
>>                             on every drive/charge stop when the
>>                             poller tracing is on?
>>
>>                             Regards,
>>                             Michael
>>
>>                             Am 18.05.24 um 02:28 schrieb Michael Geddes:
>>
>>                                 You did say max/pead value.  I also
>>                                 halved the N for both.
>>
>>                                 I'm not sure whether the 'max' should
>>                                 be the maximum of the smoothed
>>                                 value.. or the maximum of the raw value.
>>
>>                                 This is currently the raw-value maximum.
>>
>>                                 The problem is that the middle column
>>                                 is the maximum of the {{sum over 10s}
>>                                 / (10*1000,000)
>>
>>                                 I could easily change the 'period' to
>>                                 1s and see how that goes.. was just
>>                                 trying to reduce the larger
>>                                 calculations.
>>
>>                                 Usage: poller
>>                                 [pause|resume|status|times|trace]
>>
>>
>>                                 OVMS# poller time status
>>                                 Poller timing is: on
>>                                 Type         | Count    | Ave time  |
>>                                 Ave length
>>                                              | per s    | ms per s  | ms
>>                                 -------------+----------+-----------+-----------
>>                                 Poll:PRI     |      1.00|  0.559|  0.543
>>                                  peak        |          |  0.663|  1.528
>>                                 -------------+----------+-----------+-----------
>>                                 Poll:SRX     |      0.08|  0.009|  0.038
>>                                  peak        |          |  0.068|  0.146
>>                                 -------------+----------+-----------+-----------
>>                                 CAN1 RX[778] |      0.11|  0.061|  0.280
>>                                  peak        |          |  0.458|  1.046
>>                                 -------------+----------+-----------+-----------
>>                                 CAN1 RX[7a8] |      0.04|  0.024|  0.124
>>                                  peak        |          |  0.160|  0.615
>>                                 -------------+----------+-----------+-----------
>>                                 CAN1 TX[770] |      0.05|  0.004|  0.016
>>                                  peak        |          |  0.022|  0.102
>>                                 -------------+----------+-----------+-----------
>>                                 CAN1 TX[7a0] |      0.02|  0.002|  0.011
>>                                  peak        |          |  0.010|  0.098
>>                                 -------------+----------+-----------+-----------
>>                                 CAN1 TX[7b3] |      0.01|  0.001|  0.006
>>                                  peak        |          |  0.000|  0.099
>>                                 -------------+----------+-----------+-----------
>>                                 CAN1 TX[7e2] |      0.02|  0.002|  0.011
>>                                  peak        |          |  0.010|  0.099
>>                                 -------------+----------+-----------+-----------
>>                                 CAN1 TX[7e4] |      0.08|  0.008|  0.048
>>                                  peak        |          |  0.049|  0.107
>>                                 -------------+----------+-----------+-----------
>>                                 Cmd:State    |      0.00|  0.000|  0.005
>>                                  peak        |          |  0.000|  0.094
>>
>>                                 On Fri, 17 May 2024 at 15:26, Michael
>>                                 Geddes <frog at bunyip.wheelycreek.net>
>>                                 wrote:
>>
>>                                     This is what I have now.
>>
>>                                     The one on the end is the one 
>>                                     MIchael B was after using an N of
>>                                     32. (up for discussion).
>>
>>                                     The middle is the time  spent in
>>                                     that even t per second.  It
>>                                     accumulates times (in
>>                                     microseconds), and then every 10s
>>                                     it stores it as smoothed (N=16)
>>                                     value.
>>
>>                                     The Count is similar (except that
>>                                     we store a value of '100' as 1
>>                                     event so it can be still integers
>>                                     and has 2 decimal places).
>>
>>                                     Every received poll  does a
>>                                     64bit difference to 32bit (for
>>                                     the elapsed time) and 64bit
>>                                     comparison (for end-of-period).
>>
>>                                     It also does 1x 32bit smoothing
>>                                     and 2x 32bit adds.
>>
>>                                     Then at the end of a 10s period,
>>                                     it will do a 64bit add to get the
>>                                     next end-of-period value, as well
>>                                     as the 2x 32bit smoothing calcs.
>>
>>                                     This is from the Ioniq 5 so not
>>                                     any big values yet. You can
>>                                     certainly see how insignificant
>>                                     the TX callbacks are.
>>
>>                                     I'll leave it on for when the car
>>                                     is moving and gets some faster
>>                                     polling.
>>
>>                                     OVMS# poll time status
>>                                     Poller timing is: on
>>                                     Type         | Count    | Ave
>>                                     time  | Ave Length
>>                                                  | per s    | ms per
>>                                     s  | ms
>>                                     -------------+----------+-----------+-----------
>>                                     Poll:PRI     |      1.00|  0.540|
>>                                      0.539
>>                                     Poll:SRX     |      0.03|  0.004|
>>                                      0.017
>>                                     CAN1 RX[778] |      0.06|  0.042|
>>                                      0.175
>>                                     CAN1 TX[770] |      0.04|  0.002|
>>                                      0.008
>>                                     Cmd:State    |      0.01|  0.001|
>>                                      0.005
>>
>>                                     ----------------------8<--------------------------------
>>
>>                                     Nice smoothing class (forces N as
>>                                     a power of 2):
>>
>>                                       constexpr unsigned
>>                                     floorlog2(unsigned x)
>>                                         {
>>                                         return x == 1 ? 0 :
>>                                     1+floorlog2(x >> 1);
>>                                         }
>>                                       /* Maintain a smoothed average
>>                                     using shifts for division.
>>                                        * T should be an integer type
>>                                        * N needs to be a power of 2
>>                                        */
>>                                       template <typename T, unsigned N>
>>                                       class average_util_t
>>                                         {
>>                                         private:
>>                                           T m_ave;
>>                                         public:
>>                                     average_util_t() : m_ave(0) {}
>>                                           static const uint8_t _BITS
>>                                     = floorlog2(N);
>>                                           void add( T val)
>>                                             {
>>                                     static_assert(N == (1 << _BITS),
>>                                     "N must be a power of 2");
>>                                             m_ave = (((N-1) * m_ave)
>>                                     + val) >> _BITS;
>>                                             }
>>                                           T get() { return m_ave; }
>>                                           operator T() { return m_ave; }
>>                                         };
>>
>>                                     On Thu, 16 May 2024 at 10:29,
>>                                     Michael Geddes
>>                                     <frog at bunyip.wheelycreek.net> wrote:
>>
>>                                         Thanks Michael,
>>
>>                                         My calculations give me
>>                                         ((2^32)-1) / (1000*1000*3600)
>>                                         = only 1.2 hours of
>>                                         processing time in 32bit. 
>>                                         The initial subtraction is
>>                                         64bit anyway and I can't see
>>                                         a further 64bit addition
>>                                         being a problem. I have the
>>                                         calculations being performed
>>                                         in doubles at print-out where
>>                                         performance is not really an
>>                                         issue anyway. (Though
>>                                         apparently doing 64 bit
>>                                         division is worse than
>>                                         floating point).
>>
>>                                         In addition
>>
>>                                         * I currently have this being
>>                                         able to be turned on and off
>>                                         and reset manually (only do
>>                                         it when required).
>>
>>                                         *  For the lower volume
>>                                         commands, the smoothed
>>                                         average is not going to be
>>                                         useful - the count is more
>>                                         interesting for different
>>                                         reasons.
>>
>>                                         * The total time is quite
>>                                         useful. Ie a high average
>>                                         time doesn't matter if the
>>                                         count is low. The things that
>>                                         are affecting performance are
>>                                         stuff with high total time.
>>                                         Stuff which is happening 100
>>                                         times a second needs to be a
>>                                         much lower average than once
>>                                         a second.
>>
>>                                         * A measure like 'time per
>>                                         minute/second' and possibly
>>                                         count per minute/seconds as a
>>                                         smoothed average would
>>                                         potentially be more useful.
>>                                         (or in addition?)
>>
>>                                         I think we could do _that_ in
>>                                         a reasonably efficient manner
>>                                         using a 64 bit 'last measured
>>                                         time', a 32 bit accumulated
>>                                         value and the stored 32 bit
>>                                         rolling average.
>>
>>                                         It would boils down to some
>>                                         iterative (integer) sums and
>>                                         multiplications plus a divide
>>                                         by n ^ (time periods passed) 
>>                                         - which is a shift - and
>>                                         which can be optimised to '0'
>>                                         if 'time-periods-passed' is
>>                                         more than 32/(bits-per-n) -
>>                                         effectively limiting the
>>                                         number of iterations.
>>
>>                                         The one issue I can see is
>>                                         that we need to calculate
>>                                         'number of time-periods
>>                                         passed' which is a 64 bit
>>                                         subtraction followed by a 32
>>                                         bit division (not
>>                                         optimisable to a simple shift).
>>
>>                                         * I'm also happy to keep a
>>                                         rolling (32bit) average time.
>>
>>                                            Even if you assume
>>                                         averages in the 100ms, 32bit
>>                                         is going to happily support
>>                                         an N of 64 or even 128.
>>
>>                                            Am I right in thinking
>>                                         that the choice of N is
>>                                         highly dependent on
>>                                         frequency. For things
>>                                         happening 100 times per
>>                                         second, you might want an N
>>                                         like 128.. where things
>>                                         happening once per
>>
>>                                            second, you might want an
>>                                         N of 4 or 8.  The other
>>                                         things we keep track of in
>>                                         this manner we have a better
>>                                         idea of the frequency of the
>>                                         thing.
>>
>>                                         How about we have (per record
>>                                         type):
>>
>>                                           * total count (since last
>>                                         reset?) (32 bit)
>>
>>                                           * smoothed average of time
>>                                         per instance (32 bit)
>>
>>                                           * ?xx? total accumulated
>>                                         time since last reset (64bit)
>>                                         ?? <-- with the below stats
>>                                         this is much less useful
>>
>>                                           * last-measured-time (64 bit)
>>
>>                                           * accumulated count since
>>                                         last time-period (16bit - but
>>                                         maybe 32bit anyway for byte
>>                                         alignment?)
>>
>>                                           * smoothed average of count
>>                                         per time-period (32bit)
>>
>>                                           * accumulated time since
>>                                         last time-period (32bit)
>>
>>                                           * smoothed average of time
>>                                         per time-period (32bit)
>>
>>                                         It's possible to keep the
>>
>>                                         Is this going to be too much
>>                                         per record type?  The number
>>                                         of 'records' we are keeping
>>                                         is quite low (so 10 to 20
>>                                         maybe) - so it's not a huge
>>                                         memory burden.
>>
>>                                         Thoughts?
>>
>>                                         //.ichael
>>
>>                                         On Thu, 16 May 2024 at 03:09,
>>                                         Michael Balzer via OvmsDev
>>                                         <ovmsdev at lists.openvehicles.com>
>>                                         wrote:
>>
>>                                             esp_timer_get_time() is
>>                                             the right choice for
>>                                             precision timing.
>>
>>                                             I'd say uint32 is enough
>>                                             though, even if counting
>>                                             microseconds that can
>>                                             hold a total of more than
>>                                             71 hours of actual
>>                                             processing time. uint64
>>                                             has a significant
>>                                             performance penalty,
>>                                             although I don't recall
>>                                             the overhead for simple
>>                                             additions.
>>
>>                                             Also & more important,
>>                                             the average wouldn't be
>>                                             my main focus, but the
>>                                             maximum processing time
>>                                             seen per ID, which seems
>>                                             to be missing in your draft.
>>
>>                                             Second thought on the
>>                                             average… the exact
>>                                             overall average really
>>                                             has a minor meaning, I'd
>>                                             rather see the current
>>                                             average, adapting to the
>>                                             current mode of operation
>>                                             (drive/charge/…). I
>>                                             suggest feeding the
>>                                             measurements to a low
>>                                             pass filter to get the
>>                                             smoothed average of the
>>                                             last n measurements. Pattern:
>>
>>                                             runavg = ((N-1) * runavg
>>                                             + newval) / N
>>
>>                                             By using a low power of 2
>>                                             for N (e.g. 8 or 16), you
>>                                             can replace the division
>>                                             by a simple bit shift,
>>                                             and have enough headroom
>>                                             to use 32 bit integers.
>>
>>                                             Regards,
>>                                             Michael
>>
>>                                             Am 15.05.24 um 06:51
>>                                             schrieb Michael Geddes
>>                                             via OvmsDev:
>>
>>                                                 Formatting aside, I
>>                                                 have implemented what
>>                                                 I think Michael B was
>>                                                 suggesting. This is a
>>                                                 sample run on the
>>                                                 Ioniq 5 (which
>>                                                 doesn't have
>>                                                 unsolicited RX events).
>>
>>                                                 This uses the
>>                                                 call esp_timer_get_time()
>>                                                 got get a 64bit
>>                                                 *microseconds* since
>>                                                 started value - and
>>                                                 works out the time to
>>                                                 execute that way.
>>                                                 It's looking at
>>                                                 absolute time and not
>>                                                 time in the Task - so
>>                                                 other things going on
>>                                                 at the same time in
>>                                                 other tasks will have
>>                                                 an effect.  (The
>>                                                 normal tick count
>>                                                 doesn't have nearly
>>                                                 enough resolution to
>>                                                 be useful - any other
>>                                                 ideas on
>>                                                 measurement?) I've
>>                                                 got total accumulated
>>                                                 time displaying in
>>                                                 seconds and the
>>                                                 average in
>>                                                 milliseconds
>>                                                 currently - but I can
>>                                                 change that easy enough.
>>
>>                                                 The cumulative time
>>                                                 is stored as uint64_t
>>                                                 which will be plenty,
>>                                                 as 32bit wouldn't be
>>                                                 nearly enough.
>>
>>                                                 OVMS# *poller time on*
>>                                                 Poller timing is now on
>>
>>                                                 OVMS# *poller time
>>                                                 status*
>>                                                 Poller timing is: on
>>                                                 Poll [PRI]          
>>                                                 : n=390 tot=0.2s
>>                                                 ave=0.586ms
>>                                                 Poll [SRX]          
>>                                                 : n=316 tot=0.1s
>>                                                 ave=0.196ms
>>                                                 CAN1 RX[0778]        
>>                                                    : n=382 tot=0.2s
>>                                                 ave=0.615ms
>>                                                 CAN1 RX[07a8]        
>>                                                    : n=48 tot=0.0s
>>                                                 ave=0.510ms
>>                                                 CAN1 RX[07bb]        
>>                                                    : n=162 tot=0.1s
>>                                                 ave=0.519ms
>>                                                 CAN1 RX[07ce]        
>>                                                    : n=33 tot=0.0s
>>                                                 ave=0.469ms
>>                                                 CAN1 RX[07ea]        
>>                                                    : n=408 tot=0.2s
>>                                                 ave=0.467ms
>>                                                 CAN1 RX[07ec]        
>>                                                    : n=486 tot=0.2s
>>                                                 ave=0.477ms
>>                                                 CAN3 RX[07df]        
>>                                                    : n=769 tot=0.2s
>>                                                 ave=0.261ms
>>                                                 CAN1 TX[0770]        
>>                                                    : n=191 tot=0.0s
>>                                                 ave=0.054ms
>>                                                 CAN1 TX[07a0]        
>>                                                    : n=16 tot=0.0s
>>                                                 ave=0.047ms
>>                                                 CAN1 TX[07b3]        
>>                                                    : n=31 tot=0.0s
>>                                                 ave=0.069ms
>>                                                 CAN1 TX[07c6]        
>>                                                    : n=11 tot=0.0s
>>                                                 ave=0.044ms
>>                                                 CAN1 TX[07e2]        
>>                                                    : n=82 tot=0.0s
>>                                                 ave=0.067ms
>>                                                 CAN1 TX[07e4]        
>>                                                    : n=54 tot=0.0s
>>                                                 ave=0.044ms
>>                                                 Set State          
>>                                                  : n=7 tot=0.0s
>>                                                 ave=0.104ms
>>
>>                                                 This is probably
>>                                                 going to be quite
>>                                                 useful in general!
>>                                                 The TX call-backs
>>                                                 don't seem to be
>>                                                 significant here.
>>                                                 (oh, I should
>>                                                 probably implement a
>>                                                 reset of the values too).
>>
>>                                                 //.ichael
>>
>>                                                 On Sun, 12 May 2024
>>                                                 at 22:58, Michael
>>                                                 Geddes
>>                                                 <frog at bunyip.wheelycreek.net>
>>                                                 wrote:
>>
>>                                                     Yeah - I
>>                                                     certainly wasn't
>>                                                     going to put a
>>                                                     hard limit. Just
>>                                                     a log above a
>>                                                     certain time,
>>                                                     that being said,
>>                                                     the idea of just
>>                                                     collecting stats
>>                                                     (being able to
>>                                                     turn it on via a
>>                                                     "poller timer"
>>                                                     set of commands)
>>                                                     would be much
>>                                                     more useful. I'll
>>                                                     look into that.
>>
>>                                                     Average time is
>>                                                     probably a good
>>                                                     stat - and
>>                                                     certainly what we
>>                                                     care about.
>>
>>                                                     I actually am
>>                                                     hopeful that
>>                                                     those couple of
>>                                                     things I did
>>                                                     might help reduce
>>                                                     that average time
>>                                                     quite a bit (that
>>                                                     short-cutting the
>>                                                     isotp protocol
>>                                                     handling
>>                                                     especially).
>>
>>                                                     That p/r with
>>                                                     logging changes
>>                                                     might help reduce
>>                                                     the unproductive
>>                                                     log time further,
>>                                                     but also makes it
>>                                                     possible to turn
>>                                                     on the poller
>>                                                     logging without
>>                                                     the RX task logs
>>                                                     kicking in.
>>
>>                                                     //.ichael
>>
>>                                                     On Sun, 12 May
>>                                                     2024 at 22:29,
>>                                                     Michael Balzer
>>                                                     via OvmsDev
>>                                                     <ovmsdev at lists.openvehicles.com>
>>                                                     wrote:
>>
>>                                                         Warning /
>>                                                         gathering
>>                                                         debug
>>                                                         statistics
>>                                                         about slow
>>                                                         processing
>>                                                         can be
>>                                                         helpful, but
>>                                                         there must
>>                                                         not be a hard
>>                                                         limit.
>>                                                         Frame/poll
>>                                                         response
>>                                                         processing
>>                                                         may need disk
>>                                                         or network
>>                                                         I/O, and the
>>                                                         vehicle task
>>                                                         may be
>>                                                         starving from
>>                                                         punctual high
>>                                                         loads on
>>                                                         higher
>>                                                         priority
>>                                                         tasks (e.g.
>>                                                         networking)
>>                                                         or by needing
>>                                                         to wait for
>>                                                         some
>>                                                         semaphore --
>>                                                         that's
>>                                                         outside the
>>                                                         application's
>>                                                         control, and
>>                                                         must not lead
>>                                                         to
>>                                                         termination/recreation
>>                                                         of the task
>>                                                         (in case
>>                                                         you're
>>                                                         heading
>>                                                         towards that
>>                                                         direction).
>>
>>                                                         I have no
>>                                                         idea how much
>>                                                         processing
>>                                                         time the
>>                                                         current
>>                                                         vehicles
>>                                                         actually need
>>                                                         in their
>>                                                         respective
>>                                                         worst cases.
>>                                                         Your draft is
>>                                                         probably too
>>                                                         lax, poll
>>                                                         responses and
>>                                                         frames
>>                                                         normally need
>>                                                         to be
>>                                                         processed
>>                                                         much faster.
>>                                                         I'd say 10 ms
>>                                                         is already
>>                                                         too slow, but
>>                                                         any wait for
>>                                                         a
>>                                                         queue/semaphore
>>                                                         will already
>>                                                         mean at least
>>                                                         10 ms
>>                                                         (FreeRTOS
>>                                                         tick).
>>                                                         Probably best
>>                                                         to begin with
>>                                                         just
>>                                                         collecting stats.
>>
>>                                                         Btw, to help
>>                                                         in narrowing
>>                                                         down the
>>                                                         actual
>>                                                         problem case,
>>                                                         the profiler
>>                                                         could collect
>>                                                         max times per
>>                                                         RX message ID.
>>
>>                                                         Regards,
>>                                                         Michael
>>
>>                                                         Am 12.05.24
>>                                                         um 10:41
>>                                                         schrieb
>>                                                         Michael Geddes:
>>
>>                                                             I have a
>>                                                             question
>>                                                             for
>>                                                             Michael
>>                                                             B  (or
>>                                                             whoever)
>>                                                             - I have
>>                                                             a commit
>>                                                             lined up
>>                                                             that
>>                                                             would add
>>                                                             a bit of
>>                                                             a time
>>                                                             check to
>>                                                             the
>>                                                             poller
>>                                                             loop.
>>                                                             What do
>>                                                             we expect
>>                                                             the
>>                                                             maximum time
>>                                                             to
>>                                                             execute a
>>                                                             poller
>>                                                             loop
>>                                                             command
>>                                                             should be?
>>
>>                                                             This is a
>>                                                             rough
>>                                                             idea (in
>>                                                             ms) I
>>                                                             have..
>>                                                             based on
>>                                                             nothing
>>                                                             much
>>                                                             really,
>>                                                             so any
>>                                                             ideas
>>                                                             would be
>>                                                             appreciated:
>>
>>                                                                 int
>>                                                             TardyMaxTime_ms(OvmsPoller::OvmsPollEntryType
>>                                                             entry_type)
>>                                                                   {
>>                                                                  
>>                                                             switch
>>                                                             (entry_type)
>>                                                                     {
>>                                                                    
>>                                                             case
>>                                                             OvmsPoller::OvmsPollEntryType::Poll:
>>                                                             return 80;
>>                                                                    
>>                                                             case
>>                                                             OvmsPoller::OvmsPollEntryType::FrameRx:
>>                                                             return 30;
>>                                                                    
>>                                                             case
>>                                                             OvmsPoller::OvmsPollEntryType::FrameTx:
>>                                                             return 20;
>>                                                                    
>>                                                             case
>>                                                             OvmsPoller::OvmsPollEntryType::Command:
>>                                                             return 10;
>>                                                                    
>>                                                             case
>>                                                             OvmsPoller::OvmsPollEntryType::PollState:
>>                                                             return 15;
>>                                                             default:
>>                                                             return 80;
>>                                                                     }
>>                                                                   }
>>
>>                                                             //.ichael
>>
>>                                                             On Mon, 6
>>                                                             May 2024
>>                                                             at 07:45,
>>                                                             Michael
>>                                                             Geddes
>>                                                             <frog at bunyip.wheelycreek.net>
>>                                                             wrote:
>>
>>                                                                 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.
>>
>>                                                                 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!!
>>
>>                                                                 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!.
>>
>>                                                                 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).
>>
>>                                                                 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!
>>
>>                                                                 Sooo..
>>                                                                 I'm
>>                                                                 still
>>                                                                 wondering
>>                                                                 what
>>                                                                 is
>>                                                                 going
>>                                                                 on. 
>>                                                                 Some
>>                                                                 things
>>                                                                 I'm
>>                                                                 going
>>                                                                 to try:
>>
>>                                                                 * 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.
>>
>>                                                                   -
>>                                                                 Add
>>                                                                 'current
>>                                                                 queue
>>                                                                 length'
>>                                                                 to
>>                                                                 the
>>                                                                 poller
>>                                                                 status
>>                                                                 information
>>                                                                 to
>>                                                                 see
>>                                                                 if
>>                                                                 this
>>                                                                 is
>>                                                                 indeed
>>                                                                 the
>>                                                                 case?
>>
>>                                                                   -
>>                                                                 Add
>>                                                                 some
>>                                                                 kind
>>                                                                 of
>>                                                                 alert
>>                                                                 when
>>                                                                 the
>>                                                                 queue
>>                                                                 reaches
>>                                                                 a % full?
>>
>>                                                                 *
>>                                                                 Once
>>                                                                 you
>>                                                                 start
>>                                                                 overflowing
>>                                                                 and
>>                                                                 getting
>>                                                                 overflow
>>                                                                 log
>>                                                                 messages,
>>                                                                 I
>>                                                                 wonder
>>                                                                 if
>>                                                                 this
>>                                                                 is
>>                                                                 then
>>                                                                 contributing
>>                                                                 to
>>                                                                 the
>>                                                                 problem.
>>
>>                                                                   -
>>                                                                 Push
>>                                                                 the
>>                                                                 overflow
>>                                                                 logging
>>                                                                 into
>>                                                                 Poller
>>                                                                 Task
>>                                                                 which
>>                                                                 can
>>                                                                 look
>>                                                                 at
>>                                                                 how
>>                                                                 many
>>                                                                 drops
>>                                                                 occurred
>>                                                                 since
>>                                                                 last
>>                                                                 received
>>                                                                 item.
>>
>>                                                                 *
>>                                                                 Split
>>                                                                 up
>>                                                                 the
>>                                                                 flags
>>                                                                 for
>>                                                                 the
>>                                                                 poller
>>                                                                 messages
>>                                                                 into 2:
>>
>>                                                                    -
>>                                                                 Messages
>>                                                                 that
>>                                                                 are/could
>>                                                                 be
>>                                                                 happening
>>                                                                 in
>>                                                                 the
>>                                                                 TX/RX
>>                                                                 tasks
>>
>>                                                                    -
>>                                                                 Other
>>                                                                 noisy
>>                                                                 messages
>>                                                                 that
>>                                                                 always
>>                                                                 happen
>>                                                                 in
>>                                                                 the
>>                                                                 poller
>>                                                                 task.
>>
>>                                                                 Thoughts
>>                                                                 on
>>                                                                 what
>>                                                                 else
>>                                                                 we
>>                                                                 might
>>                                                                 measure
>>                                                                 to
>>                                                                 figure
>>                                                                 out
>>                                                                 what
>>                                                                 is
>>                                                                 going on?
>>
>>                                                                 //.ichael
>>
>>                                                                 On
>>                                                                 Sun,
>>                                                                 5 May
>>                                                                 2024,
>>                                                                 19:29
>>                                                                 Michael
>>                                                                 Balzer
>>                                                                 via
>>                                                                 OvmsDev,
>>                                                                 <ovmsdev at lists.openvehicles.com>
>>                                                                 wrote:
>>
>>                                                                     Michael,
>>
>>                                                                     the
>>                                                                     queue
>>                                                                     size
>>                                                                     isn't
>>                                                                     in
>>                                                                     bytes,
>>                                                                     it's
>>                                                                     in
>>                                                                     messages:
>>
>>
>>                                                                          *
>>                                                                         @param
>>                                                                         uxQueueLength
>>                                                                         The
>>                                                                         maximum
>>                                                                         number
>>                                                                         of
>>                                                                         items
>>                                                                         that
>>                                                                         the
>>                                                                         queue
>>                                                                         can
>>                                                                         contain.
>>                                                                          *
>>                                                                          *
>>                                                                         @param
>>                                                                         uxItemSize
>>                                                                         The
>>                                                                         number
>>                                                                         of
>>                                                                         bytes
>>                                                                         each
>>                                                                         item
>>                                                                         in
>>                                                                         the
>>                                                                         queue
>>                                                                         will
>>                                                                         require.
>>
>>
>>                                                                     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.
>>
>>                                                                     Queue
>>                                                                     sizes
>>                                                                     are
>>                                                                     currently:
>>
>>                                                                     CONFIG_OVMS_HW_CAN_RX_QUEUE_SIZE=60
>>                                                                     CONFIG_OVMS_VEHICLE_CAN_RX_QUEUE_SIZE=60
>>
>>                                                                     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.
>>
>>                                                                     Nevertheless,
>>                                                                     an
>>                                                                     overflow
>>                                                                     with
>>                                                                     more
>>                                                                     than
>>                                                                     60
>>                                                                     waiting
>>                                                                     messages
>>                                                                     still
>>                                                                     indicates
>>                                                                     some
>>                                                                     too
>>                                                                     long
>>                                                                     processing
>>                                                                     time
>>                                                                     in
>>                                                                     the
>>                                                                     vehicle
>>                                                                     task.
>>
>>                                                                     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.
>>
>>                                                                     Regards,
>>                                                                     Michael
>>
>>
>
>     -- 
>     Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
>     Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
>
>     _______________________________________________
>     OvmsDev mailing list
>     OvmsDev at lists.openvehicles.com
>     http://lists.openvehicles.com/mailman/listinfo/ovmsdev
>
>
> _______________________________________________
> OvmsDev mailing list
> OvmsDev at lists.openvehicles.com
> http://lists.openvehicles.com/mailman/listinfo/ovmsdev

-- 
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20240614/8f468685/attachment-0001.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_signature.asc
Type: application/pgp-signature
Size: 203 bytes
Desc: OpenPGP digital signature
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20240614/8f468685/attachment-0001.sig>


More information about the OvmsDev mailing list