fix(ixxat): preserve controller start epoch and clock metadata

can/interfaces/ixxat/canlib_vcinpl.py

@@ -626,7 +626,7 @@ def __init__(
 
         # Calculate an offset to make them relative to epoch
         # Assume that the time offset is in the middle of the start command
-        self._timeoffset = start_begin + (start_end - start_begin / 2)
+        self._timeoffset = start_begin + (start_end - start_begin) / 2
         self._overrunticks = 0
         self._starttickoffset = 0
 
@@ -642,11 +642,21 @@ def __init__(
                 _canlib.canChannelReadMessage(
                     self._channel_handle, 0, ctypes.byref(self._message)
                 )
+                self._update_timestamp()
             except (VCITimeout, VCIRxQueueEmptyError):
                 break
 
         super().__init__(channel=channel, can_filters=None, **kwargs)
 
+    def _update_timestamp(self):
+        """Retain clock metadata even when startup messages are discarded."""
+        message_type = self._message.uMsgInfo.Bits.type
+        if message_type == constants.CAN_MSGTYPE_INFO:
+            if self._message.abData[0] == constants.CAN_INFO_START:
+                self._starttickoffset = self._message.dwTime
+        elif message_type == constants.CAN_MSGTYPE_TIMEOVR:
+            self._overrunticks += self._message.dwMsgId << 32
+
     def _inWaiting(self):
         try:
             _canlib.canChannelWaitRxEvent(self._channel_handle, 0)
@@ -701,9 +711,7 @@ def _recv_internal(self, timeout):
                         f"Unknown CAN info message code {self._message.abData[0]}",
                     )
                 )
-                # Handle CAN start info message
-                if self._message.abData[0] == constants.CAN_INFO_START:
-                    self._starttickoffset = self._message.dwTime
+                self._update_timestamp()
             elif self._message.uMsgInfo.Bits.type == constants.CAN_MSGTYPE_ERROR:
                 if self._message.uMsgInfo.Bytes.bFlags & constants.CAN_MSGFLAGS_OVR:
                     raise VCIDataOverrunError("Data overrun occurred")
@@ -721,7 +729,7 @@ def _recv_internal(self, timeout):
                     )
             elif self._message.uMsgInfo.Bits.type == constants.CAN_MSGTYPE_TIMEOVR:
                 # Add the number of timestamp overruns to the high word
-                self._overrunticks += self._message.dwMsgId << 32
+                self._update_timestamp()
             else:
                 log.warning(
                     "Unexpected message info type 0x%X",

can/interfaces/ixxat/canlib_vcinpl2.py

@@ -732,7 +732,7 @@ def __init__(
 
         # Calculate an offset to make them relative to epoch
         # Assume that the time offset is in the middle of the start command
-        self._timeoffset = start_begin + (start_end - start_begin / 2)
+        self._timeoffset = start_begin + (start_end - start_begin) / 2
         self._overrunticks = 0
         self._starttickoffset = 0
 
@@ -748,11 +748,21 @@ def __init__(
                 _canlib.canChannelReadMessage(
                     self._channel_handle, 0, ctypes.byref(self._message)
                 )
+                self._update_timestamp()
             except (VCITimeout, VCIRxQueueEmptyError):
                 break
 
         super().__init__(channel=channel, can_filters=None, **kwargs)
 
+    def _update_timestamp(self):
+        """Retain clock metadata even when startup messages are discarded."""
+        message_type = self._message.uMsgInfo.Bits.type
+        if message_type == constants.CAN_MSGTYPE_INFO:
+            if self._message.abData[0] == constants.CAN_INFO_START:
+                self._starttickoffset = self._message.dwTime
+        elif message_type == constants.CAN_MSGTYPE_TIMEOVR:
+            self._overrunticks += self._message.dwMsgId << 32
+
     @staticmethod
     def _canptb_build(defaults, bitrate, tseg1, tseg2, sjw, ssp):
         if bitrate in defaults:
@@ -807,6 +817,7 @@ def _recv_internal(self, timeout):
                 # VCIError means no frame available (canChannelPeekMessage returned different from zero)
                 return None, True
             else:
+                self._update_timestamp()
                 if self._message.uMsgInfo.Bits.type == constants.CAN_MSGTYPE_DATA:
                     data_received = True
         else:
@@ -839,9 +850,7 @@ def _recv_internal(self, timeout):
                                 f"Unknown CAN info message code {self._message.abData[0]}",
                             )
                         )
-                    # Handle CAN start info message
-                    elif self._message.abData[0] == constants.CAN_INFO_START:
-                        self._starttickoffset = self._message.dwTime
+                        self._update_timestamp()
                     elif (
                         self._message.uMsgInfo.Bits.type == constants.CAN_MSGTYPE_ERROR
                     ):
@@ -864,7 +873,7 @@ def _recv_internal(self, timeout):
                         == constants.CAN_MSGTYPE_TIMEOVR
                     ):
                         # Add the number of timestamp overruns to the high word
