[Ovmsdev] Automatic naming of CAN log files

Ludovic LANGE ll-ovmsdev at lange.nom.fr
Sun Nov 27 06:31:30 HKT 2022


Hi,

To follow on this previous idea, I'd like to share a Proof Of Concept of 
my proposal in the `748-split-can-log-files` branch for comments - you 
can see the diff here 
https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/compare/master...llange:Open-Vehicle-Monitoring-System-3:748-split-can-log-files

It does not (yet !) include all the suggestions received - notably 
absent is the proposal of file logging sync period from Michael below - 
but I'll try to take them into account.

There is an open issue 
https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/issues/748 
to gather public comments regarding the code if you prefer to do it on 
GitHub.

(When talking of automatic naming, I mean in fact automatic file name 
rotation based on different criterion)

Here it is:

  * A new command is introduced `can log start vfs-auto` which is
    exactly like `can log start vfs` but, you guessed it, with automatic
    file name rotation
      o The parameter to this command is not a file name any more, but a
        `prefix` (see below)

  * New configuration items are introduced:
      o `[can] log.file.maxsize_kb` : if the log file size exceeds this
        number, the file will be rotated
      o `[can] log.file.maxduration_s` : if the log file has logged for
        more than (this number) seconds, the file will be rotated
      o `[can] log.file.keep_empty` : in case a rotation would have
        created an empty file (no messages), should we rotate
        nevertheless (`true`) or not (`false`) ?
      o `[can] log.file.pattern` : this describes how to name the file
        with some variables (see below)

  * A new event `can.log.rotate_files` is introduced to allow one to
    force a file name rotation


The file name (`log.file.pattern`) can be configured with (combination 
of) the following elements:

  * `strftime` format conversion specification (like`%Y` `%H` ...)
  * `{vehicleid}` will be replaced by the configured vehicle id
  * `{session}` will be replaced by the counter of restarts of the
    module (always incrementing) (See
    https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/pull/779
    for a discussion, will certainly evolve)
  * `{prefix}` is the argument to the log command `can log start
    vfs-auto <format> <prefix>`, so that you can configure multiple logs
    in parallel and have them log to different files (by varying `prefix`)
  * `{splits}` is a counter of the number of cycles that occurred to
    this very log file
  * `{extension}` is the preferred extension for the chosen log format

(Any non-existing directory will be created on the go during file rotation)


The default for these variables are:
```
OVMS# con lis can
can (readable writeable)
   log.file.keep_empty: false
   log.file.maxduration_s: 1800
   log.file.maxsize_kb: 1024
   log.file.pattern: 
/sd/log/{vehicleid}/{session}/{prefix}/{splits}-%Y%m%d-%H%M%S{extension}
```

To illustrate a sequence of file name rotation, here is an excerpt with 
smaller values (maxduration: 120s / maxsize : 2kb), started by the 
command `can log start vfs-auto crtd essai`.

The first two renames occur because of maxduration (>= 120s) while the 
third rename occur because the log file exceeded 2048 bytes.
(In addition, SNTP synchro occurred just before the first rename, so you 
see that the first file segment is dated 1970... while the second one 
has proper date and time)

