[libvirt-users] Libvirtd slowness

[Nathan March]

On 12/13/2011 12:51 AM, Michal Privoznik wrote:
> On 13.12.2011 01:48, Nathan March wrote:
>>
>> I've rebuilt it with debugging and found the following:
>>
>> 16:47:29.640: 5972: debug : remoteIOEventLoop:10599 : Giving up the buck
>> 66 0x7ff564a59010 (nil)
>> 16:47:29.640: 5972: debug : remoteIO:10773 : All done with our call 66
>> (nil) 0x7ff564a59010
>> 16:47:29.641: 5972: debug : remoteIO:10673 : Do proc=1 serial=1
>> length=48 wait=(nil)
>> 16:47:29.641: 5972: debug : remoteIO:10745 : We have the buck 1
>> 0x10c6130 0x10c6130
>> 16:47:31.670: 5972: debug : remoteIODecodeMessageLength:10066 : Got
>> length, now need 56 total (52 more)
>> 16:47:31.670: 5972: debug : remoteIOEventLoop:10599 : Giving up the buck
>> 1 0x10c6130 (nil)
>> 16:47:31.670: 5972: debug : remoteIO:10773 : All done with our call 1
>> (nil) 0x10c6130
>> 16:47:31.670: 5972: debug : doRemoteOpen:922 : Adding Handler for remote
>> events
>> 16:47:31.670: 5972: debug : virEventPollAddHandle:110 : Add handle fd=7
>> events=1 cb=0x7ff
>>
>> The 2s gap is pretty visible, not sure why yet.
> Yeah, the gap is obvious. However, this is not telling us why. Can you
> please provide the daemon logs? As far as I can tell, we see client
> here, waiting for response for 2 secs. Therefore we need to inspect the
> daemon for what take it so long.

Yep, here it is:

11:09:25.687: 7898: debug : virEventPollDispatchHandles:466 : i=5 w=6
11:09:25.687: 7898: debug : virEventPollDispatchHandles:466 : i=6 w=7
11:09:25.687: 7898: debug : virEventPollDispatchHandles:466 : i=7 w=8
11:09:25.687: 7898: debug : virEventPollDispatchHandles:479 : Dispatch 
n=7 f=17 w=8 e=1 0x21e19a0
11:09:25.688: 7903: debug : virEventPollUpdateHandle:143 : Update handle 
w=7 e=3
11:09:25.688: 7903: debug : virEventPollInterruptLocked:693 : Interrupting
11:09:25.688: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:25.789: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:25.889: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:25.990: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:26.091: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:26.191: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:26.292: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:26.393: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:26.494: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:26.595: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:26.696: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:26.796: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:26.897: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:27.025: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:27.126: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:27.227: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:27.328: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:27.429: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:27.530: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:27.631: 7898: debug : xenStoreDomainIntroduced:1354 : Some domains 
were missing, trying again
11:09:27.731: 7898: debug : virEventPollDispatchHandles:466 : i=8 w=9
11:09:27.732: 7898: debug : virEventPollCleanupTimeouts:497 : Cleanup 1
11:09:27.732: 7898: debug : virEventPollCleanupHandles:544 : Cleanup 9
11:09:27.732: 7898: debug : virEventRunDefaultImpl:188 :
11:09:27.732: 7898: debug : virEventPollCleanupTimeouts:497 : Cleanup 1
11:09:27.732: 7898: debug : virEventPollCleanupHandles:544 : Cleanup 9

This is on a freshly booted machine with no VM's running on it, so not 
sure what domains it's expecting to find?

- Nathan