Problem when executing multiple transfer data in sequence for firmware update

[will2k69]

Hi! I'm using TransferData service for firmware update process, but at some point when sending CFs, communication ends up being lost (generating TimeoutException) randomly, after a certain amount of time.

When testing with Busmaster, I noticed that the stmin times are being respected, however, whenever this failure is about to occur, the stmin value, which is received by the receiver, is 2ms, but sometimes the data sending does not respect this, and sends in 0.5ms or 1.6ms, approximately.
This occurs when the generator is consuming the payload bytes to send a data block via the TransferData service.

Below is an example of a firmware update attempt that failed because in a certain payload, it did not respect the stmin:

[pylessard]

So you say that the python code is sending frames too fast? And the server part doesn't like it and stops responding then python reports a timeout?

If that is so. Can you make a log with timestamps.
Both canlog and python log (enable debug logging for logger names "isotp")

What version of the module do you use? What is your hardware and os?

[will2k69]

That's right!

OS
Windows 11 Pro and Windows 10 Pro (both tested)

Modules
udsoncan 1.23.2
can-isotp 2.0.6

Interfaces
Vector VN1610, VN1630, Peak and Korlan (usb2can).
P.S.: This specific test was done using the VN1630 interface(Vector), but the same issue occurs in the others

If necessary, log files are attached in the zip file.

logs.zip

[pylessard]

You haven't enabled the "isotp" logger in debug mode, I can only see the UDS module debug logs.
Anyway, I have a good idea of what's happening, and it stinks.
Notice how the message before the violations, there is a delay of 4ms.

The stack sends data from app (uds) to transport (isotp) to link layer (CAN) from top to bottom, but we lack confirmations from bottom up. Basically, the isotp layers sends 2 messages at 2ms interval, but the CAN layer (your driver) seems to buffer those message and sends them together.

Any chance your bus load is too high and the driver can't send right away?

How do you interact with your vector hardware? python-can?

[will2k69]

log_busmaster.zip

That's right!

We use python-can to interact with the CAN vector interface.

Here are some more detailed logs (debug "isotp" enabled and CAN log recorded with Busmaster) about a failed TransferData. Also includes a screenshot of bus statistics.

Highlight for this part of the log, where stmin's were identified as being too high and too low.

14:19:40:6483 Rx 1 0x18DAEFF1 x 8 23 36 2C A0 45 25 61 92
14:19:40:6508 Rx 1 0x18DAEFF1 x 8 24 5D 36 23 89 13 D7 34
14:19:40:6559 Rx 1 0x18DAEFF1 x 8 25 61 71 65 1D D1 33 64 (time diff(Δt): 5.1ms)
14:19:40:6564 Rx 1 0x18DAEFF1 x 8 26 11 91 51 67 4D 94 54 (time diff(Δt): 0.5ms)