Anyone else getting this of late? Call is hung up, and still stuck on the lock screen, back button doesn’t work, no way to get rid of it, have to reboot phone
Yep, once or twice.
This happens to me every time I get a call while the phone is in suspend. I dont like having to force the phone off. Im hoping it gets worked out eventually.
If you all could add this line:
G_MESSAGES_DEBUG=phosh-lockscreen,phosh-calls-manager,phosh-call-notificaton
To you .profile file in home folder it should output better logs for this. I have been chasing this for months but it is (luckily) quite rare so I have never been able to get good logs out of it.
I keep wondering why it does it, its not every time or even most of the time. Is it maybe if you hang up at the same time as them, or first? I wondered about that sort of thing.
Current theory is that somehow Calls does not get “call ended” signal.
It is super hard to reproduce - I have tried to make like 1000 calls to my self but it is only happening irl randomly.
Maybe it is some rare situation where carrier send some odd signal to modemmanager and so on
I get this where after hanging up, the screen is frozen on the Lock screen on the Call window, but buttons are greyed out.
I can swipe down from the top but not get back to the “main” lock screen to unlock my phone.
The only fix is to reboot or SSH in and restart Phosh (which isn’t always an option).
It happens a bit but not enough to where I can reproduce this reliably.
Added. Of course I just got a call and it worked fine. Are there any specific keywords/messages I should be watching for? For now Ill just take note of the time and go back to try and find it.
Thats the thing. No idea. Without verbose logging there is nothing unusual in logs.
I have seen this like 10-20 times but never with verbosed logging enabled
So when someone hits that stuck call and have this:
G_MESSAGES_DEBUG=phosh-lockscreen,phosh-calls-manager,phosh-call-notificaton
enabled we need to check those logs and then we most likely know the real issue.
It happened but I don´t see anything in journalctl
purism@pureos:~$ journalctl -u phosh-lockscreen -u phosh-calls-manager -u phosh-call-notification
– Journal begins at Sat 2024-02-03 10:25:11 EST, ends at Mon 2024-02-12 18:33:46 EST. –
– No entries –
purism@pureos:~$ journalctl | grep -E ‘phosh-lockscreen|phosh-calls-manager|phosh-call-notificaton’
purism@pureos:~$
Should I be looking somewhere else?
Feb 12 17:34:56 pureos mmsdtng[706]: ../src/service.c:bearer_idle_timeout() service 0xaaaafa7d7ba0
Feb 12 17:34:56 pureos mmsdtng[706]: ../src/service.c:deactivate_bearer() service 0xaaaafa7d7ba0
Feb 12 17:34:56 pureos mmsdtng[706]: ../src/service.c:deactivate_bearer() service 0xaaaafa7d7ba0
Feb 12 17:34:56 pureos mmsdtng[706]: ../plugins/modemmanager.c:set_context() Setting Context...
Feb 12 17:34:56 pureos mmsdtng[706]: ../src/service.c:mms_service_set_mmsc() service 0xaaaafa7d7ba0 mmsc http://wholesale.mmsmvno.com/mms/wapenc
Feb 12 17:34:56 pureos mmsdtng[706]: ../plugins/modemmanager.c:set_context() Max number of bearers: 1
Feb 12 17:34:56 pureos mmsdtng[706]: ../plugins/modemmanager.c:set_context() Current Context APN: Wholesale, mmsd-tng settings MMS APN: Wholesale
Feb 12 17:34:56 pureos mmsdtng[706]: ../plugins/modemmanager.c:set_context() You are connected to the correct APN! Enabling context...
Feb 12 17:34:56 pureos mmsdtng[706]: ../src/service.c:mms_service_set_apn() Service APN Set to Wholesale
Feb 12 17:34:56 pureos mmsdtng[706]: ../src/service.c:mms_service_set_resolvers() service 0xaaaafa7d7ba0 resolvers: ipv4: 10.177.0.34,10.177.0.210, ipv6: fd00:976a::9,fd00:976a::10
Feb 12 17:34:56 pureos mmsdtng[706]: ../plugins/modemmanager.c:set_context() DNS from modemmanager IPv6: fd00:976a::9,fd00:976a::10, IPv4: 10.177.0.34,10.177.0.210
Feb 12 17:34:56 pureos mmsdtng[706]: ../plugins/modemmanager.c:set_context() Current Context APN: Wholesale, mmsd-tng settings MMS APN: Wholesale
Feb 12 17:34:56 pureos mmsdtng[706]: ../plugins/modemmanager.c:bearer_handler() At Bearer Handler: path /org/freedesktop/ModemManager1/Modem/1 active 0 context_active 1
Feb 12 17:34:56 pureos mmsdtng[706]: ../plugins/modemmanager.c:bearer_handler() checking for failure
Feb 12 17:34:56 pureos mmsdtng[706]: ../plugins/modemmanager.c:bearer_handler() No failures
Feb 12 17:34:56 pureos mmsdtng[706]: ../src/service.c:mms_service_bearer_notify() service=0xaaaafa7d7ba0 active=0 iface=wwx064b2c94ee7a proxy=(null)
Feb 12 17:34:56 pureos systemd-timesyncd[461]: Timed out waiting for reply from 50.205.57.38:123 (1.debian.pool.ntp.org).
Feb 12 17:34:56 pureos systemd-timesyncd[461]: Initial synchronization to time server 173.71.73.214:123 (1.debian.pool.ntp.org).
Feb 12 17:34:58 pureos ModemManager[644]: <info> [modem1/call2] user request to accept call
Feb 12 17:34:58 pureos ModemManager[644]: <info> [modem1/call2] call is accepted
Feb 12 17:34:58 pureos ModemManager[644]: <info> [modem1/call2] call state changed: ringing-in -> active (accepted)
Feb 12 17:34:58 pureos pulseaudio[711]: Configured maximum latency is smaller than latency, using latency instead
Feb 12 17:34:58 pureos pulseaudio[711]: Cannot set requested sink latency of 66.67 ms, adjusting to 44.00 ms
Feb 12 17:34:58 pureos pulseaudio[711]: Cannot set requested source latency of 66.67 ms, adjusting to 44.00 ms
Feb 12 17:34:58 pureos pulseaudio[711]: Configured maximum latency is smaller than latency, using latency instead
Feb 12 17:34:58 pureos pulseaudio[711]: Cannot set requested sink latency of 66.67 ms, adjusting to 44.00 ms
Feb 12 17:34:58 pureos pulseaudio[711]: Cannot set requested source latency of 66.67 ms, adjusting to 44.00 ms
Feb 12 17:34:58 pureos pulseaudio[711]: Cannot set requested source latency of 66.67 ms, adjusting to 44.00 ms
Feb 12 17:34:58 pureos pulseaudio[711]: Cannot set requested sink latency of 66.67 ms, adjusting to 44.00 ms
Feb 12 17:34:58 pureos pulseaudio[711]: Doing resync
Feb 12 17:34:58 pureos pulseaudio[711]: Playback after capture (-17435), drop sink 6768
Feb 12 17:34:59 pureos pulseaudio[711]: Playback too far ahead (5241), drop source 1004
Feb 12 17:35:00 pureos pulseaudio[711]: Playback too far ahead (10324), drop source 1980
Feb 12 17:35:01 pureos autossh[217615]: received signal to exit (15)
Feb 12 17:35:01 pureos pulseaudio[711]: Playback too far ahead (13194), drop source 2532
Feb 12 17:35:02 pureos NetworkManager[474]: <info> [1707777302.0975] manager: NetworkManager state is now CONNECTED_GLOBAL
Feb 12 17:35:02 pureos autossh[218655]: port set to 0, monitoring disabled
Feb 12 17:35:02 pureos autossh[218655]: starting ssh (count 1)
Feb 12 17:35:02 pureos autossh[218655]: ssh child pid is 218660
Feb 12 17:35:02 pureos pulseaudio[711]: Playback too far ahead (13089), drop source 2512
Feb 12 17:35:03 pureos pulseaudio[711]: Playback too far ahead (13016), drop source 2496
Feb 12 17:35:04 pureos pulseaudio[711]: Playback too far ahead (12635), drop source 2424
Feb 12 17:35:05 pureos pulseaudio[711]: Playback too far ahead (11601), drop source 2224
Feb 12 17:35:06 pureos pulseaudio[711]: Playback too far ahead (10435), drop source 2000
Feb 12 17:35:07 pureos pulseaudio[711]: Playback too far ahead (8602), drop source 1648
Feb 12 17:35:08 pureos pulseaudio[711]: Playback too far ahead (9023), drop source 1732
Feb 12 17:35:09 pureos pulseaudio[711]: Playback too far ahead (9900), drop source 1900
Feb 12 17:35:10 pureos pulseaudio[711]: Playback too far ahead (10101), drop source 1936
Feb 12 17:35:11 pureos pulseaudio[711]: Playback too far ahead (10079), drop source 1932
Feb 12 17:35:12 pureos systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Feb 12 17:35:12 pureos pulseaudio[711]: Playback too far ahead (9990), drop source 1916
Feb 12 17:35:13 pureos pulseaudio[711]: Playback too far ahead (9963), drop source 1912
Feb 12 17:35:14 pureos pulseaudio[711]: Playback too far ahead (10040), drop source 1924
Feb 12 17:35:15 pureos pulseaudio[711]: Playback too far ahead (9998), drop source 1916
Feb 12 17:35:16 pureos goa-daemon[775]: goa_http_client_check() failed: 2 — Error resolving “nextcloud.noncom.us”: Name or service not known
Feb 12 17:35:16 pureos pulseaudio[711]: Playback too far ahead (10015), drop source 1920
Feb 12 17:35:17 pureos startup.desktop[1591]: [2024-02-12 17:35:17.277] [net] [error] Failed to download matrix.org/MwaqtYQMORqJkAnPJKkXGuqO: (http: 404, matrix: M_NOT_FOUND:'Not found')
Feb 12 17:35:17 pureos startup.desktop[1591]: [2024-02-12 17:35:17.280] [qml] [warning] qrc:/qml/Avatar.qml:55:5: QML Image: Failed to download image: matrix.org/MwaqtYQMORqJkAnPJKkXGuqO (qrc:/qml/Avatar.qml:55, )
Feb 12 17:35:17 pureos startup.desktop[1591]: [2024-02-12 17:35:17.749] [net] [error] Failed to download matrix.org/EqpOjKXlnYXFYuznscYKPPUJ: (http: 404, matrix: M_NOT_FOUND:'Not found')
Feb 12 17:35:17 pureos startup.desktop[1591]: [2024-02-12 17:35:17.753] [qml] [warning] qrc:/qml/Avatar.qml:55:5: QML Image: Failed to download image: matrix.org/EqpOjKXlnYXFYuznscYKPPUJ (qrc:/qml/Avatar.qml:55, )
Feb 12 17:35:19 pureos gnome-clocks[1186]: geocoding.vala:75: Failed to obtain country code: Error resolving “nominatim.gnome.org”: Name or service not known
Feb 12 17:35:21 pureos NetworkManager[474]: <info> [1707777321.6684] manager: NetworkManager state is now CONNECTED_SITE
Feb 12 17:35:21 pureos dbus-daemon[471]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.5' (uid=0 pid=474 comm="/usr/sbin/NetworkManager --no-daemon ")
Feb 12 17:35:21 pureos systemd[1]: Starting Network Manager Script Dispatcher Service...
Feb 12 17:35:21 pureos dbus-daemon[471]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Feb 12 17:35:21 pureos systemd[1]: Started Network Manager Script Dispatcher Service.
Feb 12 17:35:29 pureos NetworkManager[474]: <info> [1707777329.7474] manager: NetworkManager state is now CONNECTED_GLOBAL
Feb 12 17:35:32 pureos goa-daemon[775]: /org/gnome/OnlineAccounts/Accounts/account_1684968479_0: Setting AttentionNeeded to FALSE because EnsureCredentials() succeded
Feb 12 17:35:39 pureos pulseaudio[711]: Playback after capture (-85), drop sink 112
Feb 12 17:35:40 pureos systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Feb 12 17:57:41 pureos startup.desktop[1591]: [2024-02-12 17:57:41.826] [net] [error] Failed to download matrix.org/MwaqtYQMORqJkAnPJKkXGuqO: (http: 404, matrix: M_NOT_FOUND:'Not found')
Feb 12 17:57:41 pureos startup.desktop[1591]: [2024-02-12 17:57:41.827] [qml] [warning] qrc:/qml/Avatar.qml:55:5: QML Image: Failed to download image: matrix.org/MwaqtYQMORqJkAnPJKkXGuqO (qrc:/qml/Avatar.qml:55, )
Feb 12 18:03:28 pureos kernel: bq25890-charger 3-006a: NTC state UNKNOWN
Feb 12 18:14:06 pureos systemd-timesyncd[461]: Timed out waiting for reply from 173.71.73.214:123 (1.debian.pool.ntp.org).
Feb 12 18:14:06 pureos systemd-timesyncd[461]: Initial synchronization to time server 142.202.190.19:123 (1.debian.pool.ntp.org).
Feb 12 18:17:01 pureos CRON[231500]: pam_unix(cron:account): account root has expired (account expired)
Feb 12 18:17:01 pureos CRON[231500]: Authentication failure
Feb 12 18:17:01 pureos cron[231500]: Authentication failure
Feb 12 18:19:20 pureos ModemManager[644]: <info> [modem1/call2] call state changed: active -> terminated (unknown)
Feb 12 18:20:31 pureos systemd-logind[497]: Power key pressed.
Feb 12 18:20:31 pureos kernel: edt_ft5x06 2-0038: Unable to fetch data, error: -6
Feb 12 18:20:31 pureos gsd-xsettings[1014]: Failed to get current UI legacy scaling factor
Feb 12 18:20:31 pureos gsd-xsettings[1014]: Failed to get current UI legacy scaling factor
Feb 12 18:20:31 pureos gsd-color[1024]: unable to get EDID for xrandr-DSI-1: unable to get EDID for output
Feb 12 18:20:32 pureos systemd-logind[497]: Power key pressed.
Feb 12 18:20:32 pureos gsd-xsettings[1014]: Failed to get current UI legacy scaling factor
Feb 12 18:20:32 pureos gsd-xsettings[1014]: Failed to get current UI legacy scaling factor
Feb 12 18:20:32 pureos gsd-color[1024]: unable to get EDID for xrandr-DSI-1: unable to get EDID for output
Feb 12 18:20:36 pureos systemd-logind[497]: Power key pressed.
Feb 12 18:20:39 pureos systemd-logind[497]: Power key pressed.
Feb 12 18:21:00 pureos kernel: Booting Linux on physical CPU 0x0000000000 [0x410fd034]
Does this give you something?
journalctl -b -1 _COMM=phosh
Hello,
I also stumbled on this bug twice in two days. I just add the debug variable in my .profile.
Result of journalctl -b -1 _COMM=phosh only returns errors from yesterday
-- Journal begins at Thu 2023-12-14 13:17:27 CET, ends at Wed 2024-02-21 13:52:13 CET. --
Feb 20 14:21:46 pureos phosh[1023]: Unable to toggle OSK: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name sm.puri.OSK0 was not provided by any .service files
Feb 20 14:21:47 pureos phosh[1023]: Disabling emergency calls
Feb 20 16:23:42 pureos phosh[1023]: g_ascii_strcasecmp: assertion 's1 != NULL' failed
Feb 20 16:23:42 pureos phosh[1023]: g_ascii_strcasecmp: assertion 's1 != NULL' failed
Just to be sure those logs are before you added the variable?
yes, indeed.
Just to be sure : there is a typo in the last one (notification) ?
G_MESSAGES_DEBUG=phosh-lockscreen,phosh-calls-manager,phosh-call-notificaton
Yeah definately typo, sorry :S
So it should be:
G_MESSAGES_DEBUG=phosh-lockscreen,phosh-calls-manager,phosh-call-notification
I got it again, interesting.
- wifi off (hard switch off)
- I received a call while was plugged in (charging). No other notifications.
- I disconnect and pick up the call.
- rather short call, maybe one minute, the caller hang up
- I plug the usb cable again to charge, then I noticed the problem…
In this situation, I flipped ON the wifi kill switch. No Wifi, nothing on my network, no ping, no icon.
I then tried to plug in my dock (ethernet, keyboard, mouse, hdmi screen): It was recognized, I now had a mouse cursor moving on the librem screen (and the external screen). In this situation:
- again, no network, despite the ethernet plugged in the usbc dock. nothing visible, no dhcp event on the network.
- ctrl alt Fx : it freezes the mouse cursor, but no way to log in.
- ctrl alt F7 : mouse cursor moving again
- ctrl alt suppr : no effect
In a desperate move, I tried ctrl alt sysrq REISUB: It did not reboot, but phosh restarted, and I was able to unlock the screen. In this situation: - all apps have been killed
- in a terminal :
ip addr
returns seg fault !sudo dmesg
freezes instead of asking my password- I was able to run
journalctl --no-pager --since "10 hours ago" | grep 'phosh' > extract.log
, and also a full journalctl log from the last 10 hours.
- I tried to reboot (with the top menu reboot button). It freezes to black screen until I did a long press on the power button and reboot again.
I am working to remove any phone number and personal informations from the log, then I will post them in a new message.
Here are the files:
grep phosh
full log no grep
Here is the received call timestamp (I changed the line in both files):
Feb 28 17:27:17 pureos phosh[1018]: (modified) name surname +33phonenumber <= the call that makes things crash one minute later
Here is the hang up:
Feb 28 17:28:16 pureos ModemManager[771]: <info> [modem0/call12] call state changed: active -> terminated (unknown)
After that, you will see lots of weird things… It even entered sleep while plugged on the usbc dock (because there was no power). You will also see that I tried several things (plug/unplug the dock, try to login blindly in a console)
Feb 28 17:38:03 pureos phoc[803]: Output 'DP-1' added ('Iiyama North America'/'X2483/2481'/'1156494725849'), 530mm x 300mm
Well, correct, the external screen is an iiyama.
Feel free to ask questions about my config, of course.
DId you have this:
G_MESSAGES_DEBUG=phosh-lockscreen,phosh-calls-manager,phosh-call-notification
in your ~/.profile ?
yes, I have.
@guido.gunther Can you help us :S? I think my instructions are wrong - should we set the " G_MESSAGES_DEBUG=phosh-lockscreen,phosh-calls-manager,phosh-call-notification" to somewhere else than .profile?