P2 timeout time issue

[sgnes]

First I send the 1003, everything is OK, then I send 1002, and the server reply pending NRC in less than 10ms, but we got a timeout issue.

The code: ` ``` bus = VectorBus(channel=1, bitrate=500000) # Link Layer (CAN protocol) tp_addr = isotp.Address(isotp.AddressingMode.Normal_11bits, txid=0x71d, rxid=0x71e) # Network layer addressing scheme stack = isotp.CanStack(bus=bus, address=tp_addr, params=isotp_params) # Network/Transport layer (IsoTP protocol) conn = PythonIsoTpConnection(stack) # interface between Application and Transport layer

with Client(conn, request_timeout=5, config=client_config) as client: # Application layer (UDS protocol) response = client.change_session(3) response = client.change_session(2)

**the config**

`isotp_params = {
   'stmin' : 32,                          # Will request the sender to wait 32ms between consecutive frame. 0-127ms or 100-900ns with values from 0xF1-0xF9
   'blocksize' : 8,                       # Request the sender to send 8 consecutives frames before sending a new flow control message
   'wftmax' : 0,                          # Number of wait frame allowed before triggering an error
   'll_data_length' : 8,                  # Link layer (CAN layer) works with 8 byte payload (CAN 2.0)
   'tx_padding' : 0,                      # Will pad all transmitted CAN messages with byte 0x00. None means no padding
   'rx_flowcontrol_timeout' : 1000,       # Triggers a timeout if a flow control is awaited for more than 1000 milliseconds
   'rx_consecutive_frame_timeout' : 1000, # Triggers a timeout if a consecutive frame is awaited for more than 1000 milliseconds
   'squash_stmin_requirement' : False     # When sending, respect the stmin requirement of the receiver. If set to True, go as fast as possible.
}

client_config  = {
    'exception_on_negative_response'    : False,
    'exception_on_invalid_response'     : False,
    'exception_on_unexpected_response'  : False,
    'security_algo'             : security_algo,
    'security_algo_params'      : None,
    'tolerate_zero_padding'     : True,
    'ignore_all_zero_dtc'       : True,
    'dtc_snapshot_did_size'     : 2,        # Not specified in standard. 2 bytes matches other services format.
    'server_address_format'     : None,     # 8,16,24,32,40
    'server_memorysize_format'  : None,     # 8,16,24,32,40
    'data_identifiers'          : {0x0100:MyCustomCodecThatShiftBy4,
    'input_output'              : {},
    'p2_timeout' :0.5,
    'p2_server_max':5,
    'request_timeout':5,
    'p2_star_timeout':5
}
`

**the error:**
Traceback (most recent call last):
  File "C:\Python38\lib\site-packages\udsoncan\client.py", line 1647, in send_request
    payload = self.conn.wait_frame(timeout=timeout_value, exception=True)   
  File "C:\Python38\lib\site-packages\udsoncan\connections.py", line 68, in wait_frame
    frame = self.specific_wait_frame(timeout=timeout)
  File "C:\Python38\lib\site-packages\udsoncan\connections.py", line 490, in specific_wait_frame
    raise TimeoutException("Did not receive frame IsoTP Transport layer in time (timeout=%s sec)" % timeout)
udsoncan.exceptions.TimeoutException: Did not receive frame IsoTP Transport layer in time (timeout=0.05 sec)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:/Users/sgnes/Bootloader-flashing-tool/flashing.py", line 70, in <module>
    start_reprogramming()
  File "C:/Users/sgnes/Bootloader-flashing-tool/flashing.py", line 48, in start_reprogramming
    response = client.change_session(2)
  File "C:\Python38\lib\site-packages\udsoncan\client.py", line 131, in decorated
    return func(self, *args, **kwargs)
  File "C:\Python38\lib\site-packages\udsoncan\client.py", line 189, in change_session
    response = self.send_request(req)
  File "C:\Python38\lib\site-packages\udsoncan\client.py", line 1655, in send_request
    raise TimeoutException('Did not receive response in time. %s time has expired (timeout=%.3f sec)' % (timeout_name_to_report, timeout_value))
