Ubuntu 20.10 Desktop on Pi4B - random Xorg freezes

Bug #1909680 reported by Juliane
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
linux-raspi (Ubuntu)
New
Undecided
Unassigned
Groovy
Fix Released
Undecided
Unassigned

Bug Description

My system:
Linux myRaspi 5.8.0-1010-raspi #13-Ubuntu SMP PREEMPT Wed Dec 9 17:14:07 UTC 2020 aarch64 aarch64 aarch64 GNU/Linux

I'm using
- Raspberry Pi4B 8GB
- Logitech MK120 Keyboard and Mouse (wired)

I'm using Ubuntu 20.10 Desktop and get random crashes in both of my desktops, ubuntu and lxqt. After 1 or 2 hours (often during CPU/GPU-heavy work like using Firefox), the system freezes, which means:
- Screen freezes (just shows the same picture. mouse-cursor not moving, keyboard not working)
- Keyboard not responding (e.g. Num-LED not changing when pressing Num)
- Changing to another tty via e.g. Ctrl+Alt+F3 is not working anymore
- BUT: System in the background still works. I can still hear audio (of a movie for example). Other tasks like ffmpeg-downloads are still working.

During a freeze, Alt+SysRq+k isn't changing much. I can hear the audio stopping. But the system is "too frozen" to be able to kill Xorg. I also tried killing it via ssh - no chance. Alt+SysRq+reisub works to do a Pi-restart.
These freezes occur during typing, during clicking, but also when doing nothing with mouse and keyboard (like watching a video).

A journalctl-log of the freeze (occurred at 00:08:something when typing with my keyboard) during ubuntu-desktop session is given here (I tried Alt+SysRq+k at 00:10:something without success):

[...]
Dez 26 00:07:31 myRaspi gnome-shell[166054]: JS ERROR: TypeError: windowActor is null
                                                     _addWindowEffect@resource:///org/gnome/shell/ui/closeDialog.js:90:28
                                                     vfunc_show@resource:///org/gnome/shell/ui/closeDialog.js:162:14
Dez 26 00:07:36 myRaspi gnome-shell[166054]: JS ERROR: TypeError: windowActor is null
                                                     _addWindowEffect@resource:///org/gnome/shell/ui/closeDialog.js:90:28
                                                     vfunc_show@resource:///org/gnome/shell/ui/closeDialog.js:162:14
Dez 26 00:07:41 myRaspi gnome-shell[166054]: JS ERROR: TypeError: windowActor is null
                                                     _addWindowEffect@resource:///org/gnome/shell/ui/closeDialog.js:90:28
                                                     vfunc_show@resource:///org/gnome/shell/ui/closeDialog.js:162:14
Dez 26 00:07:46 myRaspi gnome-shell[166054]: JS ERROR: TypeError: windowActor is null
                                                     _addWindowEffect@resource:///org/gnome/shell/ui/closeDialog.js:90:28
                                                     vfunc_show@resource:///org/gnome/shell/ui/closeDialog.js:162:14
Dez 26 00:07:48 myRaspi dbus-daemon[4131]: [session uid=1000 pid=4131] Activating via systemd: service name='org.freedesktop.Tracker1' unit='tracker-store.service' requested by ':1.2' (uid=1000 pid=4128 comm="/usr/libexec/tracker-miner-fs " label="unconfined")
Dez 26 00:07:48 myRaspi systemd[4119]: Starting Tracker metadata database store and lookup manager...
Dez 26 00:07:48 myRaspi dbus-daemon[4131]: [session uid=1000 pid=4131] Successfully activated service 'org.freedesktop.Tracker1'
Dez 26 00:07:48 myRaspi systemd[4119]: Started Tracker metadata database store and lookup manager.
Dez 26 00:07:49 myRaspi dbus-daemon[4131]: [session uid=1000 pid=4131] Activating via systemd: service name='org.freedesktop.Tracker1.Miner.Extract' unit='tracker-extract.service' requested by ':1.2' (uid=1000 pid=4128 comm="/usr/libexec/tracker-miner-fs " label="unconfined")
Dez 26 00:07:49 myRaspi systemd[4119]: Starting Tracker metadata extractor...
Dez 26 00:07:49 myRaspi tracker-extract[179165]: Set scheduler policy to SCHED_IDLE
Dez 26 00:07:49 myRaspi tracker-extract[179165]: Setting priority nice level to 19
Dez 26 00:07:49 myRaspi dbus-daemon[4131]: [session uid=1000 pid=4131] Successfully activated service 'org.freedesktop.Tracker1.Miner.Extract'
Dez 26 00:07:49 myRaspi systemd[4119]: Started Tracker metadata extractor.
Dez 26 00:07:51 myRaspi gnome-shell[166054]: JS ERROR: TypeError: windowActor is null
                                                     _addWindowEffect@resource:///org/gnome/shell/ui/closeDialog.js:90:28
                                                     vfunc_show@resource:///org/gnome/shell/ui/closeDialog.js:162:14
