PCBUSB-Library icon indicating copy to clipboard operation
PCBUSB-Library copied to clipboard

Published 20 hours ago • verified publisher icon mac-can

PCAN-USB FD error codes persist across Unitialising and Initialising again

Open Obrekr opened this issue 6 months ago • 0 comments

Testing shows a difference in handling of internal error counters in the PCAN-USB FD between PEAKS's implementation on Windows and Mac-CAN on macOS.

Observed behaviour: on macOS the PCAN-USB FD keeps any internal error codes when being re-initialised (for example bus heavy limit). Expected behaviour: the internal error counters in PCAN-USB FD get reset when being re-initialised.

The PCAN-USB FD adapter was kept plugged in USB and connected to a single, unpowered CAN node (it will never ACK any frame) with termination resistors. The issue cannot be reproduced with the PCAN-USB FD alone, something needs to be electrically connected to the CAN bus of the PCAN-USB FD device.

Here is the code that was used to test this:

Reconnecting doesn't clear error codes on macOS

Test Script

import time
import logging

from can import Message
from can.interface import Bus

# Setup logging
log = logging.getLogger()
log.setLevel(logging.INFO)
log_handler = logging.StreamHandler()
log_format = logging.Formatter('%(asctime)s %(levelname)s - %(name)s: '
                               '%(message)s')
log_handler.setFormatter(log_format)
log.addHandler(log_handler)

can_interface = None


def connect() -> None:
    global can_interface
    can_interface = Bus(
        interface='pcan',
        channel='PCAN_USBBUS1',
    )
    # wait for a bit, error codes come back after initialization,
    # if continued too soon it will falsely report no error.
    # See second part of this issue.
    time.sleep(0.01) 
    log.info('connected')


def check_status() -> bool:
    global can_interface
    state = can_interface.state
    error_code = can_interface.status()
    is_ok = can_interface.status_is_ok()
    log.info('CAN bus is in state %s with error code 0x%X, bus is %s',
             state, error_code,
             'OK' if is_ok else 'NOT OK')
    return is_ok


def disconnect() -> None:
    global can_interface
    can_interface.shutdown()
    can_interface = None
    log.info('disconnected')


def send_data():
    global can_interface
    can_interface.send(Message(
        arbitration_id=0,
        data=('test' + '\0\0').encode('ascii'),
    ))
    log.info('sent data')


def test_reset() -> tuple[bool, bool]:
    connect()
    initial_ok = check_status()

    send_data()
    start_time = time.perf_counter()
    after_send_ok = True
    while time.perf_counter() - start_time < 0.05:
        time.sleep(0.01)
        if not check_status():  # if at least once status was NOK, return NOK
            after_send_ok = False
    disconnect()

    return (initial_ok, after_send_ok)

tests_to_run = 100
all_initial_ok = []
all_after_send_ok = []
for _ in range(tests_to_run):
    (initial_ok, after_send_ok) = test_reset()
    all_initial_ok.append(initial_ok)
    all_after_send_ok.append(all_after_send_ok)

log.info('initial status was NOT OK in %d of %d tries',
         all_initial_ok.count(False), tests_to_run)
log.info('after sending status was OK in %d of %d tries',
         all_after_send_ok.count(True), tests_to_run)

Run on macOS

Using Python 3.12.5 with python-can 4.4.2 and PCBUSB 0.13 running on MacBook Air M1 (Sonoma 14.6.1).

2024-08-22 10:57:47,772 WARNING - can.pcan: uptime library not available, timestamps are relative to boot time and not to Epoch UTC
2024-08-22 10:57:47,818 INFO - root: connected
2024-08-22 10:57:47,818 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 10:57:47,818 INFO - root: sent data
2024-08-22 10:57:47,831 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,843 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,854 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,866 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,878 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,882 INFO - root: disconnected
2024-08-22 10:57:47,901 INFO - root: connected
2024-08-22 10:57:47,902 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,902 INFO - root: sent data
2024-08-22 10:57:47,914 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,926 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,937 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,947 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,960 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:47,965 INFO - root: disconnected
...
2024-08-22 10:57:56,169 INFO - root: connected
2024-08-22 10:57:56,169 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:56,169 INFO - root: sent data
2024-08-22 10:57:56,182 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:56,194 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:56,206 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:56,218 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:56,231 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 10:57:56,236 INFO - root: disconnected
2024-08-22 10:57:56,236 INFO - root: initial status was NOT OK in 99 of 100 tries
2024-08-22 10:57:56,236 INFO - root: after sending status was OK in 0 of 100 tries

Run on Windows

Using Python 3.11.4 with python-can 4.4.2 and running in Parallels on MacBook Air M1 (Windows 11 ARM64).

2024-08-22 11:00:34,155 WARNING - can.pcan: uptime library not available, timestamps are relative to boot time and not to Epoch UTC
2024-08-22 11:00:34,313 INFO - root: connected
2024-08-22 11:00:34,313 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:00:34,314 INFO - root: sent data
2024-08-22 11:00:34,325 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,336 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,347 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,358 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,369 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,462 INFO - root: disconnected
2024-08-22 11:00:34,518 INFO - root: connected
2024-08-22 11:00:34,519 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:00:34,519 INFO - root: sent data
2024-08-22 11:00:34,530 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,541 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,552 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,563 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,574 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,661 INFO - root: disconnected
2024-08-22 11:00:34,717 INFO - root: connected
2024-08-22 11:00:34,717 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:00:34,717 INFO - root: sent data
2024-08-22 11:00:34,728 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,739 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,750 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,761 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,772 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:34,862 INFO - root: disconnected
...
2024-08-22 11:00:53,913 INFO - root: connected
2024-08-22 11:00:53,913 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:00:53,913 INFO - root: sent data
2024-08-22 11:00:53,924 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:53,935 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:53,947 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:53,959 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:53,970 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:00:54,059 INFO - root: disconnected
2024-08-22 11:00:54,059 INFO - root: initial status was NOT OK in 0 of 100 tries
2024-08-22 11:00:54,059 INFO - root: after sending status was OK in 0 of 100 tries

