100% CPU usage after connecting to dock (with DisplayLink)
Hi,
I've got a fairly reproducible issue with wireplumber on Archlinux. Once a week, I connect my laptop to my office Dell dock, which has two DisplayLink displays. Almost every time, I get exactly 100% CPU usage (full CPU usage from one CPU thread) from wirepumber, until I run systemctl --user restart wireplumber
.
Looking at the strace, I get this in a loop:
15:12:40.296007 epoll_wait(4, [{events=EPOLLERR|EPOLLNVAL, data={u32=4167493568, u64=102993188284352}}], 32, 0) = 1 <0.000010>
15:12:40.296042 read(24, 0x7ffe5026bac0, 72) = -1 ENODEV (No such device) <0.000010>
15:12:40.296075 write(3, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000010>
15:12:40.296110 poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=20, events=POLLIN}, {fd=26, events=POLLIN}], 4, 0) = 3 ([{fd=3, revents=POLLIN}, {fd=4, revents=POLLIN}, {fd=20, revents=POLLIN}]) <0.000011>
15:12:40.296174 read(3, "\2\0\0\0\0\0\0\0", 8) = 8 <0.000011>
15:12:40.296213 write(3, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000011>
Where ls on fd 24 gives me '/dev/snd/controlC1 (deleted)'.
With bt
I typically get:
0x000072b958e7039d in __GI___poll (fds=0x5dabf85449d0, nfds=4, timeout=0) at ../sysdeps/unix/sysv/linux/poll.c:29
29 return SYSCALL_CANCEL (poll, fds, nfds, timeout);
#0 0x000072b958e7039d in __GI___poll (fds=0x5dabf85449d0, nfds=4, timeout=0) at ../sysdeps/unix/sysv/linux/poll.c:29
#1 0x000072b9590e68fd in g_main_context_poll_unlocked (priority=200, context=0x5dabf82645c0, timeout=<optimized out>, fds=0x5dabf85449d0, n_fds=4) at ../glib/glib/gmain.c:4521
#2 g_main_context_iterate_unlocked.isra.0 (context=0x5dabf82645c0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/glib/gmain.c:4212
#3 0x000072b959085787 in g_main_loop_run (loop=0x5dabf8264750) at ../glib/glib/gmain.c:4419
#4 0x00005dabf6721519 in ??? ()
#5 0x000072b958d8dc88 in __libc_start_call_main (main=main@entry=0x5dabf6721050, argc=argc@entry=1, argv=argv@entry=0x7ffe5026c178) at ../sysdeps/nptl/libc_start_call_main.h:58
#6 0x000072b958d8dd4c in __libc_start_main_impl (main=0x5dabf6721050, argc=1, argv=0x7ffe5026c178, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffe5026c168) at ../csu/libc-start.c:360
#7 0x00005dabf6721885 in ??? ()
Or
0x000072b958e7153d in __GI___libc_write (fd=3, buf=0x7ffe5026bde0, nbytes=8) at ../sysdeps/unix/sysv/linux/write.c:26
26 return SYSCALL_CANCEL (write, fd, buf, nbytes);
#0 0x000072b958e7153d in __GI___libc_write (fd=3, buf=0x7ffe5026bde0, nbytes=8) at ../sysdeps/unix/sysv/linux/write.c:26
#1 __GI___libc_write (fd=3, buf=buf@entry=0x7ffe5026bde0, nbytes=nbytes@entry=8) at ../sysdeps/unix/sysv/linux/write.c:24
#2 0x000072b9590d4a2c in g_wakeup_signal (wakeup=0x5dabf82645a0) at ../glib/glib/gwakeup.c:256
#3 g_wakeup_signal (wakeup=0x5dabf82645a0) at ../glib/glib/gwakeup.c:245
#4 0x000072b959081220 in unblock_source (source=0x5dabf82657f0) at ../glib/glib/gmain.c:3271
#5 0x000072b959084c58 in g_main_dispatch (context=0x5dabf82645c0) at ../glib/glib/gmain.c:3366
#6 0x000072b9590e69b7 in g_main_context_dispatch_unlocked (context=0x5dabf82645c0) at ../glib/glib/gmain.c:4152
#7 g_main_context_iterate_unlocked.isra.0 (context=0x5dabf82645c0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/glib/gmain.c:4217
#8 0x000072b959085787 in g_main_loop_run (loop=0x5dabf8264750) at ../glib/glib/gmain.c:4419
#9 0x00005dabf6721519 in ??? ()
#10 0x000072b958d8dc88 in __libc_start_call_main (main=main@entry=0x5dabf6721050, argc=argc@entry=1, argv=argv@entry=0x7ffe5026c178) at ../sysdeps/nptl/libc_start_call_main.h:58
#11 0x000072b958d8dd4c in __libc_start_main_impl (main=0x5dabf6721050, argc=1, argv=0x7ffe5026c178, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffe5026c168) at ../csu/libc-start.c:360
#12 0x00005dabf6721885 in ??? ()
Or
0x000072b958e7153d in __GI___libc_write (fd=3, buf=0x7ffe5026bde0, nbytes=8) at ../sysdeps/unix/sysv/linux/write.c:26
26 return SYSCALL_CANCEL (write, fd, buf, nbytes);
#0 0x000072b958e7153d in __GI___libc_write (fd=3, buf=0x7ffe5026bde0, nbytes=8) at ../sysdeps/unix/sysv/linux/write.c:26
#1 __GI___libc_write (fd=3, buf=buf@entry=0x7ffe5026bde0, nbytes=nbytes@entry=8) at ../sysdeps/unix/sysv/linux/write.c:24
#2 0x000072b9590d4a2c in g_wakeup_signal (wakeup=0x5dabf82645a0) at ../glib/glib/gwakeup.c:256
#3 g_wakeup_signal (wakeup=0x5dabf82645a0) at ../glib/glib/gwakeup.c:245
#4 0x000072b9590814cd in block_source (source=0x5dabf82657f0) at ../glib/glib/gmain.c:3238
#5 0x000072b959084c68 in g_main_dispatch (context=0x5dabf82645c0) at ../glib/glib/gmain.c:3323
#6 0x000072b9590e69b7 in g_main_context_dispatch_unlocked (context=0x5dabf82645c0) at ../glib/glib/gmain.c:4152
#7 g_main_context_iterate_unlocked.isra.0 (context=0x5dabf82645c0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/glib/gmain.c:4217
#8 0x000072b959085787 in g_main_loop_run (loop=0x5dabf8264750) at ../glib/glib/gmain.c:4419
#9 0x00005dabf6721519 in ??? ()
#10 0x000072b958d8dc88 in __libc_start_call_main (main=main@entry=0x5dabf6721050, argc=argc@entry=1, argv=argv@entry=0x7ffe5026c178) at ../sysdeps/nptl/libc_start_call_main.h:58
#11 0x000072b958d8dd4c in __libc_start_main_impl (main=0x5dabf6721050, argc=1, argv=0x7ffe5026c178, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffe5026c168) at ../csu/libc-start.c:360
#12 0x00005dabf6721885 in ??? ()
Perf doesn't look super interesting:
Overhead Command Shared Object Symbol
17.92% wireplumber [vdso] [.] __vdso_clock_gettime
13.98% wireplumber libglib-2.0.so.0.8000.2 [.] g_source_unref_internal
12.02% wireplumber libglib-2.0.so.0.8000.2 [.] g_source_ref
5.36% wireplumber libglib-2.0.so.0.8000.2 [.] g_source_iter_next
4.62% wireplumber [unknown] [k] 0xffffffffac0001d1
No messages from journalctl -b0 --user-unit wireplumber.service -f
even with wpctl set-log-level 5
.
After running systemctl --user restart wireplumber
everything works fine with a very low CPU usage.