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