-                        self._overrunticks += self._message.dwMsgId << 32
+                        self._update_timestamp()
                     else:
                         log.warning("Unexpected message info type")
 

doc/changelog.d/2103.fixed.rst

@@ -0,0 +1,3 @@
+Fixed IXXAT receive timestamps using an incorrect controller-start epoch offset.
+Preserve start ticks and timestamp wraps while draining startup messages and
+handling CAN FD reads, including nonblocking reads.

test/test_ixxat_timestamps.py

@@ -0,0 +1,206 @@
+"""Clock conversion regressions using real VCI structures and a mocked DLL."""
+
+import ctypes
+import time
+from collections import deque
+from contextlib import nullcontext
+from unittest.mock import Mock, patch
+
+import pytest
+
+from can import ctypesutil
+
+# Linux has no HRESULT; supply only the ABI scalar needed to import the wrappers.
+# The DLL itself remains mocked and Windows driver support is not enabled.
+with (
+    nullcontext()
+    if hasattr(ctypesutil, "HRESULT")
+    else patch.object(ctypesutil, "HRESULT", ctypes.c_int32, create=True)
+):
+    from can.interfaces.ixxat import (
+        canlib_vcinpl,
+        canlib_vcinpl2,
+        constants,
+        structures,
+    )
+
+
+@pytest.fixture(params=[canlib_vcinpl, canlib_vcinpl2], ids=["classic", "fd"])
+def backend(request):
+    return request.param
+
+
+def message(backend, kind, tick=0, first_byte=0, identifier=0):
+    msg = structures.CANMSG2() if backend is canlib_vcinpl2 else structures.CANMSG()
+    msg.uMsgInfo.Bits.type = kind
+    msg.dwTime = tick
+    msg.dwMsgId = identifier
+    msg.abData[0] = first_byte
+    if kind == constants.CAN_MSGTYPE_DATA:
+        msg.uMsgInfo.Bits.dlc = 2
+        msg.abData[1] = 0xBB
+        if backend is canlib_vcinpl2:
+            msg.uMsgInfo.Bits.edl = 1
+            msg.uMsgInfo.Bits.fdr = 1
+    return msg
+
+
+@pytest.fixture
+def open_bus(monkeypatch, backend):
+    buses = []
+
+    def create(startup=(), duration=0.25):
+        pending = deque(startup)
+        library = Mock()
+
+        def capabilities(handle, pointer):
+            caps = pointer._obj
+            if backend is canlib_vcinpl2:
+                caps.dwTscClkFreq = 1_000_000
+            else:
+                caps.dwClockFreq = 1_000_000
+            caps.dwTscDivisor = 1
+
+        def read(*args):
+            if not pending:
+                raise backend.VCIRxQueueEmptyError()
+            msg = pending.popleft()
+            ctypes.memmove(args[-1], ctypes.byref(msg), ctypes.sizeof(msg))
+
+        library.canControlGetCaps.side_effect = capabilities
+        library.canChannelReadMessage.side_effect = read
+        library.canChannelPeekMessage.side_effect = read
+        clock = Mock(wraps=time)
+        clock.time.side_effect = [1_790_000_000.0, 1_790_000_000.0 + duration]
+        monkeypatch.setattr(backend, "_canlib", library)
+        monkeypatch.setattr(backend, "time", clock)
+        bus = backend.IXXATBus(channel=0)
+        buses.append(bus)
+        return bus, pending
+
+    yield create
+    for bus in buses:
+        bus.shutdown()
+
+
+def receive(bus, timeout):
+    # Classic returns after each INFO packet; FD may consume it internally.
+    for _ in range(5):
+        msg, _ = bus._recv_internal(timeout)
+        if msg is not None:
+            return msg
+    pytest.fail("No data frame returned")
+
+
+@pytest.mark.parametrize("duration", [0, 0.25])
+def test_epoch_is_midpoint_of_controller_start(backend, open_bus, duration):
+    bus, pending = open_bus(duration=duration)
+    pending.append(
+        message(backend, constants.CAN_MSGTYPE_DATA, first_byte=0xAA, identifier=0x123)
+    )
+    msg = receive(bus, 0.1)
+    assert msg.timestamp == pytest.approx(1_790_000_000 + duration / 2, abs=1e-6, rel=0)
+    assert msg.arbitration_id == 0x123
+    assert msg.data == bytes.fromhex("AABB")
+    assert msg.is_fd == (backend is canlib_vcinpl2)
+    assert msg.bitrate_switch == (backend is canlib_vcinpl2)
+
+
+@pytest.mark.parametrize("rollover", [False, True])
+def test_startup_drain_preserves_timestamp_metadata(backend, open_bus, rollover):
+    start = 0xFFFFFFF0 if rollover else 100_000_000
+    startup = [
+        message(backend, constants.CAN_MSGTYPE_INFO, start, constants.CAN_INFO_START)
+    ]
+    if rollover:
+        startup.append(message(backend, constants.CAN_MSGTYPE_TIMEOVR, identifier=1))
+    bus, pending = open_bus(startup)
+    tick = 0x20 if rollover else start + 1_234_567
+    pending.append(message(backend, constants.CAN_MSGTYPE_DATA, tick))
+    elapsed = 0.000048 if rollover else 1.234567
+    assert receive(bus, 0.1).timestamp == pytest.approx(
+        1_790_000_000.125 + elapsed, abs=1e-6, rel=0
+    )
+
+
+@pytest.mark.parametrize("timeout", [0, 0.1])
+def test_received_start_tick_preserves_frame_spacing(backend, open_bus, timeout):
+    bus, pending = open_bus()
+    # Isolate received clock metadata from the independently tested epoch calculation.
+    bus._timeoffset = 1_790_000_000.125
+    pending.extend(
+        [
+            message(
+                backend,
+                constants.CAN_MSGTYPE_INFO,
+                100_000_000,
+                constants.CAN_INFO_START,
+            ),
+            message(backend, constants.CAN_MSGTYPE_DATA, 101_234_567),
+            message(backend, constants.CAN_MSGTYPE_DATA, 102_469_134),
+        ]
+    )
+    first = receive(bus, timeout)
+    second = receive(bus, timeout)
+    assert first.timestamp == pytest.approx(1_790_000_001.359567, abs=1e-6, rel=0)
+    assert second.timestamp - first.timestamp == pytest.approx(
+        1.234567, abs=1e-6, rel=0
+    )
+
+
+@pytest.mark.parametrize("timeout", [0, 0.1])
+def test_overrun_with_start_byte_is_not_mistaken_for_start(backend, open_bus, timeout):
+    bus, pending = open_bus()
+    bus._timeoffset = 1_790_000_000.125
+    bus._starttickoffset = 0xFFFFFFF0
+    pending.extend(
+        [
+            message(
+                backend, constants.CAN_MSGTYPE_TIMEOVR, 7, constants.CAN_INFO_START, 1
+            ),
+            message(backend, constants.CAN_MSGTYPE_DATA, 0x20),
+        ]
+    )
+    assert receive(bus, timeout).timestamp == pytest.approx(
+        1_790_000_000.125048, abs=1e-6, rel=0
+    )
+
+
+@pytest.mark.parametrize("timeout", [0, 0.1])
+def test_unrelated_info_does_not_change_clock(backend, open_bus, timeout):
+    bus, pending = open_bus()
+    bus._timeoffset = 1_790_000_000.125
+    pending.extend(
+        [
+            message(
+                backend,
+                constants.CAN_MSGTYPE_INFO,
+                500_000_000,
+                constants.CAN_INFO_STOP,
+            ),
+            message(backend, constants.CAN_MSGTYPE_DATA, 1_000_000),
+        ]
+    )
+    assert receive(bus, timeout).timestamp == pytest.approx(
+        1_790_000_001.125, abs=1e-6, rel=0
+    )
+
+
+def test_error_byte_is_not_interpreted_as_start(backend, open_bus, caplog):
+    bus, pending = open_bus()
+    bus._timeoffset = 1_790_000_000.125
+    pending.extend(
+        [
+            message(
+                backend,
+                constants.CAN_MSGTYPE_ERROR,
+                500_000_000,
+                constants.CAN_ERROR_STUFF,
+            ),
+            message(backend, constants.CAN_MSGTYPE_DATA, 1_000_000),
+        ]
+    )
+    assert receive(bus, 0.1).timestamp == pytest.approx(
+        1_790_000_001.125, abs=1e-6, rel=0
+    )
+    assert "CAN bit stuff error" in caplog.text