[Ovmsdev] OVMS Poller module/singleton

frog at bunyip.wheelycreek.net frog at bunyip.wheelycreek.net
Sun Jun 23 17:03:13 HKT 2024


This is by-and-large working (pushed).  The only thing is that occasionally the records seem to be coming in out-of-order.  For example  (after some munging with jq)

 

"2024-06-23 05:28:16",6,"RxCan1[7bb]",13.63,5.933,8.526,0.06,3.685

"2024-06-23 05:28:16",7,"RxCan1[7ce]",0.57,0.195,0.365,0.034,0.759

"2024-06-23 05:28:16",8,"RxCan1[7ea]",4.41,1.796,2.416,0.052,1.557

"2024-06-23 05:28:16",9,"RxCan1[7ec]",18.95,7.672,11.532,0.112,19.324

"2024-06-23 05:28:16",10,"RxCan3[7df]",9.09,1.554,1.999,0.023,1.242

"2024-06-23 05:28:16",16,"TxCan1[7e4]",2.15,0.06,0.094,0.003,0.079

"2024-06-23 05:28:16",17,"Cmd:Thrtl",0,0,0.004,0.004,0.044

"2024-06-23 05:28:16",18,"Cmd:RspSp",0,0,0.002,0.002,0.019

"2024-06-23 05:28:16",19,"Cmd:SucSp",0,0,0.002,0.002,0.018

"2024-06-23 05:28:16",20,"Cmd:State",0,0,0,0.01,0.104

"2024-06-23 05:28:17",1,"Poll:PRI",1.07,0.472,0.565,0.039,0.675

"2024-06-23 05:28:17",2,"Poll:SEC",2.17,0.433,0.527,0.02,0.474

"2024-06-23 05:28:17",3,"Poll:SRX",6.51,1.369,1.952,0.022,0.524

"2024-06-23 05:28:17",4,"RxCan1[778]",2.42,1.216,1.801,0.064,2.412

"2024-06-23 05:28:17",5,"RxCan1[7a8]",0.9,0.367,0.769,0.045,1.343

 

The items 1-5 should be before 6,but the timestamp is after.

 

//.ichael

 

From: OvmsDev <ovmsdev-bounces at lists.openvehicles.com> On Behalf Of Michael Balzer via OvmsDev
Sent: Friday, June 21, 2024 11:40 PM
To: OVMS Developers <ovmsdev at lists.openvehicles.com>
Cc: Michael Balzer <dexter at expeedo.de>
Subject: Re: [Ovmsdev] OVMS Poller module/singleton

 

Michael,

"data" notifications correspond to the V2/MP "historical" message type:

*	https://docs.openvehicles.com/en/latest/protocol_v2/messages.html#historical-data-update-message-0x48-h

So a record type of "*-LOG-Poll" would be OK, but I suggest using "*-LOG-PollStats" to be more precise.

The record ID needs to be an integer, and the default V2 server database defines this to be a 32 bit signed integer. Note that sending a new record won't overwrite an existing one with the same ID, as the timestamp is part of the primary key. I suggest using your report line number.

You can provide a header as line 0 then, or you can leave adding a header to the download tool (as do all the other data records up to now). If you use my server, you can download all data from the car UI, if you use another public server, you can still use my download tool via this page:

*	https://dexters-web.de/downloadtool?lang=EN

Download tools other than the ones I provide in my web UI are the scripts in the server repository's client directory:

*	https://github.com/openvehicles/Open-Vehicle-Server/tree/master/clients

The most simple form is shown by the "serverlog.sh" script, for adding headers see e.g. "rt_fetchlogs.sh". I normally let my server send me the logs by mail on a daily base, these include all historical data files with headers added.

Assuming record type "*-LOG-PollStats", I've just added auto headers to my tool based on your template as follows:

*	type,count_hz,avg_util_pm,peak_util_pm,avg_time_ms,peak_time_ms

(keeping the header style consistent with the other logs)

So you can now simply send the data rows, the tool will prepend the header once on each download.

Regards,
Michael



Am 19.06.24 um 11:10 schrieb Michael Geddes:

Sure, I can do that. 

I did it this way because it was easier and could mostly do it in one message. As soon as I added spaces for alignment it pushed the message over 2 notifications. Also, I wasn't sure about making a new Data type and how that worked.

 

I'm assuming something like: *-LOG-Poll  would work (unless you want to suggest something else)  The next 2 cols seem to be ID and lifetime.

What do I use as an ID?  Can it be an alpha string or does it have to be a number? (LIke using the first column descriptor).  I'm not sure

how the ID column is treated.  I _could_ just send a line number for the dump group I guess?

 

These are the columns I have. I can force the two cols to be always permille.

"Type","Count (hz)","Avg utlization (permille)","Peak utlization (permille)", "Avg Time (ms)","Peak Time (ms)"

 

Type is the only alpha column.. but if I can use that for the ID I guess that would be better?

 

How would I provide a  header if I wanted to? Is there some indicator saying it's a header line? I'm not sure I want to - just asking.

 

//.ichael

 

On Wed, 19 June 2024, 00:11 Michael Balzer via OvmsDev, <ovmsdev at lists.openvehicles.com <mailto:ovmsdev at lists.openvehicles.com> > wrote:

Michael,

I've received the new drive report notifications now; these need to be changed: please do not use text notifications to transport CSV data. That's what "data" notifications are meant for, which are stored in their raw form on the server for later retrieval. See e.g. the vehicle trip & grid logs for reference on how to build the messages, or have a look at the specific Twizy and UpMiiGo data messages.

Data notifications also are designed to transport one row at a time, so you normally don't run into buffer size issues. A header can be supplied as a row, but you normally add one when downloading the data from the server, so tools don't need to filter these out. I provide headers automatically on my server for known message types, just send me your template and I'll include that.

Apart from that, the timing statistics now seem to work pretty well, providing valuable insights.

Regards,
Michael




Am 14.06.24 um 08:59 schrieb Michael Geddes:

Thankyou. 

I was more worried that we might be waiting on each other.

 

I don't think I have quite the correct able to test on my friends Leaf properly, or does it use the standard cable?

 

Anyway, let me know what I can do to.

 

//.ichael

 

On Fri, 14 Jun 2024 at 14:46, Michael Balzer via OvmsDev <ovmsdev at lists.openvehicles.com <mailto:ovmsdev at lists.openvehicles.com> > wrote:

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 <mailto: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 <mailto: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 <mailto: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 <mailto: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 <mailto: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 <mailto: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 <mailto: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                : 





-- 
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/20240623/cce787b3/attachment-0001.htm>


More information about the OvmsDev mailing list