I (and others) face frequent crashes of the modem firmware. The visible effect of such crashes are that the modem and data mobile level indicator went away (will attach a picture next time).
For me this happened already before updating the modem firmware and using suspend in my L5, but now far more often.
See also: Status of Suspend for Librem 5
(there is a script for reenabling the modem)
and https://source.puri.sm/Librem5/linux-next/-/issues/303
And this is with upgraded firmware?
How do you upgrade your firmware?
Please read last messages in the referenced thread Status of Suspend for Librem 5 .
Yes, I updated the modem firmware. And yes, I did it following the instructions I got from support. And yes, I only created this new thread to move it away from the “status of suspend” thread.
This procedure is made available by Purism on a 1-to-1 basis only through their support.
I once downloaded BM818-watchmodem, that was supposed to give a notification every time the modem disappeared and then attempt to restart it, but I haven’t tried it on my phone. Now I can’t find the git repo for it, but I have a .deb on my PC with the name bm818-watchmodem_0.5+librem5ci79332.e96a15a_arm64.deb. Not sure if it is up to date or usable.
Please provide some logs showing what happens (dmesg at least), such thread is useless otherwise. The bugtracker issue you linked is either unrelated, or your system isn’t up to date because that one is already fixed.
Yeap, and how Guru know that the firmware crashing.
@dos, My system is fully uptodate, including the modem firmware.
To @carlosgonz I don’t know if “crash” is what happens. All modem indicators in the status bar are just gone in that case and the modem is not useable. The reset visible in the script in the other thread brings it back to life.
I will try to gather more information from the logs.
The idea of this new thread was to move it away from the ~400 replies in “what is the status of suspend”:
I was happy to face the situation this morning again and from events on the shell I can exactly cut out the time window from when the moment icons still have been there and to they wasn’t anymore:
I have here the log when the modem icon in the status line disappearred
since:
When I typed ‘sudo apt update’ in the terminal the modem icons still have been there;
until:
I did a screenshot of the disappeared modem in status line:
purism@pureos:~$ ls -ltr --full-time Pictures/ | tail -1
-rw-r--r-- 1 purism purism 207076 2023-04-25 09:11:08.718987940 +0200 2023-04-25-091100.png
Apr 25 09:08:15 pureos sudo[23493]: purism : TTY=pts/2 ; PWD=/home/purism ; USER=root ; COMMAND=/usr/bin/apt update
Apr 25 09:08:15 pureos sudo[23493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 25 09:09:00 pureos sudo[23493]: pam_unix(sudo:session): session closed for user root
Apr 25 09:09:59 pureos ModemManager[5761]: <warn> [modem4] port ttyUSB1 timed out 8 consecutive times
Apr 25 09:10:04 pureos ModemManager[5761]: <warn> [modem4] port ttyUSB1 timed out 9 consecutive times
Apr 25 09:10:07 pureos ModemManager[5761]: <warn> [modem4/bearer9] connection attempt #1 failed: Serial command timed out
Apr 25 09:10:07 pureos ModemManager[5761]: <info> [modem4] state changed (connecting -> registered)
Apr 25 09:10:07 pureos ModemManager[5761]: <info> [modem4/bearer9] connection #1 finished: duration 0s, tx: 0 bytes, rx: 0 bytes
Apr 25 09:10:07 pureos ModemManager[5761]: <error> [modem4] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
Apr 25 09:10:07 pureos mmsdtng[867]: ../plugins/modemmanager.c:modem_state_changed_cb() State Change: Old State: 10 New State: 8, Reason: 1
Apr 25 09:10:07 pureos mmsdtng[867]: ../plugins/modemmanager.c:mmsd_mm_get_modem_state() MM_MODEM_GOOD_STATE: 8
Apr 25 09:10:07 pureos mmsdtng[867]: ../plugins/modemmanager.c:mmsd_mm_state() MMSD_MM_STATE_READY
Apr 25 09:10:07 pureos mmsdtng[867]: ../plugins/modemmanager.c:mmsd_mm_state() Setting Bearer Handler
Apr 25 09:10:07 pureos mmsdtng[867]: ../src/service.c:mms_service_set_bearer_handler() service 0xaaaad27f8370 handler 0xaaaab6475a20
Apr 25 09:10:07 pureos NetworkManager[567]: <info> [1682406607.6709] modem["ttyUSB1"]: modem state changed, 'connecting' --> 'registered' (reason: user-requested)
Apr 25 09:10:07 pureos NetworkManager[567]: <warn> [1682406607.6712] modem-broadband[ttyUSB1]: failed to connect modem: Serial command timed out
Apr 25 09:10:07 pureos NetworkManager[567]: <info> [1682406607.6714] device (ttyUSB1): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
Apr 25 09:10:07 pureos mmsdtng[867]: ../plugins/modemmanager.c:mmsd_modem_unavailable() Disabling Bearer Handler
Apr 25 09:10:07 pureos mmsdtng[867]: ../src/service.c:mms_service_set_bearer_handler() service 0xaaaad27f8370 handler (nil)
Apr 25 09:10:07 pureos mmsdtng[867]: ../plugins/modemmanager.c:mmsd_disconnect_from_sms_wap() Stopping watching SMS WAPs
Apr 25 09:10:07 pureos mmsdtng[867]: ../plugins/modemmanager.c:mmsd_mm_state() Modem vanished, Disabling plugin
Apr 25 09:10:07 pureos mmsdtng[867]: ../plugins/modemmanager.c:mmsd_mm_state() MMSD_MM_STATE_NO_MODEM
Apr 25 09:10:07 pureos mmsdtng[867]: ../plugins/modemmanager.c:cb_object_removed() Modem removed: /org/freedesktop/ModemManager1/Modem/4
Apr 25 09:10:07 pureos NetworkManager[567]: <warn> [1682406607.6798] device (ttyUSB1): Activation: failed for connection 'Fonic'
Apr 25 09:10:07 pureos NetworkManager[567]: <info> [1682406607.6823] device (ttyUSB1): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Apr 25 09:10:07 pureos NetworkManager[567]: <info> [1682406607.6897] device (ttyUSB1): state change: disconnected -> unmanaged (reason 'removed', sys-iface-state: 'removed')
Apr 25 09:10:32 pureos sm.puri.OSK0.desktop[1285]: Debug: Tried file "/home/purism/.local/share/squeekboard/keyboards/terminal/us.yaml", but it's missing: No such file or directory (os error 2)
Apr 25 09:10:32 pureos sm.puri.OSK0.desktop[1285]: Info: Loaded layout Resource: terminal/us
Apr 25 09:10:34 pureos dbus-daemon[875]: [session uid=1000 pid=875] Activating service name='org.gnome.DejaDup' requested by ':1.29' (uid=1000 pid=1064 comm="/usr/libexec/phosh ")
Apr 25 09:10:34 pureos sm.puri.OSK0.desktop[1285]: Debug: Tried file "/home/purism/.local/share/squeekboard/keyboards/terminal/us.yaml", but it's missing: No such file or directory (os error 2)
Apr 25 09:10:34 pureos sm.puri.OSK0.desktop[1285]: Info: Loaded layout Resource: terminal/us
Apr 25 09:10:35 pureos dbus-daemon[875]: [session uid=1000 pid=875] Successfully activated service 'org.gnome.DejaDup'
Apr 25 09:10:35 pureos sm.puri.OSK0.desktop[1285]: Debug: Tried file "/home/purism/.local/share/squeekboard/keyboards/terminal/us.yaml", but it's missing: No such file or directory (os error 2)
Apr 25 09:10:35 pureos sm.puri.OSK0.desktop[1285]: Info: Loaded layout Resource: terminal/us
Apr 25 09:10:35 pureos deja-dup[23788]: g_object_set: assertion 'G_IS_OBJECT (object)' failed
Apr 25 09:10:35 pureos sm.puri.OSK0.desktop[1285]: Debug: Tried file "/home/purism/.local/share/squeekboard/keyboards/terminal/us.yaml", but it's missing: No such file or directory (os error 2)
Apr 25 09:10:35 pureos sm.puri.OSK0.desktop[1285]: Info: Loaded layout Resource: terminal/us
Apr 25 09:10:36 pureos sm.puri.OSK0.desktop[1285]: Debug: Tried file "/home/purism/.local/share/squeekboard/keyboards/terminal/us.yaml", but it's missing: No such file or directory (os error 2)
Apr 25 09:10:36 pureos sm.puri.OSK0.desktop[1285]: Info: Loaded layout Resource: terminal/us
Apr 25 09:10:42 pureos wpa_supplicant[628]: wlan0: WPA: Group rekeying completed with cc:ce:1e:7b:f5:b9 [GTK=CCMP]
Apr 25 09:10:42 pureos kernel: redpine_91x: Packet Dropped as Key ID not matched with both current and previous Key ID
Apr 25 09:10:42 pureos kernel: redpine_91x: Packet Dropped as Key ID not matched with both current and previous Key ID
Apr 25 09:10:53 pureos sm.puri.Phosh.desktop[6209]: Missing chrome or resource URL: resource://gre/modules/UpdateListener.jsm
Apr 25 09:10:53 pureos sm.puri.Phosh.desktop[6209]: Missing chrome or resource URL: resource://gre/modules/UpdateListener.sys.mjs
Apr 25 09:10:55 pureos systemd[843]: vte-spawn-d7951a5a-42b3-466c-a4a4-bd3dfdb5f19e.scope: Succeeded.
Apr 25 09:10:55 pureos systemd[843]: vte-spawn-d7951a5a-42b3-466c-a4a4-bd3dfdb5f19e.scope: Consumed 1.064s CPU time.
Apr 25 09:10:55 pureos systemd[843]: vte-spawn-2d3d46c0-02c6-4d5b-878d-927c2d6f2eeb.scope: Succeeded.
Apr 25 09:10:55 pureos systemd[843]: vte-spawn-2d3d46c0-02c6-4d5b-878d-927c2d6f2eeb.scope: Consumed 1min 29.398s CPU time.
Apr 25 09:10:56 pureos dbus-daemon[875]: [session uid=1000 pid=875] Activating via systemd: service name='org.freedesktop.Tracker1' unit='tracker-store.service' requested by ':1.2' (uid=1000 pid=872 comm="/usr/libexec/tracker-miner-fs ")
Apr 25 09:10:56 pureos systemd[843]: Starting Tracker metadata database store and lookup manager...
Apr 25 09:10:56 pureos dbus-daemon[875]: [session uid=1000 pid=875] Successfully activated service 'org.freedesktop.Tracker1'
Apr 25 09:10:56 pureos systemd[843]: Started Tracker metadata database store and lookup manager.
Apr 25 09:11:01 pureos yad[23844]: ../../../../../gdk/x11/gdkwindow-x11.c:5650 drawable is not a native X11 window
Apr 25 09:11:01 pureos phosh[1064]: Could not find application for app-id 'yad'
Apr 25 09:11:01 pureos sm.puri.OSK0.desktop[1285]: Debug: Tried file "/home/purism/.local/share/squeekboard/keyboards/terminal/us.yaml", but it's missing: No such file or directory (os error 2)
Apr 25 09:11:01 pureos sm.puri.OSK0.desktop[1285]: Info: Loaded layout Resource: terminal/us
Apr 25 09:11:03 pureos sm.puri.Phosh.desktop[23839]: /home/purism/Pictures/2023-04-25-091100.png|5|
Apr 25 09:11:09 pureos dbus-daemon[875]: [session uid=1000 pid=875] Activating via systemd: service name='org.freedesktop.Tracker1.Miner.Extract' unit='tracker-extract.service' requested by ':1.2' (uid=1000 pid=872 comm="/usr/libexec/tracker-miner-fs ")
Hope it helps.
So yeah, this is not the modem disappearing at all. It’s just ModemManager failing to probe the modem over QMI, then attempting to use PPP over AT which is completely broken and ends up making the port unusable until power cycling the modem. This should get better once the fixes for resume from suspend are deployed.
Please note, that I faced this already before using suspend at all. It’s now only more often. I will make a statistic of a day with and a day without suspend.
For me, the modem disappearing also seems unrelated to suspend as I find that it mostly happens while e.g. charging or when connected to a laptop dock when it doesn’t go into suspend. From memory, I would say the modem disappears maybe 4-5 times per day.
I flashed the new modem firmware exactly at April, 19 17:59 (time stamp of the dir backup_m100e). And now look this:
$ sudo journalctl | grep 'ttyUSB1 timed out 10 consecutive times, marking modem as invalid'
Apr 17 14:33:57 pureos ModemManager[765]: <error> [modem2] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
Apr 21 17:23:39 pureos ModemManager[786]: <error> [modem9] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
Apr 21 21:50:59 pureos ModemManager[8974]: <error> [modem3] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
...
$ sudo journalctl | grep 'ttyUSB1 timed out 10 consecutive times, marking modem as invalid' | wc -l
18
i.e. after the modem update 17 times in ~10 days.
I have had an interesting observation today: the modem indicators disappeared some minutes after a resume from suspend (i.e. with the resume they still have been there) and I was to lazy to power cycle the modem with the HKS (i.e. to lazy to have to enter the PIN again). And after some minutes the modem indicator re-appeared by its own.
Magic?
That was a completely different issue which just shared similar symptoms.
This issue has certainly gotten worse over the past week. Today I have had more than a handful of modem dropouts / cellular icon disappearing from the status bar. Checking the journalctl I get the following:
maj 02 14:44:29 pureos ModemManager[12342]: <warn> [modem8] port ttyUSB1 timed out 6 consecutive times
maj 02 14:44:32 pureos ModemManager[12342]: <warn> [modem8] port ttyUSB1 timed out 7 consecutive times
maj 02 14:44:35 pureos ModemManager[12342]: <warn> [modem8] port ttyUSB1 timed out 8 consecutive times
maj 02 14:46:35 pureos ModemManager[12342]: <warn> [modem8] port ttyUSB1 timed out 9 consecutive times
maj 02 14:46:40 pureos ModemManager[12342]: <error> [modem8] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
maj 02 14:46:40 pureos mmsdtng[1478]: ../plugins/modemmanager.c:mmsd_modem_unavailable() Disabling Bearer Handler
maj 02 14:46:40 pureos mmsdtng[1478]: ../plugins/modemmanager.c:mmsd_disconnect_from_sms_wap() Stopping watching SMS WAPs
maj 02 14:46:40 pureos mmsdtng[1478]: ../plugins/modemmanager.c:mmsd_mm_state() Modem vanished, Disabling plugin
maj 02 14:46:40 pureos mmsdtng[1478]: ../plugins/modemmanager.c:mmsd_mm_state() MMSD_MM_STATE_NO_MODEM
maj 02 14:46:40 pureos mmsdtng[1478]: ../plugins/modemmanager.c:cb_object_removed() Modem removed: /org/freedesktop/ModemManager1/Modem/8
For me, the cellular connection has become totally unreliable as it seems to time out as soon as the phone sits idle for a while (not suspending). To add to the problem, my phone really struggles to establish a mobile data connection, which is also a new problem that could be related to the updated modem firmware. Sometimes toggling the HKS or resetting the modem through the terminal 5-6 times don’t resolve the mobile connection. The latter problem noticeable when I leave my home Wifi. It is really frustrating.
I will post this log file snippet in the bugtracker as well.
Here are mine issues, the last 10:
purism@pureos:~$ sudo journalctl | grep 'timed out 10' | tail -10
[sudo] password for purism:
Apr 28 09:44:16 pureos ModemManager[666]: <error> [modem13] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
Apr 28 16:50:30 pureos ModemManager[691]: <error> [modem1] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
Apr 29 11:34:17 pureos ModemManager[701]: <error> [modem6] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
Apr 29 16:54:05 pureos ModemManager[701]: <error> [modem8] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
Apr 29 17:22:54 pureos ModemManager[701]: <error> [modem10] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
Apr 30 15:05:04 pureos ModemManager[701]: <error> [modem19] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
Apr 30 15:35:43 pureos ModemManager[701]: <error> [modem21] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
Apr 30 22:08:05 pureos ModemManager[701]: <error> [modem26] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
May 01 12:46:49 pureos ModemManager[701]: <error> [modem30] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
May 01 23:16:07 pureos ModemManager[701]: <error> [modem34] port ttyUSB1 timed out 10 consecutive times, marking modem as invalid
purism@pureos:~$