system resume: modem power cycle is needed to make it work again
Only when the device is woken up by incoming SMS or call, the modem continues to work normally. When woken up by power button, I need to power cycle the modem to bring it back.
Activity
added suspend label
I'm not yet conviced this is a kernel bug actually. The devices are all brought back after resume.
sudo systemctl restart ModemManagermakes the modem work again for me. @angus.ainslie could you test as well as you reported this issue too?
mentioned in merge request !600 (merged)
added important label
yeah it seems totally random. Sometimes a phone call/sms will make the modem work, sometimes not. Sometimes the power button will wake up the modem correctly but most of the time, it will not. When the modem is not properly woken up, sometimes I can see the bars and 4G symbols (but it does not really work) and sometimes not. Restarting ModemManager works sometimes, and sometimes not. I was unable to find any recurrent pattern in all these behaviors. The only consistant thing here is that a power cycle will make the modem work again
Edited by primalmotion-
right now this issue and #425 (closed) got a bit interleaved, that's my fault. For now I'll keep documenting in #425 (closed) even though it's actually helping this issue... not sure if we should merge them
-
here's MM logs for suspend/resume with
--debug --test-quick-suspend-resumewhen running !614 (closed) and one can see basically everything timing out after resuming:Jun 30 10:17:17 pureos ModemManager[541]: <info> [1656577037.856008] [sleep-monitor] system is about to suspend Jun 30 10:17:17 pureos ModemManager[541]: <debug> [1656577037.856113] [sleep-monitor] dropping systemd sleep inhibitor Jun 30 10:17:17 pureos ModemManager[541]: <debug> [1656577037.947489] [modem0] user request to disconnect modem (all bearers) Jun 30 10:17:17 pureos ModemManager[541]: <debug> [1656577037.955910] [modem0/bearer1] disconnecting... Jun 30 10:17:17 pureos ModemManager[541]: <info> [1656577037.956076] [modem0] state changed (connected -> disconnecting) Jun 30 10:17:17 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 61 <<<<<< data = 01:3C:00:00:01:02:00:06:00:01:00:30:00:1E:01:00:00:1C:01:00:00:1B:01:00:00:1A:01:00:00:19:01:00:00:18:01:00:00:17:01:00:00:15:01:00:00:14:01:00:00:13:01:00:00:12:01:00:00:10:01:00:00 Jun 30 10:17:17 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent generic request (translated)... <<<<<< QMUX: <<<<<< length = 60 <<<<<< flags = 0x00 <<<<<< service = "wds" <<<<<< client = 2 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 6 <<<<<< tlv_length = 48 <<<<<< message = "Set Event Report" (0x0001) <<<<<< TLV: <<<<<< type = "Extended Data Bearer Technology" (0x1e) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no <<<<<< TLV: <<<<<< type = "Limited Data System Status" (0x1c) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no <<<<<< TLV: <<<<<< type = "Uplink Flow Control" (0x1b) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no <<<<<< TLV: <<<<<< type = "Data Systems" (0x1a) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no <<<<<< TLV: <<<<<< type = "EVDO PM Change" (0x19) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no <<<<<< TLV: <<<<<< type = "Preferred Data System" (0x18) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no <<<<<< TLV: <<<<<< type = "Data Call Status" (0x17) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no <<<<<< TLV: <<<<<< type = "Current Data Bearer Technology" (0x15) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no <<<<<< TLV: <<<<<< type = "MIP Status" (0x14) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = 0 <<<<<< TLV: <<<<<< type = "Dormancy Status" (0x13) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no <<<<<< TLV: <<<<<< type = "Data Bearer Technology" (0x12) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no <<<<<< TLV: <<<<<< type = "Channel Rate" (0x10) <<<<<< length = 1 <<<<<< value = 00 <<<<<< translated = no Jun 30 10:17:17 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 20 <<<<<< data = 01:13:00:00:01:02:00:07:00:21:00:07:00:01:04:00:F0:CB:C4:85 Jun 30 10:17:17 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent generic request (translated)... <<<<<< QMUX: <<<<<< length = 19 <<<<<< flags = 0x00 <<<<<< service = "wds" <<<<<< client = 2 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 7 <<<<<< tlv_length = 7 <<<<<< message = "Stop Network" (0x0021) <<<<<< TLV: <<<<<< type = "Packet Data Handle" (0x01) <<<<<< length = 4 <<<<<< value = F0:CB:C4:85 <<<<<< translated = 2244266992 Jun 30 10:17:17 pureos ModemManager[541]: [/dev/cdc-wdm0] Received message... <<<<<< RAW: <<<<<< length = 20 <<<<<< data = 01:13:00:80:01:02:02:06:00:01:00:07:00:02:04:00:00:00:00:00 Jun 30 10:17:17 pureos ModemManager[541]: [/dev/cdc-wdm0] Received generic response (translated)... <<<<<< QMUX: <<<<<< length = 19 <<<<<< flags = 0x80 <<<<<< service = "wds" <<<<<< client = 2 <<<<<< QMI: <<<<<< flags = "response" <<<<<< transaction = 6 <<<<<< tlv_length = 7 <<<<<< message = "Set Event Report" (0x0001) <<<<<< TLV: <<<<<< type = "Result" (0x02) <<<<<< length = 4 <<<<<< value = 00:00:00:00 <<<<<< translated = SUCCESS Jun 30 10:17:18 pureos ModemManager[541]: [/dev/cdc-wdm0] Received message... <<<<<< RAW: <<<<<< length = 20 <<<<<< data = 01:13:00:80:01:02:02:07:00:21:00:07:00:02:04:00:00:00:00:00 Jun 30 10:17:18 pureos ModemManager[541]: [/dev/cdc-wdm0] Received generic response (translated)... <<<<<< QMUX: <<<<<< length = 19 <<<<<< flags = 0x80 <<<<<< service = "wds" <<<<<< client = 2 <<<<<< QMI: <<<<<< flags = "response" <<<<<< transaction = 7 <<<<<< tlv_length = 7 <<<<<< message = "Stop Network" (0x0021) <<<<<< TLV: <<<<<< type = "Result" (0x02) <<<<<< length = 4 <<<<<< value = 00:00:00:00 <<<<<< translated = SUCCESS Jun 30 10:17:18 pureos ModemManager[541]: [/dev/cdc-wdm0] Received message... <<<<<< RAW: <<<<<< length = 34 <<<<<< data = 01:21:00:80:01:02:04:0F:00:22:00:15:00:01:02:00:01:00:10:02:00:F0:03:11:04:00:06:00:24:00:12:01:00:04 Jun 30 10:17:18 pureos ModemManager[541]: [/dev/cdc-wdm0] Received generic indication (translated)... <<<<<< QMUX: <<<<<< length = 33 <<<<<< flags = 0x80 <<<<<< service = "wds" <<<<<< client = 2 <<<<<< QMI: <<<<<< flags = "indication" <<<<<< transaction = 15 <<<<<< tlv_length = 21 <<<<<< message = "Packet Service Status" (0x0022) <<<<<< TLV: <<<<<< type = "Connection Status" (0x01) <<<<<< length = 2 <<<<<< value = 01:00 <<<<<< translated = [ status = 'disconnected' reconfiguration_required = 'no' ] <<<<<< TLV: <<<<<< type = "Call End Reason" (0x10) <<<<<< length = 2 <<<<<< value = F0:03 <<<<<< translated = gsm-wcdma-regular-deactivation <<<<<< TLV: <<<<<< type = "Verbose Call End Reason" (0x11) <<<<<< length = 4 <<<<<< value = 06:00:24:00 <<<<<< translated = [ type = '3gpp' reason = '36' ] <<<<<< TLV: <<<<<< type = "IP Family" (0x12) <<<<<< length = 1 <<<<<< value = 04 <<<<<< translated = ipv4 Jun 30 10:17:18 pureos ModemManager[541]: [/dev/cdc-wdm0] Received message... <<<<<< RAW: <<<<<< length = 34 <<<<<< data = 01:21:00:80:01:01:04:02:00:22:00:15:00:01:02:00:01:00:10:02:00:F0:03:11:04:00:06:00:24:00:12:01:00:04 Jun 30 10:17:18 pureos ModemManager[541]: [/dev/cdc-wdm0] Received generic indication (translated)... <<<<<< QMUX: <<<<<< length = 33 <<<<<< flags = 0x80 <<<<<< service = "wds" <<<<<< client = 1 <<<<<< QMI: <<<<<< flags = "indication" <<<<<< transaction = 2 <<<<<< tlv_length = 21 <<<<<< message = "Packet Service Status" (0x0022) <<<<<< TLV: <<<<<< type = "Connection Status" (0x01) <<<<<< length = 2 <<<<<< value = 01:00 <<<<<< translated = [ status = 'disconnected' reconfiguration_required = 'no' ] <<<<<< TLV: <<<<<< type = "Call End Reason" (0x10) <<<<<< length = 2 <<<<<< value = F0:03 <<<<<< translated = gsm-wcdma-regular-deactivation <<<<<< TLV: <<<<<< type = "Verbose Call End Reason" (0x11) <<<<<< length = 4 <<<<<< value = 06:00:24:00 <<<<<< translated = [ type = '3gpp' reason = '36' ] <<<<<< TLV: <<<<<< type = "IP Family" (0x12) <<<<<< length = 1 <<<<<< value = 04 <<<<<< translated = ipv4 Jun 30 10:17:18 pureos ModemManager[541]: <debug> [1656577038.041472] [modem0/wwan0/net] port now disconnected Jun 30 10:17:18 pureos ModemManager[541]: <debug> [1656577038.041876] [modem0/bearer1] disconnected Jun 30 10:17:18 pureos ModemManager[541]: <info> [1656577038.042621] [modem0] state changed (disconnecting -> registered) Jun 30 10:17:18 pureos ModemManager[541]: <info> [1656577038.047934] [modem0/bearer1] connection #1 finished: duration 63s, tx: 0 bytes, rx: 0 bytes Jun 30 10:17:18 pureos ModemManager[541]: <debug> [1656577038.146743] [modem0] user request to disconnect modem (all bearers) Jun 30 10:17:18 pureos ModemManager[541]: <debug> [1656577038.156289] [modem0/ttyUSB0/qcdm] <-- 60 16 00 46 26 6c 75 f1 91 34 04 00 00 03 46 26 29 4e 1e 92 34 04 00 00 04 05 a4 7e Jun 30 10:17:18 pureos ModemManager[541]: <debug> [1656577038.380044] [modem0] user request to disconnect modem (all bearers) Jun 30 10:17:56 pureos ModemManager[541]: <debug> [1656577076.152103] [modem0/ttyUSB0/qcdm] <-- 60 26 00 46 26 21 64 a2 b8 34 04 00 00 07 46 26 a0 b8 bc b8 34 04 00 00 01 46 26 9e 3a c7 b8 34 04 00 00 02 46 a6 3a c7 02 83 97 7e 60 0b 00 46 26 06 39 8b bd 34 04 00 00 02 a9 5a 7e Jun 30 10:17:56 pureos ModemManager[541]: <info> [1656577076.643600] [sleep-monitor] system is resuming Jun 30 10:17:56 pureos ModemManager[541]: <debug> [1656577076.644825] [sleep-monitor] taking systemd sleep inhibitor Jun 30 10:17:56 pureos ModemManager[541]: <debug> [1656577076.655957] syncing modem state (quick resuming) Jun 30 10:17:56 pureos ModemManager[541]: <info> [1656577076.656990] [modem0] resume synchronization state (1/4): modem interface sync Jun 30 10:17:56 pureos ModemManager[541]: <debug> [1656577076.657327] [modem0] start checking for SIM swap in slot 0 Jun 30 10:17:56 pureos ModemManager[541]: <debug> [1656577076.657470] [modem0] checking if SIM was swapped... Jun 30 10:17:56 pureos ModemManager[541]: <debug> [1656577076.657747] [modem0/sim0] loading SIM identifier... Jun 30 10:17:56 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 33 <<<<<< data = 01:20:00:00:0B:01:00:0D:00:20:00:14:00:03:04:00:00:00:00:00:02:05:00:E2:2F:02:00:3F:01:02:00:00:00 Jun 30 10:17:56 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent generic request (translated)... <<<<<< QMUX: <<<<<< length = 32 <<<<<< flags = 0x00 <<<<<< service = "uim" <<<<<< client = 1 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 13 <<<<<< tlv_length = 20 <<<<<< message = "Read Transparent" (0x0020) <<<<<< TLV: <<<<<< type = "Read Information" (0x03) <<<<<< length = 4 <<<<<< value = 00:00:00:00 <<<<<< translated = [ offset = '0' length = '0' ] <<<<<< TLV: <<<<<< type = "File" (0x02) <<<<<< length = 5 <<<<<< value = E2:2F:02:00:3F <<<<<< translated = [ file_id = '12258' file_path = '{ [0] = '0 ' [1] = '63 '}' ] <<<<<< TLV: <<<<<< type = "Session" (0x01) <<<<<< length = 2 <<<<<< value = 00:00 <<<<<< translated = [ session_type = 'primary-gw-provisioning' application_identifier = '{}' ] Jun 30 10:17:56 pureos ModemManager[541]: <debug> [1656577076.716557] [modem0] user request to disconnect modem (all bearers) Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.151682] [sleep-monitor] inhibitor fd is 14 Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.655835] [modem0] user request to connect modem Jun 30 10:17:57 pureos ModemManager[541]: <info> [1656577077.737035] [modem0] simple connect started... Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737170] [modem0] profile ID: unspecified Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737198] [modem0] PIN: unspecified Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737222] [modem0] operator ID: unspecified Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737247] [modem0] allowed roaming: no Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737273] [modem0] APN: web Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737300] [modem0] APN type: unspecified Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737326] [modem0] IP family: ipv4v6 Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737363] [modem0] allowed authentication: none, pap, chap, mschap, mschapv2, eap Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737390] [modem0] user: web@telering.at Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737416] [modem0] password: web Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737441] [modem0] multiplex: unspecified Jun 30 10:17:57 pureos ModemManager[541]: <info> [1656577077.737465] [modem0] simple connect state (4/8): wait to get fully enabled Jun 30 10:17:57 pureos ModemManager[541]: <info> [1656577077.737621] [modem0] simple connect state (5/8): register Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737698] [modem0] already registered automatically in network '23203', automatic registration not launched... Jun 30 10:17:57 pureos ModemManager[541]: <info> [1656577077.737765] [modem0] simple connect state (6/8): bearer Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.737804] [modem0] Using already existing bearer at '/org/freedesktop/ModemManager1/Bearer/1'... Jun 30 10:17:57 pureos ModemManager[541]: <info> [1656577077.737830] [modem0] simple connect state (7/8): connect Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.738043] [modem0/bearer1] connecting... Jun 30 10:17:57 pureos ModemManager[541]: <info> [1656577077.738102] [modem0] state changed (registered -> connecting) Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.738648] [modem0/bearer1] launching connection with QMI port (cdc-wdm0) and data port (wwan0) (multiplex none) Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.738707] [cdc-wdm0/qmi] multiplex support already disabled when setting up data format Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.739040] [modem0/bearer1] defaulting to use static IP method Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.739080] [modem0/bearer1] running IPv4 connection setup Jun 30 10:17:57 pureos ModemManager[541]: <debug> [1656577077.739107] [modem0/bearer1] setting default IP family to: IPv4 Jun 30 10:17:57 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 17 <<<<<< data = 01:10:00:00:01:02:00:08:00:4D:00:04:00:01:01:00:04 Jun 30 10:17:57 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent generic request (translated)... <<<<<< QMUX: <<<<<< length = 16 <<<<<< flags = 0x00 <<<<<< service = "wds" <<<<<< client = 2 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 8 <<<<<< tlv_length = 4 <<<<<< message = "Set IP Family" (0x004D) <<<<<< TLV: <<<<<< type = "Preference" (0x01) <<<<<< length = 1 <<<<<< value = 04 <<<<<< translated = ipv4 Jun 30 10:18:06 pureos ModemManager[541]: transaction 0xd aborted, but message is not abortable Jun 30 10:18:06 pureos ModemManager[541]: <warn> [1656577086.427970] [modem0] could not load SIM identifier: QMI operation failed: Transaction timed out (3 retries left) Jun 30 10:18:07 pureos ModemManager[541]: <debug> [1656577087.420723] [modem0/sim0] loading SIM identifier... Jun 30 10:18:07 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 33 <<<<<< data = 01:20:00:00:0B:01:00:0E:00:20:00:14:00:03:04:00:00:00:00:00:02:05:00:E2:2F:02:00:3F:01:02:00:00:00 Jun 30 10:18:07 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent generic request (translated)... <<<<<< QMUX: <<<<<< length = 32 <<<<<< flags = 0x00 <<<<<< service = "uim" <<<<<< client = 1 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 14 <<<<<< tlv_length = 20 <<<<<< message = "Read Transparent" (0x0020) <<<<<< TLV: <<<<<< type = "Read Information" (0x03) <<<<<< length = 4 <<<<<< value = 00:00:00:00 <<<<<< translated = [ offset = '0' length = '0' ] <<<<<< TLV: <<<<<< type = "File" (0x02) <<<<<< length = 5 <<<<<< value = E2:2F:02:00:3F <<<<<< translated = [ file_id = '12258' file_path = '{ [0] = '0 ' [1] = '63 '}' ] <<<<<< TLV: <<<<<< type = "Session" (0x01) <<<<<< length = 2 <<<<<< value = 00:00 <<<<<< translated = [ session_type = 'primary-gw-provisioning' application_identifier = '{}' ] Jun 30 10:18:08 pureos ModemManager[541]: transaction 0x8 aborted, but message is not abortable Jun 30 10:18:08 pureos ModemManager[541]: <debug> [1656577088.420178] [modem0/bearer1] couldn't set IP family preference: Transaction timed out Jun 30 10:18:08 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 61 <<<<<< data = 01:3C:00:00:01:02:00:09:00:01:00:30:00:1E:01:00:01:1C:01:00:01:1B:01:00:01:1A:01:00:01:19:01:00:01:18:01:00:01:17:01:00:01:15:01:00:01:14:01:00:01:13:01:00:01:12:01:00:01:10:01:00:01 Jun 30 10:18:08 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent generic request (translated)... <<<<<< QMUX: <<<<<< length = 60 <<<<<< flags = 0x00 <<<<<< service = "wds" <<<<<< client = 2 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 9 <<<<<< tlv_length = 48 <<<<<< message = "Set Event Report" (0x0001) <<<<<< TLV: <<<<<< type = "Extended Data Bearer Technology" (0x1e) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes <<<<<< TLV: <<<<<< type = "Limited Data System Status" (0x1c) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes <<<<<< TLV: <<<<<< type = "Uplink Flow Control" (0x1b) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes <<<<<< TLV: <<<<<< type = "Data Systems" (0x1a) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes <<<<<< TLV: <<<<<< type = "EVDO PM Change" (0x19) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes <<<<<< TLV: <<<<<< type = "Preferred Data System" (0x18) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes <<<<<< TLV: <<<<<< type = "Data Call Status" (0x17) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes <<<<<< TLV: <<<<<< type = "Current Data Bearer Technology" (0x15) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes <<<<<< TLV: <<<<<< type = "MIP Status" (0x14) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = 1 <<<<<< TLV: <<<<<< type = "Dormancy Status" (0x13) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes <<<<<< TLV: <<<<<< type = "Data Bearer Technology" (0x12) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes <<<<<< TLV: <<<<<< type = "Channel Rate" (0x10) <<<<<< length = 1 <<<<<< value = 01 <<<<<< translated = yes Jun 30 10:18:13 pureos ModemManager[541]: transaction 0x9 aborted, but message is not abortable Jun 30 10:18:13 pureos ModemManager[541]: <warn> [1656577093.424614] [modem0/bearer1] connection attempt #2 failed: Transaction timed out Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.424889] [modem0/bearer1] cannot set QMI core error as connection error: Transaction timed out Jun 30 10:18:13 pureos ModemManager[541]: <info> [1656577093.424992] [modem0] state changed (connecting -> registered) Jun 30 10:18:13 pureos ModemManager[541]: <info> [1656577093.425623] [modem0/bearer1] connection #2 finished: duration 0s, tx: 0 bytes, rx: 0 bytes Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.425689] [modem0] couldn't connect bearer: Transaction timed out Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.438677] [modem0] user request to connect modem Jun 30 10:18:13 pureos ModemManager[541]: <info> [1656577093.447623] [modem0] simple connect started... Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.447758] [modem0] profile ID: unspecified Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.447786] [modem0] PIN: unspecified Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.447811] [modem0] operator ID: unspecified Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.447835] [modem0] allowed roaming: no Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.447861] [modem0] APN: web Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.447887] [modem0] APN type: unspecified Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.447913] [modem0] IP family: ipv4 Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.447952] [modem0] allowed authentication: none, pap, chap, mschap, mschapv2, eap Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.447979] [modem0] user: web@telering.at Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.448003] [modem0] password: web Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.448028] [modem0] multiplex: unspecified Jun 30 10:18:13 pureos ModemManager[541]: <info> [1656577093.448052] [modem0] simple connect state (4/8): wait to get fully enabled Jun 30 10:18:13 pureos ModemManager[541]: <info> [1656577093.448227] [modem0] simple connect state (5/8): register Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.448307] [modem0] already registered automatically in network '23203', automatic registration not launched... Jun 30 10:18:13 pureos ModemManager[541]: <info> [1656577093.448369] [modem0] simple connect state (6/8): bearer Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.448404] [modem0] creating new bearer... Jun 30 10:18:13 pureos ModemManager[541]: <info> [1656577093.449468] [modem0] simple connect state (7/8): connect Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.449782] [modem0/bearer2] connecting... Jun 30 10:18:13 pureos ModemManager[541]: <info> [1656577093.449865] [modem0] state changed (registered -> connecting) Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.450506] [modem0/bearer2] launching connection with QMI port (cdc-wdm0) and data port (wwan0) (multiplex none) Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.450583] [cdc-wdm0/qmi] multiplex support already disabled when setting up data format Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.450965] [modem0/bearer2] defaulting to use static IP method Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.451011] [modem0/bearer2] running IPv4 connection setup Jun 30 10:18:13 pureos ModemManager[541]: <debug> [1656577093.451039] [modem0/bearer2] setting default IP family to: IPv4 Jun 30 10:18:13 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent message... <<<<<< RAW: <<<<<< length = 17 <<<<<< data = 01:10:00:00:01:02:00:0A:00:4D:00:04:00:01:01:00:04 Jun 30 10:18:13 pureos ModemManager[541]: [/dev/cdc-wdm0] Sent generic request (translated)... <<<<<< QMUX: <<<<<< length = 16 <<<<<< flags = 0x00 <<<<<< service = "wds" <<<<<< client = 2 <<<<<< QMI: <<<<<< flags = "none" <<<<<< transaction = 10 <<<<<< tlv_length = 4 <<<<<< message = "Set IP Family" (0x004D) <<<<<< TLV: <<<<<< type = "Preference" (0x01) <<<<<< length = 1 <<<<<< value = 04 <<<<<< translated = ipv4 Jun 30 10:18:17 pureos ModemManager[541]: transaction 0xe aborted, but message is not abortable Jun 30 10:18:17 pureos ModemManager[541]: <warn> [1656577097.422616] [modem0] could not load SIM identifier: QMI operation failed: Transaction timed out (2 retries left) 
@martin.kepplinger can you add how does the "broken" state manifest in the UI? Is the wwan indicator missing completely?
-
as a rule of thumb please always check whether you're online on mobile data after resuming in any way convenient to you. even if phosh indicates "online". if not, try to restart ModemManager first and if that doesn't work, power cycle with HKS. Reports based on that would be helpful. AFAIK calls/SMS work when the internet connection works.
mentioned in issue user-personas#9
-
just to show what I'm going through:
the broken case looks like so:
053] [modem0] couldn't query SIM slots: QMI protocol error (94): 'NotSupported' 702] [modem0/sim0] couldn't load list of emergency numbers: uninitialized emergency numbers list 846] [modem0] couldn't load list of own numbers: Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned' 604] [modem0] could not load SIM identifier: QMI operation failed: Transaction timed out (3 retries left) 591] [modem0/bearer1] connection attempt #2 failed: Transaction timed out 853] [modem0] could not load SIM identifier: QMI operation failed: Transaction timed out (2 retries left) 981] [modem0/bearer2] connection attempt #1 failed: Transaction timed out 963] [modem0] could not load SIM identifier: QMI operation failed: Transaction timed out (1 retries left) 007] [modem0] could not load SIM identifier: QMI operation failed: Transaction timed out 066] [modem0] SIM swap check failed: QMI operation failed: Transaction timed out 108] [modem0] checking sim swap failed: QMI operation failed: Transaction timed out 497] [modem0/bearer3] connection attempt #1 failed: Transaction timed out 845] [modem0] checking sim lock status failed: QMI operation failed: Transaction timed out 117] [modem0/bearer1] connection attempt #3 failed: Transaction timed outin short: let's not add things like !614 (closed) or modemmanager tweaks for now. I'll test the behavior after longer periods of suspend.
I think we want !614 (closed) in because without it we have a guaranteed reset and
--test-quick-suspend-resumehas no chance to make a difference at all. The fact that it's broken in MM is another matter that needs to be debugged and fixed on its own - but without !614 (closed) it can't even be tested at all.-
(I was saying we currently won't really need !614 (closed) :) But yes, you might be right. Let's test it more and merge it if ok (and maybe after sending it out to mailings lists for discussion).
-
This has been fixed with !674 (merged).
Please register or sign in to reply