<div dir="ltr"><div>Hey,</div><div><br></div><div>The issue is the same as this one <a href="https://gitlab.freedesktop.org/mobile-broadband/ModemManager/-/issues/548">https://gitlab.freedesktop.org/mobile-broadband/ModemManager/-/issues/548</a><br><br></div><div>And I managed to fix it by adding a small sleep in libqmi here is the patch<br><br><div style="color:rgb(187,187,187);background-color:rgb(40,44,52);font-family:"Fira Code","Droid Sans Mono","monospace",monospace,"Droid Sans Fallback","Droid Sans Mono","monospace",monospace;font-weight:normal;font-size:14px;line-height:19px;white-space:pre"><div><span style="color:rgb(187,187,187)"> src/libqmi-glib/qmi-device.c | 1 +</span></div><div><span style="color:rgb(187,187,187)"> 1 file changed, 1 insertion(+)</span></div><br><div><span style="color:rgb(117,113,94)">diff --git a/src/libqmi-glib/qmi-device.c b/src/libqmi-glib/qmi-device.c</span></div><div><span style="color:rgb(117,113,94)">index 69a9b448..180352c6 100644</span></div><div><span style="color:rgb(117,113,94)">--- a/src/libqmi-glib/qmi-device.c</span></div><div><span style="color:rgb(117,113,94)">+++ b/src/libqmi-glib/qmi-device.c</span></div><div><span style="color:rgb(117,113,94)">@@ -1458,6 +1458,7 @@</span><span style="color:rgb(187,187,187)"> qmi_device_release_client (QmiDevice *self,</span></div><div><span style="color:rgb(187,187,187)"> qmi_service_get_string (service),</span></div><div><span style="color:rgb(187,187,187)"> flags_str);</span></div><div><span style="color:rgb(187,187,187)"> g_free (flags_str);</span></div><div><span style="color:rgb(152,195,121)">+ g_usleep(100000);</span></div><div><span style="color:rgb(187,187,187)"> </span></div><div><span style="color:rgb(187,187,187)"> task = g_task_new (self, cancellable, callback, user_data);</span></div></div><br></div><div>Seems like it takes time to release some clients on libqmi side<br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">Le ven. 22 sept. 2023 à 15:20, Aleksander Morgado <<a href="mailto:aleksandermj@chromium.org">aleksandermj@chromium.org</a>> a écrit :<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Hey<br> <br> > I am working with ModemManager with qmi-proxy and I have a weird behavior when I am using ModemManager with the log-level set to DEBUG like this "ModemManager --log-level=DEBUG &"<br> > everything is working fine but when I use it normally or set the log-level to anything else except debug I have "modem is unusable"<br> > Here are the logs :<br> > <debug> [modem2] cleaning up port 'net/mhi_hwip0'...<br> > <debug> [modem2] cleaning up port 'unknown/wwan0qcdm0'...<br> > <debug> [modem2] cleaning up port 'tty/ttyUSB2'...<br> > <debug> [modem2] cleaning up port 'wwan/wwan0qmi0'...<br> > <debug> [modem2] cleaning up port 'unknown/wwan0mbim0'...<br> > <debug> [ttyUSB2/at] forced to close port<br> > <debug> [modem2] (quectel) check SIM swap completed<br> > <debug> [modem2] completely disposed<br> > <debug> [device SG520TM] Reprobing modem...<br> > <info> [device SG520TM] creating modem with plugin 'quectel' and '5' ports<br> > <debug> [plugin/quectel] (quectel) QMI-powered Quectel modem found...<br> > <debug> [wwan0qmi0/qmi] timeout monitoring enabled in QMI port<br> > <debug> [modem3] port 'wwan/wwan0qmi0' grabbed<br> > <debug> [plugin/quectel] port wwan0qcdm0 is blacklisted<br> > <debug> [modem3] port 'wwan/wwan0qcdm0' grabbed<br> > <debug> [plugin/quectel] port wwan0mbim0 is blacklisted<br> > <debug> [modem3] port 'wwan/wwan0mbim0' grabbed<br> > <debug> [modem3] port 'net/mhi_hwip0' grabbed<br> > <debug> [ttyUSB2/at] timeout monitoring enabled in AT port<br> > <debug> [ttyUSB2/at] AT port flagged as primary<br> > <debug> [modem3] port 'tty/ttyUSB2' grabbed<br> > <debug> [modem3] tty/ttyUSB2 at (primary)<br> > <debug> [modem3] tty/ttyUSB2 at (data primary)<br> > <debug> [modem3] net/mhi_hwip0 net (data)<br> > <debug> [modem3] wwan/wwan0qmi0 qmi<br> > <debug> [modem3] at data ports available but ignored<br> > <debug> [wwan0qmi0/qmi] endpoint info updated: type 'pcie', interface number '0'<br> > <debug> [modem3] running QMI port 'wwan0qmi0' reset with data interface 'mhi_hwip0'<br> > <debug> [device SG520TM] modem recreated<br> > <debug> [wwan0qmi0/qmi] bringing down data interface 'mhi_hwip0'<br> > <debug> [modem3/mhi_hwip0/net] interface index: 2<br> > <debug> [wwan0qmi0/qmi] deleting all links in data interface 'mhi_hwip0'<br> > <debug> [wwan0qmi0/qmi] Opening QMI device...<br> > <debug> [wwan0qmi0/qmi] Checking if QMI device already opening...<br> > <debug> [wwan0qmi0/qmi] Checking if QMI device already open...<br> > <debug> [wwan0qmi0/qmi] Creating QMI device...<br> > <debug> [wwan0qmi0/qmi] Opening device with flags: version-info, proxy...<br> > <debug> [/dev/wwan0qmi0] opening device with flags 'version-info, proxy'...<br> > <debug> [/dev/wwan0qmi0] created endpoint<br> > <debug> [/dev/wwan0qmi0] sent message...<br> > <<<<<< RAW:<br> > <<<<<< length = 29<br> > <<<<<< data = 01:1C:00:00:00:00:00:01:00:FF:11:00...<br> ><br> > <debug> [/dev/wwan0qmi0] sent generic request (translated)...<br> > <<<<<< QMUX:<br> > <<<<<< length = 28<br> > <<<<<< flags = 0x00<br> > <<<<<< service = "ctl"<br> > <<<<<< client = 0<br> > <<<<<< QMI:<br> > <<<<<< flags = "none"<br> > <<<<<< transaction = 1<br> > <<<<<< tlv_length = 17<br> > <<<<<< message = "Internal Proxy Open" (0xFF00)<br> > <<<<<< TLV:<br> > <<<<<< type = "Device Path" (0x01)<br> > <<<<<< length = 14<br> > <<<<<< value = 2F:64:65:76:2F:77:77:61:6E:30:71:6D:69:30<br> > <<<<<< translated = /dev/wwan0qmi0<br> ><br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 1<br> > <debug> [/dev/wwan0qmi0] transaction 0xf aborted, but message is not abortable<br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 2<br> > <debug> [/dev/wwan0qmi0] transaction 0x10 aborted, but message is not abortable<br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 3<br> > <debug> [/dev/wwan0qmi0] transaction 0x11 aborted, but message is not abortable<br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 4<br> > <debug> [/dev/wwan0qmi0] transaction 0x12 aborted, but message is not abortable<br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 5<br> > <debug> [/dev/wwan0qmi0] transaction 0x13 aborted, but message is not abortable<br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 6<br> > <debug> [/dev/wwan0qmi0] transaction 0x14 aborted, but message is not abortable<br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 7<br> > <debug> [/dev/wwan0qmi0] transaction 0x15 aborted, but message is not abortable<br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 8<br> > <debug> [/dev/wwan0qmi0] transaction 0x16 aborted, but message is not abortable<br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 9<br> > <debug> [/dev/wwan0qmi0] transaction 0x17 aborted, but message is not abortable<br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 10<br> > <debug> [/dev/wwan0qmi0] transaction 0x18 aborted, but message is not abortable<br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 1<br> > <debug> [/dev/wwan0qmi0] transaction 0x1 aborted, but message is not abortable<br> > <debug> [wwan0qmi0/qmi] QMI port open operation failed: Transaction timed out<br> > <debug> [modem3] couldn't open QMI port with data format update: Transaction timed out<br> > <debug> [wwan0qmi0/qmi] Opening QMI device...<br> > <debug> [wwan0qmi0/qmi] Checking if QMI device already opening...<br> > <debug> [wwan0qmi0/qmi] Checking if QMI device already open...<br> > <debug> [wwan0qmi0/qmi] Creating QMI device...<br> > <debug> [wwan0qmi0/qmi] Opening device with flags: version-info, proxy...<br> > <debug> [/dev/wwan0qmi0] opening device with flags 'version-info, proxy'...<br> > <debug> [/dev/wwan0qmi0] created endpoint<br> > <debug> [/dev/wwan0qmi0] sent message...<br> > <<<<<< RAW:<br> > <<<<<< length = 29<br> > <<<<<< data = 01:1C:00:00:00:00:00:01:00:FF:11:00...<br> ><br> > <debug> [/dev/wwan0qmi0] sent generic request (translated)...<br> > <<<<<< QMUX:<br> > <<<<<< length = 28<br> > <<<<<< flags = 0x00<br> > <<<<<< service = "ctl"<br> > <<<<<< client = 0<br> > <<<<<< QMI:<br> > <<<<<< flags = "none"<br> > <<<<<< transaction = 1<br> > <<<<<< tlv_length = 17<br> > <<<<<< message = "Internal Proxy Open" (0xFF00)<br> > <<<<<< TLV:<br> > <<<<<< type = "Device Path" (0x01)<br> > <<<<<< length = 14<br> > <<<<<< value = 2F:64:65:76:2F:77:77:61:6E:30:71:6D:69:30<br> > <<<<<< translated = /dev/wwan0qmi0<br> ><br> > <debug> [/dev/wwan0qmi0] number of consecutive timeouts: 1<br> > <debug> [/dev/wwan0qmi0] transaction 0x1 aborted, but message is not abortable<br> > <debug> [wwan0qmi0/qmi] QMI port open operation failed: Transaction timed out<br> > <warn> [modem3] couldn't start initialization: Transaction timed out<br> > <error> [modem3] fatal error initializing: Fatal error: modem is unusable<br> ><br> <br> <br> This is weird, as if the ModemManager process cannot talk to the<br> proxy. Are you running MM as root?<br> <br> <br> -- <br> Aleksander<br> </blockquote></div>