[Pkg-libvirt-maintainers] Bug#710517: libvirt-bin: Segfault when virsh destroy is called while virsh console is connected

Carpenter, Christopher ccarpenter at camber.com
Fri May 31 15:05:16 UTC 2013


Package: libvirt-bin
Version: 0.9.12-11.1
Severity: normal

Dear Maintainer,
I already made a bug with redhat but am unsure whether it is actually an upstream issue.
You can find it here https://bugzilla.redhat.com/show_bug.cgi?id=969497.

This bug seems to happen every time I try to virsh destroy (or use appropriate libvirt API call)
while already having an open console via virsh console. Exact 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>

I get the following messages when I run virsh destroy:
error: Failed to destroy domain wheezy_system
error: End of file while reading data: Input/output error

I also get the following in the log (WARNING: lots of text below):
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 =====

-- System Information:
Debian Release: 7.0
Architecture: amd64 (x86_64)

Kernel: Linux 3.2.0-4-amd64 (SMP w/16 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages libvirt-bin depends on:
ii  adduser             3.113+nmu3
ii  gettext-base        0.18.1.1-9
ii  libavahi-client3    0.6.31-2
ii  libavahi-common3    0.6.31-2
ii  libblkid1           2.20.1-5.3
ii  libc6               2.13-38
ii  libcap-ng0          0.6.6-2
ii  libdbus-1-3         1.6.8-1
ii  libdevmapper1.02.1  2:1.02.74-7
ii  libgcrypt11         1.5.0-5
ii  libgnutls26         2.12.20-6
ii  libnetcf1           0.1.9-2
ii  libnl1              1.1-7
ii  libnuma1            2.0.8~rc4-1
ii  libparted0debian1   2.3-12
ii  libpcap0.8          1.3.0-1
ii  libpciaccess0       0.13.1-2
ii  libreadline6        6.2+dfsg-0.1
ii  libsasl2-2          2.1.25.dfsg1-6
ii  libssh2-1           1.4.2-1.1
ii  libudev0            175-7.1
ii  libvirt0            0.9.12-11.1
ii  libxenstore3.0      4.1.4-2
ii  libxml2             2.8.0+dfsg1-7+nmu1
ii  libyajl2            2.0.4-2
ii  logrotate           3.8.1-4

Versions of packages libvirt-bin recommends:
ii  bridge-utils    1.5-6
ii  dmidecode       2.11-9
ii  dnsmasq-base    2.62-3+deb7u1
ii  ebtables        2.0.10.4-1
ii  gawk            1:4.0.1+dfsg-2.1
ii  iproute         20120521-3+b3
ii  iptables        1.4.14-3.1
ii  libxml2-utils   2.8.0+dfsg1-7+nmu1
ii  netcat-openbsd  1.105-7
ii  parted          2.3-12
ii  qemu-kvm        1.1.2+dfsg-6

Versions of packages libvirt-bin suggests:
pn  policykit-1  <none>
pn  radvd        <none>

-- no debconf information




The information contained in this email message, including any attachments, is
for the sole use of the intended recipients(s) and may contain confidential and
privileged information.  Any unauthorized review, use, disclosure or distribution
is prohibited.  If you are not the intended recipient and have received this
communication in error, please contact the sender by reply e-mail and destroy all
copies of the original message.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.alioth.debian.org/pipermail/pkg-libvirt-maintainers/attachments/20130531/b87d5492/attachment-0001.html>


More information about the Pkg-libvirt-maintainers mailing list