[libvirt-users] Libvirtd slowness

[Nathan March]

On 12/13/2011 11:11 AM, Nathan March wrote:
> 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?

Anyone able to help out here?

- Nathan