[Ovmsdev] Automatic naming of CAN log files
Michael Balzer
dexter at expeedo.de
Sat Dec 3 03:15:55 HKT 2022
Ludovic,
this is far more than I ever needed for my vehicle CAN logging, but I
can see this making sense in vehicle or ECU development, and in
gathering initial data for reverse engineering from users in the field.
With this, users can easily collect data over a couple of days taking
photos & notes, and then send the collected data to the developer.
That's currently hard to do, as users would need to monitor & manage the
continuous logging.
Your config scheme looks appropriate. I assume "vfs-auto" will set
another config instance to enable continuation after a crash/reboot?
Please avoid "_" on event names. Maybe you should raise e.g.
"can.log.rotate.pre" synchronously before the actual rotation, so
handlers can add some last info to the file, and "can.log.rotate.post"
after.
Adding a status dump before closing a file would be good so you can see
if there were drops. That currently needs a "can canX status" to be
triggered. Maybe clearing the counters on transition to the next file
then also makes sense.
A command to log arbitrary comments would also make sense, that could be
used by users and scripts.
Regards,
Michael
Am 26.11.22 um 23:31 schrieb Ludovic LANGE:
> 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
>
>
>
> _______________________________________________
> 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/20221202/79270920/attachment-0001.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_signature
Type: application/pgp-signature
Size: 203 bytes
Desc: OpenPGP digital signature
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20221202/79270920/attachment-0001.sig>
More information about the OvmsDev
mailing list