[PATCH] ublox: wait for READY URCs during port probing

[Aleksander Morgado]

On Mon, Dec 25, 2017 at 8:02 PM, Aleksander Morgado
<aleksander at aleksander.es> wrote:
> The AT control TTYs in the u-blox modems may take some time to be
> usable. In order to handle this issue, we configured some longer
> timeouts during AT probing, but that may not be always enough.
>
> The u-blox TTYs will report readiness via a "+AT: READY" URC, which
> we can use during custom initialization to decide right away that the
> port is AT. We use up to 20s as that is close to the worst case seen
> during experimentation, happening after the module undergoes a full
> NVM reset. If the timeout is reached without receiving the URC, we
> still run standard AT probing afterwards. This new logic just tries
> to make it sure we don't do any probing before the module is ready to
> accept it.
>
> If the module hasn't been hotplugged (i.e. it was already there when
> ModemManager started) we do a quick first AT probing and if that fails
> we run the "+AT: READY" URC wait as if it was hotplugged.
> ---

This is an example probing log with the patch applied:

<debug> [1514231584.230722] (ttyACM2) opening serial port...
<debug> [1514231584.231929] (ttyACM2): setting up baudrate: 57600
<debug> [1514231584.232074] (ttyACM2) device open count is 1 (open)
<debug> [1514231584.232412] (ttyACM2): port attributes not fully set
<debug> [1514231584.232844] (ttyACM0) opening serial port...
<debug> [1514231584.238413] (ttyACM0): setting up baudrate: 57600
<debug> [1514231584.243670] (ttyACM0) device open count is 1 (open)
<debug> [1514231584.245634] (ttyACM0): port attributes not fully set
<debug> [1514231584.246344] [plugin manager] task 2,wwan0: checking
with plugin 'u-blox'
<debug> [1514231584.247663] (u-blox) [wwan0] probing deferred until
result suggested
<debug> [1514231584.248315] [plugin manager] task 2,wwan0: completed,
got suggested plugin (u-blox)
<debug> [1514231584.249190] [plugin manager] task 2,wwan0: finished in
'1.483957' seconds
<debug> [1514231584.249676] [plugin manager] task 2,wwan0: best plugin
matches device reported one: u-blox
<debug> [1514231584.250723] [plugin Manager] task 2: still 2 running
probes (2 active): ttyACM2, ttyACM0
<debug> [1514231584.334269] (tty/ttyACM2) waiting for READY
unsolicited message...
<debug> [1514231584.347216] (tty/ttyACM0) waiting for READY
unsolicited message...
<debug> [1514231585.218387] [plugin manager] task 2: min probing time elapsed
<debug> [1514231585.218605] [plugin Manager] task 2: still 2 running
probes (2 active): ttyACM2, ttyACM0
<debug> [1514231599.805891] (ttyACM0): <-- '<CR><LF>+AT: READY<CR><LF>'
<debug> [1514231599.806154] (tty/ttyACM0) READY received: port is AT
<debug> [1514231599.806288] (tty/ttyACM0) port is AT-capable
<debug> [1514231599.806447] [plugin manager] task 2,ttyACM0: found
best plugin for port (u-blox)
<debug> [1514231599.806567] [plugin manager] task 2,ttyACM0: finished
in '17.077844' seconds
<debug> [1514231599.806710] [plugin manager] task 2,ttyACM0: best
plugin matches device reported one: u-blox
<debug> [1514231599.806838] [plugin Manager] task 2: still 1 running
probes (1 active): ttyACM2
<debug> [1514231599.807121] (ttyACM0) device open count is 0 (close)
<debug> [1514231599.807259] (ttyACM0) closing serial port...
<debug> [1514231599.816916] (ttyACM0) serial port closed
<debug> [1514231599.817328] (ttyACM0) forced to close port
<debug> [1514231599.817650] (ttyACM2): <-- '<CR><LF>+AT: READY<CR><LF>'
<debug> [1514231599.817843] (tty/ttyACM2) READY received: port is AT
<debug> [1514231599.817972] (tty/ttyACM2) port is AT-capable
<debug> [1514231599.818126] [plugin manager] task 2,ttyACM2: found
best plugin for port (u-blox)
<debug> [1514231599.818250] [plugin manager] task 2,ttyACM2: finished
in '17.087071' seconds
<debug> [1514231599.818404] [plugin manager] task 2,ttyACM2: best
plugin matches device reported one: u-blox
<debug> [1514231599.818521] [plugin manager] task 2: no more ports to probe
<debug> [1514231599.818628] [plugin manager] task 2: finished in
'17.101765' seconds
<info>  [1514231599.818983] [device toby] creating modem with plugin
'u-blox' and '5' ports

-- 
Aleksander
https://aleksander.es