diff --git a/can/interfaces/ixxat/canlib_vcinpl.py b/can/interfaces/ixxat/canlib_vcinpl.py index c6c924d8c..58f69608f 100644 --- a/can/interfaces/ixxat/canlib_vcinpl.py +++ b/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", diff --git a/can/interfaces/ixxat/canlib_vcinpl2.py b/can/interfaces/ixxat/canlib_vcinpl2.py index f74d4cece..08e23ce74 100644 --- a/can/interfaces/ixxat/canlib_vcinpl2.py +++ b/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") diff --git a/doc/changelog.d/2103.fixed.rst b/doc/changelog.d/2103.fixed.rst new file mode 100644 index 000000000..0a01bafb9 --- /dev/null +++ b/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. diff --git a/test/test_ixxat_timestamps.py b/test/test_ixxat_timestamps.py new file mode 100644 index 000000000..1e05f4aa6 --- /dev/null +++ b/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