Logging configuration changes behavior of transfer buffers?

[Upgreydd]

Hey, While using transfer_data() I've faced Transmit buffer full exception while transferring first block. Due to that, I was going to debug it, so I've enabled logging through:

udsoncan.setup_logging(path.join(path.dirname(__file__), "logging.conf"))

but it still happened so I've decided to make log more detailed. I've changed logging.conf

[logger_root]
level=ERROR
handlers=consoleHandler

to

[logger_root]
level=DEBUG
handlers=consoleHandler

and my code works. Every time I change DEBUG to ERROR my code fails - can it be related to some race condition in code?

[pylessard]

I don't think the logging change the module behavior other than slowing it down. You may be sending too much data. Transmit buffer full can only happen if you push a LOT of data to it.

Maybe double check if you have a send() inside a loop somewhere?

[Upgreydd]

@pylessard I'm sending a few MB of data in a loop and with level=DEBUG all is fine, not sure how it's related but looks like some backend handling of buffer cleanup fails. I've added bus.flush_tx_buffer() before each client.transfer_data(seq, data) but it doesn't fix the issue :/ In python-can send looks like this: def send(self, msg: Message, timeout: Optional[float] = None). How can I set timeout parameter via udsoncan?

[EDIT] After editing module code and adding here: https://github.com/hardbyte/python-can/blob/main/can/interfaces/socketcan/socketcan.py#L734 timeout = 5 all works on any logging level

[EDIT no. 2]

class SocketcanBusWithTimeout(SocketcanBus):
    def send(self, msg: Message, timeout: Optional[float] = 5) -> None:
        super().send(msg, timeout)

I've made a subclass for SocketcanBuus and overridden default timeout, then used it in my code. Now all works fine with all logging levels.

[pylessard]

Hmm I see, you dump a lot of data into the socketcan queue and by forcing a timeout value, you tell python-can to wait for socketcan before sending data. You can leverage the rate limiter of the isotp TransportLayer instead. It will avoid dumping all the data into the python-can layer at once.

https://can-isotp.readthedocs.io/en/latest/isotp/implementation.html#rate-limiter

The rate limiter was introduced to solve a similar issue, but with a different hardware. See https://github.com/pylessard/python-can-isotp/issues/61

My guess is that the receiving party is giving you a blocksize of 0 and a stmin of 0 as well, that tells the isotp layer that it can sends everything at once. The rate limiter will reduce the stress on the buffers

[pylessard]

Also, if you want to control the send() timeout parameter, you do not have to modify python-can. The TransportLayer let you specify your own send/recv function. You're probably using the default one in the CanStack object, but you don't have to.

https://github.com/pylessard/python-can-isotp/blob/master/isotp/protocol.py#L1084-L1108

Instantiate the TransportLayer object directly and write your own rxfn/txfn. You can base your work on the CanStack I wrote.