<div dir="ltr"><div class="gmail_default" style="font-family:arial,helvetica,sans-serif">Hi all,<br><br></div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif">I added some more debug traces and found out two different problems.<br><br></div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif">1. passing from common_input_available to parse_response_buffer, it seems that part of the messag disappear (see attached file). This is the problem I saw the first time and the result is that Telit plugin's parser cache_port_mode receives a NULL string to parse and fails<br></div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif">2. The second problem might be even more weird. Parse_response_buffer gets a valid message and the content of the response is right, but still no callback is called and the initial call times out.<br><br></div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif">In the tar.gz attachment there is the full syslog of the test and two more files with ModemManager's logs only for the two problems (it is easier to read the content of the received message):<br></div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif"><br></div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif">problem 1: portcfg-message-disappear.txt<br></div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif">problem 2: portcfg-complete-no-callback-called.txt<br><br></div><div class="gmail_default" style="font-family:arial,helvetica,sans-serif">I added also the a diff so you can see where the new debug traces are.<br></div></div><div class="gmail_extra"><br><div class="gmail_quote">On 11 July 2016 at 13:56, Aleksander Morgado <span dir="ltr"><<a href="mailto:aleksander@aleksander.es" target="_blank">aleksander@aleksander.es</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div class="HOEnZb"><div class="h5">On Thu, Jul 7, 2016 at 5:45 PM, Carlo Lobrano <<a href="mailto:c.lobrano@gmail.com">c.lobrano@gmail.com</a>> wrote:<br> > I manage to replicate only a slightly different behavior, the log is in<br> > attachment.<br> ><br> ><br> > The test case is the following:<br> > 1. modem connected to the network and automatic reconnection set in the nm<br> > gui.<br> > 2. system in suspend (I used rtcwake), the MiniPCI modem is de-enumerated<br> > 3. system wake up, the modem is re-enumerated and probed again by<br> > ModemManager<br> ><br> > At this point #PORTCFG is sent to ACM0, the modem replies, but still<br> > getportcfg_ready() prints out that the command timed out. This happens 3<br> > times, then MM gives up.<br> ><br> ><br> > The following excerpt is one of the three times the portcfg times out<br> > Jul 7 17:09:42 ubuntu ModemManager[5302]: <debug> [1467904182.176461]<br> > [mm-port-serial-at.c:459] debug_log(): (ttyACM0): --> 'AT#PORTCFG?<CR>'<br> > ...<br> > Jul 7 17:09:43 ubuntu ModemManager[5302]: <debug> [1467904183.295449]<br> > [mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '<CR><LF>'<br> > Jul 7 17:09:43 ubuntu ModemManager[5302]: <debug> [1467904183.296489]<br> > [mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '#PORTCFG:<br> > 1,1<CR><LF><CR><LF>OK<CR><LF>'<br> > Jul 7 17:09:45 ubuntu ModemManager[5302]: <debug> [1467904185.574674]<br> > [telit/mm-plugin-telit.c:231] getportcfg_ready(): telit: couldn't get port<br> > mode: 'Serial command timed out'<br> ><br> > While the following comes from a valid run<br> > Jul 7 17:09:06 ubuntu ModemManager[5302]: <debug> [1467904146.343436]<br> > [mm-port-serial-at.c:459] debug_log(): (ttyACM0): --> 'AT#PORTCFG?<CR>'<br> > ...<br> > Jul 7 17:09:07 ubuntu ModemManager[5302]: <debug> [1467904147.462010]<br> > [mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '<CR><LF>'<br> > Jul 7 17:09:07 ubuntu ModemManager[5302]: <debug> [1467904147.463136]<br> > [mm-port-serial-at.c:459] debug_log(): (ttyACM0): <-- '#PORTCFG:<br> > 1,1<CR><LF><CR><LF>OK<CR><LF>'<br> > Jul 7 17:09:07 ubuntu ModemManager[5302]: <debug> [1467904147.463371]<br> > [telit/mm-plugin-telit.c:247] getportcfg_ready(): telit: retrieving port<br> > mode layout<br> ><br> > The only idea I can come up with is that the parser is receiving the wrong<br> > message. That was, in fact, the behavior I saw the first time, but as I said<br> > before this time the problem is slightly different because<br> > mm_port_serial_at_command_finish in mm-plugin-telit:getportcfg_ready returns<br> > with error this time, while the first time I saw the problem, no error was<br> > returned and the response was NULL, the process continued till<br> > mm-plugin-telit.c:cache_port_mode at line 248 and then the regex inside that<br> > function returned with error being unable to parse the NULL string.<br> <br> </div></div>This is a bit strange; we do see the reply printed in the debug log,<br> so that means we received it, but then it doesn't end up being flagged<br> as a response to the command, which is weird. Could you add some debug<br> traces in mm-port-serial.c::parse_response_buffer() and<br> mm-port-serial-at.c::parse_response() to see where exactly we end up<br> ignoring the response? E.g. I'm assuming that in this case the<br> parse_response() callback within parse_response_buffer() is returning<br> MM_PORT_SERIAL_RESPONSE_NONE; we should try to understand why is that.<br> <span class="HOEnZb"><font color="#888888"><br> --<br> Aleksander<br> <a href="https://aleksander.es" rel="noreferrer" target="_blank">https://aleksander.es</a><br> </font></span></blockquote></div><br></div>