VirtualBox causing deep recursive "add_events_to_tap" calls in macOS's "WindowServer"/"SkyLight"?

Discussions related to using VirtualBox on Mac OS X hosts.
Post Reply
a.p.
Posts: 2
Joined: 20. Jul 2018, 23:59

VirtualBox causing deep recursive "add_events_to_tap" calls in macOS's "WindowServer"/"SkyLight"?

Post by a.p. »

I suspect that VirtualBox might be causing some unexpected behavior in the macOS "WindowServer" ("SkyLight"?) process.

I've noticed this most recently with macOS 10.13.5, and VirtualBox 5.2.16 r123759 (Qt5.6.3).

VirtualBox is being used like this:
- There are typically two or three VirtualBox VMs running, started using the VirtualBox GUI front end.
- These VMs are running various Linux distros.
- They continually perform automated testing of some GUI software (their screen contents are frequently changing).
- These Linux VMs will be left running for several days at a time.

This is just based on casual observation at this point, but after the VMs have been running for about a day or more, the macOS WindowServer process appears to exhibit higher-than-expected CPU usage.

The WindowServer process CPU usage, as shown by macOS "Activity Monitor", seems to be consistently under 10% when VirtualBox isn't running. But after the VMs have been running for some time, WindowServer process CPU usage above 20% seems more common.

Out of curiosity, I used "Activity Monitor" to sample the WindowServer process. (Select the "WindowServer" process in the "Activity Monitor" process list, click on the gear-icon dropdown in the toolbar, and click "Sample Process").

I noticed that there were sections of the displayed call graph where "add_events_to_tap (in SkyLight)" appears to be being called recursively many times.

I've attached an excerpt (20180720-excerpt-virtualbox-running.txt.zip) of the call graph sampling output while the VMs are running. It shows over 1400 calls to "add_events_to_tap" for that particular sampling.

Although I don't see a direct link to VirtualBox in the sampling output, I've noticed that after saving/stopping the running VMs and then quitting VirtualBox, and then re-sampling the WindowServer process repeatedly, the sections showing the recursive "add_events_to_tap" are gone.

I've attached another excerpt (20180720-excerpt-virtualbox-just-exited.txt.zip) of the call graph sampling output, taken minutes after the earlier one, just after stopping the VMs and quitting VirtualBox. It doesn't appear to show the deep "add_events_to_tap" behavior any longer.

Unfortunately, I can't do too much debugging on this particular macOS system, and have limited access to other macOS systems.

Can anyone else with long-running VMs on macOS reproduce this possible issue?

Thanks!
Attachments
20180720-excerpt-virtualbox-just-exited.txt.zip
(8.75 KiB) Downloaded 13 times
20180720-excerpt-virtualbox-running.txt.zip
(26.69 KiB) Downloaded 26 times
a.p.
Posts: 2
Joined: 20. Jul 2018, 23:59

Re: VirtualBox causing deep recursive "add_events_to_tap" calls in macOS's "WindowServer"/"SkyLight"

Post by a.p. »

I think I've found a way to reproduce this relatively quickly.

It may also require an external keyboard with LEDs to be used on the host.

The steps to reproduce this:

1) Start two virtual machines, and put their macOS Dock icons next to one another.
2) Repeatedly click on one VM's icon, and then the other, to switch the focus between the two VM windows repeatedly. Do this, say, 50 to 100 times.
3) Use the macOS "Activity Monitor" to run "Sample Process" on the "WindowServer" process (like described in the original comment). Scroll through its output to find the recursive "add_events_to_tap" calls.
4) Repeat Step 2 another, say, 50 to 100 times.
5) Repeat Step 3. Look for there being more deeply nested "add_events_to_tap" calls than before.

Can anyone else confirm this?

I've also noticed that a call to "sHIDContinuation(_SLSEventRecord*, void*) (in SkyLight)" happens just before the recursive "add_events_to_tap (in SkyLight)" calls in the sampling output.

I'm not familiar with VirtualBox's code nor macOS programming, but looking very quickly at the code in src/VBox/Frontends/VirtualBox/src/platform/darwin/DarwinKeyboard.cpp, I'm seeing calls to various IOHID*() and CGEventTap*() functions that appear to be provided by macOS.

UIMachineLogic::eventFilter() appears to call down to the functionality implemented in DarwinKeyboard.cpp when a VM window is activated or deactivated, to keep the host's keyboard LEDs synced with the state of the VM.

The Mac system that I've noticed this problem happening on is a MacBook Pro with an external, non-Apple USB keyboard with LEDs. The keyboard LEDs do change if, for example, caps-lock is on in a guest but not the host, and the VM window gains or loses focus.

It looks like the "GUI/HidLedsSync" extra data setting can be used to disable the LED syncing.

I tried disabling the LED syncing globally by running "$ VBoxManage setextradata global 'GUI/HidLedsSync' 'off'", then restarted VirtualBox, and then started a couple of VMs. The keyboard LEDs no longer changed when the VM windows were activated/deactivated, as expected, and sampling the "WindowServer" process no longer showed the deeply recursive "add_events_to_tap" calls, even after switching between the VM windows numerous times.

So I'm thinking it might be something with the keyboard LED syncing functionality that's causing the deep, recursive "add_events_to_tap" calls shown when sampling the "WindowServer" process, which in turn might be causing the "WindowServer" process to use more and more CPU the longer the VMs have been running and the more times their windows have been activated/deactivated.
Post Reply