Candump log replay with PyCyphal v1.9

pavel.kirienko · July 15, 2022, 1:16pm

Watch this:

candump -l any

Now we have raw CAN frames stored in the standard candump log format in candump-2022-07-15_160731.log. The file looks like this:

(1657890452.649500) slcan0 197FE625#C90EED2E661A00FB
(1657890453.650392) slcan0 197FE625#C90EED2E661A00FC
(1657890455.650491) slcan0 197FE625#C90EED2E661A00FD
(1657890458.649485) slcan0 197FE625#C90EED2E661A00FE
(1657890459.649489) slcan0 197FE625#C90EED2E661A00FF

Now we can extract Cyphal/CAN traffic from that file using the candump pseudo-media-layer:

export UAVCAN__CAN__IFACE='candump:candump-2022-07-15_160731.log'
y sub uavcan.node.heartbeat 10:reg.udral.service.common.readiness 130:reg.udral.service.actuator.common.status

Monitor what was happening on the bus using y mon.

Convert data from raw candump log to JSON for multiple topics at once:

y sub +M uavcan.node.heartbeat 10:reg.udral.service.common.readiness 130:reg.udral.service.actuator.common.status > converted.json

Check out the converted JSON:

{"7509":{"_meta_":{"ts_system":1657823551.809849,"ts_monotonic":1227765.178565,"source_node_id":125,"transfer_id":31,"priority":"nominal","dtype":"uavcan.node.Heartbeat.1.0"},"uptime":3843,"health":{"value":0},"mode":{"value":0},"vendor_specific_status_code":0}}
{"130":{"_meta_":{"ts_system":1657823551.809247,"ts_monotonic":1227765.178476,"source_node_id":125,"transfer_id":31,"priority":"low","dtype":"reg.udral.service.actuator.common.Status.0.1"},"motor_temperature":{"kelvin":331.1372985839844},"controller_temperature":{"kelvin":303.8972473144531},"error_count":0,"fault_flags":{"overload":false,"voltage":false,"motor_temperature":false,"controller_temperature":false,"velocity":false,"mechanical":false,"vibration":false,"configuration":false,"control_mode":false,"other":false}}}
{"7509":{"_meta_":{"ts_system":1657823551.918804,"ts_monotonic":1227765.184008,"source_node_id":0,"transfer_id":0,"priority":"nominal","dtype":"uavcan.node.Heartbeat.1.0"},"uptime":0,"health":{"value":0},"mode":{"value":0},"vendor_specific_status_code":0}}
{"130":{"_meta_":{"ts_system":1657823552.809019,"ts_monotonic":1227766.177856,"source_node_id":125,"transfer_id":0,"priority":"low","dtype":"reg.udral.service.actuator.common.Status.0.1"},"motor_temperature":{"kelvin":331.1372985839844},"controller_temperature":{"kelvin":303.816650390625},"error_count":0,"fault_flags":{"overload":false,"voltage":false,"motor_temperature":false,"controller_temperature":false,"velocity":false,"mechanical":false,"vibration":false,"configuration":false,"control_mode":false,"other":false}}}
{"7509":{"_meta_":{"ts_system":1657823552.810083,"ts_monotonic":1227766.178854,"source_node_id":125,"transfer_id":0,"priority":"nominal","dtype":"uavcan.node.Heartbeat.1.0"},"uptime":3844,"health":{"value":0},"mode":{"value":0},"vendor_specific_status_code":0}}

You can then print that using PlotJuggler or whatever.

P.S. if you want the command to exit automatically when the log file is fully replayed, set the environment variable PYCYPHAL_CANDUMP_YOU_ARE_TERMINATED to a non-zero value. This is expected to be improved with https://github.com/OpenCyphal/pycyphal/issues/227

erik.rainey · December 21, 2023, 5:09pm

This seems broken at the moment? Part of the issue seems to be where it wants the compiled DSDL (~/.pycyphal).

I captured some socketcan format in this mechanism and it’s not playing back in monitor or in the subscription.

