Attachment 680077 Details for Bug 896403 – libvirtd-crash.log

libvirtd-crash.log

libvirtd-crash.log (text/plain), 64.42 KB, created by yanbing du on 2013-01-17 08:34:16 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: yanbing du

Created: 2013-01-17 08:34:16 UTC

Size: 64.42 KB

patch

obsolete

>2013-01-17 08:00:57.487+0000: 22484: error : virFileRewrite:501 : cannot create file '/var/lib/libvirt/qemu/snapshot/test//tmp/test.sn.xml.new': No such file or directory
>2013-01-17 08:00:57.487+0000: 22484: warning : qemuDomainSnapshotCreateXML:11790 : unable to save metadata for snapshot /tmp/test.sn
>Caught Segmentation violation dumping internal log buffer:
>
>
>    ====== start of log =====
>
>hHandles:455 : Dispatch 9
>2013-01-17 08:02:29.129+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.129+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.129+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.129+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.129+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.129+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.129+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.129+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.129+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.129+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.129+000022481: debug : virNetMessageDecodeLength:152 : Got length, now need 40 total (36 more)
>2013-01-17 08:02:29.129+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1c9f800 tx=(nil)
>2013-01-17 08:02:29.129+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.129+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.129+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.129+000022481: debug : virNetServerClientDispatchRead:872 : RPC_SERVER_CLIENT_MSG_RX: client=0x1ca0290 len=40 prog=536903814 vers=1 proc=1 type=0 status=0 serial=2
>2013-01-17 08:02:29.129+000022481: debug : virKeepAliveCheckMessage:384 : ka=0x1ca0780, client=0x1ca0290, msg=0x1c9f800
>2013-01-17 08:02:29.129+000022481: debug : virEventPollUpdateTimeout:254 : EVENT_POLL_UPDATE_TIMEOUT: timer=21 frequency=5000
>2013-01-17 08:02:29.129+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.129+000022481: debug : virObjectRef:168 : OBJECT_REF: obj=0x1ca0290
>2013-01-17 08:02:29.129+000022481: debug : virNetServerDispatchNewMessage:218 : server=0x1c96d40 client=0x1ca0290 message=0x1c9f800
>2013-01-17 08:02:29.129+000022481: debug : virObjectRef:168 : OBJECT_REF: obj=0x1ca2020
>2013-01-17 08:02:29.129+000022481: debug : virNetMessageNew:45 : msg=0x1c9fe80 tracked=1
>2013-01-17 08:02:29.129+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1c9fe80 tx=(nil)
>2013-01-17 08:02:29.129+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.129+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.129+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.129+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.129+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.129+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.129+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.129+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.129+000022488: debug : virNetServerHandleJob:189 : server=0x1c96d40 client=0x1ca0290 message=0x1c9f800 prog=0x1ca2020
>2013-01-17 08:02:29.129+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.129+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.129+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.129+000022488: debug : virNetServerProgramDispatch:284 : prog=536903814 ver=1 type=0 status=0 serial=2 proc=1
>2013-01-17 08:02:29.129+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.129+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.129+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.129+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.129+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.129+000022488: debug : remoteDispatchOpenHelper:11127 : server=0x1c96d40 client=0x1ca0290 msg=0x1c9f800 rerr=0x7f96485f6b80 args=0x7f961c001980 ret=0x7f961c001910
>2013-01-17 08:02:29.129+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=1 d=0
>2013-01-17 08:02:29.129+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.129+000022488: debug : remoteDispatchOpen:731 : priv=0x1ca0530 conn=(nil)
>2013-01-17 08:02:29.129+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.129+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754129
>2013-01-17 08:02:29.129+000022488: debug : virConnectOpen:1331 : name=
>2013-01-17 08:02:29.129+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1203 ms
>2013-01-17 08:02:29.129+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1203
>2013-01-17 08:02:29.129+000022488: debug : virObjectNew:110 : OBJECT_NEW: obj=0x7f961c000d70 classname=virConnect
>2013-01-17 08:02:29.129+000022488: debug : virConnectGetConfigFile:953 : Loading config file '/etc/libvirt/libvirt.conf'
>2013-01-17 08:02:29.129+000022488: debug : virFileClose:72 : Closed fd 19
>2013-01-17 08:02:29.129+000022488: debug : do_open:1131 : no name, allowing driver auto-select
>2013-01-17 08:02:29.129+000022488: debug : do_open:1174 : trying driver 0 (Test) ...
>2013-01-17 08:02:29.129+000022488: debug : do_open:1180 : driver 0 Test returned DECLINED
>2013-01-17 08:02:29.129+000022488: debug : do_open:1174 : trying driver 1 (ESX) ...
>2013-01-17 08:02:29.129+000022488: debug : do_open:1180 : driver 1 ESX returned DECLINED
>2013-01-17 08:02:29.129+000022488: debug : do_open:1174 : trying driver 2 (remote) ...
>2013-01-17 08:02:29.129+000022488: debug : do_open:1180 : driver 2 remote returned DECLINED
>2013-01-17 08:02:29.129+000022488: debug : do_open:1174 : trying driver 3 (QEMU) ...
>2013-01-17 08:02:29.129+000022488: debug : do_open:1180 : driver 3 QEMU returned SUCCESS
>2013-01-17 08:02:29.129+000022488: debug : do_open:1202 : network driver 0 Test returned DECLINED
>2013-01-17 08:02:29.129+000022488: debug : do_open:1202 : network driver 1 ESX returned DECLINED
>2013-01-17 08:02:29.129+000022488: debug : do_open:1202 : network driver 2 remote returned DECLINED
>2013-01-17 08:02:29.129+000022488: debug : do_open:1202 : network driver 3 Network returned SUCCESS
>2013-01-17 08:02:29.129+000022488: debug : do_open:1217 : interface driver 0 Test returned DECLINED
>2013-01-17 08:02:29.129+000022488: debug : do_open:1217 : interface driver 1 ESX returned DECLINED
>2013-01-17 08:02:29.129+000022488: debug : do_open:1217 : interface driver 2 remote returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1217 : interface driver 3 Interface returned SUCCESS
>2013-01-17 08:02:29.136+000022488: debug : do_open:1233 : storage driver 0 Test returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1233 : storage driver 1 ESX returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1233 : storage driver 2 remote returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1233 : storage driver 3 storage returned SUCCESS
>2013-01-17 08:02:29.136+000022488: debug : do_open:1249 : node driver 0 Test returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1249 : node driver 1 ESX returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1249 : node driver 2 remote returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1249 : node driver 3 udevDeviceMonitor returned SUCCESS
>2013-01-17 08:02:29.136+000022488: debug : do_open:1265 : secret driver 0 Test returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1265 : secret driver 1 ESX returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1265 : secret driver 2 remote returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1265 : secret driver 3 secret returned SUCCESS
>2013-01-17 08:02:29.136+000022488: debug : do_open:1281 : nwfilter driver 0 Test returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1281 : nwfilter driver 1 ESX returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1281 : nwfilter driver 2 remote returned DECLINED
>2013-01-17 08:02:29.136+000022488: debug : do_open:1281 : nwfilter driver 3 nwfilter returned SUCCESS
>2013-01-17 08:02:29.136+000022488: debug : virNetMessageEncodePayload:358 : Encode length as 28
>2013-01-17 08:02:29.136+000022488: debug : virNetServerClientSendMessageLocked:1116 : msg=0x1c9f800 proc=1 len=28 offset=0
>2013-01-17 08:02:29.136+000022488: debug : virNetServerClientSendMessageLocked:1124 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x1ca0290 len=28 prog=536903814 vers=1 proc=1 type=1 status=0 serial=2
>2013-01-17 08:02:29.136+000022488: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1c9fe80 tx=0x1c9f800
>2013-01-17 08:02:29.136+000022488: debug : virNetServerClientCalculateHandleMode:183 : mode=3
>2013-01-17 08:02:29.136+000022488: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=3
>2013-01-17 08:02:29.136+000022488: debug : virEventPollInterruptLocked:701 : Interrupting
>2013-01-17 08:02:29.136+000022488: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x1ca2020
>2013-01-17 08:02:29.136+000022488: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x1ca0290
>2013-01-17 08:02:29.136+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.136+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=5 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754129
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1196 ms
>2013-01-17 08:02:29.136+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1196
>2013-01-17 08:02:29.136+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=18 events=2
>2013-01-17 08:02:29.136+000022481: debug : virNetMessageFree:73 : msg=0x1c9f800 nfds=0 cb=(nil)
>2013-01-17 08:02:29.136+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1c9fe80 tx=(nil)
>2013-01-17 08:02:29.136+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.136+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754129
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1196 ms
>2013-01-17 08:02:29.136+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1196
>2013-01-17 08:02:29.136+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.136+000022481: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2013-01-17 08:02:29.136+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1c9fe80 tx=(nil)
>2013-01-17 08:02:29.136+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.136+000022481: debug : virNetServerClientDispatchRead:872 : RPC_SERVER_CLIENT_MSG_RX: client=0x1ca0290 len=28 prog=536903814 vers=1 proc=110 type=0 status=0 serial=3
>2013-01-17 08:02:29.136+000022481: debug : virKeepAliveCheckMessage:384 : ka=0x1ca0780, client=0x1ca0290, msg=0x1c9fe80
>2013-01-17 08:02:29.136+000022481: debug : virEventPollUpdateTimeout:254 : EVENT_POLL_UPDATE_TIMEOUT: timer=21 frequency=5000
>2013-01-17 08:02:29.136+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.136+000022481: debug : virObjectRef:168 : OBJECT_REF: obj=0x1ca0290
>2013-01-17 08:02:29.136+000022481: debug : virNetServerDispatchNewMessage:218 : server=0x1c96d40 client=0x1ca0290 message=0x1c9fe80
>2013-01-17 08:02:29.136+000022481: debug : virObjectRef:168 : OBJECT_REF: obj=0x1ca2020
>2013-01-17 08:02:29.136+000022481: debug : virNetMessageNew:45 : msg=0x1ca0dd0 tracked=1
>2013-01-17 08:02:29.136+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1ca0dd0 tx=(nil)
>2013-01-17 08:02:29.136+000022486: debug : virNetServerHandleJob:189 : server=0x1c96d40 client=0x1ca0290 message=0x1c9fe80 prog=0x1ca2020
>2013-01-17 08:02:29.136+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.136+000022486: debug : virNetServerProgramDispatch:284 : prog=536903814 ver=1 type=0 status=0 serial=3 proc=110
>2013-01-17 08:02:29.136+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.136+000022486: debug : remoteDispatchGetURIHelper:7297 : server=0x1c96d40 client=0x1ca0290 msg=0x1c9fe80 rerr=0x7f96499f8b80 args=0x7f9618000cb0 ret=0x7f9618000c40
>2013-01-17 08:02:29.136+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.136+000022486: debug : virConnectGetURI:1700 : conn=0x7f961c000d70
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.136+000022486: debug : virNetMessageEncodePayload:358 : Encode length as 48
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.136+000022486: debug : virNetServerClientSendMessageLocked:1116 : msg=0x1c9fe80 proc=110 len=48 offset=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.136+000022486: debug : virNetServerClientSendMessageLocked:1124 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x1ca0290 len=48 prog=536903814 vers=1 proc=110 type=1 status=0 serial=3
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.136+000022486: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1ca0dd0 tx=0x1c9fe80
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.136+000022486: debug : virNetServerClientCalculateHandleMode:183 : mode=3
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.136+000022486: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=3
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754136
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1196 ms
>2013-01-17 08:02:29.136+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1196
>2013-01-17 08:02:29.136+000022486: debug : virEventPollInterruptLocked:701 : Interrupting
>2013-01-17 08:02:29.136+000022486: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x1ca2020
>2013-01-17 08:02:29.136+000022486: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x1ca0290
>2013-01-17 08:02:29.136+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.136+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=5 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754136
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1196 ms
>2013-01-17 08:02:29.136+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1196
>2013-01-17 08:02:29.136+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.136+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=18 events=2
>2013-01-17 08:02:29.136+000022481: debug : virNetMessageFree:73 : msg=0x1c9fe80 nfds=0 cb=(nil)
>2013-01-17 08:02:29.136+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1ca0dd0 tx=(nil)
>2013-01-17 08:02:29.136+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.136+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.136+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=1 d=0
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754136
>2013-01-17 08:02:29.136+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1196 ms
>2013-01-17 08:02:29.136+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1196
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022481: debug : virNetMessageDecodeLength:152 : Got length, now need 36 total (32 more)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1ca0dd0 tx=(nil)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientDispatchRead:872 : RPC_SERVER_CLIENT_MSG_RX: client=0x1ca0290 len=36 prog=536903814 vers=1 proc=23 type=0 status=0 serial=4
>2013-01-17 08:02:29.137+000022481: debug : virKeepAliveCheckMessage:384 : ka=0x1ca0780, client=0x1ca0290, msg=0x1ca0dd0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateTimeout:254 : EVENT_POLL_UPDATE_TIMEOUT: timer=21 frequency=5000
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virObjectRef:168 : OBJECT_REF: obj=0x1ca0290
>2013-01-17 08:02:29.137+000022481: debug : virNetServerDispatchNewMessage:218 : server=0x1c96d40 client=0x1ca0290 message=0x1ca0dd0
>2013-01-17 08:02:29.137+000022481: debug : virObjectRef:168 : OBJECT_REF: obj=0x1ca2020
>2013-01-17 08:02:29.137+000022481: debug : virNetMessageNew:45 : msg=0x1c9f9c0 tracked=1
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1c9f9c0 tx=(nil)
>2013-01-17 08:02:29.137+000022482: debug : virNetServerHandleJob:189 : server=0x1c96d40 client=0x1ca0290 message=0x1ca0dd0 prog=0x1ca2020
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022482: debug : virNetServerProgramDispatch:284 : prog=536903814 ver=1 type=0 status=0 serial=4 proc=23
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022482: debug : remoteDispatchDomainLookupByNameHelper:3084 : server=0x1c96d40 client=0x1ca0290 msg=0x1ca0dd0 rerr=0x7f964c1fcb80 args=0x7f964017d170 ret=0x7f9640180640
>2013-01-17 08:02:29.137+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022482: debug : virDomainLookupByName:2117 : conn=0x7f961c000d70, name=test
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.137+000022482: debug : virObjectNew:110 : OBJECT_NEW: obj=0x7f9640180600 classname=virDomain
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.137+000022482: debug : virObjectRef:168 : OBJECT_REF: obj=0x7f961c000d70
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.137+000022482: debug : virDomainFree:2281 : dom=0x7f9640180600, (VM: name=test, uuid=c5ad5462-047a-e52e-a673-fd3a1d31328d)
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.137+000022482: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7f9640180600
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.137+000022482: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0x7f9640180600
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.137+000022482: debug : virDomainDispose:225 : release domain 0x7f9640180600 test c5ad5462-047a-e52e-a673-fd3a1d31328d
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.137+000022482: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7f961c000d70
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754137
>2013-01-17 08:02:29.137+000022482: debug : virNetMessageEncodePayload:358 : Encode length as 56
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1195 ms
>2013-01-17 08:02:29.137+000022482: debug : virNetServerClientSendMessageLocked:1116 : msg=0x1ca0dd0 proc=23 len=56 offset=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1195
>2013-01-17 08:02:29.137+000022482: debug : virNetServerClientSendMessageLocked:1124 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x1ca0290 len=56 prog=536903814 vers=1 proc=23 type=1 status=0 serial=4
>2013-01-17 08:02:29.137+000022482: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1c9f9c0 tx=0x1ca0dd0
>2013-01-17 08:02:29.137+000022482: debug : virNetServerClientCalculateHandleMode:183 : mode=3
>2013-01-17 08:02:29.137+000022482: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=3
>2013-01-17 08:02:29.137+000022482: debug : virEventPollInterruptLocked:701 : Interrupting
>2013-01-17 08:02:29.137+000022482: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x1ca2020
>2013-01-17 08:02:29.137+000022482: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x1ca0290
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=5 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754137
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1195 ms
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1195
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=18 events=2
>2013-01-17 08:02:29.137+000022481: debug : virNetMessageFree:73 : msg=0x1ca0dd0 nfds=0 cb=(nil)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1c9f9c0 tx=(nil)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754137
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1195 ms
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1195
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022481: debug : virNetMessageDecodeLength:152 : Got length, now need 76 total (72 more)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1c9f9c0 tx=(nil)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientDispatchRead:872 : RPC_SERVER_CLIENT_MSG_RX: client=0x1ca0290 len=76 prog=536903814 vers=1 proc=189 type=0 status=0 serial=5
>2013-01-17 08:02:29.137+000022481: debug : virKeepAliveCheckMessage:384 : ka=0x1ca0780, client=0x1ca0290, msg=0x1c9f9c0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateTimeout:254 : EVENT_POLL_UPDATE_TIMEOUT: timer=21 frequency=5000
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virObjectRef:168 : OBJECT_REF: obj=0x1ca0290
>2013-01-17 08:02:29.137+000022481: debug : virNetServerDispatchNewMessage:218 : server=0x1c96d40 client=0x1ca0290 message=0x1c9f9c0
>2013-01-17 08:02:29.137+000022481: debug : virObjectRef:168 : OBJECT_REF: obj=0x1ca2020
>2013-01-17 08:02:29.137+000022481: debug : virNetMessageNew:45 : msg=0x1ca0e40 tracked=1
>2013-01-17 08:02:29.137+000022483: debug : virNetServerHandleJob:189 : server=0x1c96d40 client=0x1ca0290 message=0x1c9f9c0 prog=0x1ca2020
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1ca0e40 tx=(nil)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.137+000022483: debug : virNetServerProgramDispatch:284 : prog=536903814 ver=1 type=0 status=0 serial=5 proc=189
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022483: debug : remoteDispatchDomainSnapshotLookupByNameHelper:6461 : server=0x1c96d40 client=0x1ca0290 msg=0x1c9f9c0 rerr=0x7f964b7fbb80 args=0x7f9630001120 ret=0x7f9630001160
>2013-01-17 08:02:29.137+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022483: debug : virObjectNew:110 : OBJECT_NEW: obj=0x7f9630000cd0 classname=virDomain
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022483: debug : virObjectRef:168 : OBJECT_REF: obj=0x7f961c000d70
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.137+000022483: debug : virDomainSnapshotLookupByName:18449 : dom=0x7f9630000cd0, (VM: name=test, uuid=c5ad5462-047a-e52e-a673-fd3a1d31328d), name=/tmp/test.sn, flags=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.137+000022483: debug : virObjectNew:110 : OBJECT_NEW: obj=0x7f96300011d0 classname=virDomainSnapshot
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.137+000022483: debug : virObjectRef:168 : OBJECT_REF: obj=0x7f9630000cd0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.137+000022483: debug : virDomainFree:2281 : dom=0x7f9630000cd0, (VM: name=test, uuid=c5ad5462-047a-e52e-a673-fd3a1d31328d)
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=1 d=0
>2013-01-17 08:02:29.137+000022483: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7f9630000cd0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.137+000022483: debug : virDomainSnapshotFree:18887 : snapshot=0x7f96300011d0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.137+000022483: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7f96300011d0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754137
>2013-01-17 08:02:29.137+000022483: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0x7f96300011d0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1195 ms
>2013-01-17 08:02:29.137+000022483: debug : virDomainSnapshotDispose:793 : release snapshot 0x7f96300011d0 /tmp/test.sn
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1195
>2013-01-17 08:02:29.137+000022483: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7f9630000cd0
>2013-01-17 08:02:29.137+000022483: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0x7f9630000cd0
>2013-01-17 08:02:29.137+000022483: debug : virDomainDispose:225 : release domain 0x7f9630000cd0 test c5ad5462-047a-e52e-a673-fd3a1d31328d
>2013-01-17 08:02:29.137+000022483: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x7f961c000d70
>2013-01-17 08:02:29.137+000022483: debug : virNetMessageEncodePayload:358 : Encode length as 72
>2013-01-17 08:02:29.137+000022483: debug : virNetServerClientSendMessageLocked:1116 : msg=0x1c9f9c0 proc=189 len=72 offset=0
>2013-01-17 08:02:29.137+000022483: debug : virNetServerClientSendMessageLocked:1124 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x1ca0290 len=72 prog=536903814 vers=1 proc=189 type=1 status=0 serial=5
>2013-01-17 08:02:29.137+000022483: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1ca0e40 tx=0x1c9f9c0
>2013-01-17 08:02:29.137+000022483: debug : virNetServerClientCalculateHandleMode:183 : mode=3
>2013-01-17 08:02:29.137+000022483: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=3
>2013-01-17 08:02:29.137+000022483: debug : virEventPollInterruptLocked:701 : Interrupting
>2013-01-17 08:02:29.137+000022483: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x1ca2020
>2013-01-17 08:02:29.137+000022483: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x1ca0290
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=5 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754137
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1195 ms
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1195
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=18 events=2
>2013-01-17 08:02:29.137+000022481: debug : virNetMessageFree:73 : msg=0x1c9f9c0 nfds=0 cb=(nil)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1ca0e40 tx=(nil)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754137
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1195 ms
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1195
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchTimeouts:410 : Dispatch 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:455 : Dispatch 9
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=1 w=2
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=2 w=3
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=3 w=4
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=4 w=5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=5 w=6
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=6 w=7
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=7 w=13
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:469 : i=8 w=18
>2013-01-17 08:02:29.137+000022481: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022481: debug : virNetMessageDecodeLength:152 : Got length, now need 76 total (72 more)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1ca0e40 tx=(nil)
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientDispatchRead:872 : RPC_SERVER_CLIENT_MSG_RX: client=0x1ca0290 len=76 prog=536903814 vers=1 proc=193 type=0 status=0 serial=6
>2013-01-17 08:02:29.137+000022481: debug : virKeepAliveCheckMessage:384 : ka=0x1ca0780, client=0x1ca0290, msg=0x1ca0e40
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateTimeout:254 : EVENT_POLL_UPDATE_TIMEOUT: timer=21 frequency=5000
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virObjectRef:168 : OBJECT_REF: obj=0x1ca0290
>2013-01-17 08:02:29.137+000022481: debug : virNetServerDispatchNewMessage:218 : server=0x1c96d40 client=0x1ca0290 message=0x1ca0e40
>2013-01-17 08:02:29.137+000022481: debug : virObjectRef:168 : OBJECT_REF: obj=0x1ca2020
>2013-01-17 08:02:29.137+000022481: debug : virNetMessageNew:45 : msg=0x1ca06a0 tracked=1
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:152 : tls=(nil) hs=-1, rx=0x1ca06a0 tx=(nil)
>2013-01-17 08:02:29.137+000022484: debug : virNetServerHandleJob:189 : server=0x1c96d40 client=0x1ca0290 message=0x1ca0e40 prog=0x1ca2020
>2013-01-17 08:02:29.137+000022481: debug : virNetServerClientCalculateHandleMode:183 : mode=1
>2013-01-17 08:02:29.137+000022484: debug : virNetServerProgramDispatch:284 : prog=536903814 ver=1 type=0 status=0 serial=6 proc=193
>2013-01-17 08:02:29.137+000022481: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=18 events=1
>2013-01-17 08:02:29.137+000022481: debug : virEventPollInterruptLocked:697 : Skip interrupt, 1 1376319584
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022484: debug : remoteDispatchDomainSnapshotDeleteHelper:5984 : server=0x1c96d40 client=0x1ca0290 msg=0x1ca0e40 rerr=0x7f964adfab80 args=0x7f9634009380 ret=0x7f9634009360
>2013-01-17 08:02:29.137+000022481: debug : virEventRunDefaultImpl:244 : running default event implementation
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupTimeouts:501 : Cleanup 5
>2013-01-17 08:02:29.137+000022484: debug : virObjectNew:110 : OBJECT_NEW: obj=0x7f963400a480 classname=virDomain
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCleanupHandles:549 : Cleanup 9
>2013-01-17 08:02:29.137+000022484: debug : virObjectRef:168 : OBJECT_REF: obj=0x7f961c000d70
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=7 e=1 d=0
>2013-01-17 08:02:29.137+000022484: debug : virObjectNew:110 : OBJECT_NEW: obj=0x7f9634009430 classname=virDomainSnapshot
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=9 e=1 d=0
>2013-01-17 08:02:29.137+000022484: debug : virObjectRef:168 : OBJECT_REF: obj=0x7f963400a480
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=2 w=3, f=12 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=3 w=4, f=13 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=4 w=5, f=18 e=1 d=0
>2013-01-17 08:02:29.137+000022484: debug : virDomainSnapshotDelete:18805 : snapshot=0x7f9634009430, flags=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=5 w=6, f=6 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=6 w=7, f=15 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=7 w=13, f=21 e=1 d=0
>2013-01-17 08:02:29.137+000022484: debug : virObjectRef:168 : OBJECT_REF: obj=0x7f9640169ac0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollMakePollFDs:378 : Prepare n=8 w=18, f=17 e=1 d=0
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 5 timers
>2013-01-17 08:02:29.137+000022484: debug : qemuDomainObjBeginJobInternal:808 : Starting job: modify (async=none)
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409750332
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:326 : Got a timeout scheduled for 1358409754137
>2013-01-17 08:02:29.137+000022481: debug : virEventPollCalculateTimeout:346 : Timeout at 1358409750332 due in 1195 ms
>2013-01-17 08:02:29.137+000022481: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=9 timeout=1195
>
>
>     ====== end of log =====
>

Actions: View

Attachments on bug 896403: 680077