[Ovmsdev] CAN BUS logging to flash storage
Mark Webb-Johnson
mark at webb-johnson.net
Fri Jan 19 09:18:58 HKT 2018
Which leads me to my next ’nice to have’ item…
re play start <format> <filepath> <speedfactor> <rx|tx>
re play speed <speedfactor>
re play stop
re play pause
re play resume
re play status
Point it to a log file on disk, and it plays it back. The <speedfactor> defaults to 1 (read-time), and <rx|tx> defaults to Rx. Comments in the log file come back on screen as log messages.
I did something similar with CAN-RE-TOOL, where we could replay a can bus capture back into the system, and it was extremely useful. It allows developers to test vehicle modules, against previously captured data, as well as simulate actual vehicles. However, it only really works for broadcast style systems (not request-response PID polling).
Implementation is pretty simple - just read a line from the log file and simulate reception, or actually transmit on the bus. The only tricky bit is honouring the timestamps and delaying the replay of the next frame until that time. Setting <speedfactor> to 2, plays at 2x real-time (delay/2), and 0.5 plays at 1/2 real-time (delay/0.5). The rx|tx flag controls whether we simulate reception of data (the default), or actually transmit it out on the can bus (to another system, or perhaps another ovms module for testing).
I’ll be working on this; just need to get the 3.1 hardware into production.
Regards, Mark.
> On 19 Jan 2018, at 7:17 AM, Michael Balzer <dexter at expeedo.de> wrote:
>
> OK, first implementation is done & pushed. Documentation is missing, I'll add that ASAP.
>
> Basic usage:
>
> OVMS > can ?
> can1 CANx framework
> can2 CANx framework
> can3 CANx framework
> log CAN logging framework
>
> OVMS > can log ?
> crtd ...format logging
> off Stop logging
> status Logging status
> trace Logging to syslog
>
> OVMS > can log status
> CAN logging inactive.
>
> OVMS > can log trace ?
> Usage: can log trace [filter1] [filter2] [filter3]
> Filter: <bus> / <id>[-<id>] / <bus>:<id>[-<id>]
> Example: 2:2a0-37f
>
> OVMS > can log crtd ?
> Usage: can log crtd <path> [filter1] [filter2] [filter3]
> Filter: <bus> / <id>[-<id>] / <bus>:<id>[-<id>]
> Example: 2:2a0-37f
>
>
> OVMS > can log trace
> CAN logging active: Type:trace; Path:''; Filter:off; Vehicle:;
> Note: info logging is done at log level debug, frame logging at verbose
>
> OVMS > can can2 tx standard 201 12 34 56 11 22 33 44 55
> E (358776) canlog: Error can2 rxpkt=0 txpkt=1 errflags=0x8000 rxerr=63 txerr=0 rxovr=0 txovr=0 txdelay=0
>
> OVMS > can log off
> Closing log: Type:trace; Path:''; Filter:off; Vehicle:;
> CAN logging stopped.
>
>
> OVMS > can log crtd /sd/test.crtd 1 2:780-7ff
> CAN logging active: Type:crtd; Path:'/sd/test.crtd'; Filter:1:0-ffffffff,2:780-7ff; Vehicle:;
> OVMS > can can1 rx standard 100 12 34 56 11 22 33 44 55
> OVMS > can can1 tx standard 101 12 34 56 11 22 33 44 55
> OVMS > can can2 rx standard 200 12 34 56 11 22 33 44 55
> OVMS > can can2 tx standard 201 12 34 56 11 22 33 44 55
> OVMS > can can2 rx standard 7d2 12 34 56 11 22 33 44 55
> OVMS > can can2 tx standard 7d3 12 34 56 11 22 33 44 55
> OVMS > can log off
> Closing log: Type:crtd; Path:'/sd/test.crtd'; Filter:1:0-ffffffff,2:780-7ff; Vehicle:;
> CAN logging stopped.
>
> OVMS > vfs cat /sd/test.crtd
> 459.576 CXX Info Type:crtd; Path:'/sd/test.crtd'; Filter:1:0-ffffffff,2:780-7ff; Vehicle:;
> 476.706 1R11 100 12 34 56 11 22 33 44 55
> 480.366 1T11 101 12 34 56 11 22 33 44 55
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8000a6 rxerr=28 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8000a6 rxerr=28 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8000a6 rxerr=37 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8000a6 rxerr=46 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8000a6 rxerr=55 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8000a6 rxerr=64 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8000a6 rxerr=73 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8000a6 rxerr=82 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x44000 rxerr=99 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x44000 rxerr=99 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8040a6 rxerr=100 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8040a6 rxerr=109 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8040a6 rxerr=118 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8040a6 rxerr=127 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x204000 rxerr=135 txerr=0 rxovr=0 txovr=0 txdelay=0
> 480.366 1CEV Error rxpkt=1 txpkt=1 errflags=0x8040a6 rxerr=135 txerr=0 rxovr=0 txovr=0 txdelay=0
> 522.616 2R11 7D2 12 34 56 11 22 33 44 55
> 522.616 2CEV TX_Queue T11 7D3 12 34 56 11 22 33 44 55
>
>
> Vehicle events are also logged, and if you issue "can <bus> status", the packet statistics will be logged.
>
> The crtd logger is fast enough for the (single bus) Twizy at 500 kbit without filters. I still have no means to test multiple buses.
>
> The current implementation limits the user to one active can logger, but that's just for ease of use and not fixed. We can add support for multiple parallel loggers, but I doubt there's an actual use case for this.
>
> Btw, as a next logger, we could implement the pcapng format: https://wiki.wireshark.org/Development/PcapNg <https://wiki.wireshark.org/Development/PcapNg>
>
> Regards,
> Michael
>
>
> Am 14.01.2018 um 18:13 schrieb Michael Balzer:
>> Mark,
>>
>> thanks for the info, I'll add a documentation file on this.
>>
>> It just turned out writing into a file is far too slow to be done inline with the frame processing… and yes, I _could_ have anticipated that ;)
>>
>> Maybe idf 3.x will perform better on file I/O, but a separate logging task is better anyway.
>>
>> Regards,
>> Michael
>>
>>
>> Am 12.01.2018 um 01:44 schrieb Mark Webb-Johnson:
>>> Thanks.
>>>
>>> I really should formally document the CRTD format properly somewhere. Anyway, here are my old notes on it, and an example:
>>>
>>> +++++
>>>
>>> CRTD Example:
>>>
>>> 1320724293.000 CXX OVMS Tesla Roadster cando2crtd converted log
>>> 1320724293.000 CXX OVMS Tesla roadster log: trip.20111108.csv
>>> 1320724294.072 R11 420 00 96 96
>>> 1320724294.073 R11 588 00 00 86
>>> 1320724294.073 R11 280 00 00 03 00 00 00 00 00
>>> 1320724294.073 R11 001 00 00 00 00
>>> 1320724294.073 R11 590 01 00 00 00 00 00 00 00
>>> 1320724294.113 R11 400 01 01 00 00 00 00 4C 1D
>>>
>>> Generators should use whatever line termination the host system uses. For Unix and embedded systems that is LF. Parsers should support all CR, LF, and CRLF variants.
>>>
>>> Generators should output hex fields in upper-case and front zero padded (for clarity). Parsers should support both upper and lower case, as well as variable length.
>>>
>>> By convention, the .crtd extension is used for these files. It is suggested that generators prefix all crtd files with CXX lines documenting the generator, comment and source of log file.
>>>
>>> Space-separated fields are:
>>> Timestamp (can be seconds, milliseconds, or microseconds - zero prefixed and full length padded for ms and us).
>>> Type:
>>> C*: comment
>>> CXX: general comment (rest of line is a comment)
>>> CEV: user-generated event (rest of line is event description)
>>> R11: rx standard frame
>>> R29: rx extended frame
>>> T11: tx standard frame
>>> T29: tx extended frame
>>>
>>> Other field notes:
>>> For the R?? and T?? types, the rest of the line is hex ID followed by hex data bytes (up to 8).
>>> In the case of systems supporting multiple CAN buses, the type can be prefixed with the bus number (eg; 1R11, 2T29, etc). Messages from different CAN bus captures can be written to one shared crtd file, or individual files for each bus - entirely up to the generator.
>>>
>>> +++++
>>>
>>> Regards, Mark.
>>>
>>>> On 11 Jan 2018, at 8:59 PM, Michael Balzer <dexter at expeedo.de <mailto:dexter at expeedo.de>> wrote:
>>>>
>>>> Mark,
>>>>
>>>> I'll add the logging support along with the TX queue.
>>>>
>>>> Regards,
>>>> Michael
>>>>
>>>>
>>>> Am 10.01.2018 um 01:27 schrieb Mark Webb-Johnson:
>>>>> Probably best to split this off as a separate eMail thread.
>>>>>
>>>>> I think the implementation would be relatively simple.
>>>>>
>>>>> Create a canlog class with a FILE* m_log member variable, and a virtual function Log() that is called with a direction (tx/rx) and frame to log.
>>>>> The constructor should be passed the vfs file path to log to. It should fopen the m_log file to that.
>>>>> The destructor should fclose the m_log file.
>>>>> Create a canlog_crtd class, derived from canlog, that supports Log() to log to m_log in CRTD format.
>>>>> Optionally create other canlog_* classes, for other logging formats that we want to support.
>>>>> Add a canlog* m_log member variable in canbus.
>>>>> Initialise m_log to NULL in the constructor.
>>>>> In the destructor, if m_log is not null, delete it’s object and set it to NULL.
>>>>> Have a command ‘can log’ like ‘can trace’ that specifies a vfs file path (remember to check it with OvmsConfig ProtectedPath) and logging format. It will then ’new’ a canlog_* style object (depending on logging format).
>>>>> In can::IncomingFrame, log incoming CAN messages with m_log->Log(), in the same way as m_trace is handled.
>>>>> In canbus::Write, log outgoing CAN messages with m_log->Log(), in the same way as m_trace is handled.
>>>>>
>>>>> Volunteer?
>>>>>
>>>>> Regards, Mark.
>>>>>
>>>>>> On 10 Jan 2018, at 8:07 AM, Mark Webb-Johnson <mark at webb-johnson.net <mailto:mark at webb-johnson.net>> wrote:
>>>>>>
>>>>>> Now SD CARD support is coming, anybody want to step forward and extend components/can to support CAN bus logging to a file (in crtd format, or perhaps support one or two popular formats)? Implementation would be in class canbus, very similar to m_trace; just need to have a FILE* m_log and appropriate commands / logging of packet write/read in the same place that trace does it.
>>>>>
>>>>>
>>>>>
>>>>> _______________________________________________
>>>>> OvmsDev mailing list
>>>>> OvmsDev at lists.teslaclub.hk <mailto:OvmsDev at lists.teslaclub.hk>
>>>>> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev <http://lists.teslaclub.hk/mailman/listinfo/ovmsdev>
>>>>
>>>>
>>>> --
>>>> Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
>>>> Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
>>>> _______________________________________________
>>>> OvmsDev mailing list
>>>> OvmsDev at lists.teslaclub.hk <mailto:OvmsDev at lists.teslaclub.hk>
>>>> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev <http://lists.teslaclub.hk/mailman/listinfo/ovmsdev>
>>>
>>>
>>>
>>> _______________________________________________
>>> OvmsDev mailing list
>>> OvmsDev at lists.teslaclub.hk <mailto:OvmsDev at lists.teslaclub.hk>
>>> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev <http://lists.teslaclub.hk/mailman/listinfo/ovmsdev>
>>
>> --
>> Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
>> Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
>>
>>
>> _______________________________________________
>> OvmsDev mailing list
>> OvmsDev at lists.teslaclub.hk <mailto:OvmsDev at lists.teslaclub.hk>
>> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev <http://lists.teslaclub.hk/mailman/listinfo/ovmsdev>
>
> --
> Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
> Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
> _______________________________________________
> OvmsDev mailing list
> OvmsDev at lists.teslaclub.hk
> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20180119/23e53ead/attachment.htm>
More information about the OvmsDev
mailing list