[PATCH] Hardening PORTCFG parse reply

[Carlo Lobrano]

Hi Dan, Aleksander,

I manage to replicate only a slightly different behavior, the log is in
attachment.


The test case is the following:
  1. modem connected to the network and automatic reconnection set in the
nm gui.
  2. system in suspend (I used rtcwake), the MiniPCI modem is de-enumerated
  3. system wake up, the modem is re-enumerated and probed again by
ModemManager

At this point #PORTCFG is sent to ACM0, the modem replies, but still
getportcfg_ready() prints out that the command timed out. This happens 3
times, then MM gives up.


The following excerpt is one of the three times the portcfg times out
    Jul  7 17:09:42 ubuntu ModemManager[5302]: <debug> [1467904182.176461]
[mm-port-serial-at.c:459] debug_log(): (ttyACM0): --> 'AT#PORTCFG?<CR>'
    ...
   Jul  7 17:09:43 ubuntu ModemManager[5302]: <debug> [1467904183.295449]
[mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '<CR><LF>'
   Jul  7 17:09:43 ubuntu ModemManager[5302]: <debug> [1467904183.296489]
[mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '#PORTCFG:
1,1<CR><LF><CR><LF>OK<CR><LF>'
   Jul  7 17:09:45 ubuntu ModemManager[5302]: <debug> [1467904185.574674]
[telit/mm-plugin-telit.c:231] getportcfg_ready(): telit: couldn't get port
mode: 'Serial command timed out'

While the following comes from a valid run
   Jul  7 17:09:06 ubuntu ModemManager[5302]: <debug> [1467904146.343436]
[mm-port-serial-at.c:459] debug_log(): (ttyACM0): --> 'AT#PORTCFG?<CR>'
   ...
   Jul  7 17:09:07 ubuntu ModemManager[5302]: <debug> [1467904147.462010]
[mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '<CR><LF>'
   Jul  7 17:09:07 ubuntu ModemManager[5302]: <debug> [1467904147.463136]
[mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '#PORTCFG:
1,1<CR><LF><CR><LF>OK<CR><LF>'
   Jul  7 17:09:07 ubuntu ModemManager[5302]: <debug> [1467904147.463371]
[telit/mm-plugin-telit.c:247] getportcfg_ready(): telit: retrieving port
mode layout

The only idea I can come up with is that the parser is receiving the wrong
message. That was, in fact, the behavior I saw the first time, but as I
said before this time the problem is slightly different because
mm_port_serial_at_command_finish in mm-plugin-telit:getportcfg_ready
returns with error this time, while the first time I saw the problem, no
error was returned and the response was NULL, the process continued till
mm-plugin-telit.c:cache_port_mode at line 248 and then the regex inside
that function returned with error being unable to parse the NULL string.




On 30 June 2016 at 16:30, Aleksander Morgado <aleksander at aleksander.es>
wrote:

> On Thu, Jun 30, 2016 at 4:23 PM, Carlo Lobrano <c.lobrano at gmail.com>
> wrote:
> >> A long shot maybe, but did you see this issue while you were testing
> the SIM hotplug thing? Remember that there's an extra port open reference
> in that case.
> >
> > No no :), I wouldn't have signaled such an error in a "corrupted"
> > ModemManager :D
>
> Hehe, I said it was a long shot :)
>
> --
> Aleksander
> https://aleksander.es
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/modemmanager-devel/attachments/20160707/4ccabdb3/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: portcfg-timed-out.log
Type: text/x-log
Size: 275212 bytes
Desc: not available
URL: <https://lists.freedesktop.org/archives/modemmanager-devel/attachments/20160707/4ccabdb3/attachment-0001.bin>