Hi Aleksander, Piotr,
> I'm checking the logs and if my understanding is correct it looks like
> some logic from bearer disconnect from the connection before the modem
> reset happens still executes after modem was lost and when "new" modem
> is probed, it looks like it may get in the way of AT ports probing.
> Especially this happens and afterwards it seems PORTCFG reply fails to
> parse (or it's retried 3 times for other reason)
I don't know if it's the bearer disconnection, but it seems that the modem release is mixed with the new probing:
<debug> device_context_set_best_plugin(): [plugin manager] task 9,ttyACM0: best plugin matches device reported one: Telit
<debug> device_context_continue(): [plugin Manager] task 9: still 2 running probes (2 active): ttyACM2, ttyACM1
<debug> _close_internal(): (ttyACM0) device open count is 0 (close)
<debug> _close_internal(): (ttyACM0) closing serial port...
<debug> _close_internal(): (ttyACM0) serial port closed
<debug> port_serial_close_force(): (ttyACM0) forced to close port
<debug> _close_internal(): (ttyACM0) device open count is 0 (close)
<debug> _close_internal(): (ttyACM0) closing serial port...
<debug> _close_internal(): (ttyACM0) serial port closed
<debug> port_serial_close_force(): (ttyACM0) forced to close port
<debug> finalize(): Modem (Telit) '/sys/devices/soc0/soc.1/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.4' completely disposed
in the meantime, even if ttyACM0 is replying to #PORTCFG?, the plugin seems unable to receve it and keep retring.
<debug> debug_log(): (ttyACM0): --> 'AT#PORTCFG?<CR>'
...
<debug> debug_log(): (ttyACM0): <-- '<CR><LF>'
<debug> debug_log(): (ttyACM0): <-- '#PORTCFG: 8,8<CR><LF><CR><LF>OK<CR><LF>'
<debug> getportcfg_ready(): telit: retrieving port mode layout
<debug> mm_port_probe_set_result_at(): (tty/ttyACM0) port is AT-capable
<debug> debug_log(): (ttyACM0): --> 'AT#PORTCFG?<CR>'
<debug> debug_log(): (ttyACM0): <-- '<CR><LF>'
<debug> debug_log(): (ttyACM0): <-- '#PORTCFG: 8,8<CR><LF><CR><LF>OK<CR><LF>'
<debug> getportcfg_ready(): telit: retrieving port mode layout
<debug> mm_port_probe_set_result_at(): (tty/ttyACM0) port is AT-capable
<debug> debug_log(): (ttyACM0): --> 'AT#PORTCFG?<CR>'
<debug> debug_log(): (ttyACM0): <-- '<CR><LF>'
<debug> debug_log(): (ttyACM0): <-- '#PORTCFG: 8,8<CR><LF><CR><LF>OK<CR><LF>'
<debug> getportcfg_ready(): telit: retrieving port mode layout
[and here comes the disconnection]
finally, the modem set only ttyACM3 as valid port, both at and data
<debug> log_port(): (/sys/devices/soc0/soc.1/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.4) tty/ttyACM3 at (primary)
<debug> log_port(): (/sys/devices/soc0/soc.1/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.4) tty/ttyACM3 data (primary)
Not really sure what's happening here, but I do remember a similar issue where adding some new debug logs, it appeared that the reply sent to PORTCFG? parser was an empty string, the thread in this mailing list is
"[PATCH] Hardening PORTCFG parse reply" dated mid July 2016.
> I'm checking the logs and if my understanding is correct it looks like
> some logic from bearer disconnect from the connection before the modem
> reset happens still executes after modem was lost and when "new" modem
> is probed, it looks like it may get in the way of AT ports probing.
> Especially this happens and afterwards it seems PORTCFG reply fails to
> parse (or it's retried 3 times for other reason)
I don't know if it's the bearer disconnection, but it seems that the modem release is mixed with the new probing:
<debug> device_context_set_best_plugin(): [plugin manager] task 9,ttyACM0: best plugin matches device reported one: Telit
<debug> device_context_continue(): [plugin Manager] task 9: still 2 running probes (2 active): ttyACM2, ttyACM1
<debug> _close_internal(): (ttyACM0) device open count is 0 (close)
<debug> _close_internal(): (ttyACM0) closing serial port...
<debug> _close_internal(): (ttyACM0) serial port closed
<debug> port_serial_close_force(): (ttyACM0) forced to close port
<debug> _close_internal(): (ttyACM0) device open count is 0 (close)
<debug> _close_internal(): (ttyACM0) closing serial port...
<debug> _close_internal(): (ttyACM0) serial port closed
<debug> port_serial_close_force(): (ttyACM0) forced to close port
<debug> finalize(): Modem (Telit) '/sys/devices/soc0/soc.1/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.4' completely disposed
in the meantime, even if ttyACM0 is replying to #PORTCFG?, the plugin seems unable to receve it and keep retring.
<debug> debug_log(): (ttyACM0): --> 'AT#PORTCFG?<CR>'
...
<debug> debug_log(): (ttyACM0): <-- '<CR><LF>'
<debug> debug_log(): (ttyACM0): <-- '#PORTCFG: 8,8<CR><LF><CR><LF>OK<CR><LF>'
<debug> getportcfg_ready(): telit: retrieving port mode layout
<debug> mm_port_probe_set_result_at(): (tty/ttyACM0) port is AT-capable
<debug> debug_log(): (ttyACM0): --> 'AT#PORTCFG?<CR>'
<debug> debug_log(): (ttyACM0): <-- '<CR><LF>'
<debug> debug_log(): (ttyACM0): <-- '#PORTCFG: 8,8<CR><LF><CR><LF>OK<CR><LF>'
<debug> getportcfg_ready(): telit: retrieving port mode layout
<debug> mm_port_probe_set_result_at(): (tty/ttyACM0) port is AT-capable
<debug> debug_log(): (ttyACM0): --> 'AT#PORTCFG?<CR>'
<debug> debug_log(): (ttyACM0): <-- '<CR><LF>'
<debug> debug_log(): (ttyACM0): <-- '#PORTCFG: 8,8<CR><LF><CR><LF>OK<CR><LF>'
<debug> getportcfg_ready(): telit: retrieving port mode layout
[and here comes the disconnection]
finally, the modem set only ttyACM3 as valid port, both at and data
<debug> log_port(): (/sys/devices/soc0/soc.1/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.4) tty/ttyACM3 at (primary)
<debug> log_port(): (/sys/devices/soc0/soc.1/2100000.aips-bus/2184200.usb/ci_hdrc.1/usb1/1-1/1-1.4) tty/ttyACM3 data (primary)
Not really sure what's happening here, but I do remember a similar issue where adding some new debug logs, it appeared that the reply sent to PORTCFG? parser was an empty string, the thread in this mailing list is
"[PATCH] Hardening PORTCFG parse reply" dated mid July 2016.
_______________________________________________ ModemManager-devel mailing list ModemManager-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel