DiagnosticSessionControl service takes control of timeout value

[nbusser]

Hi,

I faced a problem concerning timeouts and DiagnosticSessionControl service. Once a change_session() is made by a client, the user loses control of the timeout value.

Explanation of the problem

Nominal case

Let's take a basic example: here is a functional program, with exaggerated timeout values. This program simply sends two tester present requests.

import can
import isotp
import udsoncan
from udsoncan.client import Client
from udsoncan.connections import PythonIsoTpConnection

isotp_params = {
       'stmin' : 32,
       'blocksize' : 8,
       'wftmax' : 0,
       'll_data_length' : 8,
       'tx_padding' : 0,
       'rx_flowcontrol_timeout' : 3000,
       'rx_consecutive_frame_timeout' : 3000,
       'squash_stmin_requirement' : False,
       'can_fd' : True
}

bus = can.interface.Bus(channel="can0", bustype="socketcan", fd=True)
tp_addr = isotp.Address(isotp.AddressingMode.Normal_29bits, txid=0x18E05889, rxid=0x18E05881)
stack = isotp.CanStack(bus=bus, address=tp_addr, params=isotp_params)
conn = PythonIsoTpConnection(stack)

with Client(conn, request_timeout=300000) as client:
        client.config["p2_timeout"] = 300000
        client.config["p2_server_max"] = 300000

        client.tester_present()
        client.tester_present()

This program works perfectly when executed.

Here is the associated dump:

(006.743134)  can0  TX - -  18E05889  [08]  02 3E 00 00 00 00 00 00
(006.751650)  can0  RX B -  18E05881  [08]  02 7E 00 AA AA AA AA AA
(006.851918)  can0  TX - -  18E05889  [08]  02 3E 00 00 00 00 00 00
(006.860240)  can0  RX B -  18E05881  [08]  02 7E 00 AA AA AA AA AA

Problematic case

If I add a DiagnosticSessionControl between the two tester presents:

with Client(conn, request_timeout=300000) as client:
        client.config["p2_timeout"] = 300000
        client.config["p2_server_max"] = 300000

        client.tester_present()
        client.change_session(1)
        client.tester_present()

I receive a timeout error:

[TimeoutException] : Did not receive response in time. P2 timeout time has expired (timeout=0.030 sec)
Traceback (most recent call last):
  File "/home/nbusser/.local/lib/python3.9/site-packages/udsoncan/client.py", line 1646, in send_request
    payload = self.conn.wait_frame(timeout=timeout_value, exception=True)   
  File "/home/nbusser/.local/lib/python3.9/site-packages/udsoncan/connections.py", line 68, in wait_frame
    frame = self.specific_wait_frame(timeout=timeout)
  File "/home/nbusser/.local/lib/python3.9/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.03 sec)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/nbusser/bugfinding/udsoncan/./p2_timeout.py", line 32, in <module>
    client.tester_present()
  File "/home/nbusser/.local/lib/python3.9/site-packages/udsoncan/client.py", line 131, in decorated
    return func(self, *args, **kwargs)
  File "/home/nbusser/.local/lib/python3.9/site-packages/udsoncan/client.py", line 329, in tester_present
    response = self.send_request(req)
  File "/home/nbusser/.local/lib/python3.9/site-packages/udsoncan/client.py", line 1654, 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.030 sec)

We can see here that the p2 timeout value have been somehow modified to 0.030

Here is the associated dump:

(002.071086)  can0  TX - -  18E05889  [08]  02 3E 00 00 00 00 00 00
(002.078415)  can0  RX B -  18E05881  [08]  02 7E 00 AA AA AA AA AA
(002.175243)  can0  TX - -  18E05889  [08]  02 10 01 00 00 00 00 00
(002.178473)  can0  RX B -  18E05881  [08]  06 50 01 00 1E 00 C8 AA

Source of the problem

I checked udsoncan code and I now understand what's happening:

1. The DiagnosisSessionControl service performs its request through the function send_request(): https://github.com/pylessard/python-udsoncan/blob/af06bfe59693ba87e4667c8b766fc288595ddce5/udsoncan/client.py#L189
2. After it receives its response, interpret_response()is called, and then, some data related to p2 are assigned to the service_data of response object. https://github.com/pylessard/python-udsoncan/blob/af06bfe59693ba87e4667c8b766fc288595ddce5/udsoncan/services/DiagnosticSessionControl.py#L63
3. These metrics are then assigned to the config itself: https://github.com/pylessard/python-udsoncan/blob/af06bfe59693ba87e4667c8b766fc288595ddce5/udsoncan/client.py#L201
4. The next service (here TesterPresent), runs the function send_request() again, with the timeout parameter set to the default value, -1.
5. This time, session_timing['p2_server_max'] is set (here to a tiny value of 0.03). So, p2 takes the value of session_timing['p2_server_max']. https://github.com/pylessard/python-udsoncan/blob/af06bfe59693ba87e4667c8b766fc288595ddce5/udsoncan/client.py#L1605 This value, since it is largely smaller than overall_timeout, is defined as the reference timeout value.

At the end of the day, DiagnosisSessionControl totally took control of the timeout value.

Working around the problem

If someone else is bothered by this problem, and waiting for a fix, it can work around the problem as follows: It has to directly send the request via function send_request().

with Client(conn, request_timeout=300000) as client:
        client.config["p2_timeout"] = 300000
        client.config["p2_server_max"] = 300000

        client.tester_present()
        client.send_request(udsoncan.Request(service=udsoncan.services.DiagnosticSessionControl, subfunction=1), timeout=3)
        client.tester_present()

Using this method, we skip interpret_response() function and new metrics assignments

[nbusser]

I talked of the problem with my college, and he informed me about the existence of use_server_timing configuration option. The proper way to take control of the timeout is to put the following line of code:

client.set_config('use_server_timing', False)

At the end of the day, the problem I reported is not a problem... It works as intended ! I just missed the if statement (yes, it was right under my nose 😅): https://github.com/pylessard/python-udsoncan/blob/af06bfe59693ba87e4667c8b766fc288595ddce5/udsoncan/client.py#L199

I think it would be worthwhile to make a clear documentation about timeout system. It's unclear unless you dive directly in the code.

[pylessard]

Hi Nicolas, Yes indeed, this behaviour has been introduced in the latest UDS standard. Changing the parameter was the right thing to do in your situation.

I agree that timeout handling is a bit painful. In my defense, the standard makes it painful as well :) I will update the documentation following your recommendation.

Regards

[jxwdgd5201314]

@nbusser 请问如何让脚本可以在10服务4秒后发生3E服务，另外3E 80 为什么设置了不能发生

[nbusser]

@jxwdgd5201314 对不起，因为我很久以前写的帖子，所以我不记住。我不再在汽车行业工作。

[pylessard]

因為服務器要求客戶端無法遵守的緊迫時間。 許多中國用戶報告他們的 ECU 請求 50 毫秒超時，這對於用戶空間實現來說有點太緊了。