Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
Obrekr opened this issue Aug 24, 2024 · 0 comments
Open
Labels
analyzing Investigation required to understand the problem

Comments

@Obrekr
Copy link

Obrekr commented Aug 24, 2024

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
@mac-can mac-can added the analyzing Investigation required to understand the problem label Aug 24, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
analyzing Investigation required to understand the problem
Projects
None yet
Development

No branches or pull requests

2 participants