$ yakut compile --allow-unregulated-fixed-port-id -O ~/.cyphal ~/.cyphal/dsdl/uavcan ~/.cyphal/dsdl/reg 
$ export CYPHAL_PATH=~/.cyphal
$ export PYTHONPATH=$CYPHAL_PATH
$ export UAVCAN__NODE__IFACE=candump:can.log
.. <fails, looking in ~/.pycyphal> ...
.. move compiled items to .pycyphal and move PYTHONPATH
$ y sub +M uavcan.node.Heartbeat
... nothing
$ y mon 
... nothing

pavel.kirienko · December 22, 2023, 8:30am

Please share your can.log, I will give it a look. Also, there’s a related discussion on Matrix. In case the link doesn’t work:

erik.rainey · December 28, 2023, 5:46pm

I’m seeing a similar issue as was present in the discussion on Matrix, the data array is set to nothing.

CandumpMedia('candump-2023-12-21_094559.log', mtu=64): Parsed line 10: '(1703173565.357423) can0 0C7D5522##552000000000000E7\n' -> 2023-12-21T09:46:05.357423/5.640603 'can0' 0c7d5522#
2023-12-28 10:09:10 0044332 DEB pycyphal.transport.can._can: CANTransport(CandumpMedia('candump-2023-12-21_094559.log', mtu=64), local_node_id=None): Parsing received CAN frames:
2023-12-21T09:46:04.357314/4.638627 Envelope(frame=DataFrame(id=0x0c7d5522, data=), loopback=False)

The log is fairly short and simple:

(1703173559.356901) can0 0C7D5522##54C000000000000E1
(1703173560.357126) can0 0C7D5522##54D000000000000E2
(1703173561.357353) can0 0C7D5522##54E000000000000E3
(1703173562.357265) can0 0C7D5522##54F000000000000E4
(1703173563.357311) can0 0C7D5522##550000000000000E5
(1703173563.358325) can0 187D5622##5080000000103F81F551D561D040000000101001C40000000000000000000000000000000000000000000000000000000000000000000000000000000000000A6
(1703173563.358326) can0 187D5622##50000000000000000000000E003000000000000000000000040400000000000000000000000000000000020000000000000000000000000000000000000000006
(1703173563.359326) can0 187D5622##500000000000000000000000000000300E00300400C00000000000000000000000000000000000000000000000011CD66
(1703173564.357314) can0 0C7D5522##551000000000000E6
(1703173565.357423) can0 0C7D5522##552000000000000E7
(1703173566.357548) can0 0C7D5522##553000000000000E8
(1703173567.357462) can0 0C7D5522##554000000000000E9
(1703173568.357493) can0 0C7D5522##555000000000000EA
(1703173569.357659) can0 0C7D5522##556000000000000EB
(1703173570.357684) can0 0C7D5522##557000000000000EC
(1703173571.357780) can0 0C7D5522##558000000000000ED
(1703173572.357887) can0 0C7D5522##559000000000000EE
(1703173573.358062) can0 0C7D5522##55A000000000000EF
(1703173573.359064) can0 187D5622##5080000000103F81F551D561D040000000101001C40000000000000000000000000000000000000000000000000000000000000000000000000000000000000A7
(1703173573.359065) can0 187D5622##50000000000000000000000E003000000000000000000000040400000000000000000000000000000000020000000000000000000000000000000000000000007
(1703173573.360071) can0 187D5622##500000000000000000000000000000300E00300400C00000000000000000000000000000000000000000000000011CD67
(1703173574.357946) can0 0C7D5522##55B000000000000F0
(1703173575.358172) can0 0C7D5522##55C000000000000F1
(1703173576.358117) can0 0C7D5522##55D000000000000F2
(1703173577.358275) can0 0C7D5522##55E000000000000F3
(1703173578.358271) can0 0C7D5522##55F000000000000F4
(1703173579.358454) can0 0C7D5522##560000000000000F5
(1703173580.358434) can0 0C7D5522##561000000000000F6

