Hi Michael, Thanks for your encouraging feedback ! A few points:
I assume "vfs-auto" will set another config instance to enable continuation after a crash/reboot? In fact not at the moment :-) Based on the discussion we had in https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/issues/766 , I settled on the attachment to `sd.*` events to start/stop the log. It's working OK for the moment and starts as soon as the system is up and SC card mounted.
Please avoid "_" on event names. Any technical reason for that ? Or is it for consistency ? Should I replace with '-' or just have `can.log.rotatefiles` ?
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. Interesting. How could we ensure that all handlers have finished handling the event ? Waiting for some time ? I'm a little bit concerned of having to introduce delay in the rotation itself, not wanting to drop events.
Adding a status dump before closing a file would be good so you can see if there were drops Yes, that's useful to close the file with a dump of stats and counters. (And you're right about clearing them)
A command to log arbitrary comments would also make sense, that could be used by users and scripts. Indeed. Maybe as a broadcast to all open logs, and/or having the option to send the comments to a specific log.
Do you feel we should have all those features (pre/post events, status dump, log comment, your previous suggestion of file logging sync period) ready for a first PR candidate ? Or would you prefer that we try to polish the first functionality (some docs are needed, event naming), create a first PR, and then add incrementally those features as PRs ? Regards, Ludovic Le 02/12/2022 à 20:15, Michael Balzer a écrit :
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/mas...
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