Dez 26 00:08:00 myRaspi systemd[4119]: tracker-extract.service: Succeeded.
Dez 26 00:08:01 myRaspi gnome-shell[166054]: JS ERROR: TypeError: windowActor is null
                                                     _addWindowEffect@resource:///org/gnome/shell/ui/closeDialog.js:90:28
                                                     vfunc_show@resource:///org/gnome/shell/ui/closeDialog.js:162:14
Dez 26 00:08:06 myRaspi gnome-shell[166054]: JS ERROR: TypeError: windowActor is null
                                                     _addWindowEffect@resource:///org/gnome/shell/ui/closeDialog.js:90:28
                                                     vfunc_show@resource:///org/gnome/shell/ui/closeDialog.js:162:14
Dez 26 00:08:11 myRaspi gnome-shell[166054]: JS ERROR: TypeError: windowActor is null
                                                     _addWindowEffect@resource:///org/gnome/shell/ui/closeDialog.js:90:28
                                                     vfunc_show@resource:///org/gnome/shell/ui/closeDialog.js:162:14
Dez 26 00:08:16 myRaspi gnome-shell[166054]: JS ERROR: TypeError: windowActor is null
                                                     _addWindowEffect@resource:///org/gnome/shell/ui/closeDialog.js:90:28
                                                     vfunc_show@resource:///org/gnome/shell/ui/closeDialog.js:162:14
Dez 26 00:08:20 myRaspi tracker-store[179156]: OK
Dez 26 00:08:20 myRaspi systemd[4119]: tracker-store.service: Succeeded.
Dez 26 00:08:21 myRaspi gnome-shell[166054]: JS ERROR: TypeError: windowActor is null
                                                     _addWindowEffect@resource:///org/gnome/shell/ui/closeDialog.js:90:28
                                                     vfunc_show@resource:///org/gnome/shell/ui/closeDialog.js:162:14
Dez 26 00:08:22 myRaspi /usr/libexec/gdm-x-session[165062]: (EE) event1 - Logitech USB Keyboard: client bug: event processing lagging behind by 13ms, your system is too slow
Dez 26 00:08:23 myRaspi /usr/libexec/gdm-x-session[165062]: (EE) event1 - Logitech USB Keyboard: client bug: event processing lagging behind by 22ms, your system is too slow
Dez 26 00:10:02 myRaspi rsyslogd[823]: [origin software="rsyslogd" swVersion="8.2006.0" x-pid="823" x-info="https://www.rsyslog.com"] rsyslogd was HUPed
Dez 26 00:10:35 myRaspi kernel: INFO: task Xorg:165062 blocked for more than 120 seconds.
Dez 26 00:10:35 myRaspi kernel: Tainted: G C E 5.8.0-1010-raspi #13-Ubuntu
Dez 26 00:10:35 myRaspi kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dez 26 00:10:35 myRaspi kernel: Xorg D 0 165062 165060 0x00000001
Dez 26 00:10:35 myRaspi kernel: Call trace:
Dez 26 00:10:35 myRaspi kernel: __switch_to+0xfc/0x12c
Dez 26 00:10:35 myRaspi kernel: __schedule+0x2a8/0x72c
Dez 26 00:10:35 myRaspi kernel: schedule+0x84/0x120
Dez 26 00:10:35 myRaspi kernel: schedule_timeout+0xc8/0x100
Dez 26 00:10:35 myRaspi kernel: wait_for_completion+0x8c/0x12c
Dez 26 00:10:35 myRaspi kernel: __flush_work.isra.0+0x80/0xa0
Dez 26 00:10:35 myRaspi kernel: __cancel_work_timer+0xcc/0x1e0
Dez 26 00:10:35 myRaspi kernel: cancel_delayed_work_sync+0x20/0x30
Dez 26 00:10:35 myRaspi kernel: v3d_clock_up_get+0x58/0xa0 [v3d]
Dez 26 00:10:35 myRaspi kernel: v3d_job_init+0xc4/0xe0 [v3d]
Dez 26 00:10:35 myRaspi kernel: v3d_submit_cl_ioctl+0xac/0x740 [v3d]
Dez 26 00:10:35 myRaspi kernel: drm_ioctl_kernel+0xd0/0x120 [drm]
Dez 26 00:10:35 myRaspi kernel: drm_ioctl+0x1e8/0x460 [drm]
Dez 26 00:10:35 myRaspi kernel: ksys_ioctl+0xb4/0xf4
Dez 26 00:10:35 myRaspi kernel: __arm64_sys_ioctl+0x2c/0xbc
Dez 26 00:10:35 myRaspi kernel: el0_svc_common.constprop.0+0x84/0x200
Dez 26 00:10:35 myRaspi kernel: do_el0_svc+0x30/0xa0
Dez 26 00:10:35 myRaspi kernel: el0_svc+0x18/0x50
Dez 26 00:10:35 myRaspi kernel: el0_sync_handler+0x98/0x354
Dez 26 00:10:35 myRaspi kernel: el0_sync+0x17c/0x180
Dez 26 00:10:35 myRaspi kernel: INFO: task kworker/1:1:171257 blocked for more than 120 seconds.
Dez 26 00:10:35 myRaspi kernel: Tainted: G C E 5.8.0-1010-raspi #13-Ubuntu
Dez 26 00:10:35 myRaspi kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dez 26 00:10:35 myRaspi kernel: kworker/1:1 D 0 171257 2 0x00000028
Dez 26 00:10:35 myRaspi kernel: Workqueue: events dbs_work_handler
Dez 26 00:10:35 myRaspi kernel: Call trace:
Dez 26 00:10:35 myRaspi kernel: __switch_to+0xfc/0x12c
Dez 26 00:10:35 myRaspi kernel: __schedule+0x2a8/0x72c
Dez 26 00:10:35 myRaspi kernel: schedule+0x84/0x120
Dez 26 00:10:35 myRaspi kernel: schedule_timeout+0x88/0x100
Dez 26 00:10:35 myRaspi kernel: wait_for_completion_timeout+0x8c/0x110
Dez 26 00:10:35 myRaspi kernel: mbox_send_message+0xac/0x130
Dez 26 00:10:35 myRaspi kernel: rpi_firmware_transaction+0x6c/0x110
Dez 26 00:10:35 myRaspi kernel: rpi_firmware_property_list+0xc4/0x184
Dez 26 00:10:35 myRaspi kernel: rpi_firmware_property+0x7c/0x120
Dez 26 00:10:35 myRaspi kernel: raspberrypi_fw_get_rate+0x50/0x8c
Dez 26 00:10:35 myRaspi kernel: clk_recalc+0x40/0xac
Dez 26 00:10:35 myRaspi kernel: clk_change_rate+0xf0/0x520
Dez 26 00:10:35 myRaspi kernel: clk_core_set_rate_nolock.part.0+0xe0/0xf0
Dez 26 00:10:35 myRaspi kernel: clk_core_set_rate_nolock+0xa0/0x200
Dez 26 00:10:35 myRaspi kernel: clk_set_rate+0x44/0x18c
Dez 26 00:10:35 myRaspi kernel: dev_pm_opp_set_rate+0x4b0/0x620
Dez 26 00:10:35 myRaspi kernel: set_target+0x4c/0x94
Dez 26 00:10:35 myRaspi kernel: __target_index+0xd0/0x1e4
Dez 26 00:10:35 myRaspi kernel: __cpufreq_driver_target+0x108/0x13c
Dez 26 00:10:35 myRaspi kernel: od_update+0xe8/0x130
Dez 26 00:10:35 myRaspi kernel: od_dbs_update+0x54/0xb4
Dez 26 00:10:35 myRaspi kernel: dbs_work_handler+0x4c/0x8c
Dez 26 00:10:35 myRaspi kernel: process_one_work+0x1d8/0x4a0
Dez 26 00:10:35 myRaspi kernel: worker_thread+0x74/0x3c0
Dez 26 00:10:35 myRaspi kernel: kthread+0x138/0x14c
Dez 26 00:10:35 myRaspi kernel: ret_from_fork+0x10/0x34
Dez 26 00:10:35 myRaspi kernel: INFO: task kworker/0:1:178168 blocked for more than 120 seconds.
Dez 26 00:10:35 myRaspi kernel: Tainted: G C E 5.8.0-1010-raspi #13-Ubuntu
Dez 26 00:10:35 myRaspi kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dez 26 00:10:35 myRaspi kernel: kworker/0:1 D 0 178168 2 0x00000028
Dez 26 00:10:35 myRaspi kernel: Workqueue: events v3d_clock_down_work [v3d]
[...]