udsoncan.exceptions.TimeoutException: Did not receive response in time. P2 timeout time has expired (timeout=0.050 sec

**the log:**

14:22:42:3813 Rx 1 0x71D s 8 02 10 03 00 00 00 00 00 
14:22:42:3886 Rx 1 0x71E s 8 06 50 03 00 32 01 F4 AA 
14:22:42:4852 Rx 1 0x71D s 8 02 10 02 00 00 00 00 00 
14:22:42:4986 Rx 1 0x71E s 8 03 7F 10 78 AA AA AA AA 
14:22:42:5511 Rx 1 0x661 s 8 00 00 00 00 00 00 00 00 
14:22:42:5514 Rx 1 0x662 s 8 00 00 00 00 00 00 00 00 
14:22:42:5516 Rx 1 0x663 s 8 00 00 00 00 00 00 00 00 
14:22:42:5519 Rx 1 0x664 s 8 00 00 00 00 C4 FF 03 A0 
14:22:42:8633 Rx 1 0x71E s 8 06 50 02 00 32 01 F4 AA 

[sgnes]

and I traced to rxthread_task, seems in this task, the timeout is too long, 50ms, I tried to directly change the timeout value to 0.01s, then it will work, please help check whether this is a configuration issue from my side, thanks.

` def rxthread_task(self): while not self.exit_requested: try: while not self.toIsoTPQueue.empty(): self.isotp_layer.send(self.toIsoTPQueue.get())

            self.isotp_layer.process()

            while self.isotp_layer.available():
                self.fromIsoTPQueue.put(self.isotp_layer.recv())

            time.sleep(self.isotp_layer.sleep_time())`

[pylessard]

Hi, Can you check the version of your package? Something isn't right. The behaviour you describe doesn't match the latest code version and I honestly can't remember all the changes I did.

Regards

[sgnes]

@pylessard you can find the version information below: C:\Users\sgnes>python --version Python 3.8.2

C:\Users\sgnes>pip list Package Version

---

aenum 3.0.0 altgraph 0.17 asgiref 3.2.7 astroid 2.3.3 beautifulsoup4 4.9.0 bleach 3.3.0 bs4 0.0.1 can-isotp 1.6 certifi 2020.12.5 chardet 4.0.0 colorama 0.4.3 colour 0.1.5 configparser 5.0.0 cycler 0.10.0 decorator 4.4.2 demjson 2.2.4 Django 3.0.5 django-grappelli 2.14.1 django-object-actions 2.0.0 django-tables2 2.3.1 docutils 0.17.1 elftools 0.1.0.dev0 et-xmlfile 1.0.1 ffmpy 0.2.2 future 0.18.2 idna 2.10 importlib-metadata 4.0.1 isort 4.3.21 jdcal 1.4.1 keyring 23.0.1 kiwisolver 1.2.0 lazy-object-proxy 1.4.3 lxml 4.5.0 matplotlib 3.2.1 mccabe 0.6.1 networkx 2.4 Nuitka 0.6.10.4 numpy 1.18.4 openpyxl 3.0.5 packaging 20.9 pefile 2019.4.18 Pillow 7.1.1 pip 19.2.3 pkginfo 1.7.0 pyelftools 0.26 pyglet 1.5.0 Pygments 2.8.1 PyInstaller 3.6 pylint 2.4.4 PyMuPDF 1.18.12 pyparsing 2.4.7 PyPDF2 1.26.0 pytesseract 0.3.3 python-can 3.3.4 python-dateutil 2.8.1 python-docx 0.8.10 pytz 2019.3 pywin32-ctypes 0.2.0 readme-renderer 29.0 requests 2.25.1 requests-toolbelt 0.9.1 rfc3986 1.4.0 rlschool 0.3.1 scipy 1.5.0 setuptools 56.0.0 six 1.14.0 soupsieve 2.0 sqlparse 0.3.1 tqdm 4.60.0 trimesh 3.7.6 twine 3.4.1 udsoncan 1.13.1 urllib3 1.25.11 webencodings 0.5.1 wheel 0.36.2 windows-curses 2.2.0 wrapt 1.11.2 xlrd 1.2.0 zipp 3.4.1

[sgnes]

closed by mistake, sorry for this.

[pylessard]

I found your issue. I should have seen this right away. In your 1002 response, the server sets new timing value. P2 timeout is 0032h giving 50ms.

If you enable the log, you will see a notice saying that new timing are being used.

To ignore that value, set config use_server_timing to False

[sgnes]

yes, it's 50ms, but less than 50ms, the server send the pending NRC, so it should not timeout, right? in my case, our code did not even receive the pending NRC, I will assume the sleep timing is too long, which is 50ms.

[sgnes]

I checked you suggestion, it works, but my point is even we use the server timing, still we should not have timeout issue, because from the log, the server did not timeout, thanks.

[pylessard]

Yes, but consider that you are using a user space implementation of the isotp layer (that probably runs on windows). 50ms is a bit tight. But as you mentioned, you can reduce the sleep time to improve the performances. You can pass your own timing as parameter.

Consider that windows has a thread resolution of 16ms. We can't do miracles with that :)

[sgnes]

Thanks for the feedback. Yes, I'm running the code on windows 10, and I can only change the source code to control the sleep time, which is not a good solution. is it possible to have a configuration parameter to control this sleep timeout value? Thanks.

[pylessard]

Hi, Actually, this option exist and has been proposed in this pull request : https://github.com/pylessard/python-can-isotp/pull/35 I think it is not included in the latest release. I can make a new release later today so you just have to run pip install can-isotp -- upgrade to get it

[sgnes]

ok, thanks.

[pylessard]

can-isotp v1.7 is published. You now have the required interface to change the timings yourself.

Regards

[pompushko]

Hello @pylessard I got same issue :D

[pylessard]

Ok, but this issue is closed. Do you need something?

[sgnes]

can-isotp v1.7 is published. You now have the required interface to change the timings yourself.

Regards

Thanks for me this issue is fixed.

[funnyrabbitvu]

Hi @pylessard,

Currenty im also facing this issue on Windows 11, i tried connecting to normal 29 bits ID address (normal 11 bits ID worked normally) with below Client and ISOTP configurations and Peak CAN interface. Timeout occurred during sending request.

Please give me an advice! Thank you so much and have a great day.

[pylessard]

To debug timeout issue, start by looking at the raw can log. Also, you can enable python debug logging to get some data from the isotp module.

A common issue with CanStack is that it reads the bus directly, so if you have another task reading the same bus, it will prevent the stack from receiving message. You can use NotifierBasedCanStack

Also, please share the version of libs you are using (isotp and udsoncan)

[funnyrabbitvu]

To debug timeout issue, start by looking at the raw can log. Also, you can enable python debug logging to get some data from the isotp module.

A common issue with CanStack is that it reads the bus directly, so if you have another task reading the same bus, it will prevent the stack from receiving message. You can use NotifierBasedCanStack

Also, please share the version of libs you are using (isotp and udsoncan)

Hi, im using can-isotp==2.0.3, udsoncan==1.21.1. i will set a logger and try using NotifierBasedCanStack.

[pylessard]

As you can see, your device never responded.

[funnyrabbitvu]

As you can see, your device never responded.

Thanks man, I see now, it seemed my CAN bus was interrupted...