Attachment 584847 Details for Bug 822015 – libvirtd debug log snapshot create failed when backing file is in the NFS

libvirtd debug log snapshot create failed when backing file is in the NFS

libvirtd-fail.log (text/plain), 127.25 KB, created by Huang Wenlong on 2012-05-16 05:23:20 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Huang Wenlong

Created: 2012-05-16 05:23:20 UTC

Size: 127.25 KB

patch

obsolete

>2012-05-16 03:13:25.063+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.063+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 1
>2012-05-16 03:13:25.063+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 8
>2012-05-16 03:13:25.063+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.063+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=3 events=1
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetSocketNew:119 : localAddr=0x7fff3f8fd7e0 remoteAddr=0x7fff3f8fd750 fd=17 errfd=-1 pid=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetSocketNew:179 : RPC_SOCKET_NEW: sock=0x932150 refs=1 fd=17 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientNew:346 : sock=0x932150 auth=2 tls=(nil)
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollAddTimeout:225 : Used 1 timeout slots, adding at least 10 more
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollAddTimeout:248 : EVENT_POLL_ADD_TIMEOUT: timer=12 frequency=-1 cb=0x7f7598c756a0 opaque=0x932450 ff=(nil)
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetMessageNew:48 : msg=0x7f75992c3010 tracked=1
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientNew:380 : RPC_SERVER_CLIENT_NEW: client=0x932450 refs=1 sock=0x932150
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7f75992c3010 tx=(nil)
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientRegisterEvent:187 : Registering client event callback 1
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetSocketRef:709 : RPC_SOCKET_REF: sock=0x932150 refs=2
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollAddHandle:141 : EVENT_POLL_ADD_HANDLE: watch=9 fd=17 events=1 cb=0x7f7598c7a610 opaque=0x932150 ff=0x7f7598c7b910
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientRef:397 : RPC_SERVER_CLIENT_REF: client=0x932450 refs=3
>2012-05-16 03:13:25.064+0000: 8696: debug : virKeepAliveNew:244 : client=0x932450, interval=5, count=5
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollAddTimeout:248 : EVENT_POLL_ADD_TIMEOUT: timer=13 frequency=-1 cb=0x7f7598c7f6c0 opaque=0x931e90 ff=0x7f7598c7fa90
>2012-05-16 03:13:25.064+0000: 8696: debug : virKeepAliveNew:277 : RPC_KEEPALIVE_NEW: ka=0x931e90 client=0x932450 refs=2
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=4
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 3
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 3
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 3 timers
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=-1
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 3
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetMessageDecodeLength:149 : Got length, now need 28 total (24 more)
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7f75992c3010 tx=(nil)
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x932450 len=28 prog=536903814 vers=1 proc=66 type=0 status=0 serial=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virKeepAliveCheckMessage:408 : ka=0x931e90, client=0x932450, msg=0x7f75992c3010
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerDispatchNewMessage:199 : server=0x929c60 client=0x932450 message=0x7f75992c3010
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerProgramRef:87 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetMessageNew:48 : msg=0x7f7599282010 tracked=1
>2012-05-16 03:13:25.064+0000: 8702: debug : virNetServerHandleJob:138 : server=0x929c60 client=0x932450 message=0x7f75992c3010 prog=0x934ee0
>2012-05-16 03:13:25.064+0000: 8702: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=0 proc=66
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7f7599282010 tx=(nil)
>2012-05-16 03:13:25.064+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 3
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.064+0000: 8702: debug : remoteDispatchAuthListHelper:18 : server=0x929c60 client=0x932450 msg=0x7f75992c3010 rerr=0x7f7587a24bc0 args=0x7f7574000970 ret=0x7f7574000990
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 3
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8702: info : remoteDispatchAuthList:2091 : Bypass polkit auth for privileged client pid:8797,uid:0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8702: debug : virNetMessageEncodePayload:351 : Encode length as 36
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.064+0000: 8702: debug : virNetServerClientSendMessage:1106 : msg=0x7f75992c3010 proc=66 len=36 offset=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.064+0000: 8702: debug : virNetServerClientSendMessage:1116 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x932450 len=36 prog=536903814 vers=1 proc=66 type=1 status=0 serial=0
>2012-05-16 03:13:25.064+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 3 timers
>2012-05-16 03:13:25.065+0000: 8702: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7f7599282010 tx=0x7f75992c3010
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
>2012-05-16 03:13:25.065+0000: 8702: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=-1
>2012-05-16 03:13:25.065+0000: 8702: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=3
>2012-05-16 03:13:25.065+0000: 8702: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 03:13:25.065+0000: 8702: debug : virNetServerProgramFree:527 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.065+0000: 8702: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=4
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 3
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 3
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 3
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=5 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 3 timers
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=-1
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 3
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=2
>2012-05-16 03:13:25.065+0000: 8696: debug : virNetMessageFree:75 : msg=0x7f75992c3010 nfds=0 cb=(nil)
>2012-05-16 03:13:25.065+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7f7599282010 tx=(nil)
>2012-05-16 03:13:25.065+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 3
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 3
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 3 timers
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
>2012-05-16 03:13:25.065+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=-1
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 3
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.066+0000: 8696: debug : virNetMessageDecodeLength:149 : Got length, now need 32 total (28 more)
>2012-05-16 03:13:25.066+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7f7599282010 tx=(nil)
>2012-05-16 03:13:25.066+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.066+0000: 8696: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x932450 len=32 prog=536903814 vers=1 proc=60 type=0 status=0 serial=1
>2012-05-16 03:13:25.066+0000: 8696: debug : virKeepAliveCheckMessage:408 : ka=0x931e90, client=0x932450, msg=0x7f7599282010
>2012-05-16 03:13:25.066+0000: 8696: debug : virNetServerDispatchNewMessage:199 : server=0x929c60 client=0x932450 message=0x7f7599282010
>2012-05-16 03:13:25.066+0000: 8696: debug : virNetServerProgramRef:87 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.066+0000: 8696: debug : virNetMessageNew:48 : msg=0x9351e0 tracked=1
>2012-05-16 03:13:25.066+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=(nil)
>2012-05-16 03:13:25.066+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 3
>2012-05-16 03:13:25.066+0000: 8703: debug : virNetServerHandleJob:138 : server=0x929c60 client=0x932450 message=0x7f7599282010 prog=0x934ee0
>2012-05-16 03:13:25.066+0000: 8703: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=1 proc=60
>2012-05-16 03:13:25.066+0000: 8703: debug : remoteDispatchSupportsFeatureHelper:12643 : server=0x929c60 client=0x932450 msg=0x7f7599282010 rerr=0x7f7587023bc0 args=0x7f757c0db830 ret=0x7f757c0a0fe0
>2012-05-16 03:13:25.066+0000: 8703: debug : virKeepAliveStart:353 : RPC_KEEPALIVE_START: ka=0x931e90 client=0x932450 interval=0 count=0
>2012-05-16 03:13:25.066+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.066+0000: 8703: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 -1724540832
>2012-05-16 03:13:25.066+0000: 8703: debug : virEventPollAddTimeout:248 : EVENT_POLL_ADD_TIMEOUT: timer=14 frequency=5000 cb=0x7f7598c7f460 opaque=0x931e90 ff=0x7f7598c7fa90
>2012-05-16 03:13:25.066+0000: 8703: debug : virNetMessageEncodePayload:351 : Encode length as 32
>2012-05-16 03:13:25.066+0000: 8703: debug : virNetServerClientSendMessage:1106 : msg=0x7f7599282010 proc=60 len=32 offset=0
>2012-05-16 03:13:25.066+0000: 8703: debug : virNetServerClientSendMessage:1116 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x932450 len=32 prog=536903814 vers=1 proc=60 type=1 status=0 serial=1
>2012-05-16 03:13:25.066+0000: 8703: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=0x7f7599282010
>2012-05-16 03:13:25.066+0000: 8703: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2012-05-16 03:13:25.067+0000: 8703: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=3
>2012-05-16 03:13:25.067+0000: 8703: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 -1724540832
>2012-05-16 03:13:25.067+0000: 8703: debug : virNetServerProgramFree:527 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.067+0000: 8703: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=4
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=5 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010066
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010066 due in 4999 ms
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4999
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=2
>2012-05-16 03:13:25.067+0000: 8696: debug : virNetMessageFree:75 : msg=0x7f7599282010 nfds=0 cb=(nil)
>2012-05-16 03:13:25.067+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=(nil)
>2012-05-16 03:13:25.067+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010066
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010066 due in 4999 ms
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4999
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.067+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.067+0000: 8696: debug : virNetMessageDecodeLength:149 : Got length, now need 40 total (36 more)
>2012-05-16 03:13:25.068+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=(nil)
>2012-05-16 03:13:25.068+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.068+0000: 8696: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x932450 len=40 prog=536903814 vers=1 proc=1 type=0 status=0 serial=2
>2012-05-16 03:13:25.068+0000: 8696: debug : virKeepAliveCheckMessage:408 : ka=0x931e90, client=0x932450, msg=0x9351e0
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=14 frequency=5000
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.068+0000: 8696: debug : virNetServerDispatchNewMessage:199 : server=0x929c60 client=0x932450 message=0x9351e0
>2012-05-16 03:13:25.068+0000: 8696: debug : virNetServerProgramRef:87 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.068+0000: 8699: debug : virNetServerHandleJob:138 : server=0x929c60 client=0x932450 message=0x9351e0 prog=0x934ee0
>2012-05-16 03:13:25.068+0000: 8699: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=2 proc=1
>2012-05-16 03:13:25.068+0000: 8696: debug : virNetMessageNew:48 : msg=0x975390 tracked=1
>2012-05-16 03:13:25.068+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975390 tx=(nil)
>2012-05-16 03:13:25.068+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.068+0000: 8699: debug : remoteDispatchOpenHelper:10442 : server=0x929c60 client=0x932450 msg=0x9351e0 rerr=0x7f7589827bc0 args=0x7f75780008c0 ret=0x7f75780008e0
>2012-05-16 03:13:25.068+0000: 8699: debug : remoteDispatchOpen:636 : priv=0x9323d0 conn=(nil)
>2012-05-16 03:13:25.068+0000: 8699: debug : virConnectOpen:1349 : name=
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1155 : no name, allowing driver auto-select
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1195 : trying driver 0 (Test) ...
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1201 : driver 0 Test returned DECLINED
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1195 : trying driver 1 (ESX) ...
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1201 : driver 1 ESX returned DECLINED
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1195 : trying driver 2 (remote) ...
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1201 : driver 2 remote returned DECLINED
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1195 : trying driver 3 (QEMU) ...
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1201 : driver 3 QEMU returned SUCCESS
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1223 : network driver 0 Test returned DECLINED
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1223 : network driver 1 ESX returned DECLINED
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010068
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1223 : network driver 2 remote returned DECLINED
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010068 due in 5000 ms
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1223 : network driver 3 Network returned SUCCESS
>2012-05-16 03:13:25.068+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=5000
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1238 : interface driver 0 Test returned DECLINED
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1238 : interface driver 1 ESX returned DECLINED
>2012-05-16 03:13:25.068+0000: 8699: debug : do_open:1238 : interface driver 2 remote returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1238 : interface driver 3 Interface returned SUCCESS
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1254 : storage driver 0 Test returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1254 : storage driver 1 ESX returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1254 : storage driver 2 remote returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1254 : storage driver 3 storage returned SUCCESS
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1270 : node driver 0 Test returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1270 : node driver 1 ESX returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1270 : node driver 2 remote returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1270 : node driver 3 udevDeviceMonitor returned SUCCESS
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1286 : secret driver 0 Test returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1286 : secret driver 1 ESX returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1286 : secret driver 2 remote returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1286 : secret driver 3 secret returned SUCCESS
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1302 : nwfilter driver 0 Test returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1302 : nwfilter driver 1 ESX returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1302 : nwfilter driver 2 remote returned DECLINED
>2012-05-16 03:13:25.072+0000: 8699: debug : do_open:1302 : nwfilter driver 3 nwfilter returned SUCCESS
>2012-05-16 03:13:25.072+0000: 8699: debug : virNetMessageEncodePayload:351 : Encode length as 28
>2012-05-16 03:13:25.072+0000: 8699: debug : virNetServerClientSendMessage:1106 : msg=0x9351e0 proc=1 len=28 offset=0
>2012-05-16 03:13:25.072+0000: 8699: debug : virNetServerClientSendMessage:1116 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x932450 len=28 prog=536903814 vers=1 proc=1 type=1 status=0 serial=2
>2012-05-16 03:13:25.072+0000: 8699: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975390 tx=0x9351e0
>2012-05-16 03:13:25.072+0000: 8699: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2012-05-16 03:13:25.072+0000: 8699: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=3
>2012-05-16 03:13:25.072+0000: 8699: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 03:13:25.072+0000: 8699: debug : virNetServerProgramFree:527 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.072+0000: 8699: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=4
>2012-05-16 03:13:25.072+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.072+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.072+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.072+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=5 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010068
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010068 due in 4995 ms
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4995
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=2
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetMessageFree:75 : msg=0x9351e0 nfds=0 cb=(nil)
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975390 tx=(nil)
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010068
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010068 due in 4995 ms
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4995
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetMessageDecodeLength:149 : Got length, now need 28 total (24 more)
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975390 tx=(nil)
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x932450 len=28 prog=536903814 vers=1 proc=110 type=0 status=0 serial=3
>2012-05-16 03:13:25.073+0000: 8696: debug : virKeepAliveCheckMessage:408 : ka=0x931e90, client=0x932450, msg=0x975390
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=14 frequency=5000
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetServerDispatchNewMessage:199 : server=0x929c60 client=0x932450 message=0x975390
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetServerProgramRef:87 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetMessageNew:48 : msg=0x9351e0 tracked=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=(nil)
>2012-05-16 03:13:25.073+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.073+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8701: debug : virNetServerHandleJob:138 : server=0x929c60 client=0x932450 message=0x975390 prog=0x934ee0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8701: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=3 proc=110
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8701: debug : remoteDispatchGetURIHelper:6742 : server=0x929c60 client=0x932450 msg=0x975390 rerr=0x7f7588425bc0 args=0x7f756c0008c0 ret=0x7f756c0008e0
>2012-05-16 03:13:25.074+0000: 8701: debug : virConnectGetURI:1722 : conn=0x7f7578000c10
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.074+0000: 8701: debug : virNetMessageEncodePayload:351 : Encode length as 48
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010073
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010073 due in 4999 ms
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4999
>2012-05-16 03:13:25.074+0000: 8701: debug : virNetServerClientSendMessage:1106 : msg=0x975390 proc=110 len=48 offset=0
>2012-05-16 03:13:25.074+0000: 8701: debug : virNetServerClientSendMessage:1116 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x932450 len=48 prog=536903814 vers=1 proc=110 type=1 status=0 serial=3
>2012-05-16 03:13:25.074+0000: 8701: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=0x975390
>2012-05-16 03:13:25.074+0000: 8701: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2012-05-16 03:13:25.074+0000: 8701: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=3
>2012-05-16 03:13:25.074+0000: 8701: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 03:13:25.074+0000: 8701: debug : virNetServerProgramFree:527 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.074+0000: 8701: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=4
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=5 d=0
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010073
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010073 due in 4999 ms
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4999
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.074+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=2
>2012-05-16 03:13:25.074+0000: 8696: debug : virNetMessageFree:75 : msg=0x975390 nfds=0 cb=(nil)
>2012-05-16 03:13:25.074+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=(nil)
>2012-05-16 03:13:25.074+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010073
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010073 due in 4998 ms
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4998
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.075+0000: 8696: debug : virNetMessageDecodeLength:149 : Got length, now need 36 total (32 more)
>2012-05-16 03:13:25.075+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=(nil)
>2012-05-16 03:13:25.075+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.075+0000: 8696: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x932450 len=36 prog=536903814 vers=1 proc=23 type=0 status=0 serial=4
>2012-05-16 03:13:25.075+0000: 8696: debug : virKeepAliveCheckMessage:408 : ka=0x931e90, client=0x932450, msg=0x9351e0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=14 frequency=5000
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.075+0000: 8696: debug : virNetServerDispatchNewMessage:199 : server=0x929c60 client=0x932450 message=0x9351e0
>2012-05-16 03:13:25.075+0000: 8696: debug : virNetServerProgramRef:87 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.075+0000: 8696: debug : virNetMessageNew:48 : msg=0x975250 tracked=1
>2012-05-16 03:13:25.075+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975250 tx=(nil)
>2012-05-16 03:13:25.075+0000: 8698: debug : virNetServerHandleJob:138 : server=0x929c60 client=0x932450 message=0x9351e0 prog=0x934ee0
>2012-05-16 03:13:25.075+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.075+0000: 8698: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=4 proc=23
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.075+0000: 8698: debug : remoteDispatchDomainLookupByNameHelper:2748 : server=0x929c60 client=0x932450 msg=0x9351e0 rerr=0x7f758a228bc0 args=0x7f75700008c0 ret=0x7f75700008e0
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.075+0000: 8698: debug : virDomainLookupByName:2146 : conn=0x7f7578000c10, name=s1
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.075+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.075+0000: 8698: debug : virDomainFree:2313 : dom=0x7f7570000a30, (VM: name=s1, uuid=04c31b46-4c4d-9952-2dd4-ac9849e41a35)
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8698: debug : virUnrefDomain:276 : unref domain 0x7f7570000a30 s1 1
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8698: debug : virReleaseDomain:238 : release domain 0x7f7570000a30 s1 04c31b46-4c4d-9952-2dd4-ac9849e41a35
>2012-05-16 03:13:25.076+0000: 8698: debug : virReleaseDomain:246 : unref connection 0x7f7578000c10 2
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8698: debug : virNetMessageEncodePayload:351 : Encode length as 56
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8698: debug : virNetServerClientSendMessage:1106 : msg=0x9351e0 proc=23 len=56 offset=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8698: debug : virNetServerClientSendMessage:1116 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x932450 len=56 prog=536903814 vers=1 proc=23 type=1 status=0 serial=4
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.076+0000: 8698: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975250 tx=0x9351e0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8698: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.076+0000: 8698: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=3
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010075
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010075 due in 4999 ms
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4999
>2012-05-16 03:13:25.076+0000: 8698: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 03:13:25.076+0000: 8698: debug : virNetServerProgramFree:527 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.076+0000: 8698: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=4
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=5 d=0
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010075
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010075 due in 4999 ms
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4999
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=2
>2012-05-16 03:13:25.076+0000: 8696: debug : virNetMessageFree:75 : msg=0x9351e0 nfds=0 cb=(nil)
>2012-05-16 03:13:25.076+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975250 tx=(nil)
>2012-05-16 03:13:25.076+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.076+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010075
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010075 due in 4998 ms
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4998
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.077+0000: 8696: debug : virNetMessageDecodeLength:149 : Got length, now need 84 total (80 more)
>2012-05-16 03:13:25.077+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975250 tx=(nil)
>2012-05-16 03:13:25.077+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.077+0000: 8696: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x932450 len=84 prog=536903814 vers=1 proc=185 type=0 status=0 serial=5
>2012-05-16 03:13:25.077+0000: 8696: debug : virKeepAliveCheckMessage:408 : ka=0x931e90, client=0x932450, msg=0x975250
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=14 frequency=5000
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.077+0000: 8696: debug : virNetServerDispatchNewMessage:199 : server=0x929c60 client=0x932450 message=0x975250
>2012-05-16 03:13:25.077+0000: 8696: debug : virNetServerProgramRef:87 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.077+0000: 8696: debug : virNetMessageNew:48 : msg=0x9351e0 tracked=1
>2012-05-16 03:13:25.077+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=(nil)
>2012-05-16 03:13:25.077+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.077+0000: 8697: debug : virNetServerHandleJob:138 : server=0x929c60 client=0x932450 message=0x975250 prog=0x934ee0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.077+0000: 8697: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=5 proc=185
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8697: debug : remoteDispatchDomainSnapshotCreateXMLHelper:5460 : server=0x929c60 client=0x932450 msg=0x975250 rerr=0x7f758ac29bc0 args=0x7f75640008c0 ret=0x7f7564000900
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8697: debug : virDomainSnapshotCreateXML:17073 : dom=0x7f7564000a50, (VM: name=s1, uuid=04c31b46-4c4d-9952-2dd4-ac9849e41a35), xmlDesc=<domainsnapshot/>, flags=10
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8697: debug : qemuProcessAutoDestroyActive:4203 : vm=s1
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010077
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010077 due in 5000 ms
>2012-05-16 03:13:25.077+0000: 8697: debug : qemuDriverCloseCallbackGet:605 : vm=s1, uuid=04c31b46-4c4d-9952-2dd4-ac9849e41a35, conn=(nil)
>2012-05-16 03:13:25.077+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=5000
>2012-05-16 03:13:25.077+0000: 8697: debug : qemuDriverCloseCallbackGet:611 : cb=(nil)
>2012-05-16 03:13:25.078+0000: 8697: debug : virDomainSnapshotObjNew:13881 : obj=0x7f7564007370
>2012-05-16 03:13:25.078+0000: 8697: debug : virDomainObjRef:1623 : obj=0x7f757c00eb80 refs=3
>2012-05-16 03:13:25.078+0000: 8697: debug : qemuDomainObjBeginJobInternal:753 : Starting job: modify (async=none)
>2012-05-16 03:13:25.113+0000: 8697: debug : virCgroupNew:603 : New group /libvirt/qemu/s1
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupDetect:262 : Detected mount/mapping 0:cpu at /cgroup/cpu in 
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupDetect:262 : Detected mount/mapping 1:cpuacct at /cgroup/cpuacct in 
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupDetect:262 : Detected mount/mapping 2:cpuset at /cgroup/cpuset in 
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupDetect:262 : Detected mount/mapping 3:memory at /cgroup/memory in 
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupDetect:262 : Detected mount/mapping 4:devices at /cgroup/devices in 
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupDetect:262 : Detected mount/mapping 5:freezer at /cgroup/freezer in 
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupDetect:262 : Detected mount/mapping 6:blkio at /cgroup/blkio in 
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupMakeGroup:524 : Make group /libvirt/qemu/s1
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupMakeGroup:546 : Make controller /cgroup/cpu/libvirt/qemu/s1/
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupMakeGroup:546 : Make controller /cgroup/cpuacct/libvirt/qemu/s1/
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupMakeGroup:546 : Make controller /cgroup/cpuset/libvirt/qemu/s1/
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupMakeGroup:546 : Make controller /cgroup/memory/libvirt/qemu/s1/
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupMakeGroup:546 : Make controller /cgroup/devices/libvirt/qemu/s1/
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupMakeGroup:546 : Make controller /cgroup/freezer/libvirt/qemu/s1/
>2012-05-16 03:13:25.114+0000: 8697: debug : virCgroupMakeGroup:546 : Make controller /cgroup/blkio/libvirt/qemu/s1/
>2012-05-16 03:13:25.114+0000: 8697: debug : qemuMonitorRef:201 : QEMU_MONITOR_REF: mon=0x7f7574000d60 refs=3
>2012-05-16 03:13:25.114+0000: 8697: debug : virStorageFileIsSharedFSType:1031 : Check if path /var/lib/libvirt/images/new.1337138005 with FS magic 61267 is shared
>2012-05-16 03:13:25.114+0000: 8697: debug : virDomainLockManagerNew:123 : plugin=0x7f757c008a10 dom=0x7f757c00eb80 withResources=0
>2012-05-16 03:13:25.114+0000: 8697: debug : virLockManagerNew:291 : plugin=0x7f757c008a10 type=0 nparams=4 params=0x7f758ac29650 flags=0
>2012-05-16 03:13:25.114+0000: 8697: debug : virLockManagerLogParams:98 :   key=uuid type=uuid value=04c31b46-4c4d-9952-2dd4-ac9849e41a35
>2012-05-16 03:13:25.114+0000: 8697: debug : virLockManagerLogParams:94 :   key=name type=string value=s1
>2012-05-16 03:13:25.114+0000: 8697: debug : virLockManagerLogParams:82 :   key=id type=uint value=1
>2012-05-16 03:13:25.114+0000: 8697: debug : virLockManagerLogParams:82 :   key=pid type=uint value=8560
>2012-05-16 03:13:25.114+0000: 8697: debug : virDomainLockManagerAddDisk:86 : Add disk /var/lib/libvirt/images/new.1337138005
>2012-05-16 03:13:25.114+0000: 8697: debug : virLockManagerAddResource:320 : lock=0x7f756400e300 type=0 name=/var/lib/libvirt/images/new.1337138005 nparams=0 params=(nil) flags=0
>2012-05-16 03:13:25.114+0000: 8697: debug : virLockManagerAcquire:337 : lock=0x7f756400e300 state='(null)' flags=0 fd=(nil)
>2012-05-16 03:13:25.114+0000: 8697: debug : virLockManagerFree:374 : lock=0x7f756400e300
>2012-05-16 03:13:25.114+0000: 8697: debug : qemuSetupDiskPathAllow:70 : Process path /var/lib/libvirt/images/new.1337138005 for disk
>2012-05-16 03:13:25.114+0000: 8697: info : virSecurityDACSetOwnership:99 : Setting DAC user and group on '/var/lib/libvirt/images/new.1337138005' to '107:107'
>2012-05-16 03:13:25.114+0000: 8697: debug : qemuMonitorDiskSnapshot:2620 : mon=0x7f7574000d60, actions=0x7f7564001c30, device=drive-ide0-0-0, file=/var/lib/libvirt/images/new.1337138005, format=qcow2, reuse=0
>2012-05-16 03:13:25.116+0000: 8697: debug : qemuMonitorTransaction:2679 : mon=0x7f7574000d60, actions=0x7f7564001c30
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToString:1071 : object=0x7f756400e8d0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f756400e8d0 type=0 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f756400e850 type=2 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564002340 type=0 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564001c30 type=1 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f756400dc20 type=0 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f75640022b0 type=2 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564000b10 type=0 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564000b30 type=2 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564002030 type=2 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564002010 type=2 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f75640023c0 type=2 gen=0x7f75640074e0
>2012-05-16 03:13:25.116+0000: 8697: debug : virJSONValueToString:1105 : result={"execute":"transaction","arguments":{"actions":[{"type":"blockdev-snapshot-sync","data":{"device":"drive-ide0-0-0","snapshot-file":"/var/lib/libvirt/images/new.1337138005","format":"qcow2"}}]},"id":"libvirt-5"}
>2012-05-16 03:13:25.116+0000: 8697: debug : qemuMonitorJSONCommandWithFd:248 : Send command '{"execute":"transaction","arguments":{"actions":[{"type":"blockdev-snapshot-sync","data":{"device":"drive-ide0-0-0","snapshot-file":"/var/lib/libvirt/images/new.1337138005","format":"qcow2"}}]},"id":"libvirt-5"}' for write with FD -1
>2012-05-16 03:13:25.116+0000: 8697: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=8 events=15
>2012-05-16 03:13:25.116+0000: 8697: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 03:13:25.116+0000: 8697: debug : qemuMonitorSend:823 : QEMU_MONITOR_SEND_MSG: mon=0x7f7574000d60 msg={"execute":"transaction","arguments":{"actions":[{"type":"blockdev-snapshot-sync","data":{"device":"drive-ide0-0-0","snapshot-file":"/var/lib/libvirt/images/new.1337138005","format":"qcow2"}}]},"id":"libvirt-5"}
> fd=-1
>2012-05-16 03:13:25.116+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.116+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.116+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.116+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=29 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010077
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010077 due in 4960 ms
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4960
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=8 events=2
>2012-05-16 03:13:25.117+0000: 8696: debug : qemuMonitorRef:201 : QEMU_MONITOR_REF: mon=0x7f7574000d60 refs=4
>2012-05-16 03:13:25.117+0000: 8696: debug : qemuMonitorIOWrite:432 : QEMU_MONITOR_IO_WRITE: mon=0x7f7574000d60 buf={"execute":"transaction","arguments":{"actions":[{"type":"blockdev-snapshot-sync","data":{"device":"drive-ide0-0-0","snapshot-file":"/var/lib/libvirt/images/new.1337138005","format":"qcow2"}}]},"id":"libvirt-5"}
> len=213 ret=213 errno=11
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=8 events=13
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.117+0000: 8696: debug : qemuMonitorUnref:210 : QEMU_MONITOR_UNREF: mon=0x7f7574000d60 refs=3
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010077
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010077 due in 4960 ms
>2012-05-16 03:13:25.117+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4960
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=8 events=1
>2012-05-16 03:13:25.138+0000: 8696: debug : qemuMonitorRef:201 : QEMU_MONITOR_REF: mon=0x7f7574000d60 refs=4
>2012-05-16 03:13:25.138+0000: 8696: debug : qemuMonitorIOProcess:327 : QEMU_MONITOR_IO_PROCESS: mon=0x7f7574000d60 buf={"id": "libvirt-5", "error": {"class": "OpenFileFailed", "desc": "Could not open '/var/lib/libvirt/images/new.1337138005'", "data": {"filename": "/var/lib/libvirt/images/new.1337138005"}}}
> len=190
>2012-05-16 03:13:25.138+0000: 8696: debug : qemuMonitorJSONIOProcessLine:135 : Line [{"id": "libvirt-5", "error": {"class": "OpenFileFailed", "desc": "Could not open '/var/lib/libvirt/images/new.1337138005'", "data": {"filename": "/var/lib/libvirt/images/new.1337138005"}}}]
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONValueFromString:948 : string={"id": "libvirt-5", "error": {"class": "OpenFileFailed", "desc": "Could not open '/var/lib/libvirt/images/new.1337138005'", "data": {"filename": "/var/lib/libvirt/images/new.1337138005"}}}
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleStartMap:825 : parser=0x7fff3f8fd6e0
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleMapKey:806 : parser=0x7fff3f8fd6e0 key=0x9307f2
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleString:786 : parser=0x7fff3f8fd6e0 str=0x9307f8
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleMapKey:806 : parser=0x7fff3f8fd6e0 key=0x930805
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleStartMap:825 : parser=0x7fff3f8fd6e0
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleMapKey:806 : parser=0x7fff3f8fd6e0 key=0x93080f
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleString:786 : parser=0x7fff3f8fd6e0 str=0x930818
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleMapKey:806 : parser=0x7fff3f8fd6e0 key=0x93082a
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleString:786 : parser=0x7fff3f8fd6e0 str=0x930832
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleMapKey:806 : parser=0x7fff3f8fd6e0 key=0x93086d
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleStartMap:825 : parser=0x7fff3f8fd6e0
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleMapKey:806 : parser=0x7fff3f8fd6e0 key=0x930876
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleString:786 : parser=0x7fff3f8fd6e0 str=0x930882
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleEndMap:854 : parser=0x7fff3f8fd6e0
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleEndMap:854 : parser=0x7fff3f8fd6e0
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONParserHandleEndMap:854 : parser=0x7fff3f8fd6e0
>2012-05-16 03:13:25.138+0000: 8696: debug : virJSONValueFromString:992 : result=0x907ab0
>2012-05-16 03:13:25.138+0000: 8696: debug : qemuMonitorJSONIOProcessLine:155 : QEMU_MONITOR_RECV_REPLY: mon=0x7f7574000d60 reply={"id": "libvirt-5", "error": {"class": "OpenFileFailed", "desc": "Could not open '/var/lib/libvirt/images/new.1337138005'", "data": {"filename": "/var/lib/libvirt/images/new.1337138005"}}}
>2012-05-16 03:13:25.138+0000: 8696: debug : qemuMonitorJSONIOProcess:206 : Total used 190 bytes out of 190 available in buffer
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=8 events=13
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.138+0000: 8696: debug : qemuMonitorUnref:210 : QEMU_MONITOR_UNREF: mon=0x7f7574000d60 refs=3
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.138+0000: 8697: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=8 events=13
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010077
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010077 due in 4939 ms
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4939
>2012-05-16 03:13:25.138+0000: 8697: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 03:13:25.138+0000: 8697: debug : qemuMonitorJSONCommandWithFd:253 : Receive command reply ret=0 rxObject=0x907ab0
>2012-05-16 03:13:25.138+0000: 8697: debug : virJSONValueToString:1071 : object=0x7f756400e8d0
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.138+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.138+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f756400e8d0 type=0 gen=0x7f75640077d0
>2012-05-16 03:13:25.138+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f756400e850 type=2 gen=0x7f75640077d0
>2012-05-16 03:13:25.138+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564002340 type=0 gen=0x7f75640077d0
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564001c30 type=1 gen=0x7f75640077d0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f756400dc20 type=0 gen=0x7f75640077d0
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f75640022b0 type=2 gen=0x7f75640077d0
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564000b10 type=0 gen=0x7f75640077d0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564000b30 type=2 gen=0x7f75640077d0
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564002030 type=2 gen=0x7f75640077d0
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f7564002010 type=2 gen=0x7f75640077d0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x7f75640023c0 type=2 gen=0x7f75640077d0
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToString:1105 : result={"execute":"transaction","arguments":{"actions":[{"type":"blockdev-snapshot-sync","data":{"device":"drive-ide0-0-0","snapshot-file":"/var/lib/libvirt/images/new.1337138005","format":"qcow2"}}]},"id":"libvirt-5"}
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToString:1071 : object=0x907ab0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x907ab0 type=0 gen=0x7f75640073a0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x9079d0 type=2 gen=0x7f75640073a0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x9077b0 type=0 gen=0x7f75640073a0
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x932090 type=2 gen=0x7f75640073a0
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x907600 type=2 gen=0x7f75640073a0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x907670 type=0 gen=0x7f75640073a0
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToStringOne:1003 : object=0x92fc60 type=2 gen=0x7f75640073a0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.139+0000: 8697: debug : virJSONValueToString:1105 : result={"id":"libvirt-5","error":{"class":"OpenFileFailed","desc":"Could not open '/var/lib/libvirt/images/new.1337138005'","data":{"filename":"/var/lib/libvirt/images/new.1337138005"}}}
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.139+0000: 8697: debug : qemuMonitorJSONCheckError:327 : unable to execute QEMU command {"execute":"transaction","arguments":{"actions":[{"type":"blockdev-snapshot-sync","data":{"device":"drive-ide0-0-0","snapshot-file":"/var/lib/libvirt/images/new.1337138005","format":"qcow2"}}]},"id":"libvirt-5"}: {"id":"libvirt-5","error":{"class":"OpenFileFailed","desc":"Could not open '/var/lib/libvirt/images/new.1337138005'","data":{"filename":"/var/lib/libvirt/images/new.1337138005"}}}
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.139+0000: 8697: error : qemuMonitorJSONCheckError:338 : internal error unable to execute QEMU command 'transaction': Could not open '/var/lib/libvirt/images/new.1337138005'
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.139+0000: 8697: info : virSecurityDACRestoreSecurityFileLabel:139 : Restoring DAC user and group on '/var/lib/libvirt/images/new.1337138005'
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.139+0000: 8697: info : virSecurityDACSetOwnership:99 : Setting DAC user and group on '/var/lib/libvirt/images/new.1337138005' to '0:0'
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.139+0000: 8697: debug : qemuTeardownDiskPathDeny:114 : Process path /var/lib/libvirt/images/new.1337138005 for disk
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010077
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010077 due in 4938 ms
>2012-05-16 03:13:25.139+0000: 8697: debug : virDomainLockManagerNew:123 : plugin=0x7f757c008a10 dom=0x7f757c00eb80 withResources=0
>2012-05-16 03:13:25.139+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4938
>2012-05-16 03:13:25.139+0000: 8697: debug : virLockManagerNew:291 : plugin=0x7f757c008a10 type=0 nparams=4 params=0x7f758ac29650 flags=0
>2012-05-16 03:13:25.139+0000: 8697: debug : virLockManagerLogParams:98 :   key=uuid type=uuid value=04c31b46-4c4d-9952-2dd4-ac9849e41a35
>2012-05-16 03:13:25.139+0000: 8697: debug : virLockManagerLogParams:94 :   key=name type=string value=s1
>2012-05-16 03:13:25.139+0000: 8697: debug : virLockManagerLogParams:82 :   key=id type=uint value=1
>2012-05-16 03:13:25.139+0000: 8697: debug : virLockManagerLogParams:82 :   key=pid type=uint value=8560
>2012-05-16 03:13:25.139+0000: 8697: debug : virDomainLockManagerAddDisk:86 : Add disk /var/lib/libvirt/images/new.1337138005
>2012-05-16 03:13:25.139+0000: 8697: debug : virLockManagerAddResource:320 : lock=0x7f7564002390 type=0 name=/var/lib/libvirt/images/new.1337138005 nparams=0 params=(nil) flags=0
>2012-05-16 03:13:25.139+0000: 8697: debug : virLockManagerRelease:352 : lock=0x7f7564002390 state=(nil) flags=0
>2012-05-16 03:13:25.139+0000: 8697: debug : virLockManagerFree:374 : lock=0x7f7564002390
>2012-05-16 03:13:25.139+0000: 8697: debug : qemuMonitorUnref:210 : QEMU_MONITOR_UNREF: mon=0x7f7574000d60 refs=2
>2012-05-16 03:13:25.139+0000: 8697: debug : qemuDomainObjEndJob:870 : Stopping job: modify (async=none)
>2012-05-16 03:13:25.180+0000: 8697: debug : virDomainObjUnref:1630 : obj=0x7f757c00eb80 refs=2
>2012-05-16 03:13:25.180+0000: 8697: debug : virDomainSnapshotObjFree:13891 : obj=0x7f7564007370
>2012-05-16 03:13:25.180+0000: 8697: debug : virDomainFree:2313 : dom=0x7f7564000a50, (VM: name=s1, uuid=04c31b46-4c4d-9952-2dd4-ac9849e41a35)
>2012-05-16 03:13:25.180+0000: 8697: debug : virUnrefDomain:276 : unref domain 0x7f7564000a50 s1 1
>2012-05-16 03:13:25.180+0000: 8697: debug : virReleaseDomain:238 : release domain 0x7f7564000a50 s1 04c31b46-4c4d-9952-2dd4-ac9849e41a35
>2012-05-16 03:13:25.180+0000: 8697: debug : virReleaseDomain:246 : unref connection 0x7f7578000c10 2
>2012-05-16 03:13:25.180+0000: 8697: debug : virNetServerProgramSendError:135 : prog=536903814 ver=1 proc=185 type=1 serial=5 msg=0x975250 rerr=0x7f758ac29bc0
>2012-05-16 03:13:25.180+0000: 8697: debug : virNetMessageEncodePayload:351 : Encode length as 324
>2012-05-16 03:13:25.180+0000: 8697: debug : virNetServerClientSendMessage:1106 : msg=0x975250 proc=185 len=324 offset=0
>2012-05-16 03:13:25.180+0000: 8697: debug : virNetServerClientSendMessage:1116 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x932450 len=324 prog=536903814 vers=1 proc=185 type=1 status=1 serial=5
>2012-05-16 03:13:25.180+0000: 8697: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=0x975250
>2012-05-16 03:13:25.180+0000: 8697: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2012-05-16 03:13:25.180+0000: 8697: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=3
>2012-05-16 03:13:25.180+0000: 8697: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 03:13:25.180+0000: 8697: debug : virNetServerProgramFree:527 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.180+0000: 8697: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=4
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.180+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=5 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010077
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010077 due in 4896 ms
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4896
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=2
>2012-05-16 03:13:25.181+0000: 8696: debug : virNetMessageFree:75 : msg=0x975250 nfds=0 cb=(nil)
>2012-05-16 03:13:25.181+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=(nil)
>2012-05-16 03:13:25.181+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010077
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010077 due in 4896 ms
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4896
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.181+0000: 8696: debug : virNetMessageDecodeLength:149 : Got length, now need 28 total (24 more)
>2012-05-16 03:13:25.181+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x9351e0 tx=(nil)
>2012-05-16 03:13:25.181+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.181+0000: 8696: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x932450 len=28 prog=536903814 vers=1 proc=2 type=0 status=0 serial=6
>2012-05-16 03:13:25.181+0000: 8696: debug : virKeepAliveCheckMessage:408 : ka=0x931e90, client=0x932450, msg=0x9351e0
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=14 frequency=5000
>2012-05-16 03:13:25.181+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.181+0000: 8696: debug : virNetServerDispatchNewMessage:199 : server=0x929c60 client=0x932450 message=0x9351e0
>2012-05-16 03:13:25.182+0000: 8696: debug : virNetServerProgramRef:87 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.182+0000: 8702: debug : virNetServerHandleJob:138 : server=0x929c60 client=0x932450 message=0x9351e0 prog=0x934ee0
>2012-05-16 03:13:25.182+0000: 8696: debug : virNetMessageNew:48 : msg=0x975250 tracked=1
>2012-05-16 03:13:25.182+0000: 8702: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=6 proc=2
>2012-05-16 03:13:25.182+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975250 tx=(nil)
>2012-05-16 03:13:25.182+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.182+0000: 8702: debug : remoteDispatchCloseHelper:124 : server=0x929c60 client=0x932450 msg=0x9351e0 rerr=0x7f7587a24bc0 args=0x7f7574000a90 ret=0x7f7574000970
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.182+0000: 8702: debug : virNetMessageEncodePayload:351 : Encode length as 28
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.182+0000: 8702: debug : virNetServerClientSendMessage:1106 : msg=0x9351e0 proc=2 len=28 offset=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.182+0000: 8702: debug : virNetServerClientSendMessage:1116 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x932450 len=28 prog=536903814 vers=1 proc=2 type=1 status=0 serial=6
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8702: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975250 tx=0x9351e0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8702: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8702: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=3
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010181
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010181 due in 4999 ms
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4999
>2012-05-16 03:13:25.182+0000: 8702: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 03:13:25.182+0000: 8702: debug : virNetServerProgramFree:527 : prog=0x934ee0 refs=3
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.182+0000: 8702: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=4
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=9, f=17 e=5 d=0
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 4 timers
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337138010181
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 1337138010181 due in 4999 ms
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=9 imeout=4999
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchTimeouts:415 : Dispatch 4
>2012-05-16 03:13:25.182+0000: 8696: debug : virEventPollDispatchHandles:460 : Dispatch 9
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollDispatchHandles:474 : i=7 w=8
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollDispatchHandles:474 : i=8 w=9
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=9 events=2
>2012-05-16 03:13:25.183+0000: 8696: debug : virNetMessageFree:75 : msg=0x9351e0 nfds=0 cb=(nil)
>2012-05-16 03:13:25.183+0000: 8696: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x975250 tx=(nil)
>2012-05-16 03:13:25.183+0000: 8696: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=9 events=1
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.183+0000: 8696: debug : virNetServerClientClose:632 : client=0x932450 refs=3
>2012-05-16 03:13:25.183+0000: 8696: debug : virKeepAliveStop:382 : RPC_KEEPALIVE_STOP: ka=0x931e90 client=0x932450
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollRemoveTimeout:293 : EVENT_POLL_REMOVE_TIMEOUT: timer=14
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 -1724540832
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollRemoveTimeout:293 : EVENT_POLL_REMOVE_TIMEOUT: timer=13
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 -1724540832
>2012-05-16 03:13:25.183+0000: 8696: debug : virKeepAliveFree:304 : RPC_KEEPALIVE_FREE: ka=0x931e90 client=0x932450 refs=3
>2012-05-16 03:13:25.183+0000: 8696: debug : daemonRemoveAllClientStreams:493 : stream=(nil)
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollRemoveHandle:180 : EVENT_POLL_REMOVE_HANDLE: watch=9
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollRemoveHandle:193 : mark delete 8 17
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 -1724540832
>2012-05-16 03:13:25.183+0000: 8696: debug : virNetMessageFree:75 : msg=0x975250 nfds=0 cb=(nil)
>2012-05-16 03:13:25.183+0000: 8696: debug : virNetSocketFree:722 : RPC_SOCKET_FREE: sock=0x932150 refs=2
>2012-05-16 03:13:25.183+0000: 8696: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=3
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollCleanupTimeouts:506 : Cleanup 4
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollCleanupTimeouts:519 : EVENT_POLL_PURGE_TIMEOUT: timer=13
>2012-05-16 03:13:25.183+0000: 8696: debug : virKeepAliveFree:304 : RPC_KEEPALIVE_FREE: ka=0x931e90 client=0x932450 refs=2
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollCleanupTimeouts:519 : EVENT_POLL_PURGE_TIMEOUT: timer=14
>2012-05-16 03:13:25.183+0000: 8696: debug : virKeepAliveFree:304 : RPC_KEEPALIVE_FREE: ka=0x931e90 client=0x932450 refs=1
>2012-05-16 03:13:25.183+0000: 8696: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=2
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollCleanupHandles:554 : Cleanup 9
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollCleanupHandles:567 : EVENT_POLL_PURGE_HANDLE: watch=9
>2012-05-16 03:13:25.183+0000: 8696: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x932450 refs=1
>2012-05-16 03:13:25.183+0000: 8696: debug : virConnectClose:1462 : conn=0x7f7578000c10
>2012-05-16 03:13:25.183+0000: 8696: debug : virUnrefConnect:145 : unref connection 0x7f7578000c10 1
>2012-05-16 03:13:25.183+0000: 8696: debug : virReleaseConnect:94 : release connection 0x7f7578000c10
>2012-05-16 03:13:25.183+0000: 8696: debug : qemuDriverCloseCallbackRunAll:661 : conn=0x7f7578000c10
>2012-05-16 03:13:25.183+0000: 8696: debug : virEventPollRemoveTimeout:293 : EVENT_POLL_REMOVE_TIMEOUT: timer=12
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 -1724540832
>2012-05-16 03:13:25.184+0000: 8696: debug : virNetSocketFree:722 : RPC_SOCKET_FREE: sock=0x932150 refs=1
>2012-05-16 03:13:25.184+0000: 8696: debug : virNetSocketFree:730 : sock=0x932150 fd=17
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollRemoveHandle:180 : EVENT_POLL_REMOVE_HANDLE: watch=9
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=8, f=21 e=25 d=0
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 2 timers
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollCalculateTimeout:351 : Timeout at 0 due in -1 ms
>2012-05-16 03:13:25.184+0000: 8696: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=8 imeout=-1

Actions: View

Attachments on bug 822015: 584846 | 584847 | 584848