pylessard / python-udsoncan

Python implementation of UDS (ISO-14229) standard.
MIT License
564 stars 195 forks source link

PythonIsoTpConnection [cilent.py]send_request() tigger TimeoutException,then ISOTP rxthread_task run isotp_send() #193

Closed caocheng7979 closed 7 months ago

caocheng7979 commented 7 months ago

run change_session(3), goto send_request() 'self.conn.send(payload)' ' def specific_send(self, payload): if self.mtu is not None: if len(payload) > self.mtu: self.logger.warning("Truncating payload to be set to a length of %d" % (self.mtu)) payload = payload[0:self.mtu] self.toIsoTPQueue.put(bytearray(payload)) # isotp.protocol.TransportLayer uses byte array. udsoncan is strict on bytes format print("send msg queue put")' however, send_requeset() tigger TimeoutException,after that rxthread_task() start to execute. uds

uds2

uds3

uds4

Why?Is there something wrong with the Settings?

pylessard commented 7 months ago

Can you show how you initialize the communication stack? It's weird, according to your log, the isotp layer starts transmitting over 1 sec after send() is called.

caocheng7979 commented 7 months ago

Thank you for your reply! uds5 uds6 My device is the ZLGCan,I turn on the Can device and start the receiving thread.

    if self.cmbUDSEnable.get() == 'YES':
        self.udsclient.open()
        self._terminated = False

After send() is called ,The msg has been put into the queue. ··· log info:send msg queue put ··· But rxthread_task seems to be blocked. main thread TIMEOUT,rxthread_task start calling isotp_send().

    toIsoTPQueue queue size is now 0
    Sending xxxx
    Receiving:xxx
    fromIsoTPQueue queue size is now 1

something wrong with threading?

pylessard commented 7 months ago

I suspect your zcan lib to takes ownership of the GIL and not release it. Preventing any thread to work during that time. Can you make an experiment for me?

make a simple thread that prints to the console in a loop. And try calling your zcan function, See if it stops the thread.

import threading
import time
stop_event = threading.Event()

def func:
    while not stop_event.is_set():
        print("%s Thread: Still running" % time.time())
        time.sleep(0.1)

def main():
    t = threading.thread(target=func)
    t.start()
    time.sleep(0.5)
    try:
        printf("%s Main thread: Sending a zcan message" % time.time())
        zcan.Transmit(...)
        printf("%s Main thread: Sending a zcan message" % time.time())
        #...  Test each function.  Then see if the thread ever stops for a long time.
    finally:
        stop_event.set()
        t.join()
caocheng7979 commented 7 months ago

zcan lib I found out why the problem happened. I want to output log to textbox.

        self.logger = logging.getLogger('logger')
        # self.logger.setLevel(logging.DEBUG)
        udsLogHandler = TextboxHandler(self.text_log)
        self.logger.addHandler(udsLogHandler)

        # self.isotp_layer.logger.setLevel(logging.DEBUG)
        # isotpLogHandler = TextboxHandler(self.text_log)
        # self.isotp_layer.logger.addHandler(isotpLogHandler)

        # self.udsclient.conn.logger.setLevel(logging.DEBUG)
        # connLogHandler = TextboxHandler(self.text_log)
        # self.udsclient.conn.logger.addHandler(connLogHandler)

        self.udsclient.logger.setLevel(logging.DEBUG)
        clientLogHandler = TextboxHandler(self.text_log)
        self.udsclient.logger.addHandler(clientLogHandler)

If I uncomment isotp_layer.logger,problems are going to happen.

Thanks again for your reply!

pylessard commented 7 months ago

Ohh, you are using a UI framework and it's the UI that takes ownership of the GIL. You may want to consider running the isotp communication in a different process and use IPC mechanism to itnerract with the GUI

cheers

caocheng7979 commented 6 months ago

guilog.txt pycharmlog.txt CANdevicelog.asc.txt

Hi!After updating udsoncan to 1.21.2 and isotp to 2.0.3, I am now using PythonIsoTpV2Connection, but the Timeout is triggered again.Now I'm using a separate thread to log to ScrolledText.

In older versions, self.udsclient.logger was set to DEBUG and the flush was successful, but it was set to INFO and a Timeout occurred.

I even removed the srrollText to stop logging.But Timeout is still triggered.

Would you like to check the logs and see what you can find?Looking forward to your reply!

pylessard commented 5 months ago

If I remember correctly, your GUI framework seemed to take ownership of the GIL. That blocks every threads. If you configure your GUI to not do that, it would be ideal. Otherwise, maybe the cleanest way is to put the transmission part into a different process and make the GUI commnunicate through IPC.