After reconnecting, error codes have delay coming back on macOS

Test Script

import time
import logging

from can import Message
from can.interface import Bus

# Setup logging
log = logging.getLogger()
log.setLevel(logging.INFO)
log_handler = logging.StreamHandler()
log_format = logging.Formatter('%(asctime)s %(levelname)s - %(name)s: '
                               '%(message)s')
log_handler.setFormatter(log_format)
log.addHandler(log_handler)

can_interface = None
last_ok_status = True

def connect() -> None:
    global can_interface
    can_interface = Bus(
        interface='pcan',
        channel='PCAN_USBBUS1',
    )
    log.info('connected')


def check_status() -> bool:
    global can_interface
    global last_ok_status
    state = can_interface.state
    error_code = can_interface.status()
    is_ok = can_interface.status_is_ok()
    if is_ok or last_ok_status != is_ok:
        log.info('CAN bus is in state %s with error code 0x%X, bus is %s',
                 state, error_code,
                 'OK' if is_ok else 'NOT OK')
    
    last_ok_status = is_ok
    return is_ok


def disconnect() -> None:
    global can_interface
    can_interface.shutdown()
    can_interface = None
    log.info('disconnected')


def send_data():
    global can_interface
    can_interface.send(Message(
        arbitration_id=0,
        data=('test' + '\0\0').encode('ascii'),
    ))
    log.info('sent data')


def test_reconnect() -> bool:
    connect()
    start_time = time.perf_counter()
    initial_ok = False
    while time.perf_counter() - start_time < 0.01:
        if check_status():  # if at least once status was OK, return OK
            initial_ok = True
    disconnect()

    return initial_ok


connect()
send_data()
time.sleep(0.01)
disconnect()
time.sleep(0.01)

initial_status_list = []
total_tries = 100
for _ in range(total_tries):
    initial_status = test_reconnect()
    initial_status_list.append(initial_status)

log.info('initial status was OK in %d and NOT OK %d of %d tries',
         initial_status_list.count(True), initial_status_list.count(False),
         total_tries)

run on macOS

Using Python 3.12.5 with python-can 4.4.2 and PCBUSB 0.13 running on MacBook Air M1 (Sonoma 14.6.1).

2024-08-22 11:27:09,456 WARNING - can.pcan: uptime library not available, timestamps are relative to boot time and not to Epoch UTC
2024-08-22 11:27:09,505 INFO - root: connected
2024-08-22 11:27:09,505 INFO - root: sent data
2024-08-22 11:27:09,522 INFO - root: disconnected
2024-08-22 11:27:09,543 INFO - root: connected
2024-08-22 11:27:09,543 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:27:09,558 INFO - root: disconnected
2024-08-22 11:27:09,566 INFO - root: connected
2024-08-22 11:27:09,580 INFO - root: disconnected
2024-08-22 11:27:09,589 INFO - root: connected
2024-08-22 11:27:09,589 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:09,589 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:09,589 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:09,589 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:09,589 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:27:09,604 INFO - root: disconnected
2024-08-22 11:27:09,612 INFO - root: connected
2024-08-22 11:27:09,612 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:09,612 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:09,612 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:09,612 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:27:09,626 INFO - root: disconnected
...
2024-08-22 11:27:11,674 INFO - root: connected
2024-08-22 11:27:11,674 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:11,674 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:27:11,689 INFO - root: disconnected
2024-08-22 11:27:11,697 INFO - root: connected
2024-08-22 11:27:11,697 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:11,697 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:11,697 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:11,697 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:11,697 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:27:11,712 INFO - root: disconnected
2024-08-22 11:27:11,720 INFO - root: connected
2024-08-22 11:27:11,720 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:11,720 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:27:11,734 INFO - root: disconnected
2024-08-22 11:27:11,742 INFO - root: connected
2024-08-22 11:27:11,742 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:27:11,742 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x8, bus is NOT OK
2024-08-22 11:27:11,758 INFO - root: disconnected
2024-08-22 11:27:11,770 INFO - root: connected
2024-08-22 11:27:11,785 INFO - root: disconnected
2024-08-22 11:27:11,793 INFO - root: connected
2024-08-22 11:27:11,807 INFO - root: disconnected
2024-08-22 11:27:11,816 INFO - root: connected
2024-08-22 11:27:11,830 INFO - root: disconnected
2024-08-22 11:27:11,830 INFO - root: initial status was OK in 66 and NOT OK 34 of 100 tries

Run on Windows

2024-08-22 11:33:29,343 WARNING - can.pcan: uptime library not available, timestamps are relative to boot time and not to Epoch UTC
2024-08-22 11:33:29,388 INFO - root: connected
2024-08-22 11:33:29,388 INFO - root: sent data
2024-08-22 11:33:29,483 INFO - root: disconnected
2024-08-22 11:33:29,539 INFO - root: connected
2024-08-22 11:33:29,540 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:33:29,540 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:33:29,540 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
...
2024-08-22 11:33:43,550 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:33:43,550 INFO - root: CAN bus is in state BusState.ACTIVE with error code 0x0, bus is OK
2024-08-22 11:33:43,635 INFO - root: disconnected
2024-08-22 11:33:43,635 INFO - root: initial status was OK in 100 and NOT OK 0 of 100 tries

Obrekr avatar Aug 24 '24 10:08 Obrekr