Attachment 585138 Details for Bug 822373 – libvirtd crash log

libvirtd crash log

libvirtd.log (text/x-log), 64.12 KB, created by EricLee on 2012-05-17 08:01:58 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: EricLee

Created: 2012-05-17 08:01:58 UTC

Size: 64.12 KB

patch

obsolete

>Caught Segmentation violation dumping internal log buffer:
>
>
>    ====== start of log =====
>
>239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.596+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.596+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.596+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.596+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.596+000017239: debug : virNetMessageDecodeLength:149 : Got length, now need 40 total (36 more)
>2012-05-16 13:12:11.596+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x2036160 tx=(nil)
>2012-05-16 13:12:11.596+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.596+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.596+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.596+000017239: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x1fb2e90 len=40 prog=536903814 vers=1 proc=1 type=0 status=0 serial=2
>2012-05-16 13:12:11.596+000017239: debug : virKeepAliveCheckMessage:408 : ka=0x1fb52c0, client=0x1fb2e90, msg=0x2036160
>2012-05-16 13:12:11.596+000017239: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=62 frequency=5000
>2012-05-16 13:12:11.596+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.596+000017239: debug : virNetServerDispatchNewMessage:199 : server=0x1faad10 client=0x1fb2e90 message=0x2036160
>2012-05-16 13:12:11.596+000017239: debug : virNetServerProgramRef:87 : prog=0x1fb5e40 refs=3
>2012-05-16 13:12:11.596+000017239: debug : virNetMessageNew:48 : msg=0x1fb6080 tracked=1
>2012-05-16 13:12:11.596+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x1fb6080 tx=(nil)
>2012-05-16 13:12:11.596+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.596+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.596+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.596+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.596+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.596+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.596+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.596+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.596+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.596+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.596+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.596+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.596+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.596+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.596+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.596+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.596+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.596+000017249: debug : virNetServerHandleJob:138 : server=0x1faad10 client=0x1fb2e90 message=0x2036160 prog=0x1fb5e40
>2012-05-16 13:12:11.596+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=1 d=0
>2012-05-16 13:12:11.596+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.596+000017249: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=2 proc=1
>2012-05-16 13:12:11.596+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.596+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936596
>2012-05-16 13:12:11.596+000017249: debug : remoteDispatchOpenHelper:10442 : server=0x1faad10 client=0x1fb2e90 msg=0x2036160 rerr=0x7fde02e26bc0 args=0x7fddf0000ca0 ret=0x7fddf00009a0
>2012-05-16 13:12:11.596+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4925 ms
>2012-05-16 13:12:11.596+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4925
>2012-05-16 13:12:11.596+000017249: debug : remoteDispatchOpen:636 : priv=0x1fb2e10 conn=(nil)
>2012-05-16 13:12:11.596+000017249: debug : virConnectOpen:1349 : name=
>2012-05-16 13:12:11.596+000017249: debug : do_open:1155 : no name, allowing driver auto-select
>2012-05-16 13:12:11.596+000017249: debug : do_open:1195 : trying driver 0 (Test) ...
>2012-05-16 13:12:11.596+000017249: debug : do_open:1201 : driver 0 Test returned DECLINED
>2012-05-16 13:12:11.596+000017249: debug : do_open:1195 : trying driver 1 (ESX) ...
>2012-05-16 13:12:11.596+000017249: debug : do_open:1201 : driver 1 ESX returned DECLINED
>2012-05-16 13:12:11.596+000017249: debug : do_open:1195 : trying driver 2 (remote) ...
>2012-05-16 13:12:11.596+000017249: debug : do_open:1201 : driver 2 remote returned DECLINED
>2012-05-16 13:12:11.596+000017249: debug : do_open:1195 : trying driver 3 (QEMU) ...
>2012-05-16 13:12:11.596+000017249: debug : do_open:1201 : driver 3 QEMU returned SUCCESS
>2012-05-16 13:12:11.596+000017249: debug : do_open:1223 : network driver 0 Test returned DECLINED
>2012-05-16 13:12:11.596+000017249: debug : do_open:1223 : network driver 1 ESX returned DECLINED
>2012-05-16 13:12:11.596+000017249: debug : do_open:1223 : network driver 2 remote returned DECLINED
>2012-05-16 13:12:11.596+000017249: debug : do_open:1223 : network driver 3 Network returned SUCCESS
>2012-05-16 13:12:11.596+000017249: debug : do_open:1238 : interface driver 0 Test returned DECLINED
>2012-05-16 13:12:11.596+000017249: debug : do_open:1238 : interface driver 1 ESX returned DECLINED
>2012-05-16 13:12:11.596+000017249: debug : do_open:1238 : interface driver 2 remote returned DECLINED
>2012-05-16 13:12:11.603+000017249: debug : do_open:1238 : interface driver 3 Interface returned SUCCESS
>2012-05-16 13:12:11.603+000017249: debug : do_open:1254 : storage driver 0 Test returned DECLINED
>2012-05-16 13:12:11.603+000017249: debug : do_open:1254 : storage driver 1 ESX returned DECLINED
>2012-05-16 13:12:11.603+000017249: debug : do_open:1254 : storage driver 2 remote returned DECLINED
>2012-05-16 13:12:11.603+000017249: debug : do_open:1254 : storage driver 3 storage returned SUCCESS
>2012-05-16 13:12:11.603+000017249: debug : do_open:1270 : node driver 0 Test returned DECLINED
>2012-05-16 13:12:11.603+000017249: debug : do_open:1270 : node driver 1 ESX returned DECLINED
>2012-05-16 13:12:11.603+000017249: debug : do_open:1270 : node driver 2 remote returned DECLINED
>2012-05-16 13:12:11.603+000017249: debug : do_open:1270 : node driver 3 udevDeviceMonitor returned SUCCESS
>2012-05-16 13:12:11.603+000017249: debug : do_open:1286 : secret driver 0 Test returned DECLINED
>2012-05-16 13:12:11.604+000017249: debug : do_open:1286 : secret driver 1 ESX returned DECLINED
>2012-05-16 13:12:11.604+000017249: debug : do_open:1286 : secret driver 2 remote returned DECLINED
>2012-05-16 13:12:11.604+000017249: debug : do_open:1286 : secret driver 3 secret returned SUCCESS
>2012-05-16 13:12:11.604+000017249: debug : do_open:1302 : nwfilter driver 0 Test returned DECLINED
>2012-05-16 13:12:11.604+000017249: debug : do_open:1302 : nwfilter driver 1 ESX returned DECLINED
>2012-05-16 13:12:11.604+000017249: debug : do_open:1302 : nwfilter driver 2 remote returned DECLINED
>2012-05-16 13:12:11.604+000017249: debug : do_open:1302 : nwfilter driver 3 nwfilter returned SUCCESS
>2012-05-16 13:12:11.604+000017249: debug : virNetMessageEncodePayload:351 : Encode length as 28
>2012-05-16 13:12:11.604+000017249: debug : virNetServerClientSendMessage:1106 : msg=0x2036160 proc=1 len=28 offset=0
>2012-05-16 13:12:11.604+000017249: debug : virNetServerClientSendMessage:1116 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x1fb2e90 len=28 prog=536903814 vers=1 proc=1 type=1 status=0 serial=2
>2012-05-16 13:12:11.604+000017249: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x1fb6080 tx=0x2036160
>2012-05-16 13:12:11.604+000017249: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2012-05-16 13:12:11.604+000017249: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=3
>2012-05-16 13:12:11.604+000017249: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 13:12:11.604+000017249: debug : virNetServerProgramFree:527 : prog=0x1fb5e40 refs=3
>2012-05-16 13:12:11.604+000017249: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x1fb2e90 refs=4
>2012-05-16 13:12:11.604+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.604+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=5 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936596
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4917 ms
>2012-05-16 13:12:11.604+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4917
>2012-05-16 13:12:11.604+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=26 events=2
>2012-05-16 13:12:11.604+000017239: debug : virNetMessageFree:75 : msg=0x2036160 nfds=0 cb=(nil)
>2012-05-16 13:12:11.604+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x1fb6080 tx=(nil)
>2012-05-16 13:12:11.604+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.604+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.604+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.604+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936596
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4917 ms
>2012-05-16 13:12:11.604+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4917
>2012-05-16 13:12:11.604+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.604+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.604+000017239: debug : virNetMessageDecodeLength:149 : Got length, now need 28 total (24 more)
>2012-05-16 13:12:11.604+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x1fb6080 tx=(nil)
>2012-05-16 13:12:11.604+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.604+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.604+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.604+000017239: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x1fb2e90 len=28 prog=536903814 vers=1 proc=110 type=0 status=0 serial=3
>2012-05-16 13:12:11.604+000017239: debug : virKeepAliveCheckMessage:408 : ka=0x1fb52c0, client=0x1fb2e90, msg=0x1fb6080
>2012-05-16 13:12:11.604+000017239: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=62 frequency=5000
>2012-05-16 13:12:11.604+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.604+000017239: debug : virNetServerDispatchNewMessage:199 : server=0x1faad10 client=0x1fb2e90 message=0x1fb6080
>2012-05-16 13:12:11.604+000017239: debug : virNetServerProgramRef:87 : prog=0x1fb5e40 refs=3
>2012-05-16 13:12:11.604+000017245: debug : virNetServerHandleJob:138 : server=0x1faad10 client=0x1fb2e90 message=0x1fb6080 prog=0x1fb5e40
>2012-05-16 13:12:11.604+000017239: debug : virNetMessageNew:48 : msg=0x2036160 tracked=1
>2012-05-16 13:12:11.604+000017245: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=3 proc=110
>2012-05-16 13:12:11.604+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x2036160 tx=(nil)
>2012-05-16 13:12:11.604+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.604+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.604+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.604+000017245: debug : remoteDispatchGetURIHelper:6742 : server=0x1faad10 client=0x1fb2e90 msg=0x1fb6080 rerr=0x7fde0562abc0 args=0x7fdde4001420 ret=0x7fdde4000910
>2012-05-16 13:12:11.604+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.604+000017245: debug : virConnectGetURI:1722 : conn=0x7fddf0000e10
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.604+000017245: debug : virNetMessageEncodePayload:351 : Encode length as 48
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.604+000017245: debug : virNetServerClientSendMessage:1106 : msg=0x1fb6080 proc=110 len=48 offset=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.604+000017245: debug : virNetServerClientSendMessage:1116 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x1fb2e90 len=48 prog=536903814 vers=1 proc=110 type=1 status=0 serial=3
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.604+000017245: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x2036160 tx=0x1fb6080
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.604+000017245: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.604+000017245: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=3
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=1 d=0
>2012-05-16 13:12:11.604+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936604
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4916 ms
>2012-05-16 13:12:11.605+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4916
>2012-05-16 13:12:11.605+000017245: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 13:12:11.605+000017245: debug : virNetServerProgramFree:527 : prog=0x1fb5e40 refs=3
>2012-05-16 13:12:11.605+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.605+000017245: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x1fb2e90 refs=4
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.605+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=5 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936604
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4916 ms
>2012-05-16 13:12:11.605+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4916
>2012-05-16 13:12:11.605+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=26 events=2
>2012-05-16 13:12:11.605+000017239: debug : virNetMessageFree:75 : msg=0x1fb6080 nfds=0 cb=(nil)
>2012-05-16 13:12:11.605+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x2036160 tx=(nil)
>2012-05-16 13:12:11.605+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.605+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936604
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4916 ms
>2012-05-16 13:12:11.605+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4916
>2012-05-16 13:12:11.605+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.605+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.605+000017239: debug : virNetMessageDecodeLength:149 : Got length, now need 36 total (32 more)
>2012-05-16 13:12:11.605+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x2036160 tx=(nil)
>2012-05-16 13:12:11.605+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.605+000017239: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x1fb2e90 len=36 prog=536903814 vers=1 proc=23 type=0 status=0 serial=4
>2012-05-16 13:12:11.605+000017239: debug : virKeepAliveCheckMessage:408 : ka=0x1fb52c0, client=0x1fb2e90, msg=0x2036160
>2012-05-16 13:12:11.605+000017239: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=62 frequency=5000
>2012-05-16 13:12:11.605+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.605+000017239: debug : virNetServerDispatchNewMessage:199 : server=0x1faad10 client=0x1fb2e90 message=0x2036160
>2012-05-16 13:12:11.605+000017239: debug : virNetServerProgramRef:87 : prog=0x1fb5e40 refs=3
>2012-05-16 13:12:11.605+000017239: debug : virNetMessageNew:48 : msg=0x1fb6080 tracked=1
>2012-05-16 13:12:11.605+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x1fb6080 tx=(nil)
>2012-05-16 13:12:11.605+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.605+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.605+000017244: debug : virNetServerHandleJob:138 : server=0x1faad10 client=0x1fb2e90 message=0x2036160 prog=0x1fb5e40
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.605+000017244: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=4 proc=23
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.605+000017244: debug : remoteDispatchDomainLookupByNameHelper:2748 : server=0x1faad10 client=0x1fb2e90 msg=0x2036160 rerr=0x7fde0602bbc0 args=0x7fdddc001530 ret=0x7fdddc001590
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.605+000017244: debug : virDomainLookupByName:2146 : conn=0x7fddf0000e10, name=test
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=1 d=0
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.605+000017244: debug : virDomainFree:2313 : dom=0x7fdddc001550, (VM: name=test, uuid=0bbb9307-a1e2-e130-e4c0-72aed9be6405)
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936605
>2012-05-16 13:12:11.605+000017244: debug : virUnrefDomain:276 : unref domain 0x7fdddc001550 test 1
>2012-05-16 13:12:11.605+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4916 ms
>2012-05-16 13:12:11.606+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4916
>2012-05-16 13:12:11.606+000017244: debug : virReleaseDomain:238 : release domain 0x7fdddc001550 test 0bbb9307-a1e2-e130-e4c0-72aed9be6405
>2012-05-16 13:12:11.606+000017244: debug : virReleaseDomain:246 : unref connection 0x7fddf0000e10 2
>2012-05-16 13:12:11.606+000017244: debug : virNetMessageEncodePayload:351 : Encode length as 56
>2012-05-16 13:12:11.606+000017244: debug : virNetServerClientSendMessage:1106 : msg=0x2036160 proc=23 len=56 offset=0
>2012-05-16 13:12:11.606+000017244: debug : virNetServerClientSendMessage:1116 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x1fb2e90 len=56 prog=536903814 vers=1 proc=23 type=1 status=0 serial=4
>2012-05-16 13:12:11.606+000017244: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x1fb6080 tx=0x2036160
>2012-05-16 13:12:11.606+000017244: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2012-05-16 13:12:11.606+000017244: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=3
>2012-05-16 13:12:11.606+000017244: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 13:12:11.606+000017244: debug : virNetServerProgramFree:527 : prog=0x1fb5e40 refs=3
>2012-05-16 13:12:11.606+000017244: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x1fb2e90 refs=4
>2012-05-16 13:12:11.606+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.606+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=5 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936605
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4915 ms
>2012-05-16 13:12:11.606+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4915
>2012-05-16 13:12:11.606+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=26 events=2
>2012-05-16 13:12:11.606+000017239: debug : virNetMessageFree:75 : msg=0x2036160 nfds=0 cb=(nil)
>2012-05-16 13:12:11.606+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x1fb6080 tx=(nil)
>2012-05-16 13:12:11.606+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.606+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.606+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.606+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936605
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4915 ms
>2012-05-16 13:12:11.606+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4915
>2012-05-16 13:12:11.606+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.606+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.606+000017239: debug : virNetMessageDecodeLength:149 : Got length, now need 220 total (216 more)
>2012-05-16 13:12:11.606+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x1fb6080 tx=(nil)
>2012-05-16 13:12:11.606+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.606+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.606+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.606+000017239: debug : virNetServerClientDispatchRead:886 : RPC_SERVER_CLIENT_MSG_RX: client=0x1fb2e90 len=220 prog=536903814 vers=1 proc=13 type=0 status=0 serial=5
>2012-05-16 13:12:11.606+000017239: debug : virKeepAliveCheckMessage:408 : ka=0x1fb52c0, client=0x1fb2e90, msg=0x1fb6080
>2012-05-16 13:12:11.606+000017239: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=62 frequency=5000
>2012-05-16 13:12:11.606+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.606+000017239: debug : virNetServerDispatchNewMessage:199 : server=0x1faad10 client=0x1fb2e90 message=0x1fb6080
>2012-05-16 13:12:11.606+000017239: debug : virNetServerProgramRef:87 : prog=0x1fb5e40 refs=3
>2012-05-16 13:12:11.606+000017239: debug : virNetMessageNew:48 : msg=0x2036160 tracked=1
>2012-05-16 13:12:11.606+000017239: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x2036160 tx=(nil)
>2012-05-16 13:12:11.606+000017239: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2012-05-16 13:12:11.606+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=26 events=1
>2012-05-16 13:12:11.606+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.606+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.606+000017242: debug : virNetServerHandleJob:138 : server=0x1faad10 client=0x1fb2e90 message=0x1fb6080 prog=0x1fb5e40
>2012-05-16 13:12:11.606+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=1 d=0
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.606+000017242: debug : virNetServerProgramDispatch:269 : prog=536903814 ver=1 type=0 status=0 serial=5 proc=13
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936606
>2012-05-16 13:12:11.606+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4915 ms
>2012-05-16 13:12:11.606+000017242: debug : remoteDispatchDomainDetachDeviceHelper:1144 : server=0x1faad10 client=0x1fb2e90 msg=0x1fb6080 rerr=0x7fde0742dbc0 args=0x7fddd4009460 ret=0x7fddd4009400
>2012-05-16 13:12:11.606+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4915
>2012-05-16 13:12:11.606+000017242: debug : virDomainDetachDevice:9302 : dom=0x7fddd4009420, (VM: name=test, uuid=0bbb9307-a1e2-e130-e4c0-72aed9be6405), xml=   <hostdev mode='subsystem' type='pci'>
>            <source>
>                <address bus='0x07' slot='0' function='0'/>
>            </source>
>    </hostdev>
>
>2012-05-16 13:12:11.606+000017242: debug : virDomainObjRef:1623 : obj=0x7fddfc01c620 refs=3
>2012-05-16 13:12:11.606+000017242: debug : qemuDomainObjBeginJobInternal:753 : Starting job: modify (async=none)
>2012-05-16 13:12:11.607+000017242: debug : qemuMonitorRef:201 : QEMU_MONITOR_REF: mon=0x7fddd4008960 refs=3
>2012-05-16 13:12:11.607+000017242: debug : qemuMonitorDelDevice:2458 : mon=0x7fddd4008960 devalias=hostdev0
>2012-05-16 13:12:11.607+000017242: debug : virJSONValueToString:1071 : object=0x7fddd4002e20
>2012-05-16 13:12:11.607+000017242: debug : virJSONValueToStringOne:1003 : object=0x7fddd4002e20 type=0 gen=0x7fddd40076d0
>2012-05-16 13:12:11.607+000017242: debug : virJSONValueToStringOne:1003 : object=0x7fddd4002a00 type=2 gen=0x7fddd40076d0
>2012-05-16 13:12:11.607+000017242: debug : virJSONValueToStringOne:1003 : object=0x7fddd4001010 type=0 gen=0x7fddd40076d0
>2012-05-16 13:12:11.607+000017242: debug : virJSONValueToStringOne:1003 : object=0x7fddd4001fb0 type=2 gen=0x7fddd40076d0
>2012-05-16 13:12:11.607+000017242: debug : virJSONValueToStringOne:1003 : object=0x7fddd4002070 type=2 gen=0x7fddd40076d0
>2012-05-16 13:12:11.607+000017242: debug : virJSONValueToString:1105 : result={"execute":"device_del","arguments":{"id":"hostdev0"},"id":"libvirt-332"}
>2012-05-16 13:12:11.607+000017242: debug : qemuMonitorJSONCommandWithFd:248 : Send command '{"execute":"device_del","arguments":{"id":"hostdev0"},"id":"libvirt-332"}' for write with FD -1
>2012-05-16 13:12:11.607+000017242: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=15
>2012-05-16 13:12:11.607+000017242: debug : virEventPollInterruptLocked:706 : Interrupting
>2012-05-16 13:12:11.607+000017242: debug : qemuMonitorSend:823 : QEMU_MONITOR_SEND_MSG: mon=0x7fddd4008960 msg={"execute":"device_del","arguments":{"id":"hostdev0"},"id":"libvirt-332"}
> fd=-1
>2012-05-16 13:12:11.607+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.607+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.607+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.607+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.607+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.607+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.607+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.607+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.607+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.607+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.607+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.607+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.607+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.607+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.607+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=29 d=0
>2012-05-16 13:12:11.607+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=1 d=0
>2012-05-16 13:12:11.607+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.607+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.607+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936606
>2012-05-16 13:12:11.607+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4914 ms
>2012-05-16 13:12:11.607+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4914
>2012-05-16 13:12:11.607+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.607+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=16 events=2
>2012-05-16 13:12:11.607+000017239: debug : qemuMonitorRef:201 : QEMU_MONITOR_REF: mon=0x7fddd4008960 refs=4
>2012-05-16 13:12:11.608+000017239: debug : qemuMonitorIOWrite:432 : QEMU_MONITOR_IO_WRITE: mon=0x7fddd4008960 buf={"execute":"device_del","arguments":{"id":"hostdev0"},"id":"libvirt-332"}
> len=75 ret=75 errno=11
>2012-05-16 13:12:11.608+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=13
>2012-05-16 13:12:11.608+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.608+000017239: debug : qemuMonitorUnref:210 : QEMU_MONITOR_UNREF: mon=0x7fddd4008960 refs=3
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.608+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936606
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4913 ms
>2012-05-16 13:12:11.608+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4913
>2012-05-16 13:12:11.608+000017239: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchTimeouts:415 : Dispatch 7
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=7 w=10
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=8 w=16
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=16 events=1
>2012-05-16 13:12:11.608+000017239: debug : qemuMonitorRef:201 : QEMU_MONITOR_REF: mon=0x7fddd4008960 refs=4
>2012-05-16 13:12:11.608+000017239: debug : qemuMonitorIOProcess:327 : QEMU_MONITOR_IO_PROCESS: mon=0x7fddd4008960 buf={"return": {}, "id": "libvirt-332"}
> len=37
>2012-05-16 13:12:11.608+000017239: debug : qemuMonitorJSONIOProcessLine:135 : Line [{"return": {}, "id": "libvirt-332"}]
>2012-05-16 13:12:11.608+000017239: debug : virJSONValueFromString:948 : string={"return": {}, "id": "libvirt-332"}
>2012-05-16 13:12:11.608+000017239: debug : virJSONParserHandleStartMap:825 : parser=0x7fff0b6da510
>2012-05-16 13:12:11.608+000017239: debug : virJSONParserHandleMapKey:806 : parser=0x7fff0b6da510 key=0x1fb5352
>2012-05-16 13:12:11.608+000017239: debug : virJSONParserHandleStartMap:825 : parser=0x7fff0b6da510
>2012-05-16 13:12:11.608+000017239: debug : virJSONParserHandleEndMap:854 : parser=0x7fff0b6da510
>2012-05-16 13:12:11.608+000017239: debug : virJSONParserHandleMapKey:806 : parser=0x7fff0b6da510 key=0x1fb5360
>2012-05-16 13:12:11.608+000017239: debug : virJSONParserHandleString:786 : parser=0x7fff0b6da510 str=0x1fb5366
>2012-05-16 13:12:11.608+000017239: debug : virJSONParserHandleEndMap:854 : parser=0x7fff0b6da510
>2012-05-16 13:12:11.608+000017239: debug : virJSONValueFromString:992 : result=0x1f94950
>2012-05-16 13:12:11.608+000017239: debug : qemuMonitorJSONIOProcessLine:155 : QEMU_MONITOR_RECV_REPLY: mon=0x7fddd4008960 reply={"return": {}, "id": "libvirt-332"}
>2012-05-16 13:12:11.608+000017239: debug : qemuMonitorJSONIOProcess:206 : Total used 37 bytes out of 37 available in buffer
>2012-05-16 13:12:11.608+000017239: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=13
>2012-05-16 13:12:11.608+000017239: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 241969248
>2012-05-16 13:12:11.608+000017239: debug : qemuMonitorUnref:210 : QEMU_MONITOR_UNREF: mon=0x7fddd4008960 refs=3
>2012-05-16 13:12:11.608+000017239: debug : virEventPollDispatchHandles:474 : i=9 w=26
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.608+000017242: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=13
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.608+000017239: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-05-16 13:12:11.608+000017242: debug : virEventPollInterruptLocked:702 : Skip interrupt, 0 241969248
>2012-05-16 13:12:11.608+000017242: debug : qemuMonitorJSONCommandWithFd:253 : Receive command reply ret=0 rxObject=0x1f94950
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCleanupTimeouts:506 : Cleanup 7
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2012-05-16 13:12:11.608+000017242: debug : qemuMonitorUnref:210 : QEMU_MONITOR_UNREF: mon=0x7fddd4008960 refs=2
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=12 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=13 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=14 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=15 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=16 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=10, f=17 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=16, f=25 e=25 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=26, f=19 e=1 d=0
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 7 timers
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936521
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1337173936606
>2012-05-16 13:12:11.608+000017239: debug : virEventPollCalculateTimeout:351 : Timeout at 1337173936521 due in 4913 ms
>2012-05-16 13:12:11.608+000017239: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 imeout=4913
>2012-05-16 13:12:11.609+000017242: debug : pciGetDevice:1401 : 8086 10fb 0000:07:00.0: initialized
>
>
>     ====== end of log =====
>

Actions: View

Attachments on bug 822373: 585138