ANN: ModemManager 1.18.4 released / Avoiding PPP
Peter Naulls
peter at chocky.org
Wed Jan 12 15:16:30 UTC 2022
On 1/12/22 9:58 AM, Aleksander Morgado wrote:
> Hey,
>
> I'm not sure there's an easy way to do that; but in this case we may
> also be interested in the QMI messages really, because we also want to
> make sure the port probing is working as expected; i.e. if this issue
> happens not only upon MM start, also when you power cycle the modem,
> it could be that the port probing of the QMI port is not completing
> successfully, so even if the ports are reported to MM, they're not
> used as MM couldn't verify it's a valid QMI port.
>
Here we go. I may have to increase the ring buffer size; the top is
the earliest I was able to grab.
Some of the AT commands are coming from an external application using
mmcli; i wonder if that's confouding MM.
Wed Jan 12 14:50:08 2022 daemon.debug [2670]: <debug> [1641999008.905414]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:08 2022 daemon.debug [2670]: <debug> [1641999008.905722]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:08 2022 daemon.debug [2670]: <debug> [1641999008.906044]
[modem0/ttyUSB2/at] --> 'AT+CLCK="PP",2<CR>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.044547]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.045268]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.045577]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.045887]
[modem0/ttyUSB2/at] --> 'AT+CLCK="PC",2<CR>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.184502]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CLCK: 0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.185363]
[modem0] loading IMEI...
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.185597]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.185935]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.186344]
[modem0] loaded IMEI: 001119000013505
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.186606]
[modem0] loading UE mode of operation for EPS...
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.186806]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.187086]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.187382]
[modem0/ttyUSB2/at] --> 'AT+CEMODE?<CR>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.291833]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CEMODE: 2<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.296783]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.297253]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.299541]
[modem0/ttyUSB2/at] device open count is 1 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.303960]
[modem0/ttyUSB2/at] device open count is 2 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.304451]
[modem0/ttyUSB2/at] --> 'AT+QGPS=?<CR>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.393243]
[modem0/ttyUSB2/at] <-- '<CR><LF>+QGPS:
(1-4),(1-255),(1-3),(100-65535)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.393933]
[modem0] (quectel) GPS management with +QGPS is supported
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.399827]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.400289]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.400607]
[modem0/ttyUSB2/at] --> 'AT+CNMI=?<CR>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.490668]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CNMI:
(0-2),(0-3),(0,2),(0-2),(0,1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.491404]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.491690]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.491954]
[modem0/ttyUSB2/at] --> 'AT+CPMS=?<CR>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.580850]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS:
("ME","MT","SM","SR"),("ME","MT","SM","SR"),("ME","MT","SM","SR")<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.583725]
[modem0] supported storages loaded:
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.583885]
[modem0] mem1 (list/read/delete) storages: 'me, mt, sm, sr'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.583993]
[modem0] mem2 (write/send) storages: 'me, mt, sm, sr'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.584100]
[modem0] mem3 (reception) storages: 'me, mt, sm, sr'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.584559]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.584853]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.585143]
[modem0/ttyUSB2/at] --> 'AT+CPMS?<CR>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.660979]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS:
"ME",0,127,"ME",0,127,"ME",0,127<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.661826]
[modem0] current storages initialized:
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.661969]
[modem0] mem1 (list/read/delete) storages: 'me'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.662094]
[modem0] mem2 (write/send) storages: 'me'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.662226]
[modem0] current storages initialized
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.664799]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.665199]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.665498]
[modem0/ttyUSB2/at] --> 'AT+CTZU=?<CR>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.750667]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CTZU: (0,1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.751384]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.751654]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.751916]
[modem0/ttyUSB2/at] --> 'AT+CTZU=1<CR>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.841040]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.841567]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.841812]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.842070]
[modem0/ttyUSB2/at] --> 'AT+CCLK?<CR>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.920845]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CCLK:
"22/01/12,15:08:32-20"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.922630]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.923005]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:09 2022 daemon.debug [2670]: <debug> [1641999009.923287]
[modem0/ttyUSB2/at] --> 'AT+CESQ=?<CR>'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.010633]
[modem0/ttyUSB2/at] <-- '<CR><LF>ERROR<CR><LF>'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.011066]
[modem0/ttyUSB2/at] operation failure: 100 (Unknown error)
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.011275]
[modem0] extended signal support check failed: Unknown error
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.011439]
[modem0] couldn't initialize interface: 'Extended Signal information not supported'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.013177]
[modem0/ttyUSB2/at] device open count is 1 (close)
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.013491]
[modem0] couldn't initialize interface: 'OMA not supported'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.017120]
[modem0/ttyUSB2/at] device open count is 2 (open)
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.017618]
[modem0/ttyUSB2/at] --> 'ATH<CR>'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.050618]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.051206]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.051450]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.051706]
[modem0/ttyUSB2/at] --> 'AT+CLCC=?<CR>'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.140698]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.141569]
[modem0] periodic call list polling will be used if supported
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.142783]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.143121]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.143404]
[modem0/ttyUSB2/at] --> 'AT+QFASTBOOT=?<CR>'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.283064]
[modem0/ttyUSB2/at] <-- '<CR><LF>ERROR<CR><LF>'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.283524]
[modem0/ttyUSB2/at] operation failure: 100 (Unknown error)
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.288969]
[modem0] creating ports context for SIM hot swap
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.289183]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:10 2022 daemon.info [2670]: <info> [1641999010.289971]
[modem0] state changed (unknown -> disabled)
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.290611]
[modem0] modem initialized
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.300337]
[device /sys/devices/platform/1e1c0000.xhci/usb2/2-1] exported modem at path
'/org/freedesktop/ModemManager1/Modem/0'
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.300608]
[device /sys/devices/platform/1e1c0000.xhci/usb2/2-1] plugin: quectel
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.300786]
[device /sys/devices/platform/1e1c0000.xhci/usb2/2-1] vid:pid: 0x2C7C:0x0512
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.301201]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:10 2022 daemon.debug [2670]: <debug> [1641999010.301562]
[modem0/ttyUSB2/at] device open count is 1 (close)
Wed Jan 12 14:50:11 2022 user.notice ModemManager: hotplug: modem exported
successfully at /sys/devices/platform/1e1c0000.xhci/usb2/2-1
Wed Jan 12 14:50:11 2022 user.notice ModemManager: hotplug: setting interface
'wwan' as available
Wed Jan 12 14:50:11 2022 daemon.notice netifd: Interface 'wwan' is setting up now
Wed Jan 12 14:50:11 2022 daemon.notice netifd: wwan (4960): modem available at
/org/freedesktop/ModemManager1/Modem/0
Wed Jan 12 14:50:11 2022 daemon.notice netifd: wwan (4960): starting connection
with apn 'firstnet-broadband'...
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.616275]
[modem0] user request to connect modem
Wed Jan 12 14:50:11 2022 daemon.info [2670]: <info> [1641999011.617097]
[modem0] simple connect started...
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.617233]
[modem0] profile ID: unspecified
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.617341]
[modem0] PIN: unspecified
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.617447]
[modem0] operator ID: unspecified
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.617558]
[modem0] allowed roaming: yes
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.617666]
[modem0] APN: firstnet-broadband
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.617774]
[modem0] APN type: unspecified
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.617888]
[modem0] IP family: ipv4v6
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.618004]
[modem0] allowed authentication: unspecified
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.618118]
[modem0] user: unspecified
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.618223]
[modem0] password: unspecified
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.618332]
[modem0] multiplex: unspecified
Wed Jan 12 14:50:11 2022 daemon.info [2670]: <info> [1641999011.618439]
[modem0] simple connect state (3/8): enable
Wed Jan 12 14:50:11 2022 daemon.info [2670]: <info> [1641999011.619017]
[modem0] state changed (disabled -> enabling)
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.620911]
[modem0] skipping initialization: device hotplugged
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.621154]
[modem0/ttyUSB2/at] device open count is 2 (open)
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.621273]
[modem0] flashing primary AT port before enabling...
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.621757]
[modem0] loading power state...
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.621991]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.622413]
[modem0/ttyUSB2/at] --> 'AT+CFUN?<CR>'
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.700679]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CFUN: 1<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.701469]
[modem0] no need to change power state: already 'on'
Wed Jan 12 14:50:11 2022 daemon.info [2670]: <info> [1641999011.701600]
[modem0] power state updated: on
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.701847]
[modem0] checking if SIM was swapped...
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.702018]
[modem0/sim0] loading SIM identifier...
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.702207]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.702524]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.702805]
[modem0/ttyUSB2/at] --> 'AT+CRSM=176,12258,0,0,10<CR>'
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.940975]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CRSM:
144,0,"98100140030092884575"<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.942000]
[modem0/sim0] loaded SIM identifier: 89011004300029885457
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.942348]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.942715]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:11 2022 daemon.debug [2670]: <debug> [1641999011.943045]
[modem0/ttyUSB2/at] --> 'AT+IFC=?<CR>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.020589]
[modem0/ttyUSB2/at] <-- '<CR><LF>+IFC: (0-2),(0-2)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.021417]
[modem0] TE supports no flow control
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.021570]
[modem0] TE supports XON/XOFF flow control
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.021730]
[modem0] TE supports RTS/CTS flow control
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.021926]
[modem0] TA supports no flow control
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.022066]
[modem0] TA supports XON/XOFF flow control
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.022219]
[modem0] TA supports RTS/CTS flow control
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.022473]
[modem0] flow control settings automatically selected: rts-cts
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.022722]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.023046]
[modem0] modem has 3GPP capabilities, enabling the Modem 3GPP interface...
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.023292]
[modem0] checking indicator support...
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.023491]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.023957]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.024415]
[modem0/ttyUSB2/at] --> 'AT+IFC=2,2<CR>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.111036]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.111797]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.112264]
[modem0/ttyUSB2/at] --> 'AT+CIND=?<CR>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.200752]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CIND:
("battchg",(0-5)),("signal",(0-5)),("service",(0-1)),("call",(0-1)),("roam",(0-1)),("smsfull",(0-1)),("GPRS
coverage",(0-1)),("callsetup",(0-3))<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.201985]
[modem0] signal quality indications via CIND are supported at index '2' (min: 0,
max: 5)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.202152]
[modem0] roaming indications via CIND are supported at index '5'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.202314]
[modem0] service indications via CIND are supported at index '3'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.202649]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.202943]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.203276]
[modem0/ttyUSB2/at] --> 'AT+CMER=?<CR>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.290028]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CMER:
(0-3),(0),(0),(0,1),(0,1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.291317]
[modem0] supported +CMER modes: discard-urcs, discard-urcs-if-link-reserved,
buffer-urcs-if-link-reserved, forward-urcs
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.291626]
[modem0] supported +CMER indication settings: disable, enable-not-caused-by-cind
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.291867]
[modem0] +CMER enable mode: forward-urcs
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.292028]
[modem0] +CMER disable mode: discard-urcs
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.292191]
[modem0] +CMER indication setting: enable-not-caused-by-cind
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.292366]
[modem0] checking packet domain event reporting...
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.292684]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.293043]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.293574]
[modem0/ttyUSB2/at] --> 'AT+CGEREP=?<CR>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.400722]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGEREP: (0-2),(0,1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.401382]
[modem0] packet domain event reporting is supported
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.401606]
[modem0] setting 3GPP +CIEV unsolicited events handlers in ttyUSB2
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.401783]
[modem0] setting 3GPP +CGEV unsolicited events handlers in ttyUSB2
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.402019]
[modem0] enabling +CIND event reporting in primary port...
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.402215]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.402511]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.402775]
[modem0/ttyUSB2/at] --> 'AT+CMER=3,0,0,1<CR>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.551250]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.552079]
[modem0] enabling +CGEV event reporting in primary port...
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.552417]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.552787]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.553218]
[modem0/ttyUSB2/at] --> 'AT+CGEREP=2<CR>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.633749]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.640772]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.643278]
[modem0] setting up 3GPP unsolicited registration messages handlers in ttyUSB2
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.643753]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.644179]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.644479]
[modem0/ttyUSB2/at] --> 'AT+QGPSCFG=autogps,1<CR>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.842945]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CME ERROR: 501<CR><LF>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.843449]
[modem0/ttyUSB2/at] operation failure: 501 (GNSS - Invalid parameter)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.844410]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.844773]
[modem0/ttyUSB2/at] --> 'AT+CREG=2<CR>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.930700]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.931439]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.931731]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:12 2022 daemon.debug [2670]: <debug> [1641999012.932000]
[modem0/ttyUSB2/at] --> 'AT+CGREG=2<CR>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.020850]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.021762]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.022232]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.022660]
[modem0/ttyUSB2/at] --> 'AT+CEREG=2<CR>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.047590]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.110659]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.111302]
[modem0] modem has 3GPP profile management capabilities, enabling the Modem 3GPP
Profile Manager interface...
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.111623]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.111899]
[modem0] modem has 3GPP/USSD capabilities, enabling the Modem 3GPP/USSD interface...
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.112161]
[modem0] setting unsolicited result code handlers in ttyUSB2
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.112543]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.112832]
[modem0/ttyUSB2/at] --> 'AT+QGPS=1<CR>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.207745]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.209029]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.209409]
[modem0/ttyUSB2/at] --> 'AT+CUSD=1<CR>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.299578]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.300847]
[modem0] modem has location capabilities, enabling the Location interface...
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.301303]
[modem0] location 'gps-raw' gathering is already disabled...
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.301521]
[modem0] location 'gps-nmea' gathering is already disabled...
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.301739]
[modem0] location 'gps-unmanaged' gathering is already disabled...
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.301954]
[modem0] need to enable the following location sources: '3gpp-lac-ci'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.310078]
[modem0] running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes', 5GS: 'no')
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.310553]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.311201]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.314498]
[modem0] modem has messaging capabilities, enabling the Messaging interface...
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.315793]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.316427]
[modem0/ttyUSB2/at] --> 'AT+CREG?<CR>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.389738]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.390399]
[modem0] 3GPP registration state change ignored as modem isn't enabled
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.390969]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.391203]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.391495]
[modem0/ttyUSB2/at] --> 'AT+CMGF=?<CR>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.479613]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CMGF: (0,1)<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.480570]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.480824]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.481137]
[modem0/ttyUSB2/at] --> 'AT+CGREG?<CR>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.569545]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.570262]
[modem0] 3GPP registration state change ignored as modem isn't enabled
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.570852]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.571091]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.571391]
[modem0/ttyUSB2/at] --> 'AT+CMGF=0<CR>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.656569]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.657235]
[modem0] successfully set preferred SMS mode: 'PDU'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.657938]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.658404]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.660232]
[modem0/ttyUSB2/at] --> 'AT+CEREG?<CR>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.690379]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.739507]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CEREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.740115]
[modem0] 3GPP registration state change ignored as modem isn't enabled
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.740767]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.741123]
[modem0/ttyUSB2/at] --> 'AT+CPMS="ME","MT","MT"<CR>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.962244]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS: 0,127,0,127,0,127<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.962864]
[modem0] listing SMS parts in storage 'me'
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.963026]
[modem0] locking SMS storages to: mem1 (ME), mem2 (none)...
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.963233]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.963491]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:13 2022 daemon.debug [2670]: <debug> [1641999013.963768]
[modem0/ttyUSB2/at] --> 'AT+CPIN?<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.039510]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPIN: READY<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.040741]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.041902]
[modem0/ttyUSB2/at] --> 'AT+CPMS="ME"<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.160024]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS: 0,127,0,127,0,127<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.161054]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.161572]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.161999]
[modem0/ttyUSB2/at] --> 'AT+CMGL=4<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.239995]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.241191]
[modem0] listing SMS parts in storage 'sm'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.241488]
[modem0] locking SMS storages to: mem1 (SM), mem2 (none)...
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.241802]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.242259]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.242705]
[modem0/ttyUSB2/at] --> 'AT+CPMS="SM"<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.245847]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.354983]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS: 0,5,0,127,0,127<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.355700]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.355964]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.356239]
[modem0/ttyUSB2/at] --> 'AT+GSN<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.409610]
[modem0/ttyUSB2/at] <-- '<CR><LF>001119000013505<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.410992]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.412163]
[modem0/ttyUSB2/at] --> 'AT+CMGL=4<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.499728]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.500649]
[modem0] listing SMS parts in storage 'sr'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.500819]
[modem0] locking SMS storages to: mem1 (SR), mem2 (none)...
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.501032]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.501333]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.501603]
[modem0/ttyUSB2/at] --> 'AT+CPMS="SR"<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.612500]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CPMS:
0,0,0,127,0,127<CR><LF><CR><LF>OK<CR><LF><CR><LF>+CIEV: 5,1<CR><LF>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.613933]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.614757]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.615424]
[modem0/ttyUSB2/at] --> 'AT+CMGL=4<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.639793]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.689538]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.690470]
[modem0] setting messaging unsolicited events handlers in ttyUSB2
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.690784]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.691113]
[modem0] enabling messaging unsolicited events on primary port ttyUSB2
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.691311]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.691602]
[modem0/ttyUSB2/at] --> 'AT+QCCID<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.769532]
[modem0/ttyUSB2/at] <-- '<CR><LF>+QCCID:
89011004300029885457<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.770849]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.771346]
[modem0/ttyUSB2/at] --> 'AT+CNMI=2,1,2,1,0<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.940985]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.941637]
[modem0] messaging unsolicited events enabled on primary port ttyUSB2
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.941814]
[modem0] modem has time capabilities, enabling the Time interface...
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.942225]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.942506]
[modem0] modem has voice capabilities, enabling the Voice interface...
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.942995]
[modem0] setting voice unsolicited events handlers in ttyUSB2
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.943419]
[modem0] enabling +CLIP calling line reporting in primary port...
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.943642]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.944102]
[modem0/ttyUSB2/at] --> 'AT+CLIP=1<CR>'
Wed Jan 12 14:50:14 2022 daemon.debug [2670]: <debug> [1641999014.974978]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.019519]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.020079]
[modem0] enabling +CRC extended format of incoming call indications in primary
port...
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.020282]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.020498]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.020778]
[modem0/ttyUSB2/at] --> 'AT+CIMI<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.089543]
[modem0/ttyUSB2/at] <-- '<CR><LF>313100002988545<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.090872]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.091302]
[modem0/ttyUSB2/at] --> 'AT+CRC=1<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.169578]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.170282]
[modem0] enabling +CCWA call waiting indications in primary port...
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.170544]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.170840]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.171165]
[modem0/ttyUSB2/at] --> 'AT+CCWA=1<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.262568]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.info [2670]: <info> [1641999015.263299]
[modem0] simple connect state (4/8): wait to get fully enabled
Wed Jan 12 14:50:15 2022 daemon.info [2670]: <info> [1641999015.263668]
[modem0] state changed (enabling -> enabled)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.266642]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:15 2022 daemon.info [2670]: <info> [1641999015.267280]
[modem0] simple connect state (5/8): register
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.267815]
[modem0] launching automatic network registration...
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.268318]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.269469]
[modem0] running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes', 5GS: 'no')
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.270060]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.270538]
[modem0/ttyUSB2/at] --> 'AT+COPS=0<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.298120]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.366187]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.366812]
[modem0] running registration checks (CS: 'yes', PS: 'yes', EPS: 'yes', 5GS: 'no')
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.367047]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.367298]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.367605]
[modem0/ttyUSB2/at] --> 'AT+CREG?<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.449499]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.info [2670]: <info> [1641999015.450222]
[modem0] 3GPP registration state changed (unknown -> registering)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.450432]
[modem0] loading Operator Code...
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.450615]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.450867]
[modem0/ttyUSB2/at] device open count is 7 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.451344]
[modem0] access technology changed (unknown -> lte)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.451536]
[modem0] 3GPP tracking area code updated: '000000->005507'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.451650]
[modem0] 3GPP cell id updated: '00000000->0BE722D8'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.451769]
[modem0] 3GPP location updated (MCCMNC: '<none>', location area code: '0000',
tracking area code: '005507', cell ID: '0BE722D8')
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.452210]
[modem0/ttyUSB2/at] device open count is 8 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.452423]
[modem0/ttyUSB2/at] device open count is 7 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.453513]
[modem0/ttyUSB2/at] --> 'AT+CGMR<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.519584]
[modem0/ttyUSB2/at] <-- '<CR><LF>EM12AWPAR01A07M4G<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.521037]
[modem0/ttyUSB2/at] device open count is 6 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.522175]
[modem0/ttyUSB2/at] --> 'AT+CREG?<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.590822]
[modem0/ttyUSB2/at] <-- '<CR><LF>+QLWURC: "pdp
active","failed","firstnetbroadband"<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.591748]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.592735]
[modem0/ttyUSB2/at] device open count is 7 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.592985]
[modem0/ttyUSB2/at] device open count is 6 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.593285]
[modem0/ttyUSB2/at] --> 'AT+COPS=3,2<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.689911]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.690598]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.691020]
[modem0/ttyUSB2/at] --> 'AT+COPS?<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.721423]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.749491]
[modem0/ttyUSB2/at] <-- '<CR><LF>+COPS: 0,2,"313100",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.750524]
[modem0] couldn't convert operator string '313100' from charset 'UCS2': Invalid
conversion from UCS2 to UTF-8: Couldn't convert from UCS2 to UTF-8 with
translit: Could not open converter from “UCS-2BE” to “UTF-8”
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.750715]
[modem0] operator normalized '313100'->'313100'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.750878]
[modem0] loaded Operator Code: 313100
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.751356]
[modem0] 3GPP location updated (MCCMNC: '313100', location area code: '0000',
tracking area code: '005507', cell ID: '0BE722D8')
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.751523]
[modem0] loading Operator Name...
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.751760]
[modem0/ttyUSB2/at] device open count is 7 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.752063]
[modem0/ttyUSB2/at] device open count is 8 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.752323]
[modem0/ttyUSB2/at] device open count is 7 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.753435]
[modem0/ttyUSB2/at] --> 'AT+CGREG?<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.839467]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.840326]
[modem0] 3GPP location area code updated: '0000->5507'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.840477]
[modem0] 3GPP tracking area code cleared: '005507->000000'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.840652]
[modem0] 3GPP location updated (MCCMNC: '313100', location area code: '5507',
tracking area code: '000000', cell ID: '0BE722D8')
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.841229]
[modem0/ttyUSB2/at] device open count is 8 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.841507]
[modem0/ttyUSB2/at] device open count is 7 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.841864]
[modem0/ttyUSB2/at] --> 'AT+CGREG?<CR>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.929436]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.930407]
[modem0/ttyUSB2/at] device open count is 8 (open)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.930645]
[modem0/ttyUSB2/at] device open count is 7 (close)
Wed Jan 12 14:50:15 2022 daemon.debug [2670]: <debug> [1641999015.930942]
[modem0/ttyUSB2/at] --> 'AT+QCFG="band"<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.069687]
[modem0/ttyUSB2/at] <-- '<CR><LF>+QCFG:
"band",0x260,0x2000000003000281a,0x0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.071007]
[modem0/ttyUSB2/at] device open count is 6 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.071437]
[modem0/ttyUSB2/at] --> 'AT+COPS=3,0<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.179819]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.180629]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.181070]
[modem0/ttyUSB2/at] --> 'AT+COPS?<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.249879]
[modem0/ttyUSB2/at] <-- '<CR><LF>+COPS: 0,0,"FirstNet",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.250932]
[modem0] couldn't convert operator string 'FirstNet' from charset 'UCS2': Hex
byte conversion from 'Fi' failed
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.251157]
[modem0] operator normalized 'FirstNet'->'FirstNet'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.251320]
[modem0] loaded Operator Name: FirstNet
Wed Jan 12 14:50:16 2022 daemon.info [2670]: <info> [1641999016.251789]
[modem0] 3GPP registration state changed (registering -> home)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.251939]
[modem0] consolidated registration state: cs 'home', ps 'home', eps 'home', 5gs
'unknown' --> 'home'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.252485]
[modem0] will start keeping track of state for subsystem '3gpp'
Wed Jan 12 14:50:16 2022 daemon.info [2670]: <info> [1641999016.252709]
[modem0] state changed (enabled -> registered)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.253307]
[modem0] network timezone polling started
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.256161]
[modem0] periodic signal checks enabled
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.256497]
[modem0] periodic signal check refresh requested
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.256697]
[modem0] loading signal quality...
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.257042]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.257569]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.262863]
[modem0/ttyUSB2/at] --> 'AT+CEREG?<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.281030]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.329512]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CEREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.330246]
[modem0] 3GPP tracking area code updated: '000000->005507'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.330398]
[modem0] 3GPP location area code cleared: '5507->0000'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.330578]
[modem0] 3GPP location updated (MCCMNC: '313100', location area code: '0000',
tracking area code: '005507', cell ID: '0BE722D8')
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.331115]
[modem0] initial 3GPP registration checks finished
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.331335]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.331679]
[modem0/ttyUSB2/at] --> 'AT+CEREG?<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.419509]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CEREG:
2,1,"5507","BE722D8",7<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.420440]
[modem0] periodic signal check refresh ignored: check already running
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.420588]
[modem0] currently registered in a 3GPP network
Wed Jan 12 14:50:16 2022 daemon.info [2670]: <info> [1641999016.420798]
[modem0] simple connect state (6/8): bearer
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.420952]
[modem0] creating new bearer...
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.421218]
[modem0] creating broadband bearer in broadband modem...
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.436529]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.437069]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 14:50:16 2022 daemon.info [2670]: <info> [1641999016.438846]
[modem0] simple connect state (7/8): connect
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.442000]
[modem0/bearer0] connecting...
Wed Jan 12 14:50:16 2022 daemon.info [2670]: <info> [1641999016.442377]
[modem0] state changed (registered -> connecting)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.444650]
[modem0/bearer0] launching 3GPP connection attempt
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.445020]
[modem0] set profile state (1/8): check format
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.445377]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.445881]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.447888]
[modem0/ttyUSB2/at] --> 'AT+CIND?<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.529577]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CIND: 0,5,1,1,0,1,1,0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.530964]
[modem0] signal quality updated (100)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.531379]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.532517]
[modem0] polling to refresh access technologies is unsupported
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.533745]
[modem0] periodic signal quality and access technology checks scheduled
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.534175]
[modem0/ttyUSB2/at] --> 'AT+QTEMP<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.647867]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.649481]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.650764]
[modem0/ttyUSB2/at] <-- '<CR><LF>+QTEMP:
"xo_therm_buf","23"<CR><LF><CR><LF>+QTEMP:
"mdm_case_therm","23"<CR><LF><CR><LF>+QTEMP:
"pa_therm1","22"<CR><LF><CR><LF>+QTEMP:
"tsens_tz_sensor0","26"<CR><LF><CR><LF>+QTEMP:
"tsens_tz_sensor1","26"<CR><LF><CR><LF>+QTEMP:
"tsens_tz_sensor2","26"<CR><LF><CR><LF>+QTEMP:
"tsens_tz_sensor3","26"<CR><LF><CR><LF>+QTEMP: "tsens_tz_sensor4","26"<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.652957]
[modem0] unhandled PDP type in CGDCONT=? reply: 'PPP'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.653432]
[modem0] +CGDCONT format details for PDP type 'ipv4v6': minimum 1, maximum 42
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.653708]
[modem0] context definition format: minimum 1, maximum 42
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.653828]
[modem0] set profile state (2/8): list before
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.654105]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.654401]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.654727]
[modem0/ttyUSB2/at] --> 'AT+CGDCONT?<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.761059]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGDCONT:
1,"IPV4V6","firstnet-broadband","0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,0<CR><LF>+CGDCONT:
16,"IP","firstnetbroadband","0.0.0.0",0,0,0,0<CR><LF>+CGDCONT:
2,"IPV4V6","ims","0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,0<CR><LF>+CGDCONT:
3,"IPV4V6","SOS","0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0",0,0,0,1<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.764328]
[modem0] set profile state (3/8): select profile (best)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.764880]
[modem0] found exact context at profile 1
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.765170]
[modem0] reusing profile '1'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.765432]
[modem0] set profile state (4/8): check activated profile
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.765859]
[modem0] checking if profile with id '1' is already activated...
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.766292]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.766910]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.767545]
[modem0/ttyUSB2/at] --> 'AT+CGACT?<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.849726]
[modem0/ttyUSB2/at] <-- '<CR><LF>+CGACT: 1,1<CR><LF>+CGACT: 16,0<CR><LF>+CGACT:
2,0<CR><LF>+CGACT: 3,0<CR><LF><CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.851120]
[modem0] profile '1' is activated
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.851356]
[modem0] set profile state (5/8): deactivate profile
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.851585]
[modem0] deactivating profile with id '1'...
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.851911]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.852345]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.853189]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.853540]
[modem0/ttyUSB2/at] --> 'AT+CGACT=0,1<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.969735]
[modem0/ttyUSB2/at] <-- '<CR><LF>ERROR<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.970307]
[modem0/ttyUSB2/at] operation failure: 100 (Unknown error)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.970555]
[modem0] couldn't deactivate profile with id '1': Unknown error
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.970671]
[modem0] set profile state (6/8): profile already stored
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.970779]
[modem0] set profile state (8/8): all done
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.970978]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.971088]
[modem0/bearer0] connection through a plain serial AT port: ttyUSB2
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.971292]
[modem0/ttyUSB2/at] device open count is 6 (open)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.971685]
[modem0/ttyUSB2/at] device open count is 5 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.971980]
[modem0/ttyUSB2/at] --> 'AT<CR>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.989507]
[modem0/ttyUSB2/at] <-- '<CR><LF>OK<CR><LF>'
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.990700]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:16 2022 daemon.debug [2670]: <debug> [1641999016.991241]
[modem0/ttyUSB2/at] --> 'ATD*99***1#<CR>'
Wed Jan 12 14:50:17 2022 daemon.debug [2670]: <debug> [1641999017.103929]
[modem0/ttyUSB2/at] <-- '<CR><LF>CONNECT 150000000<CR><LF>'
Wed Jan 12 14:50:17 2022 daemon.debug [2670]: <debug> [1641999017.105184]
[modem0/bearer0] setting flow control in ttyUSB2: rts-cts
Wed Jan 12 14:50:17 2022 daemon.debug [2670]: <debug> [1641999017.105508]
[modem0/ttyUSB2/at] enabling RTS/CTS flow control
Wed Jan 12 14:50:17 2022 daemon.debug [2670]: <debug> [1641999017.105655]
[modem0/ttyUSB2/at] port attributes not fully set
Wed Jan 12 14:50:17 2022 daemon.debug [2670]: <debug> [1641999017.105776]
[modem0/ttyUSB2/at] flow control settings updated to rts-cts
Wed Jan 12 14:50:17 2022 daemon.debug [2670]: <debug> [1641999017.106223]
[modem0/ttyUSB2/at] port now connected
Wed Jan 12 14:50:17 2022 daemon.debug [2670]: <debug> [1641999017.106987]
[modem0/bearer0] connected
Wed Jan 12 14:50:17 2022 daemon.debug [2670]: <debug> [1641999017.109636]
[modem0/bearer0] PPP is required for connection, will ignore disconnection reports
Wed Jan 12 14:50:17 2022 daemon.info [2670]: <info> [1641999017.110160]
[modem0] state changed (connecting -> connected)
Wed Jan 12 14:50:17 2022 daemon.info [2670]: <info> [1641999017.119730]
[modem0] simple connect state (8/8): all done
Wed Jan 12 14:50:17 2022 daemon.debug [2670]: <debug> [1641999017.121774]
[modem0/ttyUSB2/at] device open count is 3 (close)
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (4960): successfully
connected the modem
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (4960): signal refresh rate
is not set
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (4960): network operator
name: FirstNet
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (4960): network operator
MCCMNC: 313100
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (4960): registration type: home
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (4960): access technology: lte
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (4960): signal quality: 100%
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (5161): stopping network
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (5161): IPv4 connection
teardown required in interface wwan: ppp
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (5161): IPv6 connection
teardown required in interface wwan: ppp
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (5161): running
disconnection (ppp method)
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (5161): pppd result code not
given
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (5161): running
disconnection (common)
Wed Jan 12 14:50:17 2022 daemon.notice netifd: wwan (5161): Command failed:
Permission denied
Wed Jan 12 14:50:18 2022 daemon.debug [2670]: <debug> [1641999018.093772]
[modem0] user request to disconnect modem (all bearers)
Wed Jan 12 14:50:18 2022 daemon.debug [2670]: <debug> [1641999018.094330]
[modem0/bearer0] disconnecting...
Wed Jan 12 14:50:18 2022 daemon.info [2670]: <info> [1641999018.094588]
[modem0] state changed (connected -> disconnecting)
Wed Jan 12 14:50:18 2022 daemon.debug [2670]: <debug> [1641999018.096886]
[modem0/bearer0] reopening data port ttyUSB2...
Wed Jan 12 14:50:18 2022 daemon.debug [2670]: <debug> [1641999018.097173]
[modem0/ttyUSB2/at] reopening port (3)
Wed Jan 12 14:50:18 2022 daemon.debug [2670]: <debug> [1641999018.097328]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:18 2022 daemon.debug [2670]: <debug> [1641999018.097490]
[modem0/ttyUSB2/at] device open count is 1 (close)
Wed Jan 12 14:50:18 2022 daemon.debug [2670]: <debug> [1641999018.097664]
[modem0/ttyUSB2/at] device open count is 0 (close)
Wed Jan 12 14:50:18 2022 daemon.debug [2670]: <debug> [1641999018.097845]
[modem0/ttyUSB2/at] closing serial port...
Wed Jan 12 14:50:18 2022 daemon.debug [2670]: <debug> [1641999018.098038]
[modem0/ttyUSB2/at] port now disconnected
Wed Jan 12 14:50:18 2022 daemon.debug [2670]: <debug> [1641999018.099014]
[modem0/ttyUSB2/at] serial port closed
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.108635]
[modem0/ttyUSB2/at] opening serial port...
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.109415]
[modem0/ttyUSB2/at] setting up baudrate: 57600
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.109563]
[modem0/ttyUSB2/at] no flow control explicitly requested for device
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.109694]
[modem0/ttyUSB2/at] port attributes not fully set
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.109950]
[modem0/ttyUSB2/at] device open count is 1 (open)
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.110072]
[modem0/ttyUSB2/at] device open count is 2 (open)
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.110180]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.110388]
[modem0/bearer0] flashing data port ttyUSB2...
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.110739]
[modem0/ttyUSB2/at] device open count is 2 (close)
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.110859]
[modem0/ttyUSB2/at] running init sequence...
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.111167]
[modem0/bearer0] sending PDP context deactivation in primary/data port...
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.111335]
[modem0/ttyUSB2/at] device open count is 3 (open)
Wed Jan 12 14:50:19 2022 daemon.debug [2670]: <debug> [1641999019.111631]
[modem0/ttyUSB2/at] --> 'ATE0<CR>'
Wed Jan 12 14:50:21 2022 daemon.debug [2670]: <debug> [1641999021.398795]
[modem0/ttyUSB2/at] device open count is 4 (open)
Wed Jan 12 14:50:22 2022 authpriv.info dropbear[5214]: Child connection from
192.168.113.254:35818
Wed Jan 12 14:50:22 2022 daemon.debug [2670]: <debug> [1641999022.399108]
[modem0/ttyUSB2/at] --> 'ATV1<CR>'
Wed Jan 12 14:50:22 2022 daemon.notice netifd: Interface 'wwan' is now down
Wed Jan 12 14:50:22 2022 daemon.notice netifd: Interface 'wwan' is setting up now
Wed Jan 12 14:50:22 2022 authpriv.notice dropbear[5214]: Auth succeeded with
blank password for 'root' from 192.168.113.254:35818
Wed Jan 12 14:50:22 2022 daemon.debug [2670]: <debug> [1641999022.664913]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:22 2022 daemon.notice netifd: wwan (5223): modem available at
/org/freedesktop/ModemManager1/Modem/0
Wed Jan 12 14:50:22 2022 daemon.debug [2670]: <debug> [1641999022.960945]
[modem0] user request to disconnect modem (all bearers)
Wed Jan 12 14:50:23 2022 daemon.notice netifd: wwan (5223): starting connection
with apn 'firstnet-broadband'...
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.251778]
[modem0] user request to connect modem
Wed Jan 12 14:50:23 2022 daemon.info [2670]: <info> [1641999023.252417]
[modem0] simple connect started...
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.252557]
[modem0] profile ID: unspecified
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.252712]
[modem0] PIN: unspecified
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.252866]
[modem0] operator ID: unspecified
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.253020]
[modem0] allowed roaming: yes
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.253177]
[modem0] APN: firstnet-broadband
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.253334]
[modem0] APN type: unspecified
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.253498]
[modem0] IP family: ipv4v6
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.253657]
[modem0] allowed authentication: unspecified
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.253819]
[modem0] user: unspecified
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.253977]
[modem0] password: unspecified
Wed Jan 12 14:50:23 2022 daemon.debug [2670]: <debug> [1641999023.254131]
[modem0] multiplex: unspecified
Wed Jan 12 14:50:23 2022 daemon.info [2670]: <info> [1641999023.254282]
[modem0] simple connect state (4/8): wait to get fully enabled
Wed Jan 12 14:50:25 2022 daemon.warn [2670]: <warn> [1641999025.398906]
[modem0] port ttyUSB2 timed out 2 consecutive times
Wed Jan 12 14:50:25 2022 daemon.debug [2670]: <debug> [1641999025.399308]
[modem0/ttyUSB2/at] --> 'AT+CMEE=1<CR>'
Wed Jan 12 14:50:28 2022 daemon.warn [2670]: <warn> [1641999028.398897]
[modem0] port ttyUSB2 timed out 3 consecutive times
Wed Jan 12 14:50:28 2022 daemon.debug [2670]: <debug> [1641999028.399241]
[modem0/ttyUSB2/at] --> 'ATX4<CR>'
Wed Jan 12 14:50:31 2022 daemon.warn [2670]: <warn> [1641999031.398894]
[modem0] port ttyUSB2 timed out 4 consecutive times
Wed Jan 12 14:50:31 2022 daemon.debug [2670]: <debug> [1641999031.399295]
[modem0/ttyUSB2/at] --> 'AT&C1<CR>'
Wed Jan 12 14:50:33 2022 daemon.notice netifd: wwan (5223): error: couldn't
connect the modem: 'GDBus.Error:org.freedesktop.ModemManager1.Error.Core.Retry:
Too much time waiting to get to a final state'
Wed Jan 12 14:50:33 2022 daemon.notice netifd: wwan (5362): stopping network
Wed Jan 12 14:50:33 2022 daemon.notice netifd: wwan (5362): IPv4 connection
teardown required in interface wwan: ppp
Wed Jan 12 14:50:33 2022 daemon.notice netifd: wwan (5362): IPv6 connection
teardown required in interface wwan: ppp
Wed Jan 12 14:50:33 2022 daemon.notice netifd: wwan (5362): running
disconnection (ppp method)
Wed Jan 12 14:50:33 2022 daemon.notice netifd: wwan (5362): pppd result code not
given
Wed Jan 12 14:50:33 2022 daemon.notice netifd: wwan (5362): running
disconnection (common)
Wed Jan 12 14:50:33 2022 daemon.notice netifd: wwan (5362): Command failed:
Permission denied
Wed Jan 12 14:50:33 2022 daemon.debug [2670]: <debug> [1641999033.924642]
[modem0] user request to disconnect modem (all bearers)
Wed Jan 12 14:50:33 2022 daemon.notice netifd: wwan (5362): error: couldn't
disconnect all bearers in the modem:
'GDBus.Error:org.freedesktop.ModemManager1.Error.Core.InProgress: Bearer already
being disconnected'
Wed Jan 12 14:50:34 2022 daemon.warn [2670]: <warn> [1641999034.398739]
[modem0] port ttyUSB2 timed out 5 consecutive times
Wed Jan 12 14:50:34 2022 daemon.debug [2670]: <debug> [1641999034.399073]
[modem0/ttyUSB2/at] --> 'AT+CGACT=0,1<CR>'
Wed Jan 12 14:50:38 2022 daemon.notice netifd: Interface 'wwan' is now down
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.399693]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:44 2022 daemon.info [2670]: <info> [1641999044.399981]
[modem0] state changed (disconnecting -> unknown)
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.403042]
[modem0] signal quality updated (0)
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.403726]
[modem0] access technology changed (lte -> unknown)
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.403990]
[modem0] periodic signal checks disabled
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.404519]
[modem0/bearer0] PDP context deactivation failed (not fatal): Serial command
timed out
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.404856]
[modem0/bearer0] disconnected
Wed Jan 12 14:50:44 2022 daemon.info [2670]: <info> [1641999044.405236]
[modem0] state changed (unknown -> registered)
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.406127]
[modem0] network timezone polling started
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.409009]
[modem0] periodic signal checks enabled
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.409309]
[modem0] periodic signal check refresh requested
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.409548]
[modem0] loading signal quality...
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.409922]
[modem0/ttyUSB2/at] device open count is 5 (open)
Wed Jan 12 14:50:44 2022 daemon.info [2670]: <info> [1641999044.412744]
[modem0/bearer0] connection #1 finished: duration 27s, tx: 0 bytes, rx: 0 bytes
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.413935]
[modem0/ttyUSB2/at] device open count is 4 (close)
Wed Jan 12 14:50:44 2022 daemon.warn [2670]: <warn> [1641999044.414398]
[modem0] port ttyUSB2 timed out 6 consecutive times
Wed Jan 12 14:50:44 2022 daemon.debug [2670]: <debug> [1641999044.416680]
[modem0/ttyUSB2/at] --> 'AT+CCLK?<CR>'
More information about the ModemManager-devel
mailing list