```
...
I (119937) canlog-vfs: canlog_vfs_autonaming::OutputMsg() size:172, log 
duration: 120s
I (119957) canlog-vfs: Closed vfs log 
'/sd/log/ovms-vehicle/00000390/essai/00000001-19700101-010008.crtd': 
Size:172 Messages:2 Dropped:0 Filtered:0 Rate:0.0%
I (119967) canlog-vfs: Changing file name from 
'/sd/log/ovms-vehicle/00000390/essai/00000001-19700101-010008.crtd' to 
'/sd/log/ovms-vehicle/00000390/essai/00000002-20221126-155952.crtd'
I (119977) canlog-vfs: Now logging CAN messages to 
'/sd/log/ovms-vehicle/00000390/essai/00000002-20221126-155952.crtd'

I (239967) canlog-vfs: canlog_vfs_autonaming::OutputMsg() size:1943, log 
duration: 120s
I (239987) canlog-vfs: Closed vfs log 
'/sd/log/ovms-vehicle/00000390/essai/00000002-20221126-155952.crtd': 
Size:1.9k Messages:22 Dropped:0 Filtered:0 Rate:0.0%
I (239997) canlog-vfs: Changing file name from 
'/sd/log/ovms-vehicle/00000390/essai/00000002-20221126-155952.crtd' to 
'/sd/log/ovms-vehicle/00000390/essai/00000003-20221126-160152.crtd'
I (240007) canlog-vfs: Now logging CAN messages to 
'/sd/log/ovms-vehicle/00000390/essai/00000003-20221126-160152.crtd'

I (334967) canlog-vfs: canlog_vfs_autonaming::OutputMsg() size:2111, log 
duration: 95s
I (334987) canlog-vfs: Closed vfs log 
'/sd/log/ovms-vehicle/00000390/essai/00000003-20221126-160152.crtd': 
Size:2.1k Messages:24 Dropped:0 Filtered:0 Rate:0.0%
I (334997) canlog-vfs: Changing file name from 
'/sd/log/ovms-vehicle/00000390/essai/00000003-20221126-160152.crtd' to 
'/sd/log/ovms-vehicle/00000390/essai/00000004-20221126-160327.crtd'
I (335007) canlog-vfs: Now logging CAN messages to 
'/sd/log/ovms-vehicle/00000390/essai/00000004-20221126-160327.crtd'
...

OVMS# vfs rls /sd/log/ovms-vehicle/00000390/essai/
      172  26-Nov-2022 15:59 
/sd/log/ovms-vehicle/00000390/essai/00000001-19700101-010008.crtd
     1.9k  26-Nov-2022 16:01 
/sd/log/ovms-vehicle/00000390/essai/00000002-20221126-155952.crtd
     2.1k  26-Nov-2022 16:03 
/sd/log/ovms-vehicle/00000390/essai/00000003-20221126-160152.crtd
        0  30-Nov-1979 00:00 
/sd/log/ovms-vehicle/00000390/essai/00000004-20221126-160327.crtd

```

Notes:

  * maxsize comparisons are done after writing, which means that you
    will have files slightly bigger than maxsize - not under maxsize.
    (for maxduration however it should be OK as the comparison is done
    before writing)

  * While the comparison of maxsize is done on the real number of bytes
    written, the concept of empty file (for `[can] log.file.keep_empty`)
    is based on the number of messages logged to the file.
    This, because most of the files will have a header written even if
    no messages are written ; which I considered to be nevertheless an
    empty file.
    Those "empty" files with no messages will not be rotated in that
    case (and kept open for logging).

Let me know what you think of this, if you have some remarks, and even 
if you feel it has no interest whatsoever.

Regards,

Ludovic


