Tried new version xfce4-settings-4.9.0, and the issue persists. This time in xfsettingsd of course.

Comment 2 Nick Schermer 2011-08-12 22:27:29 CEST

I really need to know where in xfsettingsd the code is looping. Maybe running xfsettingsd with XFSETTINGSD_DEBUG=1 gives a clue.

I'm quite certain this is somehow related to xmodmap, which is
spawned by xfsettingsd.

In my attempt to track this down, I found out the following:

* Starting xfsettingsd with ~/.Xmodmap present causes high cpu load.
* Executing xmodmap ~/.Xmodmap while xfsettingsd is running causes
  high cpu load.
* Not having a ~/.Xmodmap file means this problem disappears.
* No xfsettingsd running and executing xmodmap means this problem
  does not occur.
* The more instructions there are in the ~/.Xmodmap file, the longer
  it will take until the cpu load reaches a normal level again.
* This problem has existed already before the xserver changes,
  but now the commit mentioned above makes it very noticeable.
* Keyboard settings are set to 'Use system defaults'.
* Apparently, other users suffer from this problem too:
  http://ubuntuforums.org/showthread.php?t=1162057
  https://bugs.launchpad.net/ubuntu/+source/xfce4-settings/+bug/363664

Here is some debug output, as suggested:

xfce4-settings(xsettings): _XSETTINGS_S0 registered on screen 0
xfce4-settings(xsettings): 30 settings changed (serial=0, len=1144)
xfce4-settings(xsettings): resource manager (xft) changed (len=567)

(xfsettingsd:25793): xfsettingsd-CRITICAL **: Stored Xfconf properties disable all outputs, aborting.
xfce4-settings(pointers): initialized xi 2.0
xfce4-settings(pointers): [MLK Wireless Mouse] buttonmap not changed
xfce4-settings(pointers): [MLK Wireless Mouse] change feedback (threshold=4, accelNum=12, accelDenom=5)
xfce4-settings(keyboards): initialized xkb 1.0
xfce4-settings(keyboards): set auto repeat on
xfce4-settings(keyboards): set key repeat (delay=500, rate=16)
xfce4-settings(keyboards): set numlock on
xfce4-settings(accessibility): stickykeys disabled
xfce4-settings(accessibility): slowkeys disabled
xfce4-settings(accessibility): bouncekeys disabled
xfce4-settings(accessibility): mousekeys disabled
xfce4-settings(keyboard-shortcuts): 53 shortcuts loaded
xfce4-settings(keyboard-layout): spawning "xmodmap ~/.Xmodmap"
xfce4-settings(workspaces): 1 desktop names set from xfconf
xfce4-settings(fontconfig): monitoring 50 paths

Quite some time is spent after printing 'desktop names set from
xfconf' and before 'monitoring 50 paths'.

Sorry, but I don't know where to look for the suspicious loop.
Maybe xmodmap causes some race condition in xfsettingsd regarding
the processing of events?

Ok. I have further tracked this down to the pointer helper.

When executing xmodmap, there will be many calls of xfce_pointers_helper_event_filter() which takes quite some time to finish. As it seems, this time is spent *between* the calls, not in the function.

I build in some more debug printing and now I can see the following events getting processed:
Enter xfce_pointers_helper_event_filter().
xfce_pointers_helper_event_filter(): user_data=21c0550 xevent_type=28
Exit xfce_pointers_helper_event_filter().
Enter xfce_pointers_helper_event_filter().
xfce_pointers_helper_event_filter(): user_data=21c0550 xevent_type=28
Exit xfce_pointers_helper_event_filter().
Enter xfce_pointers_helper_event_filter().
xfce_pointers_helper_event_filter(): user_data=21c0550 xevent_type=90
Exit xfce_pointers_helper_event_filter().
Enter xfce_pointers_helper_event_filter().
xfce_pointers_helper_event_filter(): user_data=21c0550 xevent_type=34
Exit xfce_pointers_helper_event_filter().
Enter xfce_pointers_helper_event_filter().
xfce_pointers_helper_event_filter(): user_data=21c0550 xevent_type=90
Exit xfce_pointers_helper_event_filter().
Enter xfce_pointers_helper_event_filter().
xfce_pointers_helper_event_filter(): user_data=21c0550 xevent_type=34
Exit xfce_pointers_helper_event_filter().
[...]

There are lots of these xevtype=90 and following 34.

Now man xmodmap (version 1.0.5) tells us:

BUGS
Every time a keycode expression is evaluated, the server generates a MappingNotify event on every client. This can cause some thrashing. All of the changes should be batched together and done at once. Clients that receive keyboard input and ignore MappingNotify events will not notice any changes made to keyboard mappings.

Could this be the problem?

Comment 5 Nick Schermer 2011-09-18 11:49:22 CEST

And if you print this:
g_message ("event->type=%d, device_presence_event_type=%d", event->type, helper->device_presence_event_type);

Because I think we already skip all those events.

Ok, update: If I disable only the shortcut helper in main.c, then everything is blazingly fast. So the pointers helper may not be the culprit after all, considering that disabling the pointer helper doesn't make the whole thing faster either. I will look there now to find out what slows this down.

> And if you print this:
> g_message ("event->type=%d, device_presence_event_type=%d", event->type,
> helper->device_presence_event_type);

Then I get lots of these:
xfsettingsd-Message: event->type=28, device_presence_event_type=86
xfsettingsd-Message: event->type=90, device_presence_event_type=86
xfsettingsd-Message: event->type=34, device_presence_event_type=86

I haven't got a clue what's going on. With only the shortcuts helper and the keyboard layout helper enabled, it hangs for a while somewhere in gtk_main(). If I disable the keyboard layout helper too, but use xmodmap from the command line, the same things happens. Without loading any shortcuts everything is fast. Shortcut loading itself is fast.

The cause for the high cpu load seems to be the shortcut grabber in libxfce4ui. On every xfce_shortcuts_grabber_keys_changed() (I've counted 44 produced by a one-time xmodmap call), there are lots of ungrab_all and grab_all calls. Of course, processing these takes quite some time, depending on how fast the machine is.

Note that these tests have been performed without that blamed xserver-commit, so I guess there will be even more calls with it applied.

I decided to remove my .Xmodmap file and go through the setkeycodes / xkb configuration hell. Using xmodmap instead of xkb would have been much, much easier and time-saving, but now everything works fine.

So for me, this issue is solved, though the actual problem still exists.

Comment 12 Nick Schermer 2011-09-29 10:01:12 CEST

Still not good. I've tried to reproduce it, but everything works fine here, unfortunately.

@Reproducibility: Using the latest xserver from GIT, the following test case hogs one cpu of a Core2 Duo@2.66GHz for 100% for 1 minute and 17 seconds:

for i in $(seq 1 20); do xmodmap -e "keysym a = a"; done

I guess the time spent might depend on the number of shortcuts that are configured. Another try with a completely clean profile did not take that much time.

Comment 14 Jérôme Guelfucci 2012-12-23 14:22:02 CET

I tried to reproduce it too, using your "for i in $(seq 1 20); do xmodmap -e "keysym a = a"; done" command. I get a 5% CPU usage until the command is done. This happens with xserver-xorg 7.7.

Do you still have this issue?

I can no longer reproduce this any more (xserver: 1.13.1). xmodmap still produces 50% cpu load for about 2 seconds (on a two-core machine with hyperthreading), but this is over much faster than previously where the machine was busy for over a minute. I'll try it on another machine some time later and reopen if necessary, but for the time being: Thanks for trying, and consider it fixed.