pavel.kirienko · December 28, 2023, 5:50pm

Your log file seems to separate the payload with double ##. Try adding + after the # in these regexes:

github.com

OpenCyphal/pycyphal/blob/4846761a20dba7c23efd403c0a5c053ee9196f6c/pycyphal/transport/can/media/candump/_candump.py#L242-L243


      
          _RE_REC_REMOTE = re.compile(r"(?a)^\s*\((\d+\.\d+)\)\s+([\w-]+)\s+([\da-fA-F]+)#R")
          _RE_REC_DATA = re.compile(r"(?a)^\s*\((\d+\.\d+)\)\s+([\w-]+)\s+([\da-fA-F]+)#([\da-fA-F]*)")

erik.rainey · December 28, 2023, 6:22pm

That didn’t seem to change anything:

_RE_REC_REMOTE = re.compile(r"(?a)^\s*\((\d+\.\d+)\)\s+([\w-]+)\s+([\da-fA-F]+)#+R")
_RE_REC_DATA = re.compile(r"(?a)^\s*\((\d+\.\d+)\)\s+([\w-]+)\s+([\da-fA-F]+)#+([\da-fA-F]*)")

Output from -v -v

2023-12-28 12:16:02 0062162 DEB pycyphal.transport.can.media.candump._candump: CandumpMedia('candump-2023-12-21_094559.log', mtu=64): Parsed line 8: '(1703173563.359326) can0 187D5622##500000000000000000000000000000300E00300400C00000000000000000000000000000000000000000000000011CD66\n' -> 2023-12-21T09:46:03.359326/4.680741 'can0' 187d5622#
2023-12-28 12:16:02 0062162 DEB pycyphal.transport.can._can: CANTransport(CandumpMedia('candump-2023-12-21_094559.log', mtu=64), local_node_id=None): Parsing received CAN frames:

I’ll follow these instruction Development guide — PyCyphal 1.15.4 documentation to run the testing and I can add some pedantic ## test to those too.

pavel.kirienko · December 28, 2023, 6:38pm

From the project root, run:

nox -- -k candump

The test is likely to report failure because it will fail to meet the minimum coverage level, please ignore that.

erik.rainey · December 28, 2023, 7:36pm

I was able to isolate to just the _candump.py file itself using

pytest pycyphal/transport/can/media/candump

I added this test

    rec = Record.parse("(1703173569.357659) can0 0C7D5522##556000000000000EB\n")
    assert isinstance(rec, DataFrameRecord)
    assert rec.ts.system_ns == 1703173569_357659
    assert rec.iface_name == "can0"
    assert rec.fmt == FrameFormat.EXTENDED
    assert rec.can_id == 0x0C7D5522
    assert rec.can_payload == bytes.fromhex("556000000000000EB")
    print(rec)

It reported (after I added a _logger.info with the found groups) that the #+ is parsing the groups apart but there’s something else.

INFO     pycyphal.transport.can.media.candump._candump:_candump.py:257 Groups: 1703173569.357659, can0, 0C7D5522, 556000000000000EB
DEBUG    pycyphal.transport.can.media.candump._candump:_candump.py:269 Cannot convert values from line '(1703173569.357659) can0 0C7D5522##556000000000000EB\n': ValueError('non-hexadecimal number found in fromhex() arg at position 17')

The assert isinstance(rec, DataFrameRecord) is firing, so I think it’s the fromhex inside the object.

Maybe it’s the new line?

pavel.kirienko · December 28, 2023, 7:41pm

Yeah:

>>> '556000000000000EB\n'[17]
'\n'

erik.rainey · December 28, 2023, 7:45pm

I took the line from the above capture (1703173569.357659) can0 0C7D5522##556000000000000EB however it’s got an odd number of nibbles.

55 60 00 00 00 00 00 0E B

that last B needs to be paired with something else, so it’s actually but complaining that it’s not the correct number of nibbles, which it seems it’s not. Maybe the ## indicates something?

pavel.kirienko · December 28, 2023, 7:52pm

Sadly there doesn’t appear to be a comprehensive specification of the log format used by candump. We may need to check the sources: https://github.com/linux-can/can-utils/blob/master/candump.c

erik.rainey · December 28, 2023, 7:53pm

github.com

linux-can/can-utils/blob/master/lib.c#L271


      
          	/* documentation see lib.h */
          
          	char buf[CL_CFSZ]; /* max length */
          
          	sprint_canframe(buf, cf, sep, maxdlen);
          	fprintf(stream, "%s", buf);
          	if (eol)
          		fprintf(stream, "%s", eol);
          }
          
          void sprint_canframe(char *buf, struct canfd_frame *cf, int sep, int maxdlen)
          {
          	/* documentation see lib.h */
          
          	int i, offset;
          	int len = (cf->len > maxdlen) ? maxdlen : cf->len;
          
          	if (cf->can_id & CAN_ERR_FLAG) {
          		put_eff_id(buf, cf->can_id & (CAN_ERR_MASK | CAN_ERR_FLAG));
          		buf[8] = '#';
          		offset = 9;

Looks like it may be an error indicator or CAN-FD flag.

Also the header has a few mentions

github.com

linux-can/can-utils/blob/master/lib.h#L146


      
          * 123#R8_9 -> standard CAN-Id = 0x123, len = 8, dlc = 9, RTR-frame
          * 7A1#r -> standard CAN-Id = 0x7A1, len = 0, RTR-frame
          *
          * 123#00 -> standard CAN-Id = 0x123, len = 1, data[0] = 0x00
          * 123#1122334455667788 -> standard CAN-Id = 0x123, len = 8
          * 123#1122334455667788_E -> standard CAN-Id = 0x123, len = 8, dlc = 14
          * 123#11.22.33.44.55.66.77.88 -> standard CAN-Id = 0x123, len = 8
          * 123#11.2233.44556677.88 -> standard CAN-Id = 0x123, len = 8
          * 32345678#112233 -> error frame with CAN_ERR_FLAG (0x2000000) set
          *
          * 123##0112233 -> CAN FD frame standard CAN-Id = 0x123, flags = 0, len = 3
          * 123##1112233 -> CAN FD frame, flags = CANFD_BRS, len = 3
          * 123##2112233 -> CAN FD frame, flags = CANFD_ESI, len = 3
          * 123##3 -> CAN FD frame, flags = (CANFD_ESI | CANFD_BRS), len = 0
          *     ^^
          *     CAN FD extension to handle the canfd_frame.flags content
          *
          * Simple facts on this compact ASCII CAN frame representation:
          *
          * - 3 digits: standard frame format
          * - 8 digits: extendend frame format OR error frame

Looks like the ##\d is a Flag digit, then bytes are after that.

erik.rainey · December 28, 2023, 8:57pm

With some tweaking this seems to work in the unit tests:

_RE_REC_DATA = re.compile(r"(?a)^\s*\((\d+\.\d+)\)\s+([\w-]+)\s+([\da-fA-F]+)#(#\d)?([\da-fA-F]*)")

With some additions in the parser.

Now I can candump again:

$ yakut --path ~/.cyphal -j sub 7509:uavcan.node.Heartbeat | jq
{
  "7509": {
    "_meta_": {
      "ts_system": 1703173559.356901,
      "ts_monotonic": 0.679424,
      "source_node_id": 34,
      "transfer_id": 1,
      "priority": "high",
      "dtype": "uavcan.node.Heartbeat.1.0"
    },
    "uptime": 76,
    "health": {
      "value": 0
    },
    "mode": {
      "value": 0
    },
    "vendor_specific_status_code": 0
  }
}

erik.rainey · December 28, 2023, 9:12pm

Submitted Support candump formatting for flags by emrainey · Pull Request #317 · OpenCyphal/pycyphal · GitHub