Huawei ME909s-120 modem goes offline and disappears
Bruno Vetter
bruno.vetter at outlook.com
Wed Dec 11 10:32:43 UTC 2019
>Hey,
>>
>> I am testing a device Management Framework named balenaOS on a couple of Edge devices. Networking is managed by ModemManager/NetworkManager. After a couple of hours my device (Raspberry CM3 based) goes offline, having no Internet Connection via LTE any more. When I connect to the device via LAN, I can see that the modem has disappeared:
>>
>>
>>
>> root at 9d52738:~# mmcli -L
>>
>> No modems were found
>>
>
> This could indicate a timing problem after re-probing the modem ports
> if the modem rebooted itself. If all TTY ports are exposed but MM
> doesn't handle the modem, that's a good explanation. We would need MM
> debug logs to check this further, could you setup the daemon to run
> --debug (and e.g. --log-file=[PATH] to avoid using syslog, if your
> system log is being rotated)
>
>
> --
>Aleksander
Thanks Alexander,
first I want to thank you for the reply. Second I apologize for not being confident in using mailing lists.
Third I have been able to reproduce the problem with debug logging on. I hope attaching the logs as files is ok.
If not, here is the last bit of the ModemManger log inline:
<info> [1575979048.136426] ModemManager (version 1.10.6) starting in system bus...
<debug> [1575979048.138282] create MMSleepMonitor singleton (0x1354520)
<debug> [1575979048.142405] Bus acquired, creating manager...
<debug> [1575979048.143407] [filter] created
<debug> [1575979048.143426] [filter] explicit whitelist: yes
<debug> [1575979048.143436] [filter] explicit blacklist: yes
<debug> [1575979048.143445] [filter] plugin whitelist: no
<debug> [1575979048.143454] [filter] virtual devices forbidden: yes
<debug> [1575979048.143462] [filter] net devices allowed: yes
<debug> [1575979048.143471] [filter] cdc-wdm devices allowed: yes
<debug> [1575979048.143479] [filter] tty devices:
<debug> [1575979048.143487] [filter] blacklist applied: yes
<debug> [1575979048.143497] [filter] manual scan only applied: yes
<debug> [1575979048.143506] [filter] platform driver check: yes
<debug> [1575979048.143514] [filter] driver check: no
<debug> [1575979048.143523] [filter] cdc-acm interface check: no
<debug> [1575979048.143531] [filter] with net check: no
<debug> [1575979048.143540] [filter] default: allowed
<debug> [1575979048.143658] [plugin manager] looking for plugins in '/usr/lib/ModemManager'
<debug> [1575979048.144699] [plugin manager] loaded plugin 'Sierra'
<debug> [1575979048.145466] [plugin manager] loaded plugin 'Cinterion'
<debug> [1575979048.146033] [plugin manager] loaded plugin 'Option'
<debug> [1575979048.146531] [plugin manager] loaded plugin 'Linktop'
<debug> [1575979048.147434] [plugin manager] loaded plugin 'Nokia (Icera)'
<debug> [1575979048.147886] [plugin manager] loaded plugin 'SimTech'
<debug> [1575979048.148537] [plugin manager] loaded plugin 'Option High-Speed'
<debug> [1575979048.148942] [plugin manager] loaded plugin 'X22X'
<debug> [1575979048.149583] [plugin manager] loaded plugin 'Ericsson MBM'
<debug> [1575979048.149982] [plugin manager] loaded plugin 'Longcheer'
<debug> [1575979048.150372] [plugin manager] loaded plugin 'Via CBP7'
<debug> [1575979048.151083] [plugin manager] loaded plugin 'Novatel'
<debug> [1575979048.151486] [plugin manager] loaded plugin 'Pantech'
<debug> [1575979048.152192] [plugin manager] loaded plugin 'u-blox'
<debug> [1575979048.152651] [plugin manager] loaded plugin 'Novatel LTE'
<debug> [1575979048.153483] [plugin manager] loaded plugin 'Huawei'
<debug> [1575979048.153837] [plugin manager] loaded plugin 'Generic'
<debug> [1575979048.154455] [plugin manager] loaded plugin 'Fibocom'
<debug> [1575979048.154997] [plugin manager] loaded plugin 'Thuraya'
<debug> [1575979048.155786] [plugin manager] loaded plugin 'Sierra (legacy)'
<debug> [1575979048.156170] [plugin manager] loaded plugin 'Quectel'
<debug> [1575979048.156595] [plugin manager] loaded plugin 'Wavecom'
<debug> [1575979048.157686] [plugin manager] loaded plugin 'Dell'
<debug> [1575979048.158507] [plugin manager] loaded plugin 'ZTE'
<debug> [1575979048.159222] [plugin manager] loaded plugin 'Samsung'
<debug> [1575979048.159633] [plugin manager] loaded plugin 'MTK'
<debug> [1575979048.160271] [plugin manager] loaded plugin 'Altair LTE'
<debug> [1575979048.160684] [plugin manager] loaded plugin 'Nokia'
<debug> [1575979048.161018] [plugin manager] loaded plugin 'Haier'
<debug> [1575979048.161418] [plugin manager] loaded plugin 'AnyDATA'
<debug> [1575979048.161765] [plugin manager] loaded plugin 'Motorola'
<debug> [1575979048.162207] [plugin manager] loaded plugin 'Iridium'
<debug> [1575979048.162884] [plugin manager] loaded plugin 'Telit'
<debug> [1575979048.162909] [plugin manager] successfully loaded 33 plugins
<debug> [1575979048.164556] Service name 'org.freedesktop.ModemManager1' was acquired
<debug> [1575979048.164588] Starting automatic device scan...
<debug> [1575979048.219290] Finished device scan...
<debug> [1575979048.219517] [sleep-monitor] taking systemd sleep inhibitor
<debug> [1575979048.220077] (tty/ttyAMA0): adding device at sysfs path: /sys/devices/platform/soc/3f201000.serial/tty/ttyAMA0
<debug> [1575979048.221397] [filter] (tty/ttyAMA0): port filtered: port's parent platform driver is not whitelisted
<debug> [1575979048.221576] (tty/ttyUSB0): adding device at sysfs path: /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2:1.0/ttyUSB0/tty/ttyUSB0
<debug> [1575979048.223227] [filter] (tty/ttyUSB0): port filtered: device probed only in manual scan
<debug> [1575979048.223422] (tty/ttyUSB1): adding device at sysfs path: /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:2.2/ttyUSB1/tty/ttyUSB1
<debug> [1575979048.224923] [filter] (tty/ttyUSB1) port allowed
<debug> [1575979048.224938] (tty/ttyUSB1): first port in device /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4
<debug> [1575979048.225210] [plugin manager] task 0: new support task for device: /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4
<debug> [1575979048.225452] [plugin manager] task 0: port grabbed: ttyUSB1
<debug> [1575979048.225468] [plugin manager] task 0,ttyUSB1: new support task for port
<debug> [1575979048.225479] [plugin manager) task 0,ttyUSB1: deferred until min wait time elapsed
<debug> [1575979048.225556] (tty/ttyUSB2): adding device at sysfs path: /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:2.3/ttyUSB2/tty/ttyUSB2
<debug> [1575979048.227105] [filter] (tty/ttyUSB2) port allowed
<debug> [1575979048.227128] (tty/ttyUSB2): additional port in device /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4
<debug> [1575979048.227256] [plugin manager] task 0: port grabbed: ttyUSB2
<debug> [1575979048.227274] [plugin manager] task 0,ttyUSB2: new support task for port
<debug> [1575979048.227285] [plugin manager) task 0,ttyUSB2: deferred until min wait time elapsed
<debug> [1575979048.227359] (tty/ttyUSB3): adding device at sysfs path: /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:2.4/ttyUSB3/tty/ttyUSB3
<debug> [1575979048.228856] [filter] (tty/ttyUSB3) port allowed
<debug> [1575979048.228879] (tty/ttyUSB3): additional port in device /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4
<debug> [1575979048.229002] [plugin manager] task 0: port grabbed: ttyUSB3
<debug> [1575979048.229018] [plugin manager] task 0,ttyUSB3: new support task for port
<debug> [1575979048.229029] [plugin manager) task 0,ttyUSB3: deferred until min wait time elapsed
<debug> [1575979048.229102] (tty/ttyUSB4): adding device at sysfs path: /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:2.5/ttyUSB4/tty/ttyUSB4
<debug> [1575979048.230590] [filter] (tty/ttyUSB4) port allowed
<debug> [1575979048.230621] (tty/ttyUSB4): additional port in device /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4
<debug> [1575979048.230757] [plugin manager] task 0: port grabbed: ttyUSB4
<debug> [1575979048.230775] [plugin manager] task 0,ttyUSB4: new support task for port
<debug> [1575979048.230786] [plugin manager) task 0,ttyUSB4: deferred until min wait time elapsed
<debug> [1575979048.230862] (tty/ttyUSB5): adding device at sysfs path: /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:2.6/ttyUSB5/tty/ttyUSB5
<debug> [1575979048.232354] [filter] (tty/ttyUSB5) port allowed
<debug> [1575979048.232384] (tty/ttyUSB5): additional port in device /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4
<debug> [1575979048.232513] [plugin manager] task 0: port grabbed: ttyUSB5
<debug> [1575979048.232532] [plugin manager] task 0,ttyUSB5: new support task for port
<debug> [1575979048.232543] [plugin manager) task 0,ttyUSB5: deferred until min wait time elapsed
<debug> [1575979048.232605] (tty/console): adding device at sysfs path: /sys/devices/virtual/tty/console
<debug> [1575979048.232957] [filter] (tty/console) port filtered: virtual device
<debug> [1575979048.233034] (tty/ptmx): adding device at sysfs path: /sys/devices/virtual/tty/ptmx
<debug> [1575979048.233377] [filter] (tty/ptmx) port filtered: virtual device
<debug> [1575979048.233452] (tty/tty): adding device at sysfs path: /sys/devices/virtual/tty/tty
<debug> [1575979048.233799] [filter] (tty/tty) port filtered: virtual device
...
...
...
<debug> [1576037495.306307] connection status loaded: connected
<debug> [1576037495.306363] (ttyUSB3) device open count is 1 (close)
<debug> [1576037500.292637] (ttyUSB3) device open count is 2 (open)
<debug> [1576037500.292813] (ttyUSB3): --> 'AT+CGACT?<CR>'
<debug> [1576037500.305091] (ttyUSB3): <-- '<CR><LF>+CGACT: 1,1<CR><LF>+CGACT: 11,0<CR><LF>+CGACT: 21,0<CR><LF>+CGACT: 22,0<CR><LF>+CGACT: 23,0<CR><LF>+CGACT: 24,0<CR><LF>+CGACT: 25,0<CR><LF>+CGACT: 26,0<CR><LF>+CGACT: 27,0<CR><LF>+CGACT: 28,0<CR><LF>+CGACT: 29,0<CR><LF>+CGACT: 30,0<CR><LF>+CGACT: 31,0<CR><LF><CR><LF>OK<CR><LF>'
<debug> [1576037500.306250] connection status loaded: connected
<debug> [1576037500.306307] (ttyUSB3) device open count is 1 (close)
<debug> [1576037505.292212] (ttyUSB3) device open count is 2 (open)
<debug> [1576037505.292343] loading signal quality...
<debug> [1576037505.292394] loading signal quality...
<debug> [1576037505.292445] (ttyUSB3) device open count is 3 (open)
<debug> [1576037505.293325] (ttyUSB3): --> 'AT+CGACT?<CR>'
<debug> [1576037505.305768] (ttyUSB3): <-- '<CR><LF>+CGACT: 1,1<CR><LF>+CGACT: 11,0<CR><LF>+CGACT: 21,0<CR><LF>+CGACT: 22,0<CR><LF>+CGACT: 23,0<CR><LF>+CGACT: 24,0<CR><LF>+CGACT: 25,0<CR><LF>+CGACT: 26,0<CR><LF>+CGACT: 27,0<CR><LF>+CGACT: 28,0<CR><LF>+CGACT: 29,0<CR><LF>+CGACT: 30,0<CR><LF>+CGACT: 31,0<CR><LF><CR><LF>OK<CR><LF>'
<debug> [1576037505.306998] connection status loaded: connected
<debug> [1576037505.307063] (ttyUSB3) device open count is 2 (close)
<debug> [1576037505.307157] (ttyUSB3): --> 'AT+CSQ<CR>'
<debug> [1576037505.315526] (ttyUSB3): <-- '<CR><LF>+CSQ: 31,99<CR><LF><CR><LF>OK<CR><LF>'
<debug> [1576037505.316062] Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (100)
<debug> [1576037505.316106] loading access technology (huawei)...
<debug> [1576037505.316189] (ttyUSB3) device open count is 3 (open)
<debug> [1576037505.316288] (ttyUSB3) device open count is 2 (close)
<debug> [1576037505.316365] (ttyUSB3): --> 'AT^SYSINFOEX<CR>'
<debug> [1576037505.332095] (ttyUSB3): <-- '<CR><LF>^SYSINFOEX: 2,3,0,1,,3,"WCDMA",41,"WCDMA"<CR><LF><CR><LF>OK<CR><LF>'
<debug> [1576037505.332662] Access Technology: 'umts'
<debug> [1576037505.332714] Periodic signal quality checks scheduled in 30s
<debug> [1576037505.332770] (ttyUSB3) device open count is 1 (close)
<debug> [1576037510.292021] (ttyUSB3) device open count is 2 (open)
<debug> [1576037510.292202] (ttyUSB3): --> 'AT+CGACT?<CR>'
<debug> [1576037510.304418] (ttyUSB3): <-- '<CR><LF>+CGACT: 1,1<CR><LF>+CGACT: 11,0<CR><LF>+CGACT: 21,0<CR><LF>+CGACT: 22,0<CR><LF>+CGACT: 23,0<CR><LF>+CGACT: 24,0<CR><LF>+CGACT: 25,0<CR><LF>+CGACT: 26,0<CR><LF>+CGACT: 27,0<CR><LF>+CGACT: 28,0<CR><LF>+CGACT: 29,0<CR><LF>+CGACT: 30,0<CR><LF>+CGACT: 31,0<CR><LF><CR><LF>OK<CR><LF>'
<debug> [1576037510.305566] connection status loaded: connected
<debug> [1576037510.305625] (ttyUSB3) device open count is 1 (close)
<debug> [1576037515.292900] (ttyUSB3) device open count is 2 (open)
<debug> [1576037515.293121] (ttyUSB3): --> 'AT+CGACT?<CR>'
<debug> [1576037515.304765] (ttyUSB3): <-- '<CR><LF>+CGACT: 1,1<CR><LF>+CGACT: 11,0<CR><LF>+CGACT: 21,0<CR><LF>+CGACT: 22,0<CR><LF>+CGACT: 23,0<CR><LF>+CGACT: 24,0<CR><LF>+CGACT: 25,0<CR><LF>+CGACT: 26,0<CR><LF>+CGACT: 27,0<CR><LF>+CGACT: 28,0<CR><LF>+CGACT: 29,0<CR><LF>+CGACT: 30,0<CR><LF>+CGACT: 31,0<CR><LF><CR><LF>OK<CR><LF>'
<debug> [1576037515.305871] connection status loaded: connected
<debug> [1576037515.305925] (ttyUSB3) device open count is 1 (close)
<debug> [1576037518.116330] (ttyUSB3): <-- '<CR><LF>^MODE: 5,4<CR><LF>'
<debug> [1576037518.116482] Access Technology: 'umts'
<debug> [1576037518.116936] (ttyUSB3): <-- '<CR><LF>+CREG: 1,"B3B1","00F45101",7<CR><LF>'
<debug> [1576037518.117229] building consolidated registration state: cs 'home', ps 'home', eps 'unknown' --> 'home'
<debug> [1576037518.117303] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '262', MNC: '2', Location area code: '0', Tracking area code: 'B3B1', Cell ID: 'F45101')
<debug> [1576037518.117584] (ttyUSB3): <-- '<CR><LF>+CGREG: 1,"B3B1","00F45101",7<CR><LF>'
<debug> [1576037518.117851] building consolidated registration state: cs 'home', ps 'home', eps 'unknown' --> 'home'
<debug> [1576037518.117901] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '262', MNC: '2', Location area code: 'B3B1', Tracking area code: '0', Cell ID: 'F45101')
<debug> [1576037518.632061] (ttyUSB3): <-- '<CR><LF>+CREG: 0<CR><LF>'
<debug> [1576037518.632488] building consolidated registration state: cs 'idle', ps 'home', eps 'unknown' --> 'home'
<debug> [1576037518.632709] (ttyUSB3): <-- '<CR><LF>^SRVST: 0<CR><LF><CR><LF>+CGREG: 0<CR><LF>'
<debug> [1576037518.632986] building consolidated registration state: cs 'idle', ps 'idle', eps 'unknown' --> 'idle'
<info> [1576037518.633023] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (home -> idle)
<debug> [1576037518.633246] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: 'B3B1', Tracking area code: '0', Cell ID: 'F45101')
<debug> [1576037518.633395] Connected bearer not registered in 3GPP network
<debug> [1576037518.633474] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037518.692459] Disconnecting bearer '/org/freedesktop/ModemManager1/Bearer/0'
<info> [1576037518.692526] Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connected -> disconnecting)
<debug> [1576037518.693010] Sending PDP context deactivation in secondary port...
<debug> [1576037518.693052] (ttyUSB3) device open count is 2 (open)
<debug> [1576037518.693148] (ttyUSB3): --> 'AT+CGACT=0,1<CR>'
<debug> [1576037518.707274] (ttyUSB3): <-- '<CR><LF>^RSSI: 16<CR><LF><CR><LF>^HCSQ: "LTE",41,25,51,4<CR><LF>'
<debug> [1576037518.707538] 3GPP signal quality: 51
<debug> [1576037518.707696] Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (51)
<debug> [1576037518.708110] (ttyUSB3): <-- '<CR><LF>OK<CR><LF>'
<debug> [1576037518.708318] Reopening data port (ttyUSB1)...
<debug> [1576037518.708351] (ttyUSB1) reopening port (2)
<debug> [1576037518.708362] (ttyUSB1) device open count is 1 (close)
<debug> [1576037518.708373] (ttyUSB1) device open count is 0 (close)
<debug> [1576037518.708388] (ttyUSB1) closing serial port...
<debug> [1576037518.708403] (ttyUSB1): port now disconnected
<debug> [1576037518.708441] (ttyUSB1) serial port closed
<debug> [1576037518.708462] (ttyUSB3) device open count is 1 (close)
<info> [1576037518.776560] Simple connect started...
<debug> [1576037518.776587] PIN: unspecified
<debug> [1576037518.776597] Operator ID: unspecified
<debug> [1576037518.776607] Allowed roaming: yes
<debug> [1576037518.776617] APN: web.vodafone.de
<debug> [1576037518.776628] IP family: ipv4
<debug> [1576037518.776651] Allowed authentication: none, pap, chap, mschap, mschapv2, eap
<debug> [1576037518.776683] User: unspecified
<debug> [1576037518.776693] Password: unspecified
<info> [1576037518.776702] Simple connect state (4/8): Wait to get fully enabled
<debug> [1576037519.709825] (ttyUSB1) opening serial port...
<debug> [1576037519.710402] (ttyUSB1): setting up baudrate: 57600
<debug> [1576037519.710444] (ttyUSB1): no flow control explicitly requested for device
<debug> [1576037519.710484] (ttyUSB1): port attributes not fully set
<debug> [1576037519.710585] (ttyUSB1) device open count is 1 (open)
<debug> [1576037519.710611] (ttyUSB1) device open count is 2 (open)
<debug> [1576037519.710684] Flashing data port (ttyUSB1)...
<debug> [1576037519.710740] (ttyUSB1): port attributes not fully set
<debug> [1576037520.287636] (ttyUSB1) device open count is 3 (open)
<debug> [1576037520.287804] (ttyUSB1): --> 'AT+CGACT?<CR>'
<debug> [1576037520.711067] (ttyUSB1) device open count is 2 (close)
<debug> [1576037520.711127] (ttyUSB1): running init sequence...
<debug> [1576037520.711231] PDP disconnection already sent
<debug> [1576037520.711263] Disconnected bearer '/org/freedesktop/ModemManager1/Bearer/0'
<info> [1576037520.711379] Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disconnecting -> enabled)
<info> [1576037520.711564] Simple connect state (5/8): Register
<debug> [1576037520.711648] Launching automatic network registration...
<debug> [1576037520.711706] (ttyUSB1) device open count is 3 (open)
<debug> [1576037520.712647] Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (0)
<debug> [1576037520.712758] Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (umts -> unknown)
<debug> [1576037520.712791] Periodic signal checks disabled
<warn> [1576037523.655707] checking if connected failed: Couldn't check current list of active PDP contexts: Sending command failed: 'Resource temporarily unavailable'
<debug> [1576037523.655803] (ttyUSB1) device open count is 2 (close)
<debug> [1576037523.655893] (ttyUSB1): --> 'ATE0<CR>'
<debug> [1576037525.880202] (ttyUSB3): <-- '<CR><LF>+CGREG: 2<CR><LF>'
<debug> [1576037525.880558] building consolidated registration state: cs 'idle', ps 'searching', eps 'unknown' --> 'searching'
<info> [1576037525.880611] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (idle -> searching)
<debug> [1576037525.880794] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<info> [1576037525.880981] Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabled -> searching)
<debug> [1576037525.882605] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037526.909448] (ttyUSB3): <-- '<CR><LF>^SRVST: 1<CR><LF>'
<warn> [1576037527.005141] (tty/ttyUSB1) at port timed out 2 consecutive times
<debug> [1576037527.005306] (ttyUSB1): --> 'ATV1<CR>'
<warn> [1576037530.346891] (tty/ttyUSB1) at port timed out 3 consecutive times
<debug> [1576037530.347068] (ttyUSB1): --> 'AT+CMEE=1<CR>'
<warn> [1576037533.677720] (tty/ttyUSB1) at port timed out 4 consecutive times
<debug> [1576037533.677845] (ttyUSB1): --> 'ATX4<CR>'
<debug> [1576037534.291548] (ttyUSB3): <-- '<CR><LF>^SRVST: 0<CR><LF>'
<debug> [1576037534.292084] (ttyUSB3): <-- '<CR><LF>+CGREG: 0<CR><LF>'
<debug> [1576037534.292259] building consolidated registration state: cs 'idle', ps 'idle', eps 'unknown' --> 'idle'
<info> [1576037534.292288] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (searching -> idle)
<debug> [1576037534.292409] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037534.292530] Bearer not allowed to connect, not registered in 3GPP network
<debug> [1576037534.292570] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037534.292664] (ttyUSB3): <-- '<CR><LF>+CGREG: 2<CR><LF>'
<debug> [1576037534.292797] building consolidated registration state: cs 'idle', ps 'searching', eps 'unknown' --> 'searching'
<info> [1576037534.292821] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (idle -> searching)
<debug> [1576037534.292891] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037534.292978] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<warn> [1576037537.037186] (tty/ttyUSB1) at port timed out 5 consecutive times
<debug> [1576037537.037353] (ttyUSB1): --> 'AT&C1<CR>'
<debug> [1576037537.241255] (ttyUSB3): <-- '<CR><LF>^RSSI: 17<CR><LF>'
<debug> [1576037537.241450] 3GPP signal quality: 54
<debug> [1576037537.241691] Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (54)
<debug> [1576037537.241950] (ttyUSB3): <-- '<CR><LF>^HCSQ: "LTE",42,23,0,252<CR><LF>'
<debug> [1576037537.284239] (ttyUSB3): <-- '<CR><LF>^RSSI: 17<CR><LF>'
<debug> [1576037537.284424] 3GPP signal quality: 54
<debug> [1576037537.284615] Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (54)
<debug> [1576037537.284900] (ttyUSB3): <-- '<CR><LF>^HCSQ: "LTE",42,23,41,252<CR><LF>'
<debug> [1576037540.380133] (ttyUSB3): <-- '<CR><LF>^SRVST: 1<CR><LF>'
<warn> [1576037540.383831] (tty/ttyUSB1) at port timed out 6 consecutive times
<debug> [1576037540.383972] (ttyUSB1): --> 'AT+COPS=0<CR>'
<warn> [1576037543.717511] (tty/ttyUSB1) at port timed out 7 consecutive times
<debug> [1576037543.717659] building consolidated registration state: cs 'idle', ps 'searching', eps 'unknown' --> 'searching'
<debug> [1576037543.717704] building consolidated registration state: cs 'idle', ps 'idle', eps 'unknown' --> 'idle'
<info> [1576037543.717737] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (searching -> idle)
<debug> [1576037543.717906] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037543.718071] Bearer not allowed to connect, not registered in 3GPP network
<debug> [1576037543.718160] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037543.718632] (ttyUSB1) device open count is 1 (close)
<info> [1576037543.760549] Simple connect started...
<debug> [1576037543.760578] PIN: unspecified
<debug> [1576037543.760589] Operator ID: unspecified
<debug> [1576037543.760598] Allowed roaming: yes
<debug> [1576037543.760608] APN: web.vodafone.de
<debug> [1576037543.760619] IP family: ipv4
<debug> [1576037543.760645] Allowed authentication: none, pap, chap, mschap, mschapv2, eap
<debug> [1576037543.760657] User: unspecified
<debug> [1576037543.760667] Password: unspecified
<info> [1576037543.760676] Simple connect state (4/8): Wait to get fully enabled
<info> [1576037543.760724] Simple connect state (5/8): Register
<debug> [1576037543.760771] Launching automatic network registration...
<debug> [1576037543.760803] (ttyUSB1) device open count is 2 (open)
<debug> [1576037543.760868] (ttyUSB1): --> 'AT+COPS=0<CR>'
<warn> [1576037547.093772] (tty/ttyUSB1) at port timed out 8 consecutive times
<debug> [1576037547.093924] building consolidated registration state: cs 'idle', ps 'idle', eps 'unknown' --> 'idle'
<debug> [1576037547.093970] building consolidated registration state: cs 'idle', ps 'idle', eps 'unknown' --> 'idle'
<debug> [1576037547.094496] (ttyUSB1) device open count is 1 (close)
<info> [1576037547.127470] Simple connect started...
<debug> [1576037547.127505] PIN: unspecified
<debug> [1576037547.127515] Operator ID: unspecified
<debug> [1576037547.127525] Allowed roaming: yes
<debug> [1576037547.127563] APN: web.vodafone.de
<debug> [1576037547.127574] IP family: ipv4
<debug> [1576037547.127599] Allowed authentication: none, pap, chap, mschap, mschapv2, eap
<debug> [1576037547.127612] User: unspecified
<debug> [1576037547.127621] Password: unspecified
<info> [1576037547.127631] Simple connect state (4/8): Wait to get fully enabled
<info> [1576037547.127680] Simple connect state (5/8): Register
<debug> [1576037547.127726] Launching automatic network registration...
<debug> [1576037547.127760] (ttyUSB1) device open count is 2 (open)
<debug> [1576037547.127829] (ttyUSB1): --> 'AT+COPS=0<CR>'
<debug> [1576037548.012429] (ttyUSB3): <-- '<CR><LF>^RSSI: 15<CR><LF>'
<debug> [1576037548.012577] 3GPP signal quality: 48
<debug> [1576037548.012811] Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (48)
<debug> [1576037548.013084] (ttyUSB3): <-- '<CR><LF>^HCSQ: "LTE",38,28,41,6<CR><LF>'
<debug> [1576037548.013926] (ttyUSB3): <-- '<CR><LF>^SRVST: 0<CR><LF>'
<debug> [1576037548.014556] (ttyUSB3): <-- '<CR><LF>+CGREG: 0<CR><LF>'
<debug> [1576037548.015548] building consolidated registration state: cs 'idle', ps 'idle', eps 'unknown' --> 'idle'
<debug> [1576037548.015760] (ttyUSB3): <-- '<CR><LF>+CGREG: 2<CR><LF>'
<debug> [1576037548.015994] building consolidated registration state: cs 'idle', ps 'searching', eps 'unknown' --> 'searching'
<info> [1576037548.016032] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (idle -> searching)
<debug> [1576037548.016187] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037548.016382] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037549.042472] (ttyUSB3): <-- '<CR><LF>^SRVST: 1<CR><LF>'
<warn> [1576037550.465411] (tty/ttyUSB1) at port timed out 9 consecutive times
<debug> [1576037550.465552] building consolidated registration state: cs 'idle', ps 'searching', eps 'unknown' --> 'searching'
<debug> [1576037550.465596] building consolidated registration state: cs 'idle', ps 'idle', eps 'unknown' --> 'idle'
<info> [1576037550.465629] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (searching -> idle)
<debug> [1576037550.465794] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037550.465961] Bearer not allowed to connect, not registered in 3GPP network
<debug> [1576037550.466047] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037550.466507] (ttyUSB1) device open count is 1 (close)
<info> [1576037550.497815] Simple connect started...
<debug> [1576037550.497845] PIN: unspecified
<debug> [1576037550.497855] Operator ID: unspecified
<debug> [1576037550.497865] Allowed roaming: yes
<debug> [1576037550.497875] APN: web.vodafone.de
<debug> [1576037550.497887] IP family: ipv4
<debug> [1576037550.497910] Allowed authentication: none, pap, chap, mschap, mschapv2, eap
<debug> [1576037550.497921] User: unspecified
<debug> [1576037550.497930] Password: unspecified
<info> [1576037550.497939] Simple connect state (4/8): Wait to get fully enabled
<info> [1576037550.497991] Simple connect state (5/8): Register
<debug> [1576037550.498039] Launching automatic network registration...
<debug> [1576037550.498072] (ttyUSB1) device open count is 2 (open)
<debug> [1576037550.498139] (ttyUSB1): --> 'AT+COPS=0<CR>'
<debug> [1576037553.597340] (ttyUSB3): <-- '<CR><LF>^RSSI: 9<CR><LF>'
<debug> [1576037553.597492] 3GPP signal quality: 29
<debug> [1576037553.597730] Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (29)
<debug> [1576037553.598148] (ttyUSB3): <-- '<CR><LF>^HCSQ: "LTE",27,17,41,12<CR><LF>'
<debug> [1576037553.599112] (ttyUSB3): <-- '<CR><LF>^SRVST: 0<CR><LF>'
<debug> [1576037553.599497] (ttyUSB3): <-- '<CR><LF>+CGREG: 0<CR><LF>'
<debug> [1576037553.599749] building consolidated registration state: cs 'idle', ps 'idle', eps 'unknown' --> 'idle'
<debug> [1576037553.600526] (ttyUSB3): <-- '<CR><LF>+CGREG: 2<CR><LF>'
<debug> [1576037553.600777] building consolidated registration state: cs 'idle', ps 'searching', eps 'unknown' --> 'searching'
<info> [1576037553.600818] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (idle -> searching)
<debug> [1576037553.601020] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037553.601255] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<error> [1576037553.833904] (tty/ttyUSB1) at port timed out 10 consecutive times, marking modem '/org/freedesktop/ModemManager1/Modem/0' as invalid
<debug> [1576037553.834088] building consolidated registration state: cs 'idle', ps 'searching', eps 'unknown' --> 'searching'
<debug> [1576037553.834136] building consolidated registration state: cs 'idle', ps 'idle', eps 'unknown' --> 'idle'
<info> [1576037553.834166] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (searching -> idle)
<debug> [1576037553.834335] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037553.834503] Bearer not allowed to connect, not registered in 3GPP network
<debug> [1576037553.834587] Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Tracking area code: '0', Cell ID: '0')
<debug> [1576037553.835064] (ttyUSB1) device open count is 1 (close)
<debug> [1576037553.836368] Removing from DBus bearer at '/org/freedesktop/ModemManager1/Bearer/0'
<debug> [1576037553.836454] [device /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4] unexported modem from path '/org/freedesktop/ModemManager1/Modem/0'
<debug> [1576037553.837184] Extended signal information reporting disabled
<debug> [1576037553.838127] (ttyUSB4) forced to close port
<debug> [1576037553.838238] (ttyUSB1) device open count is 0 (close)
<debug> [1576037553.838276] (ttyUSB1) closing serial port...
<debug> [1576037553.838872] (ttyUSB1) serial port closed
<debug> [1576037553.839016] (ttyUSB1) forced to close port
<debug> [1576037553.839098] (ttyUSB3) device open count is 0 (close)
<debug> [1576037553.839127] (ttyUSB3) closing serial port...
<debug> [1576037553.839670] (ttyUSB3) serial port closed
<debug> [1576037553.839940] (ttyUSB3) forced to close port
<debug> [1576037553.840024] Modem (Huawei) '/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4' completely disposed
Thanks
Bruno
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/modemmanager-devel/attachments/20191211/c355d7eb/attachment-0001.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: logs.zip
Type: application/zip
Size: 633434 bytes
Desc: logs.zip
URL: <https://lists.freedesktop.org/archives/modemmanager-devel/attachments/20191211/c355d7eb/attachment-0001.zip>
More information about the ModemManager-devel
mailing list