Revision history for this message
Juliane (juliane11) wrote :

A fresh Xorg.0.log.old after such a crash is given as attachment. I changed some stuff like mac-address, but all relevant details are kept original.

It is full of "Logitech USB Optical Mouse/Keyboard: client bug: event processing lagging behind" messages.

Juliane (juliane11)
summary: - Ubuntu 20.10 Desktop on Pi4B - random X server crashes
+ Ubuntu 20.10 Desktop on Pi4B - random Xorg freezes
description: updated
Revision history for this message
Juliane (juliane11) wrote :

See attachment for Xorg backtrace. My steps:
- connecting to raspberry pi via ssh
- pgrep Xorg returned 4193
- sudo gdb /usr/bin/Xorg 2>&1 | tee gdb-Xorg-backtrace.txt
- (gdb) attach 4193
- (gdb) cont
After the freeze occurred:
- (gdb) thread apply all bt full

Revision history for this message
Juliane (juliane11) wrote :
Revision history for this message
Juliane (juliane11) wrote :
Revision history for this message
Juerg Haefliger (juergh) wrote :

Are there specific things you run to trigger this? Is this still an issue with an update groovy system and the latest kernel 5.8.0-1019.22? Also, do you see similar issues with hirsute http://cdimage.ubuntu.com/daily-preinstalled/current/?

Revision history for this message
Juliane (juliane11) wrote :

I don't want to jinx it, but I couldn't trigger it anymore using the latest kernel.

And regarding your first question: No, there were no specific things to trigger the freeze.

Revision history for this message
Juerg Haefliger (juergh) wrote :

Thanks for reporting back. I'll close the ticker as 'Fix Released'. Please open a new one if you encounter the issue again.

Changed in linux-raspi (Ubuntu Groovy):
status: New → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.