BroadMobi BM818 modem seems to sometimes stop responding to AT commands

[Aleksander Morgado]

Hey Elias,

>
> I have a Librem 5 phone with a BroadMobi BM818-E1 modem. The operating
> system is PureOS 10 with ModemManager 1.14.12. Making phonecalls works
> most of the time, but sometimes it does not work and I have been trying
> to figure out why.
>
> Having added the ModemManager --debug option and compared logs for cases
> when making phonecalls work and not, now I think it looks like the
> problem is that the modem sometimes stops responding to AT commands.
>
> For a successful case, part of the log related to [modem0/ttyUSB1/at]
> looks like this:
>
> <debug> [1640639307.692391] [modem0/ttyUSB1/at] --> 'AT+CCWA=1<CR>'
> <debug> [1640639307.703945] [modem0/ttyUSB1/at] <-- '<CR><LF>OK<CR><LF>'
> <debug> [1640639307.704293] [modem0/ttyUSB1/at] device open count is 1
> (close)
> <debug> [1640639313.155180] [modem0/ttyUSB1/at] device open count is 2
> (open)
> <debug> [1640639313.155742] [modem0/ttyUSB1/at] --> 'AT+CCLK?<CR>'
> <debug> [1640639313.168020] [modem0/ttyUSB1/at] <-- '<CR><LF>+CCLK:
> "21/12/27,21:08:32+04"<CR><LF><CR><LF>OK<CR><LF>'
> <debug> [1640639313.168825] [modem0/ttyUSB1/at] device open count is 1
> (close)
> <debug> [1640639333.490220] [modem0/ttyUSB1/at] device open count is 2
> (open)
> <debug> [1640639333.490682] [modem0/ttyUSB1/at] device open count is 3
> (open)
> <debug> [1640639333.490880] [modem0/ttyUSB1/at] --> 'ATD90510;<CR>'
> <debug> [1640639333.534638] [modem0/ttyUSB1/at] <-- '<CR><LF>OK<CR><LF>'
>
> If I understand correctly, each "-->" line indicates an AT command sent
> to the modem, and each time there is a corresponding "<--" line that
> shows the response from the modem. That looks fine above, where each
> "-->" line is followed by a "<--" line.
>
> Below is the corresponding part of the log for a case when I could not
> make phonecalls:
>
> <debug> [1640636606.219473] [modem0/ttyUSB1/at] --> 'AT+CCWA=1<CR>'
> <debug> [1640636606.230312] [modem0/ttyUSB1/at] <-- '<CR><LF>OK<CR><LF>'
> <debug> [1640636606.230674] [modem0/ttyUSB1/at] device open count is 1
> (close)
> <debug> [1640636611.155941] [modem0/ttyUSB1/at] device open count is 2
> (open)
> <debug> [1640636611.156211] [modem0/ttyUSB1/at] --> 'AT+CCLK?<CR>'
> <debug> [1640636614.159204] [modem0/ttyUSB1/at] device open count is 1
> (close)
> <debug> [1640636660.623905] [modem0/ttyUSB1/at] device open count is 2
> (open)
> <debug> [1640636660.624328] [modem0/ttyUSB1/at] device open count is 3
> (open)
> <debug> [1640636660.624529] [modem0/ttyUSB1/at] --> 'ATD90510;<CR>'
> <debug> [1640636662.656478] [modem0/ttyUSB1/at] device open count is 4
> (open)
>
> In that case the modem responds to the "AT+CCWA" command, but for the
> "AT+CCLK" and the "ATD" commands there is no response from the modem.
>
> There are also messages about timeouts, like this:
>
> <debug> [1640636614.158768] [modem0] couldn't load network timezone:
> Serial command timed out
>
> <warn>  [1640636750.659447] [modem0/call0] couldn't start call: Serial
> command timed out
>
> Why would the modem stop responding to AT commands?
>
> Any ideas about possible solutions or workarounds, or ways to
> investigate further?
>

There are 2 main explanations for that behavior:
1) some other process is trying to talk to the AT port, so "hijacking"
the reading part from ModemManager.
2) the AT command handler inside the modem firmware, or some AT
command processing got stuck in the modem firmware.

When this happens, MM would count up to 10 consecutive AT timeouts,
and when that happens it flags the modem as invalid, and it's
reprobed. When reprobing, if the QMI port still works, MM will use
exclusively that one. If the QMI also doesn't work, the modem will be
unusable.

I would try to ask whether case 1) is possible in the Librem5, and if
it isn't, then you're facing a modem firmware issue very likely.

-- 
Aleksander
https://aleksander.es