> Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.408139] [plugin manager] task 4,ttyACM0: found '7' plugins to try > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.408278] [plugin manager] task 4,ttyACM0: will try with plugin > 'u-blox' > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.408414] [plugin manager] task 4,ttyACM0: will try with plugin > 'Telit' > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.408538] [plugin manager] task 4,ttyACM0: will try with plugin > 'Via CBP7' > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.408662] [plugin manager] task 4,ttyACM0: will try with plugin > 'Iridium' > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.408789] [plugin manager] task 4,ttyACM0: will try with plugin > 'Nokia' > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.408907] [plugin manager] task 4,ttyACM0: will try with plugin > 'Cinterion' > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.409032] [plugin manager] task 4,ttyACM0: will try with plugin > 'Generic' > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.409184] [plugin manager) task 4,ttyACM0: started > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.409322] [plugin manager] task 4,ttyACM0: checking with plugin > 'u-blox' > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.409547] (u-blox) [ttyACM0] probe required: 'at' > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.409740] (tty/ttyACM0) launching port probing: 'at' > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.411520] [plugin manager] task 4,ttyACM0: got suggested plugin > (u-blox) > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.414868] [plugin Manager] task 4: still 1 running probes (1 > active): ttyACM0 > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.428515] (ttyACM0) opening serial port... > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.430200] (ttyACM0): setting up baudrate: 57600 > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.431460] (ttyACM0) device open count is 1 (open) > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.432402] (ttyACM0): port attributes not fully set > Apr 9 15:10:40 canect2 daemon.debug ModemManager[252]: <debug> > [1523286640.533980] (tty/ttyACM0) waiting for READY unsolicited message... > Apr 9 15:10:41 canect2 daemon.debug ModemManager[252]: <debug> > [1523286641.372499] [plugin manager] task 4: min probing time elapsed > Apr 9 15:10:41 canect2 daemon.debug ModemManager[252]: <debug> > [1523286641.372683] [plugin Manager] task 4: still 1 running probes (1 > active): ttyACM0 > Apr 9 15:10:41 canect2 daemon.debug ModemManager[252]: <debug> > [1523286641.697020] (ttyACM0): <-- '<CR><LF>+PACSP0<CR><LF>' > Apr 9 15:11:00 canect2 daemon.debug ModemManager[252]: <debug> > [1523286660.874992] (tty/ttyACM0) timed out waiting for READY unsolicited > message > Apr 9 15:11:00 canect2 daemon.debug ModemManager[252]: <debug> > [1523286660.875680] (ttyACM0): --> 'AT<CR>' > Apr 9 15:11:00 canect2 daemon.debug ModemManager[252]: <debug> > [1523286660.879180] (ttyACM0): <-- 'AT<CR><CR><LF>OK<CR><LF>' > Apr 9 15:11:00 canect2 daemon.debug ModemManager[252]: <debug> > [1523286660.879990] (tty/ttyACM0) port is AT-capable > Apr 9 15:11:00 canect2 daemon.debug ModemManager[252]: <debug> > [1523286660.880393] [plugin manager] task 4,ttyACM0: found best plugin for > port (u-blox) > Apr 9 15:11:00 canect2 daemon.debug ModemManager[252]: <debug> > [1523286660.880603] [plugin manager] task 4,ttyACM0: finished in '22.009174' > seconds > Apr 9 15:11:00 canect2 daemon.debug ModemManager[252]: <debug> > [1523286660.880830] [plugin manager] task 4,ttyACM0: best plugin matches > device reported one: u-blox > Apr 9 15:11:00 canect2 daemon.debug ModemManager[252]: <debug> > [1523286660.880996] [plugin manager] task 4: no more ports to probe > Apr 9 15:11:00 canect2 daemon.debug ModemManager[252]: <debug> > [1523286660.881226] [plugin manager] task 4: finished in '22.010629' seconds > > The above issue where the 20 second timeout occurs is only if MM starts > before the ttyACM interfaces are initialized. In that case the registration > issue does not seem to occur (after testing several times). > > If I put in a 7 second sleep in the MM init script right before MM is > lauched, I do not see the 20 second timeout. In this case I instead get the > longer registration where the "Simple connect state (5/8): Register" step > reports "Launching automatic network registration..." and takes 60 seconds to > register with the network before moving on to the next simple connect state. > The interesting thing is that the ttyACM0 interface takes 60 seconds to > receive the +CEREG and other messages, but the ttyACM1 interface is receiving > those messages at various points during the 60 seconds. Also when the > ttyACM0 receives its messages, it gets several messages all at once with 4 > copies of the messages received all at once. It almost looks like a modem > firmware issue where ttyACM0 stops responding for 60 seconds and then blasts > out all waiting messages that occurred during that time. > > > It looks like no matter what I do I am encountering a delay or some sort on > boot, one in probing the modem or another in the registration. If I could > resolve the 20 second timeout issue, that would resolve my main issue as I > really don't want to put a delay before MM starts. > > I don't understand why there is a 20 second timeout. Couldn't you just test > the AT interface right away with 'AT' instead of waiting a timeout and then > trying it. Also 20 seconds is a long time. Couldn't a much shorter timeout > be put in with some message sent to the modem to get it to respond (like > 'AT') and do that several times to add up to 20 seconds. This seems like it > would be much quicker in cases where the modem did not respond immediately > and might resolve this issue. >
That 20s timeout is really an artifact added for the TOBY-L4, to wait for the +READY URC it sends if the port is detected via hotplug events. It's actually just to make it quicker the probing in the TOBY-L4. This should be therefore something specific for the TOBY-L4 and not something generic for all u-blox modems... sorry for that :/ I'll gladly accept a patch that makes this 20s timeout something specific for the TOBY-L4 ;) -- Aleksander https://aleksander.es _______________________________________________ ModemManager-devel mailing list ModemManager-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
