Bug#951000: xfce4-panel: constant CPU consumption when displaying logout menu
Dear Maintainer,
could reproduce this inside a minimal amd64 qemu VM in current testing.
In my test Xorg consumed on CPU completely, another thread xfce4/panel/wrapper-2.0
used 6% when this menu is opened.
It looked like this process triggers redrawing in a fast loop, which
seem most expensive on Xorg side.
Another thing that might be related is this logging message that is
constructed but never appears in any logfile as I see:
#0 __vasprintf_internal (result_ptr=result_ptr@entry=0x7ffd775615b0, format=0x7fe32cafc6e8 "State %u for %s %p doesn't match state %u set via gtk_style_context_set_state ()", format@entry=0x7ffd775615b0 "", args=0x7ffd775615d8, mode_flags=mode_flags@entry=2) at vasprintf.c:34
...
#5 0x00007fe32c1274dd in g_log_structured_standard (log_domain=log_domain@entry=0x7fe32ca94047 "Gtk", log_level=log_level@entry=G_LOG_LEVEL_DEBUG, file=file@entry=0x7fe32cafc740 "../../../../gtk/gtkstylecontext.c", line=<optimized out>, func=<optimized out>, message_format=<optimized out>) at ../../../glib/gmessages.c:1976
#6 0x00007fe32c990a64 in gtk_style_context_push_state (context=context@entry=0x5601349a9150, state=state@entry=GTK_STATE_FLAG_NORMAL) at ../../../../gtk/gtkstylecontext.c:525
...
Kind regards,
Bernhard
# Bullseye/testing amd64 qemu VM 2020-10-18
apt update
apt dist-upgrade
apt install systemd-coredump mc htop psmisc net-tools gdb xfce4 libxfce4panel-2.0-4-dbgsym libglib2.0-0-dbgsym xserver-xorg-core-dbgsym libpixman-1-0-dbgsym libgtk-3-0-dbgsym libx11-6-dbgsym libxcb1-dbgsym linux-perf
apt build-dep libxfce4panel-2.0-4
reboot
mkdir /home/benutzer/source/libxfce4panel-2.0-4/orig -p
cd /home/benutzer/source/libxfce4panel-2.0-4/orig
apt source libxfce4panel-2.0-4
cd
# Login
# Open "User menu"
taskset -pc 14 542
taskset -pc 15 876
root@debian:~# ps aux | grep -E "^USER|876|542"
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 542 27.6 2.9 2628860 90952 tty7 Rsl+ 21:54 10:10 /usr/lib/xorg/Xorg :0 -seat seat0 -auth /var/run/lightdm/root/:0 -nolisten tcp vt7 -novtswitch
benutzer 876 1.4 5.9 203028 182108 ? Sl 21:54 0:31 /usr/lib/x86_64-linux-gnu/xfce4/panel/wrapper-2.0 /usr/lib/x86_64-linux-gnu/xfce4/panel/plugins/libactions.so 14 14680075 actions Aktionsknöpfe Abmelden, sperren oder andere Systemaktionen
perf record -p 876 -g
perf report
(gdb) bt
#0 __vasprintf_internal (result_ptr=result_ptr@entry=0x7ffd775615b0, format=0x7fe32cafc6e8 "State %u for %s %p doesn't match state %u set via gtk_style_context_set_state ()", format@entry=0x7ffd775615b0 "", args=0x7ffd775615d8, mode_flags=mode_flags@entry=2) at vasprintf.c:34
#1 0x00007fe32c016238 in __vasprintf_chk (result_ptr=result_ptr@entry=0x7ffd775615b0, flag=flag@entry=1, format=format@entry=0x7ffd775615b0 "", ap=<optimized out>) at vasprintf_chk.c:36
#2 0x00007fe32c16c47f in vasprintf (__ap=<optimized out>, __fmt=0x7ffd775615b0 "", __ptr=0x7ffd775615b0) at /usr/include/x86_64-linux-gnu/bits/stdio2.h:213
#3 g_vasprintf (string=string@entry=0x7ffd775615b0, format=<optimized out>, args=args@entry=0x7ffd775615d8) at ../../../glib/gprintf.c:337
#4 0x00007fe32c13f95d in g_strdup_vprintf (format=<optimized out>, args=args@entry=0x7ffd775615d8) at ../../../glib/gstrfuncs.c:519
#5 0x00007fe32c1274dd in g_log_structured_standard (log_domain=log_domain@entry=0x7fe32ca94047 "Gtk", log_level=log_level@entry=G_LOG_LEVEL_DEBUG, file=file@entry=0x7fe32cafc740 "../../../../gtk/gtkstylecontext.c", line=<optimized out>, func=<optimized out>, message_format=<optimized out>) at ../../../glib/gmessages.c:1976
#6 0x00007fe32c990a64 in gtk_style_context_push_state (context=context@entry=0x5601349a9150, state=state@entry=GTK_STATE_FLAG_NORMAL) at ../../../../gtk/gtkstylecontext.c:525
#7 0x00007fe32c991761 in gtk_style_context_get_property (context=0x5601349a9150, property=0x560133f65582 "background-color", state=GTK_STATE_FLAG_NORMAL, value=0x7ffd77561c00) at ../../../../gtk/gtkstylecontext.c:840
#8 0x00007fe32c991945 in gtk_style_context_get_valist (context=context@entry=0x5601349a9150, state=state@entry=GTK_STATE_FLAG_NORMAL, args=args@entry=0x7ffd77561cb0) at ../../../../gtk/gtkstylecontext.c:876
#9 0x00007fe32c991c3a in gtk_style_context_get (context=0x5601349a9150, state=state@entry=GTK_STATE_FLAG_NORMAL) at ../../../../gtk/gtkstylecontext.c:918
#10 0x0000560133f63ca3 in wrapper_plug_draw (widget=0x560134bd2470, cr=0x560134b9dc00) at wrapper-plug.c:221
#11 0x00007fe32ca3c144 in gtk_widget_draw_internal (widget=widget@entry=0x560134bd2470, cr=cr@entry=0x560134b9dc00, clip_to_size=clip_to_size@entry=1) at ../../../../gtk/gtkwidget.c:7080
#12 0x00007fe32ca45740 in gtk_widget_render (widget=widget@entry=0x560134bd2470, window=0x5601348f5900, region=<optimized out>) at ../../../../gtk/gtkwidget.c:17606
#13 0x00007fe32c8e6798 in gtk_main_do_event (event=0x7ffd77561f50) at ../../../../gtk/gtkmain.c:1843
#14 gtk_main_do_event (event=<optimized out>) at ../../../../gtk/gtkmain.c:1690
#15 0x00007fe32c5d0775 in _gdk_event_emit (event=event@entry=0x7ffd77561f50) at ../../../../gdk/gdkevents.c:73
#16 0x00007fe32c5e1971 in _gdk_window_process_updates_recurse_helper (window=0x5601348f5900, expose_region=<optimized out>) at ../../../../gdk/gdkwindow.c:3874
#17 0x00007fe32c5e3541 in gdk_window_process_updates_internal (window=0x5601348f5900) at ../../../../gdk/gdkwindow.c:4020
#18 0x00007fe32c5e3738 in gdk_window_process_updates_with_mode (window=<optimized out>, recurse_mode=<optimized out>) at ../../../../gdk/gdkwindow.c:4215
#19 0x00007fe32c2292de in _g_closure_invoke_va (closure=<optimized out>, return_value=<optimized out>, instance=<optimized out>, args=<optimized out>, n_params=<optimized out>, param_types=<optimized out>) at ../../../gobject/gclosure.c:873
#20 0x00007fe32c2419f8 in g_signal_emit_valist (instance=0x56013492a370, signal_id=<optimized out>, detail=0, var_args=var_args@entry=0x7ffd77562250) at ../../../gobject/gsignal.c:3403
#21 0x00007fe32c241bef in g_signal_emit (instance=instance@entry=0x56013492a370, signal_id=<optimized out>, detail=detail@entry=0) at ../../../gobject/gsignal.c:3550
#22 0x00007fe32c5d9a0f in _gdk_frame_clock_emit_paint (frame_clock=frame_clock@entry=0x56013492a370) at ../../../../gdk/gdkframeclock.c:657
#23 0x00007fe32c5da4fe in gdk_frame_clock_paint_idle (data=0x56013492a370) at ../../../../gdk/gdkframeclockidle.c:597
#24 0x00007fe32c5c4dc9 in gdk_threads_dispatch (data=0x560134a8a760, data@entry=<error reading variable: value has been optimized out>) at ../../../../gdk/gdk.c:769
#25 0x00007fe32c120634 in g_timeout_dispatch (source=0x560134b69790, callback=<optimized out>, user_data=<optimized out>) at ../../../glib/gmain.c:4849
#26 0x00007fe32c11faaf in g_main_dispatch (context=0x560134928830) at ../../../glib/gmain.c:3325
#27 g_main_context_dispatch (context=0x560134928830) at ../../../glib/gmain.c:4016
#28 0x00007fe32c11fe58 in g_main_context_iterate (context=0x560134928830, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../../../glib/gmain.c:4092
#29 0x00007fe32c12014b in g_main_loop_run (loop=loop@entry=0x560134a781c0) at ../../../glib/gmain.c:4290
#30 0x00007fe32c8e57a5 in gtk_main () at ../../../../gtk/gtkmain.c:1328
#31 0x0000560133f62ae6 in main (argc=<optimized out>, argv=<optimized out>) at main.c:434
Reply to: