Very slow debug output from multi-CPU VMs

[emusic]

Hello!

I’m working with VirtualKD from its first release but always see a VERY slow debugging output to WinDbg (about 5-8 kilobytes per second). It’s too slow for real-time software debugging so I use Debug View in XP VMs to intercept debugging messages inside the guest system. It works in 2k/XP/2k3 but does not work in Vista/Win7 because Debug View uses a system event interception mechanism that does not allow to prevent debug messages from going to a kernel debugger.

I tried to enable TraceAssist in VirtualKD 2.5.4 but it did create no files in the specified log directory. Watching for vmware-vmx.exe in Process Monitor, I noticed that kdclient.dll uses RegCreateKeyEx to read “TraceAssist” and “Patcher” subkeys of “HKEY_LOCAL_MACHINESOFTWAREBazisSoftKdVMWare”, specifying KEY_ALL_ACCESS. VMMON is launched from administrative account but VMware and its VMs are started under a plain (non-privileged) user account, these subkeys are not write accessible for vmware-vmx.exe. Therefore, kdclient.dll cannot read config values and does not log to a file. I think it’s definitely a bug because there is no reason for kdclient.dll to have write access to these subkeys. vboxdd.dll has the same behavior.

I have patched kdclient.dll and vboxdd.dll, changing KEY_ALL_ACCESS to KEY_READ and file logging started to work in both VMware and VBox. But file logging is still VERY slow as to WinDbg (about 5-8 kilobytes per second). Starting a process that simply executes a 64-character OutputDebugString 1000 times (64 kb total) and watching for CPU load, I see that vmware-vmx.exe or virtualbox.exe processes consume 50% if CPU time (I have quad-core host CPU and two-CPU Windows VMs); it means that each virtual CPU is 100% loaded. Outputting 64 kb of debug messages takes 8-10 seconds, regardless of is TraceAssist enabled or not.

I tried to change number of VM processors from 2 to 1 and message speed had been dramatically increased – now it requires less than a second to output 1000 64-character messages in both VMware and VBox. Unfortunately, single-CPU VMs are not enough for my tasks.

I’m afraid there are thread synchronization problems somewhere in kdvm.dll or in kdclient.dll and vboxdd.dll. 🙁

Did somebody experienced a fast (at least dozens of kilobytes per second) debug output via kdvm.dll?

My host configuration: Core 2 Quad Q9550, XP SP3 32-bit, VMware Workstation 6.0.5, VirtualBox 4.1.4, WinDbg 6.12.0002.633, VirtualKD 2.5.4.
Guest systems are XP SP3 32-bit, 2003 Server SP2 32-bit, Vista SP2 32- and 64-bit, Win7 64-bit.

[emusic]

Tested with a hardware 1394 connection and XP/Win7 systems – in multiprocessor mode, string output it more times (5 kB/s vs 280 kB/s) slower than in uniprocessor (with ONECPU) mode.

So VirtualKD does not affect string output speed. I’m afraid Windows uses a kind of all-CPU synchronization method for string output.

[Author]

Posts