Le 12/11/2022 à 09:02, Michael Balzer a écrit :
> Ludovic,
>
> most of your thoughts were also mine on designing the file logging 
> scheme, I suggest taking that as a reference & inspiration.
>
> I suggest controlling this through a similar config scheme, 
> introducing more can config param instances as needed. There's 
> currently only the queue size:
>
> OVMS# con lis can
> can (readable writeable)
>   log.queuesize: 300
>
> The file logging sync period feature is what you need to not lose a 
> complete file on crash, it also enables following a file by "vfs tail" 
> and transferring the file content written so far without stopping the 
> logger.
>
> Regards,
> Michael
>
>
> Am 09.11.22 um 22:52 schrieb Ludovic LANGE:
>>
>> Hi,
>>
>> I'm planning to implement an "automatic naming" of the CAN log files 
>> for the VFS target. It would also take care of the file name rotation 
>> according to some criterion (file size, and/or log duration).
>>
>> I've created an issue to follow it here 
>> https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/issues/748 
>> (and some others also) but let me first share what I have in mind:
>>
>>
>> The use case is the following: I want to setup OVMS as a CAN bus 
>> datalogger. It should be always-on, always and continuously logging, 
>> event after a restart.
>>
>> (For that, my current solution is to use event scripts, cf 
>> https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/issues/766 
>> )
>>
>> Logging to the same file, in that case, present some challenges:
>>
>>   * file size would grow indefinitely, which could be then make it
>>     difficult to copy / network send somewhere
>>   * file would always be opened, which could prevent any action on it
>>     (if we want to send it somewhere else, or remove it)
>>   * in case of crash / corruption the whole file could be lost
>>   * in case of reboot you'd end overwriting the file.
>>
>> Of course we should change the file name, but it's not easy to do it 
>> in a script.
>>
>> It may be possible to do this with Duktape and `|OvmsCommand.Exec|` 
>> but I fear that we may miss events if we stop / start logging on a 
>> highly loaded bus.
>>
>>
>> A proposal to solve this would be to add a new mode in 
>> `canlog_vfs.cpp` that would cater for this automatic naming 
>> (inspiration for this feature coming from another product).
>>
>>
>> In this mode you don't pass the path as a parameter, but instead a 
>> `log prefix` that will be used to construct the file path.
>>
>> Syntax could be something like : `can log start vfs-auto crtd <log 
>> prefix> [filter1] ... [filterN]` (no filename).
>>
>> It would automatically generate a log file name, taking into account 
>> the splits / rotations that can be configured:
>>
>>   * if asked for by configuration - rotate file name (= increment
>>     file name) after a file size is reached
>>   * if asked for by configuration - rotate file name (= increment
>>     file name) after a certain logging duration has been reached
>>
>>
>> Naming would be 'automatic' with something like :
>> `/sd/log/<vehicleid>/<#power on>/<log prefix>/<#rotations>.<log 
>> extension>`
>>
>> where:
>> * `/sd/log/` is arbitrary. Could be coming from configuration if 
>> wanted (esp. for module without sd card)
>> * `<vehicleid>` is there to help to declutter your sdcard (if you 
>> share it with multiple modules), or to declutter your storage server 
>> (when 
>> https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/issues/749 
>> has been completed). We may have to make it a valid filename.
>> * `<#power on>` is the number of time the module has powered on ; it 
>> is an always incrementing number expressed as an integer on 8 digits. 
>> Depending on the configuration, some modules will be always-on ; 
>> others will stop more frequently - the number will overflow after 
>> 99.999.999 power on, which will certainly see a change of sd card, so 
>> no fear of unwanted overwriting of files
>> * `<log prefix>` is a way to distinguish between multiple concurrent 
>> can logs active.
>> * `<#rotations>` is a counter of rotations for this file and this 
>> power on ; it is an integer on 8 digits ; reset to `00000001` at each 
>> poweroff and that will increment each time there is a file name rotation.
>>
>> some configuration items cater for the file name rotation:
>> * `split_size_mb` : when the file has reached this size, the file is 
>> closed, the element `<#rotations>` is incremented, and a new file 
>> with the 'automatic' name is opened.
>> * `split_duration_s` : when the file has logged for this duration, 
>> the file is closed, the element `<#rotations>` is incremented, and a 
>> new file with the 'automatic' name is opened.
>>
>>
>>
>> example of file name:  `/sd/log/mycar/00000024/can1-25k/00000005.crtd`
>>
>>
>> (Of course we need a way to either stop logging once the VFS is full, 
>> or to auto-remove some log files under this path)
>>
>>
>> Let me know if you have any thoughts / concerns about this.
>>
>>
>> Regards,
>>
>> Ludovic
>>
>
> -- 
> 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

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20221126/be4b2c00/attachment-0001.htm>


More information about the OvmsDev mailing list