Attachment 915720 Details for Bug 969497 – Comment

Comment

comment_5967116.txt (text/plain), 64.88 KB, created by Chris Carpenter on 2013-05-31 14:49:22 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Chris Carpenter

Created: 2013-05-31 14:49:22 UTC

Size: 64.88 KB

patch

obsolete

>Description of problem:
>When I am connected using virsh console to a domain and I or someone else calls destroy on that domain it causes libvirtd to have a segmentation violation.
>
>Version-Release number of selected component (if applicable):
>Debian libvirt-bin version 0.9.12-11
>
>How reproducible:
>Every time
>
>Steps to Reproduce:
>1. Start domain using virsh start <domain>
>2. Connect to domain console using virsh console <domain>
>3. In another terminal call virsh destroy <domain>
>
>Note: This also happens when using the ruby libvirt API, easier to reproduce using virsh though.
>
>Actual results:
>error: Failed to destroy domain wheezy_system
>error: End of file while reading data: Input/output error
>
>Expected results:
>Domain is destroyed without errors
>
>Additional info:
>Caught Segmentation violation dumping internal log buffer:
>
>
>    ====== start of log =====
>
>\001 14:34:30.118+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce500828f0 tx=(nil)
>2013-05-31 14:34:30.118+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2013-05-31 14:34:30.118+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.118+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.118+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.118+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.118+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.118+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.118+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=11, f=21 e=25 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=10 w=16, f=20 e=1 d=0
>2013-05-31 14:34:30.118+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.118+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.118+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875118
>2013-05-31 14:34:30.118+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 3497 ms
>2013-05-31 14:34:30.118+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=11 timeout=3497
>2013-05-31 14:34:30.118+00007962: debug : remoteDispatchOpenHelper:10494 : server=0xe2e920 client=0x7fce50000f60 msg=0x7fce50042160 rerr=0x7fce5a9d2c90 args=0xfe55d0 ret=0xf42850
>2013-05-31 14:34:30.118+00007962: debug : remoteDispatchOpen:682 : priv=0xe2f900 conn=(nil)
>2013-05-31 14:34:30.118+00007962: debug : virConnectOpen:1383 : name=
>2013-05-31 14:34:30.118+00007962: debug : virConnectGetConfigFile:1008 : Loading config file '/etc/libvirt/libvirt.conf'
>2013-05-31 14:34:30.118+00007962: debug : do_open:1186 : no name, allowing driver auto-select
>2013-05-31 14:34:30.118+00007962: debug : do_open:1226 : trying driver 0 (Test) ...
>2013-05-31 14:34:30.118+00007962: debug : do_open:1232 : driver 0 Test returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1226 : trying driver 1 (Xen) ...
>2013-05-31 14:34:30.118+00007962: debug : do_open:1232 : driver 1 Xen returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1226 : trying driver 2 (OPENVZ) ...
>2013-05-31 14:34:30.118+00007962: debug : do_open:1232 : driver 2 OPENVZ returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1226 : trying driver 3 (VMWARE) ...
>2013-05-31 14:34:30.118+00007962: debug : do_open:1232 : driver 3 VMWARE returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1226 : trying driver 4 (PHYP) ...
>2013-05-31 14:34:30.118+00007962: debug : do_open:1232 : driver 4 PHYP returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1226 : trying driver 5 (VBOX) ...
>2013-05-31 14:34:30.118+00007962: debug : do_open:1232 : driver 5 VBOX returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1226 : trying driver 6 (remote) ...
>2013-05-31 14:34:30.118+00007962: debug : do_open:1232 : driver 6 remote returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1226 : trying driver 7 (QEMU) ...
>2013-05-31 14:34:30.118+00007962: debug : do_open:1232 : driver 7 QEMU returned SUCCESS
>2013-05-31 14:34:30.118+00007962: debug : do_open:1254 : network driver 0 Test returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1254 : network driver 1 VBOX returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1254 : network driver 2 remote returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1254 : network driver 3 Network returned SUCCESS
>2013-05-31 14:34:30.118+00007962: debug : do_open:1269 : interface driver 0 Test returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1269 : interface driver 1 PHYP returned DECLINED
>2013-05-31 14:34:30.118+00007962: debug : do_open:1269 : interface driver 2 remote returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1269 : interface driver 3 Interface returned SUCCESS
>2013-05-31 14:34:30.126+00007962: debug : do_open:1285 : storage driver 0 Test returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1285 : storage driver 1 PHYP returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1285 : storage driver 2 VBOX returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1285 : storage driver 3 remote returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1285 : storage driver 4 storage returned SUCCESS
>2013-05-31 14:34:30.126+00007962: debug : do_open:1301 : node driver 0 Test returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1301 : node driver 1 remote returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1301 : node driver 2 udevDeviceMonitor returned SUCCESS
>2013-05-31 14:34:30.126+00007962: debug : do_open:1317 : secret driver 0 Test returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1317 : secret driver 1 remote returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1317 : secret driver 2 secret returned SUCCESS
>2013-05-31 14:34:30.126+00007962: debug : do_open:1333 : nwfilter driver 0 Test returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1333 : nwfilter driver 1 remote returned DECLINED
>2013-05-31 14:34:30.126+00007962: debug : do_open:1333 : nwfilter driver 2 nwfilter returned SUCCESS
>2013-05-31 14:34:30.126+00007962: debug : virNetMessageEncodePayload:351 : Encode length as 28
>2013-05-31 14:34:30.126+00007962: debug : virNetServerClientSendMessage:1109 : msg=0x7fce50042160 proc=1 len=28 offset=0
>2013-05-31 14:34:30.126+00007962: debug : virNetServerClientSendMessage:1119 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x7fce50000f60 len=28 prog=536903814 vers=1 proc=1 type=1 status=0 serial=2
>2013-05-31 14:34:30.126+00007962: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce500828f0 tx=0x7fce50042160
>2013-05-31 14:34:30.126+00007962: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2013-05-31 14:34:30.126+00007962: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=3
>2013-05-31 14:34:30.126+00007962: debug : virEventPollInterruptLocked:706 : Interrupting
>2013-05-31 14:34:30.126+00007962: debug : virNetServerProgramFree:534 : prog=0xe39bc0 refs=4
>2013-05-31 14:34:30.126+00007962: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x7fce50000f60 refs=4
>2013-05-31 14:34:30.126+00007959: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 11
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=11
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=14
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=9 w=15
>2013-05-31 14:34:30.126+00007959: debug : virEventPollDispatchHandles:474 : i=10 w=16
>2013-05-31 14:34:30.126+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.126+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.126+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.126+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.126+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.126+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.126+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=11, f=21 e=25 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=10 w=16, f=20 e=5 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875118
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 3488 ms
>2013-05-31 14:34:30.127+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=11 timeout=3488
>2013-05-31 14:34:30.127+00007959: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 11
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=11
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=14
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=9 w=15
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=10 w=16
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=16 events=2
>2013-05-31 14:34:30.127+00007959: debug : virNetMessageFree:75 : msg=0x7fce50042160 nfds=0 cb=(nil)
>2013-05-31 14:34:30.127+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce500828f0 tx=(nil)
>2013-05-31 14:34:30.127+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2013-05-31 14:34:30.127+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.127+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.127+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=11, f=21 e=25 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=10 w=16, f=20 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875118
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 3488 ms
>2013-05-31 14:34:30.127+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=11 timeout=3488
>2013-05-31 14:34:30.127+00007959: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 11
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=11
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=14
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=9 w=15
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=10 w=16
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.127+00007959: debug : virNetMessageDecodeLength:149 : Got length, now need 28 total (24 more)
>2013-05-31 14:34:30.127+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce500828f0 tx=(nil)
>2013-05-31 14:34:30.127+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2013-05-31 14:34:30.127+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.127+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.127+00007959: debug : virNetServerClientDispatchRead:889 : RPC_SERVER_CLIENT_MSG_RX: client=0x7fce50000f60 len=28 prog=536903814 vers=1 proc=110 type=0 status=0 serial=3
>2013-05-31 14:34:30.127+00007959: debug : virKeepAliveCheckMessage:424 : ka=0x7fce50000d30, client=0x7fce50000f60, msg=0x7fce500828f0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=17 frequency=5000
>2013-05-31 14:34:30.127+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.127+00007959: debug : virNetServerDispatchNewMessage:196 : server=0xe2e920 client=0x7fce50000f60 message=0x7fce500828f0
>2013-05-31 14:34:30.127+00007959: debug : virNetServerProgramRef:87 : prog=0xe39bc0 refs=4
>2013-05-31 14:34:30.127+00007960: debug : virNetServerHandleJob:135 : server=0xe2e920 client=0x7fce50000f60 message=0x7fce500828f0 prog=0xe39bc0
>2013-05-31 14:34:30.127+00007960: debug : virNetServerProgramDispatch:276 : prog=536903814 ver=1 type=0 status=0 serial=3 proc=110
>2013-05-31 14:34:30.127+00007959: debug : virNetMessageNew:48 : msg=0x7fce50042160 tracked=1
>2013-05-31 14:34:30.127+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce50042160 tx=(nil)
>2013-05-31 14:34:30.127+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2013-05-31 14:34:30.127+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.127+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.127+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.127+00007960: debug : remoteDispatchGetURIHelper:6794 : server=0xe2e920 client=0x7fce50000f60 msg=0x7fce500828f0 rerr=0x7fce5b9d4c90 args=0xf42850 ret=0x10bc600
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.127+00007960: debug : virConnectGetURI:1756 : conn=0xf45440
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.127+00007960: debug : virNetMessageEncodePayload:351 : Encode length as 48
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.127+00007960: debug : virNetServerClientSendMessage:1109 : msg=0x7fce500828f0 proc=110 len=48 offset=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.127+00007960: debug : virNetServerClientSendMessage:1119 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x7fce50000f60 len=48 prog=536903814 vers=1 proc=110 type=1 status=0 serial=3
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=11, f=21 e=25 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.127+00007960: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce50042160 tx=0x7fce500828f0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.127+00007960: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=10 w=16, f=20 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.127+00007960: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=3
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875127
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 3488 ms
>2013-05-31 14:34:30.127+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=11 timeout=3488
>2013-05-31 14:34:30.127+00007960: debug : virEventPollInterruptLocked:706 : Interrupting
>2013-05-31 14:34:30.127+00007960: debug : virNetServerProgramFree:534 : prog=0xe39bc0 refs=4
>2013-05-31 14:34:30.127+00007960: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x7fce50000f60 refs=4
>2013-05-31 14:34:30.127+00007959: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 11
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=11
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=14
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=9 w=15
>2013-05-31 14:34:30.127+00007959: debug : virEventPollDispatchHandles:474 : i=10 w=16
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.127+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.127+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.127+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=11, f=21 e=25 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=10 w=16, f=20 e=5 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875127
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 3487 ms
>2013-05-31 14:34:30.128+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=11 timeout=3487
>2013-05-31 14:34:30.128+00007959: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 11
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=11
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=14
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=9 w=15
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=10 w=16
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=16 events=2
>2013-05-31 14:34:30.128+00007959: debug : virNetMessageFree:75 : msg=0x7fce500828f0 nfds=0 cb=(nil)
>2013-05-31 14:34:30.128+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce50042160 tx=(nil)
>2013-05-31 14:34:30.128+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2013-05-31 14:34:30.128+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.128+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.128+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=11, f=21 e=25 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=10 w=16, f=20 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875127
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 3487 ms
>2013-05-31 14:34:30.128+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=11 timeout=3487
>2013-05-31 14:34:30.128+00007959: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 11
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=11
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=14
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=9 w=15
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:474 : i=10 w=16
>2013-05-31 14:34:30.128+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.128+00007959: debug : virNetMessageDecodeLength:149 : Got length, now need 48 total (44 more)
>2013-05-31 14:34:30.128+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce50042160 tx=(nil)
>2013-05-31 14:34:30.128+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2013-05-31 14:34:30.128+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.128+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.128+00007959: debug : virNetServerClientDispatchRead:889 : RPC_SERVER_CLIENT_MSG_RX: client=0x7fce50000f60 len=48 prog=536903814 vers=1 proc=23 type=0 status=0 serial=4
>2013-05-31 14:34:30.128+00007959: debug : virKeepAliveCheckMessage:424 : ka=0x7fce50000d30, client=0x7fce50000f60, msg=0x7fce50042160
>2013-05-31 14:34:30.128+00007959: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=17 frequency=5000
>2013-05-31 14:34:30.128+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.128+00007959: debug : virNetServerDispatchNewMessage:196 : server=0xe2e920 client=0x7fce50000f60 message=0x7fce50042160
>2013-05-31 14:34:30.128+00007959: debug : virNetServerProgramRef:87 : prog=0xe39bc0 refs=4
>2013-05-31 14:34:30.128+00007964: debug : virNetServerHandleJob:135 : server=0xe2e920 client=0x7fce50000f60 message=0x7fce50042160 prog=0xe39bc0
>2013-05-31 14:34:30.128+00007964: debug : virNetServerProgramDispatch:276 : prog=536903814 ver=1 type=0 status=0 serial=4 proc=23
>2013-05-31 14:34:30.128+00007959: debug : virNetMessageNew:48 : msg=0x7fce500828f0 tracked=1
>2013-05-31 14:34:30.128+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce500828f0 tx=(nil)
>2013-05-31 14:34:30.128+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2013-05-31 14:34:30.128+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.128+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.128+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=11, f=21 e=25 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=10 w=16, f=20 e=1 d=0
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875128
>2013-05-31 14:34:30.128+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 3487 ms
>2013-05-31 14:34:30.128+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=11 timeout=3487
>2013-05-31 14:34:30.129+00007964: debug : remoteDispatchDomainLookupByNameHelper:2748 : server=0xe2e920 client=0x7fce50000f60 msg=0x7fce50042160 rerr=0x7fce599d0c90 args=0x10bc600 ret=0x10bcb20
>2013-05-31 14:34:30.129+00007964: debug : virDomainLookupByName:2178 : conn=0xf45440, name=wheezy_system
>2013-05-31 14:34:30.129+00007964: debug : virDomainFree:2345 : dom=0x10bcae0, (VM: name=wheezy_system, uuid=d1c016b1-e7c0-4ce5-a039-2f06f7c7f8dd)
>2013-05-31 14:34:30.129+00007964: debug : virUnrefDomain:276 : unref domain 0x10bcae0 wheezy_system 1
>2013-05-31 14:34:30.129+00007964: debug : virReleaseDomain:238 : release domain 0x10bcae0 wheezy_system d1c016b1-e7c0-4ce5-a039-2f06f7c7f8dd
>2013-05-31 14:34:30.129+00007964: debug : virReleaseDomain:246 : unref connection 0xf45440 2
>2013-05-31 14:34:30.129+00007964: debug : virNetMessageEncodePayload:351 : Encode length as 68
>2013-05-31 14:34:30.129+00007964: debug : virNetServerClientSendMessage:1109 : msg=0x7fce50042160 proc=23 len=68 offset=0
>2013-05-31 14:34:30.129+00007964: debug : virNetServerClientSendMessage:1119 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x7fce50000f60 len=68 prog=536903814 vers=1 proc=23 type=1 status=0 serial=4
>2013-05-31 14:34:30.129+00007964: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce500828f0 tx=0x7fce50042160
>2013-05-31 14:34:30.129+00007964: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2013-05-31 14:34:30.129+00007964: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=3
>2013-05-31 14:34:30.129+00007964: debug : virEventPollInterruptLocked:706 : Interrupting
>2013-05-31 14:34:30.129+00007964: debug : virNetServerProgramFree:534 : prog=0xe39bc0 refs=4
>2013-05-31 14:34:30.129+00007964: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x7fce50000f60 refs=4
>2013-05-31 14:34:30.129+00007959: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 11
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=11
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=14
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=9 w=15
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=10 w=16
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.129+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=11, f=21 e=25 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=10 w=16, f=20 e=5 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875128
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 3486 ms
>2013-05-31 14:34:30.129+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=11 timeout=3486
>2013-05-31 14:34:30.129+00007959: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 11
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=11
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=14
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=9 w=15
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=10 w=16
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=16 events=2
>2013-05-31 14:34:30.129+00007959: debug : virNetMessageFree:75 : msg=0x7fce50042160 nfds=0 cb=(nil)
>2013-05-31 14:34:30.129+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce500828f0 tx=(nil)
>2013-05-31 14:34:30.129+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2013-05-31 14:34:30.129+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.129+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.129+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=11, f=21 e=25 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=10 w=16, f=20 e=1 d=0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875128
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 3486 ms
>2013-05-31 14:34:30.129+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=11 timeout=3486
>2013-05-31 14:34:30.129+00007959: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 11
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=11
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=14
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=9 w=15
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:474 : i=10 w=16
>2013-05-31 14:34:30.129+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.129+00007959: debug : virNetMessageDecodeLength:149 : Got length, now need 68 total (64 more)
>2013-05-31 14:34:30.129+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce500828f0 tx=(nil)
>2013-05-31 14:34:30.129+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2013-05-31 14:34:30.129+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.129+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.129+00007959: debug : virNetServerClientDispatchRead:889 : RPC_SERVER_CLIENT_MSG_RX: client=0x7fce50000f60 len=68 prog=536903814 vers=1 proc=12 type=0 status=0 serial=5
>2013-05-31 14:34:30.129+00007959: debug : virKeepAliveCheckMessage:424 : ka=0x7fce50000d30, client=0x7fce50000f60, msg=0x7fce500828f0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollUpdateTimeout:259 : EVENT_POLL_UPDATE_TIMEOUT: timer=17 frequency=5000
>2013-05-31 14:34:30.129+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.129+00007959: debug : virNetServerDispatchNewMessage:196 : server=0xe2e920 client=0x7fce50000f60 message=0x7fce500828f0
>2013-05-31 14:34:30.129+00007959: debug : virNetServerProgramRef:87 : prog=0xe39bc0 refs=4
>2013-05-31 14:34:30.129+00007959: debug : virNetMessageNew:48 : msg=0x7fce50042160 tracked=1
>2013-05-31 14:34:30.129+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce50042160 tx=(nil)
>2013-05-31 14:34:30.129+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=1
>2013-05-31 14:34:30.129+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=1
>2013-05-31 14:34:30.129+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.129+00007961: debug : virNetServerHandleJob:135 : server=0xe2e920 client=0x7fce50000f60 message=0x7fce500828f0 prog=0xe39bc0
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.129+00007961: debug : virNetServerProgramDispatch:276 : prog=536903814 ver=1 type=0 status=0 serial=5 proc=12
>2013-05-31 14:34:30.129+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.129+00007961: debug : remoteDispatchDomainDestroyHelper:1040 : server=0xe2e920 client=0x7fce50000f60 msg=0x7fce500828f0 rerr=0x7fce5b1d3c90 args=0x10bf040 ret=0xf42850
>2013-05-31 14:34:30.129+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.129+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.130+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.130+00007961: debug : virDomainDestroy:2236 : dom=0x10bf000, (VM: name=wheezy_system, uuid=d1c016b1-e7c0-4ce5-a039-2f06f7c7f8dd)
>2013-05-31 14:34:30.130+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.130+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.130+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.130+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.130+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.130+00007961: debug : qemuProcessKill:3781 : vm=wheezy_system pid=8016 flags=1
>2013-05-31 14:34:30.130+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=11, f=21 e=25 d=0
>2013-05-31 14:34:30.130+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.130+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.130+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=10 w=16, f=20 e=1 d=0
>2013-05-31 14:34:30.130+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.130+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.130+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875129
>2013-05-31 14:34:30.130+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 3485 ms
>2013-05-31 14:34:30.130+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=11 timeout=3485
>2013-05-31 14:34:30.130+00007959: debug : virEventPollRunOnce:630 : Poll got 1 event(s)
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 11
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=11
>2013-05-31 14:34:30.130+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=11 events=1
>2013-05-31 14:34:30.130+00007959: debug : qemuMonitorRef:239 : QEMU_MONITOR_REF: mon=0xf7bab0 refs=3
>2013-05-31 14:34:30.130+00007959: debug : qemuMonitorIOProcess:365 : QEMU_MONITOR_IO_PROCESS: mon=0xf7bab0 buf={"timestamp": {"seconds": 1370010870, "microseconds": 130177}, "event": "SHUTDOWN"}
> len=85
>2013-05-31 14:34:30.130+00007959: debug : qemuMonitorJSONIOProcessLine:139 : Line [{"timestamp": {"seconds": 1370010870, "microseconds": 130177}, "event": "SHUTDOWN"}]
>2013-05-31 14:34:30.130+00007959: debug : virJSONValueFromString:947 : string={"timestamp": {"seconds": 1370010870, "microseconds": 130177}, "event": "SHUTDOWN"}
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleStartMap:824 : parser=0x7fff8affd540
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleMapKey:805 : parser=0x7fff8affd540 key=0x7fce500015b2
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleStartMap:824 : parser=0x7fff8affd540
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleMapKey:805 : parser=0x7fff8affd540 key=0x7fce500015c0
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleNumber:764 : parser=0x7fff8affd540 str=(null)
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleMapKey:805 : parser=0x7fff8affd540 key=0x7fce500015d7
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleNumber:764 : parser=0x7fff8affd540 str=(null)
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleEndMap:853 : parser=0x7fff8affd540
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleMapKey:805 : parser=0x7fff8affd540 key=0x7fce500015f0
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleString:785 : parser=0x7fff8affd540 str=0x7fce500015f9
>2013-05-31 14:34:30.130+00007959: debug : virJSONParserHandleEndMap:853 : parser=0x7fff8affd540
>2013-05-31 14:34:30.130+00007959: debug : virJSONValueFromString:991 : result=0x7fce50001ee0
>2013-05-31 14:34:30.130+00007959: debug : qemuMonitorJSONIOProcessLine:154 : QEMU_MONITOR_RECV_EVENT: mon=0xf7bab0 event={"timestamp": {"seconds": 1370010870, "microseconds": 130177}, "event": "SHUTDOWN"}
>2013-05-31 14:34:30.130+00007959: debug : qemuMonitorJSONIOProcessEvent:111 : mon=0xf7bab0 obj=0x7fce50001ee0
>2013-05-31 14:34:30.130+00007959: debug : qemuMonitorJSONIOProcessEvent:125 : handle SHUTDOWN handler=0x4aaf70 data=(nil)
>2013-05-31 14:34:30.130+00007959: debug : qemuMonitorEmitShutdown:945 : mon=0xf7bab0
>2013-05-31 14:34:30.130+00007959: debug : qemuMonitorRef:239 : QEMU_MONITOR_REF: mon=0xf7bab0 refs=4
>2013-05-31 14:34:30.130+00007959: debug : qemuProcessHandleShutdown:636 : vm=0xf7a110
>2013-05-31 14:34:30.730+00007961: debug : virDomainObjRef:1644 : obj=0xf7a110 refs=3
>2013-05-31 14:34:30.730+00007961: debug : virDomainObjUnref:1651 : obj=0xf7a110 refs=2
>2013-05-31 14:34:30.730+00007961: debug : virDomainObjRef:1644 : obj=0xf7a110 refs=3
>2013-05-31 14:34:30.730+00007961: debug : qemuDomainObjBeginJobInternal:807 : Starting job: destroy (async=none)
>2013-05-31 14:34:30.730+00007961: debug : qemuProcessStop:3884 : Shutting down VM 'wheezy_system' pid=8016 migrated=0
>2013-05-31 14:34:30.730+00007961: debug : qemuMonitorClose:797 : QEMU_MONITOR_CLOSE: mon=0xf7bab0 refs=4
>2013-05-31 14:34:30.730+00007961: debug : virEventPollRemoveHandle:180 : EVENT_POLL_REMOVE_HANDLE: watch=11
>2013-05-31 14:34:30.730+00007961: debug : virEventPollRemoveHandle:193 : mark delete 7 21
>2013-05-31 14:34:30.730+00007961: debug : virEventPollInterruptLocked:706 : Interrupting
>2013-05-31 14:34:30.730+00007961: debug : qemuMonitorUnref:248 : QEMU_MONITOR_UNREF: mon=0xf7bab0 refs=3
>2013-05-31 14:34:30.730+00007961: debug : qemuProcessKill:3781 : vm=wheezy_system pid=8016 flags=5
>2013-05-31 14:34:30.730+00007961: debug : qemuDomainCleanupRun:1995 : driver=0xe41b60, vm=wheezy_system
>2013-05-31 14:34:30.730+00007961: debug : qemuProcessAutoDestroyRemove:4329 : vm=wheezy_system
>2013-05-31 14:34:30.730+00007961: debug : qemuDriverCloseCallbackUnset:578 : vm=wheezy_system, uuid=d1c016b1-e7c0-4ce5-a039-2f06f7c7f8dd, cb=0x491940
>2013-05-31 14:34:30.730+00007961: debug : virSecurityDACRestoreSecurityAllLabel:516 : Restoring security label on wheezy_system migrated=0
>2013-05-31 14:34:30.730+00007961: info : virSecurityDACRestoreSecurityFileLabel:144 : Restoring DAC user and group on '/build-pool/d1c016b1-e7c0-4ce5-a039-2f06f7c7f8dd.img'
>2013-05-31 14:34:30.730+00007961: info : virSecurityDACSetOwnership:100 : Setting DAC user and group on '/build-pool/d1c016b1-e7c0-4ce5-a039-2f06f7c7f8dd.img' to '0:0'
>2013-05-31 14:34:30.730+00007961: debug : networkReleaseActualDevice:3109 : Nothing to release to network build-net
>2013-05-31 14:34:30.730+00007961: debug : qemuDomainObjEndJob:937 : Stopping job: destroy (async=none)
>2013-05-31 14:34:30.730+00007961: debug : virDomainObjUnref:1651 : obj=0xf7a110 refs=2
>2013-05-31 14:34:30.730+00007961: debug : virDomainObjUnref:1651 : obj=0xf7a110 refs=1
>2013-05-31 14:34:30.730+00007961: debug : virDomainFree:2345 : dom=0x10bf000, (VM: name=wheezy_system, uuid=d1c016b1-e7c0-4ce5-a039-2f06f7c7f8dd)
>2013-05-31 14:34:30.730+00007961: debug : virUnrefDomain:276 : unref domain 0x10bf000 wheezy_system 1
>2013-05-31 14:34:30.730+00007961: debug : virReleaseDomain:238 : release domain 0x10bf000 wheezy_system d1c016b1-e7c0-4ce5-a039-2f06f7c7f8dd
>2013-05-31 14:34:30.730+00007961: debug : virReleaseDomain:246 : unref connection 0xf45440 2
>2013-05-31 14:34:30.730+00007961: debug : virNetMessageEncodePayload:351 : Encode length as 28
>2013-05-31 14:34:30.730+00007961: debug : virNetServerClientSendMessage:1109 : msg=0x7fce500828f0 proc=12 len=28 offset=0
>2013-05-31 14:34:30.731+00007961: debug : virNetServerClientSendMessage:1119 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x7fce50000f60 len=28 prog=536903814 vers=1 proc=12 type=1 status=0 serial=5
>2013-05-31 14:34:30.731+00007961: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce50042160 tx=0x7fce500828f0
>2013-05-31 14:34:30.731+00007961: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2013-05-31 14:34:30.731+00007961: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=16 events=3
>2013-05-31 14:34:30.731+00007961: debug : virEventPollInterruptLocked:706 : Interrupting
>2013-05-31 14:34:30.731+00007961: debug : virNetServerProgramFree:534 : prog=0xe39bc0 refs=4
>2013-05-31 14:34:30.731+00007961: debug : virNetServerClientFree:591 : RPC_SERVER_CLIENT_FREE: client=0x7fce50000f60 refs=4
>2013-05-31 14:34:30.731+00007959: debug : qemuProcessHandleShutdown:647 : Ignoring SHUTDOWN event from inactive domain wheezy_system
>2013-05-31 14:34:30.731+00007959: debug : qemuMonitorUnref:248 : QEMU_MONITOR_UNREF: mon=0xf7bab0 refs=2
>2013-05-31 14:34:30.731+00007959: debug : qemuMonitorJSONIOProcess:210 : Total used 85 bytes out of 85 available in buffer
>2013-05-31 14:34:30.731+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=11 events=13
>2013-05-31 14:34:30.731+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.731+00007959: debug : qemuMonitorUnref:248 : QEMU_MONITOR_UNREF: mon=0xf7bab0 refs=1
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=14
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=9 w=15
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=10 w=16
>2013-05-31 14:34:30.731+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.731+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 11
>2013-05-31 14:34:30.731+00007959: debug : virEventPollCleanupHandles:567 : EVENT_POLL_PURGE_HANDLE: watch=11
>2013-05-31 14:34:30.731+00007959: debug : qemuMonitorUnref:248 : QEMU_MONITOR_UNREF: mon=0xf7bab0 refs=0
>2013-05-31 14:34:30.731+00007959: debug : qemuMonitorFree:225 : mon=0xf7bab0
>2013-05-31 14:34:30.731+00007959: debug : virDomainObjUnref:1651 : obj=0xf7a110 refs=0
>2013-05-31 14:34:30.731+00007959: debug : virDomainObjFree:1627 : obj=0xf7a110
>2013-05-31 14:34:30.731+00007959: debug : virStreamFree:15495 : stream=0xf44890
>2013-05-31 14:34:30.731+00007959: debug : virUnrefStream:1126 : unref stream 0xf44890 3
>2013-05-31 14:34:30.731+00007959: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-05-31 14:34:30.731+00007959: debug : virEventPollCleanupTimeouts:506 : Cleanup 6
>2013-05-31 14:34:30.731+00007959: debug : virEventPollCleanupHandles:554 : Cleanup 10
>2013-05-31 14:34:30.731+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-05-31 14:34:30.731+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-05-31 14:34:30.731+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=2 w=3, f=11 e=1 d=0
>2013-05-31 14:34:30.731+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=3 w=4, f=12 e=1 d=0
>2013-05-31 14:34:30.731+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=4 w=5, f=6 e=1 d=0
>2013-05-31 14:34:30.731+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=5 w=6, f=14 e=1 d=0
>2013-05-31 14:34:30.731+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-05-31 14:34:30.731+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=7 w=14, f=16 e=1 d=0
>2013-05-31 14:34:30.731+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=8 w=15, f=19 e=1 d=0
>2013-05-31 14:34:30.731+00007959: debug : virEventPollMakePollFDs:383 : Prepare n=9 w=16, f=20 e=5 d=0
>2013-05-31 14:34:30.731+00007959: debug : virEventPollCalculateTimeout:325 : Calculate expiry of 6 timers
>2013-05-31 14:34:30.731+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010873615
>2013-05-31 14:34:30.731+00007959: debug : virEventPollCalculateTimeout:331 : Got a timeout scheduled for 1370010875129
>2013-05-31 14:34:30.731+00007959: debug : virEventPollCalculateTimeout:351 : Timeout at 1370010873615 due in 2884 ms
>2013-05-31 14:34:30.731+00007959: debug : virEventPollRunOnce:619 : EVENT_POLL_RUN: nhandles=10 timeout=2884
>2013-05-31 14:34:30.731+00007959: debug : virEventPollRunOnce:630 : Poll got 4 event(s)
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchTimeouts:415 : Dispatch 6
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:460 : Dispatch 10
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=0 w=1
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=1 w=2
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=2 w=3
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=3 w=4
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=4 w=5
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=5 w=6
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=6 events=1
>2013-05-31 14:34:30.731+00007959: debug : udevEventHandleCallback:1467 : udev action: 'remove'
>2013-05-31 14:34:30.731+00007959: debug : udevRemoveOneDevice:1218 : Failed to find device to remove that has udev name '/sys/devices/virtual/net/vnet0/queues/rx-0'
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=6 w=7
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=7 w=14
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:474 : i=8 w=15
>2013-05-31 14:34:30.731+00007959: debug : virEventPollDispatchHandles:488 : EVENT_POLL_DISPATCH_HANDLE: watch=15 events=13
>2013-05-31 14:34:30.731+00007959: debug : daemonStreamEvent:144 : st=0xf44890 events=13 EOF=0 closed=0
>2013-05-31 14:34:30.731+00007959: debug : daemonStreamHandleRead:722 : client=0x7fce500014d0, stream=0xf448c0 tx=1 closed=0
>2013-05-31 14:34:30.731+00007959: debug : virStreamRecv:15027 : stream=0xf44890, data=0x7fce500c2960, nbytes=262120
>2013-05-31 14:34:30.731+00007959: debug : virNetMessageNew:48 : msg=0x7fce50102950 tracked=0
>2013-05-31 14:34:30.731+00007959: debug : virNetServerProgramSendStreamData:495 : client=0x7fce500014d0 msg=0x7fce50102950 data=0x7fce500c2960 len=0
>2013-05-31 14:34:30.731+00007959: debug : virNetMessageEncodePayloadEmpty:441 : Encode length as 28
>2013-05-31 14:34:30.731+00007959: debug : virNetServerProgramSendStreamData:523 : Total 28
>2013-05-31 14:34:30.731+00007959: debug : virNetServerClientSendMessage:1109 : msg=0x7fce50102950 proc=201 len=28 offset=0
>2013-05-31 14:34:30.731+00007959: debug : virNetServerClientSendMessage:1119 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x7fce500014d0 len=28 prog=536903814 vers=1 proc=201 type=3 status=2 serial=6
>2013-05-31 14:34:30.731+00007959: debug : virNetServerClientCalculateHandleMode:137 : tls=(nil) hs=-1, rx=0x7fce500020f0 tx=0x7fce50102950
>2013-05-31 14:34:30.731+00007959: debug : virNetServerClientCalculateHandleMode:167 : mode=3
>2013-05-31 14:34:30.731+00007959: debug : virEventPollUpdateHandle:151 : EVENT_POLL_UPDATE_HANDLE: watch=14 events=3
>2013-05-31 14:34:30.731+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.731+00007959: debug : virStreamEventRemoveCallback:15365 : stream=0xf44890
>2013-05-31 14:34:30.731+00007959: debug : virEventPollRemoveHandle:180 : EVENT_POLL_REMOVE_HANDLE: watch=15
>2013-05-31 14:34:30.731+00007959: debug : virEventPollRemoveHandle:193 : mark delete 8 19
>2013-05-31 14:34:30.731+00007959: debug : virEventPollInterruptLocked:702 : Skip interrupt, 1 1632499744
>2013-05-31 14:34:30.731+00007959: debug : virStreamAbort:15449 : stream=0xf44890
>2013-05-31 14:34:30.731+00007959: debug : virFDStreamCloseInt:250 : st=0xf44890
>
>
>     ====== end of log =====

Actions: View

Attachments on bug 969497: 915720