[libvirt] 1.2.0 segfault on Centos 6
Hi, using libvirt 1.2.0 on a up-to-date Centos6.5 machine leads to occasional segmentation faults (see below). Sometimes it runs for 5 minutes, sometimes for an hour, but after that the result is always the same: segfault after some weird qom-list, that apparently the qemu version on centos doesn't know. Has 1.2.1 a known fix for this? Franky (debug log of last crash is below the dotted line) ------------------------------------------------- 2014-02-04 15:50:27.351+0000: 9082: error : qemuMonitorJSONCheckError:354 : internal error: unable to execute QEMU command 'qom-list': The command qom-list has not been found Caught Segmentation violation dumping internal log buffer: ====== start of log ===== +0000: 9084: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac58000ac0 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac58000ac0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventRunDefaultImpl:271 : running default event implementation 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.347+0000: 9084: debug : remoteDispatchDomainLookupByNameHelper:4965 : server=0x7fac7ce77ae0 client=0x7fac7ce86610 msg=0x7fac7ce827f0 rerr=0x7fac6c5b3bc0 args=0x7fac40002730 ret=0x7fac40002790 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.347+0000: 9084: debug : virDomainLookupByName:2269 : conn=0x7fac340018a0, name=bqafm0001ap.frm.meshcore.net 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=0 w=1, f=5 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=1 w=2, f=7 e=1 d=0 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac7ce760b0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=2 w=3, f=12 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=3 w=4, f=13 e=1 d=0 2014-02-04 15:50:27.347+0000: 9084: debug : virAccessManagerCheckDomain:231 : manager=0x7fac7ce760b0(name=stack) driver=QEMU domain=0x7fac5c2386c0 perm=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=4 w=5, f=14 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=5 w=6, f=15 e=1 d=0 2014-02-04 15:50:27.347+0000: 9084: debug : virAccessManagerCheckDomain:231 : manager=0x7fac7ce776f0(name=none) driver=QEMU domain=0x7fac5c2386c0 perm=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=6 w=7, f=16 e=1 d=0 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac7ce760b0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=7 w=8, f=17 e=1 d=0 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectNew:199 : OBJECT_NEW: obj=0x7fac40002750 classname=virDomain 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=8 w=9, f=19 e=1 d=0 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac340018a0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=9 w=10, f=23 e=25 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=10 w=11, f=25 e=25 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=11 w=12, f=24 e=25 d=0 2014-02-04 15:50:27.347+0000: 9084: debug : virDomainFree:2433 : dom=0x7fac40002750, (VM: name=bqafm0001ap.frm.meshcore.net, uuid=3b009e73-e095-29fa-8970-f5c2b647d5a0) 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=12 w=13, f=26 e=25 d=0 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac40002750 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=13 w=14, f=27 e=1 d=0 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectUnref:258 : OBJECT_DISPOSE: obj=0x7fac40002750 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=14 w=58, f=28 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 5 timers 2014-02-04 15:50:27.347+0000: 9084: debug : virDomainDispose:264 : release domain 0x7fac40002750 bqafm0001ap.frm.meshcore.net 3b009e73-e095-29fa-8970-f5c2b647d5a0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529031312 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac340018a0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529032347 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac58000ac0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1391529031312 now=1391529027347 2014-02-04 15:50:27.347+0000: 9084: debug : virNetMessageEncodePayload:374 : Encode length as 80 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCalculateTimeout:362 : Timeout at 1391529031312 due in 3965 ms 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac58000ac0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollRunOnce:630 : EVENT_POLL_RUN: nhandles=15 timeout=3965 2014-02-04 15:50:27.347+0000: 9084: debug : virNetServerClientSendMessageLocked:1451 : msg=0x7fac7ce827f0 proc=23 len=80 offset=0 2014-02-04 15:50:27.347+0000: 9084: debug : virNetServerClientSendMessageLocked:1459 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x7fac7ce86610 len=80 prog=536903814 vers=1 proc=23 type=1 status=0 serial=4 2014-02-04 15:50:27.347+0000: 9084: debug : virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1, rx=0x7fac7ce86c80 tx=0x7fac7ce827f0 2014-02-04 15:50:27.347+0000: 9084: debug : virNetServerClientCalculateHandleMode:188 : mode=3 2014-02-04 15:50:27.347+0000: 9084: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=58 events=3 2014-02-04 15:50:27.347+0000: 9084: debug : virEventPollInterruptLocked:717 : Interrupting 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac7ce80030 2014-02-04 15:50:27.347+0000: 9084: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac7ce86610 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollRunOnce:641 : Poll got 1 event(s) 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchTimeouts:426 : Dispatch 5 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:471 : Dispatch 15 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=0 w=1 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:499 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=1 w=2 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=2 w=3 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=3 w=4 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=4 w=5 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=5 w=6 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=6 w=7 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=7 w=8 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=8 w=9 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=9 w=10 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=10 w=11 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=11 w=12 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=12 w=13 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=13 w=14 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollDispatchHandles:485 : i=14 w=58 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.347+0000: 9081: debug : virEventRunDefaultImpl:271 : running default event implementation 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=0 w=1, f=5 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=1 w=2, f=7 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=2 w=3, f=12 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=3 w=4, f=13 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=4 w=5, f=14 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=5 w=6, f=15 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=6 w=7, f=16 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=7 w=8, f=17 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=8 w=9, f=19 e=1 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=9 w=10, f=23 e=25 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=10 w=11, f=25 e=25 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=11 w=12, f=24 e=25 d=0 2014-02-04 15:50:27.347+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=12 w=13, f=26 e=25 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=13 w=14, f=27 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=14 w=58, f=28 e=5 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 5 timers 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529031312 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529032347 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1391529031312 now=1391529027348 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:362 : Timeout at 1391529031312 due in 3964 ms 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollRunOnce:630 : EVENT_POLL_RUN: nhandles=15 timeout=3964 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollRunOnce:641 : Poll got 1 event(s) 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchTimeouts:426 : Dispatch 5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:471 : Dispatch 15 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=0 w=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=1 w=2 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=2 w=3 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=3 w=4 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=4 w=5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=5 w=6 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=6 w=7 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=7 w=8 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=8 w=9 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=9 w=10 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=10 w=11 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=11 w=12 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=12 w=13 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=13 w=14 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=14 w=58 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:499 : EVENT_POLL_DISPATCH_HANDLE: watch=58 events=2 2014-02-04 15:50:27.348+0000: 9081: debug : virNetMessageFree:72 : msg=0x7fac7ce827f0 nfds=0 cb=(nil) 2014-02-04 15:50:27.348+0000: 9081: debug : virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1, rx=0x7fac7ce86c80 tx=(nil) 2014-02-04 15:50:27.348+0000: 9081: debug : virNetServerClientCalculateHandleMode:188 : mode=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=58 events=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollInterruptLocked:713 : Skip interrupt, 1 140378773645312 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.348+0000: 9081: debug : virEventRunDefaultImpl:271 : running default event implementation 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=0 w=1, f=5 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=1 w=2, f=7 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=2 w=3, f=12 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=3 w=4, f=13 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=4 w=5, f=14 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=5 w=6, f=15 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=6 w=7, f=16 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=7 w=8, f=17 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=8 w=9, f=19 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=9 w=10, f=23 e=25 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=10 w=11, f=25 e=25 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=11 w=12, f=24 e=25 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=12 w=13, f=26 e=25 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=13 w=14, f=27 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=14 w=58, f=28 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 5 timers 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529031312 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529032347 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1391529031312 now=1391529027348 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:362 : Timeout at 1391529031312 due in 3964 ms 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollRunOnce:630 : EVENT_POLL_RUN: nhandles=15 timeout=3964 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollRunOnce:641 : Poll got 1 event(s) 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchTimeouts:426 : Dispatch 5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:471 : Dispatch 15 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=0 w=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=1 w=2 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=2 w=3 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=3 w=4 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=4 w=5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=5 w=6 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=6 w=7 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=7 w=8 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=8 w=9 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=9 w=10 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=10 w=11 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=11 w=12 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=12 w=13 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=13 w=14 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=14 w=58 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:499 : EVENT_POLL_DISPATCH_HANDLE: watch=58 events=1 2014-02-04 15:50:27.348+0000: 9081: debug : virNetMessageDecodeLength:149 : Got length, now need 80 total (76 more) 2014-02-04 15:50:27.348+0000: 9081: debug : virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1, rx=0x7fac7ce86c80 tx=(nil) 2014-02-04 15:50:27.348+0000: 9081: debug : virNetServerClientCalculateHandleMode:188 : mode=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=58 events=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollInterruptLocked:713 : Skip interrupt, 1 140378773645312 2014-02-04 15:50:27.348+0000: 9081: debug : virNetServerClientDispatchRead:1202 : RPC_SERVER_CLIENT_MSG_RX: client=0x7fac7ce86610 len=80 prog=536903814 vers=1 proc=150 type=0 status=0 serial=5 2014-02-04 15:50:27.348+0000: 9081: debug : virKeepAliveCheckMessage:374 : ka=0x7fac7ce86d60, client=0x7fac7ce86610, msg=0x7fac7ce86c80 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollUpdateTimeout:260 : EVENT_POLL_UPDATE_TIMEOUT: timer=59 frequency=5000 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollUpdateTimeout:278 : Set timer freq=5000 expires=1391529032348 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollInterruptLocked:713 : Skip interrupt, 1 140378773645312 2014-02-04 15:50:27.348+0000: 9081: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac7ce86610 2014-02-04 15:50:27.348+0000: 9081: debug : virNetServerDispatchNewMessage:213 : server=0x7fac7ce77ae0 client=0x7fac7ce86610 message=0x7fac7ce86c80 2014-02-04 15:50:27.348+0000: 9081: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac7ce80030 2014-02-04 15:50:27.348+0000: 9081: debug : virNetMessageNew:44 : msg=0x7fac7ce86e60 tracked=1 2014-02-04 15:50:27.348+0000: 9081: debug : virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1, rx=0x7fac7ce86e60 tx=(nil) 2014-02-04 15:50:27.348+0000: 9083: debug : virNetServerHandleJob:184 : server=0x7fac7ce77ae0 client=0x7fac7ce86610 message=0x7fac7ce86c80 prog=0x7fac7ce80030 2014-02-04 15:50:27.348+0000: 9081: debug : virNetServerClientCalculateHandleMode:188 : mode=1 2014-02-04 15:50:27.348+0000: 9083: debug : virNetServerProgramDispatch:285 : prog=536903814 ver=1 type=0 status=0 serial=5 proc=150 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=58 events=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollInterruptLocked:713 : Skip interrupt, 1 140378773645312 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac58000ac0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventRunDefaultImpl:271 : running default event implementation 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac58000ac0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.348+0000: 9083: debug : remoteDispatchDomainIsActiveHelper:4723 : server=0x7fac7ce77ae0 client=0x7fac7ce86610 msg=0x7fac7ce86c80 rerr=0x7fac6cfb4bc0 args=0x7fac50000970 ret=0x7fac50000910 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectNew:199 : OBJECT_NEW: obj=0x7fac50000930 classname=virDomain 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=0 w=1, f=5 e=1 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac340018a0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=1 w=2, f=7 e=1 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virDomainIsActive:17649 : dom=0x7fac50000930 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=2 w=3, f=12 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=3 w=4, f=13 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=4 w=5, f=14 e=1 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac7ce760b0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=5 w=6, f=15 e=1 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virAccessManagerCheckDomain:231 : manager=0x7fac7ce760b0(name=stack) driver=QEMU domain=0x7fac5c2386c0 perm=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=6 w=7, f=16 e=1 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virAccessManagerCheckDomain:231 : manager=0x7fac7ce776f0(name=none) driver=QEMU domain=0x7fac5c2386c0 perm=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=7 w=8, f=17 e=1 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac7ce760b0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=8 w=9, f=19 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=9 w=10, f=23 e=25 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virDomainFree:2433 : dom=0x7fac50000930, (VM: name=bqafm0001ap.frm.meshcore.net, uuid=3b009e73-e095-29fa-8970-f5c2b647d5a0) 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=10 w=11, f=25 e=25 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac50000930 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=11 w=12, f=24 e=25 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectUnref:258 : OBJECT_DISPOSE: obj=0x7fac50000930 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=12 w=13, f=26 e=25 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=13 w=14, f=27 e=1 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virDomainDispose:264 : release domain 0x7fac50000930 bqafm0001ap.frm.meshcore.net 3b009e73-e095-29fa-8970-f5c2b647d5a0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=14 w=58, f=28 e=1 d=0 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac340018a0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 5 timers 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac58000ac0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529031312 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529032348 2014-02-04 15:50:27.348+0000: 9083: debug : virNetMessageEncodePayload:374 : Encode length as 32 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac58000ac0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1391529031312 now=1391529027348 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:362 : Timeout at 1391529031312 due in 3964 ms 2014-02-04 15:50:27.348+0000: 9083: debug : virNetServerClientSendMessageLocked:1451 : msg=0x7fac7ce86c80 proc=150 len=32 offset=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollRunOnce:630 : EVENT_POLL_RUN: nhandles=15 timeout=3964 2014-02-04 15:50:27.348+0000: 9083: debug : virNetServerClientSendMessageLocked:1459 : RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x7fac7ce86610 len=32 prog=536903814 vers=1 proc=150 type=1 status=0 serial=5 2014-02-04 15:50:27.348+0000: 9083: debug : virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1, rx=0x7fac7ce86e60 tx=0x7fac7ce86c80 2014-02-04 15:50:27.348+0000: 9083: debug : virNetServerClientCalculateHandleMode:188 : mode=3 2014-02-04 15:50:27.348+0000: 9083: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=58 events=3 2014-02-04 15:50:27.348+0000: 9083: debug : virEventPollInterruptLocked:717 : Interrupting 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac7ce80030 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollRunOnce:641 : Poll got 1 event(s) 2014-02-04 15:50:27.348+0000: 9083: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac7ce86610 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchTimeouts:426 : Dispatch 5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:471 : Dispatch 15 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=0 w=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:499 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=1 w=2 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=2 w=3 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=3 w=4 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=4 w=5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=5 w=6 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=6 w=7 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=7 w=8 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=8 w=9 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=9 w=10 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=10 w=11 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=11 w=12 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=12 w=13 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=13 w=14 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=14 w=58 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.348+0000: 9081: debug : virEventRunDefaultImpl:271 : running default event implementation 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=0 w=1, f=5 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=1 w=2, f=7 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=2 w=3, f=12 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=3 w=4, f=13 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=4 w=5, f=14 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=5 w=6, f=15 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=6 w=7, f=16 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=7 w=8, f=17 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=8 w=9, f=19 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=9 w=10, f=23 e=25 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=10 w=11, f=25 e=25 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=11 w=12, f=24 e=25 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=12 w=13, f=26 e=25 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=13 w=14, f=27 e=1 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=14 w=58, f=28 e=5 d=0 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 5 timers 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529031312 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529032348 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1391529031312 now=1391529027348 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollCalculateTimeout:362 : Timeout at 1391529031312 due in 3964 ms 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollRunOnce:630 : EVENT_POLL_RUN: nhandles=15 timeout=3964 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollRunOnce:641 : Poll got 1 event(s) 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchTimeouts:426 : Dispatch 5 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:471 : Dispatch 15 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=0 w=1 2014-02-04 15:50:27.348+0000: 9081: debug : virEventPollDispatchHandles:485 : i=1 w=2 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=2 w=3 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=3 w=4 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=4 w=5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=5 w=6 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=6 w=7 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=7 w=8 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=8 w=9 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=9 w=10 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=10 w=11 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=11 w=12 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=12 w=13 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=13 w=14 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=14 w=58 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:499 : EVENT_POLL_DISPATCH_HANDLE: watch=58 events=2 2014-02-04 15:50:27.349+0000: 9081: debug : virNetMessageFree:72 : msg=0x7fac7ce86c80 nfds=0 cb=(nil) 2014-02-04 15:50:27.349+0000: 9081: debug : virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1, rx=0x7fac7ce86e60 tx=(nil) 2014-02-04 15:50:27.349+0000: 9081: debug : virNetServerClientCalculateHandleMode:188 : mode=1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=58 events=1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollInterruptLocked:713 : Skip interrupt, 1 140378773645312 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.349+0000: 9081: debug : virEventRunDefaultImpl:271 : running default event implementation 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=0 w=1, f=5 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=1 w=2, f=7 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=2 w=3, f=12 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=3 w=4, f=13 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=4 w=5, f=14 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=5 w=6, f=15 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=6 w=7, f=16 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=7 w=8, f=17 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=8 w=9, f=19 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=9 w=10, f=23 e=25 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=10 w=11, f=25 e=25 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=11 w=12, f=24 e=25 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=12 w=13, f=26 e=25 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=13 w=14, f=27 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=14 w=58, f=28 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 5 timers 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529031312 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529032348 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1391529031312 now=1391529027349 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:362 : Timeout at 1391529031312 due in 3963 ms 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollRunOnce:630 : EVENT_POLL_RUN: nhandles=15 timeout=3963 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollRunOnce:641 : Poll got 1 event(s) 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchTimeouts:426 : Dispatch 5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:471 : Dispatch 15 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=0 w=1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=1 w=2 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=2 w=3 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=3 w=4 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=4 w=5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=5 w=6 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=6 w=7 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=7 w=8 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=8 w=9 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=9 w=10 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=10 w=11 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=11 w=12 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=12 w=13 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=13 w=14 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=14 w=58 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:499 : EVENT_POLL_DISPATCH_HANDLE: watch=58 events=1 2014-02-04 15:50:27.349+0000: 9081: debug : virNetMessageDecodeLength:149 : Got length, now need 88 total (84 more) 2014-02-04 15:50:27.349+0000: 9081: debug : virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1, rx=0x7fac7ce86e60 tx=(nil) 2014-02-04 15:50:27.349+0000: 9081: debug : virNetServerClientCalculateHandleMode:188 : mode=1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=58 events=1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollInterruptLocked:713 : Skip interrupt, 1 140378773645312 2014-02-04 15:50:27.349+0000: 9081: debug : virNetServerClientDispatchRead:1202 : RPC_SERVER_CLIENT_MSG_RX: client=0x7fac7ce86610 len=88 prog=536903814 vers=1 proc=159 type=0 status=0 serial=6 2014-02-04 15:50:27.349+0000: 9081: debug : virKeepAliveCheckMessage:374 : ka=0x7fac7ce86d60, client=0x7fac7ce86610, msg=0x7fac7ce86e60 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollUpdateTimeout:260 : EVENT_POLL_UPDATE_TIMEOUT: timer=59 frequency=5000 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollUpdateTimeout:278 : Set timer freq=5000 expires=1391529032349 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollInterruptLocked:713 : Skip interrupt, 1 140378773645312 2014-02-04 15:50:27.349+0000: 9081: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac7ce86610 2014-02-04 15:50:27.349+0000: 9081: debug : virNetServerDispatchNewMessage:213 : server=0x7fac7ce77ae0 client=0x7fac7ce86610 message=0x7fac7ce86e60 2014-02-04 15:50:27.349+0000: 9081: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac7ce80030 2014-02-04 15:50:27.349+0000: 9081: debug : virNetMessageNew:44 : msg=0x7fac7ce78c60 tracked=1 2014-02-04 15:50:27.349+0000: 9081: debug : virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1, rx=0x7fac7ce78c60 tx=(nil) 2014-02-04 15:50:27.349+0000: 9081: debug : virNetServerClientCalculateHandleMode:188 : mode=1 2014-02-04 15:50:27.349+0000: 9082: debug : virNetServerHandleJob:184 : server=0x7fac7ce77ae0 client=0x7fac7ce86610 message=0x7fac7ce86e60 prog=0x7fac7ce80030 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=58 events=1 2014-02-04 15:50:27.349+0000: 9082: debug : virNetServerProgramDispatch:285 : prog=536903814 ver=1 type=0 status=0 serial=6 proc=159 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollInterruptLocked:713 : Skip interrupt, 1 140378773645312 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.349+0000: 9082: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac58000ac0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.349+0000: 9082: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac58000ac0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventRunDefaultImpl:271 : running default event implementation 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.349+0000: 9082: debug : remoteDispatchDomainMemoryStatsHelper:5195 : server=0x7fac7ce77ae0 client=0x7fac7ce86610 msg=0x7fac7ce86e60 rerr=0x7fac6d9b5bc0 args=0x7fac44000900 ret=0x7fac440009a0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.349+0000: 9082: debug : virObjectNew:199 : OBJECT_NEW: obj=0x7fac440008c0 classname=virDomain 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=0 w=1, f=5 e=1 d=0 2014-02-04 15:50:27.349+0000: 9082: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac340018a0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=1 w=2, f=7 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=2 w=3, f=12 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=3 w=4, f=13 e=1 d=0 2014-02-04 15:50:27.349+0000: 9082: debug : virDomainMemoryStats:8719 : dom=0x7fac440008c0, (VM: name=bqafm0001ap.frm.meshcore.net, uuid=3b009e73-e095-29fa-8970-f5c2b647d5a0), stats=0x7fac44000af0, nr_stats=8, flags=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=4 w=5, f=14 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=5 w=6, f=15 e=1 d=0 2014-02-04 15:50:27.349+0000: 9082: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac7ce760b0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=6 w=7, f=16 e=1 d=0 2014-02-04 15:50:27.349+0000: 9082: debug : virAccessManagerCheckDomain:231 : manager=0x7fac7ce760b0(name=stack) driver=QEMU domain=0x7fac5c2386c0 perm=1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=7 w=8, f=17 e=1 d=0 2014-02-04 15:50:27.349+0000: 9082: debug : virAccessManagerCheckDomain:231 : manager=0x7fac7ce776f0(name=none) driver=QEMU domain=0x7fac5c2386c0 perm=1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=8 w=9, f=19 e=1 d=0 2014-02-04 15:50:27.349+0000: 9082: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac7ce760b0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=9 w=10, f=23 e=25 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=10 w=11, f=25 e=25 d=0 2014-02-04 15:50:27.349+0000: 9082: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac5c209c20 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=11 w=12, f=24 e=25 d=0 2014-02-04 15:50:27.349+0000: 9082: debug : qemuDomainObjBeginJobInternal:1024 : Starting job: query (async=none vm=0x7fac5c2141a0 name=bqafm0001ap.frm.meshcore.net) 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=12 w=13, f=26 e=25 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=13 w=14, f=27 e=1 d=0 2014-02-04 15:50:27.349+0000: 9082: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac5c2141a0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=14 w=58, f=28 e=1 d=0 2014-02-04 15:50:27.349+0000: 9082: debug : qemuDomainObjBeginJobInternal:1066 : Started job: query (async=none vm=0x7fac5c2141a0 name=bqafm0001ap.frm.meshcore.net) 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 5 timers 2014-02-04 15:50:27.349+0000: 9082: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac5c209c20 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529031312 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529032349 2014-02-04 15:50:27.349+0000: 9082: debug : qemuDomainObjEnterMonitorInternal:1252 : Entering monitor (mon=0x7fac54000c00 vm=0x7fac5c2141a0 name=bqafm0001ap.frm.meshcore.net) 2014-02-04 15:50:27.349+0000: 9082: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac54000c00 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1391529031312 now=1391529027349 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:362 : Timeout at 1391529031312 due in 3963 ms 2014-02-04 15:50:27.349+0000: 9082: debug : qemuMonitorGetMemoryStats:1565 : mon=0x7fac54000c00 stats=0x7fac44000af0 nstats=8 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollRunOnce:630 : EVENT_POLL_RUN: nhandles=15 timeout=3963 2014-02-04 15:50:27.349+0000: 9082: debug : qemuMonitorFindBalloonObjectPath:1045 : Searching for Balloon Object Path starting at / 2014-02-04 15:50:27.349+0000: 9082: debug : virJSONValueToString:1106 : object=0x7fac44000a50 2014-02-04 15:50:27.349+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac44000a50 type=0 gen=0x7fac44000d60 2014-02-04 15:50:27.349+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac44000a70 type=2 gen=0x7fac44000d60 2014-02-04 15:50:27.349+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac44000bf0 type=0 gen=0x7fac44000d60 2014-02-04 15:50:27.349+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac44000c10 type=2 gen=0x7fac44000d60 2014-02-04 15:50:27.349+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac44000ce0 type=2 gen=0x7fac44000d60 2014-02-04 15:50:27.349+0000: 9082: debug : virJSONValueToString:1139 : result={"execute":"qom-list","arguments":{"path":"/"},"id":"libvirt-6"} 2014-02-04 15:50:27.349+0000: 9082: debug : qemuMonitorJSONCommandWithFd:264 : Send command '{"execute":"qom-list","arguments":{"path":"/"},"id":"libvirt-6"}' for write with FD -1 2014-02-04 15:50:27.349+0000: 9082: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=10 events=15 2014-02-04 15:50:27.349+0000: 9082: debug : virEventPollInterruptLocked:717 : Interrupting 2014-02-04 15:50:27.349+0000: 9082: debug : qemuMonitorSend:959 : QEMU_MONITOR_SEND_MSG: mon=0x7fac54000c00 msg={"execute":"qom-list","arguments":{"path":"/"},"id":"libvirt-6"} fd=-1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollRunOnce:641 : Poll got 1 event(s) 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchTimeouts:426 : Dispatch 5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:471 : Dispatch 15 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=0 w=1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:499 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=1 w=2 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=2 w=3 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=3 w=4 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=4 w=5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=5 w=6 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=6 w=7 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=7 w=8 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=8 w=9 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=9 w=10 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=10 w=11 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=11 w=12 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=12 w=13 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=13 w=14 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=14 w=58 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.349+0000: 9081: debug : virEventRunDefaultImpl:271 : running default event implementation 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=0 w=1, f=5 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=1 w=2, f=7 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=2 w=3, f=12 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=3 w=4, f=13 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=4 w=5, f=14 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=5 w=6, f=15 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=6 w=7, f=16 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=7 w=8, f=17 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=8 w=9, f=19 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=9 w=10, f=23 e=29 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=10 w=11, f=25 e=25 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=11 w=12, f=24 e=25 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=12 w=13, f=26 e=25 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=13 w=14, f=27 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=14 w=58, f=28 e=1 d=0 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 5 timers 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529031312 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529032349 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1391529031312 now=1391529027349 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollCalculateTimeout:362 : Timeout at 1391529031312 due in 3963 ms 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollRunOnce:630 : EVENT_POLL_RUN: nhandles=15 timeout=3963 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollRunOnce:641 : Poll got 1 event(s) 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchTimeouts:426 : Dispatch 5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:471 : Dispatch 15 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=0 w=1 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=1 w=2 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=2 w=3 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=3 w=4 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=4 w=5 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=5 w=6 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=6 w=7 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=7 w=8 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=8 w=9 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=9 w=10 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:499 : EVENT_POLL_DISPATCH_HANDLE: watch=10 events=2 2014-02-04 15:50:27.349+0000: 9081: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac54000c00 2014-02-04 15:50:27.349+0000: 9081: debug : qemuMonitorIOWrite:504 : QEMU_MONITOR_IO_WRITE: mon=0x7fac54000c00 buf={"execute":"qom-list","arguments":{"path":"/"},"id":"libvirt-6"} len=66 ret=66 errno=22 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=10 events=13 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollInterruptLocked:713 : Skip interrupt, 1 140378773645312 2014-02-04 15:50:27.349+0000: 9081: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac54000c00 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=10 w=11 2014-02-04 15:50:27.349+0000: 9081: debug : virEventPollDispatchHandles:485 : i=11 w=12 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=12 w=13 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=13 w=14 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=14 w=58 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.350+0000: 9081: debug : virEventRunDefaultImpl:271 : running default event implementation 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=0 w=1, f=5 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=1 w=2, f=7 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=2 w=3, f=12 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=3 w=4, f=13 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=4 w=5, f=14 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=5 w=6, f=15 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=6 w=7, f=16 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=7 w=8, f=17 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=8 w=9, f=19 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=9 w=10, f=23 e=25 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=10 w=11, f=25 e=25 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=11 w=12, f=24 e=25 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=12 w=13, f=26 e=25 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=13 w=14, f=27 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=14 w=58, f=28 e=1 d=0 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 5 timers 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529031312 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529032349 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1391529031312 now=1391529027350 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollCalculateTimeout:362 : Timeout at 1391529031312 due in 3962 ms 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollRunOnce:630 : EVENT_POLL_RUN: nhandles=15 timeout=3962 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollRunOnce:641 : Poll got 1 event(s) 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchTimeouts:426 : Dispatch 5 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:471 : Dispatch 15 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=0 w=1 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=1 w=2 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=2 w=3 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=3 w=4 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=4 w=5 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=5 w=6 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=6 w=7 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=7 w=8 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=8 w=9 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=9 w=10 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:499 : EVENT_POLL_DISPATCH_HANDLE: watch=10 events=1 2014-02-04 15:50:27.350+0000: 9081: debug : virObjectRef:293 : OBJECT_REF: obj=0x7fac54000c00 2014-02-04 15:50:27.350+0000: 9081: debug : qemuMonitorIOProcess:396 : QEMU_MONITOR_IO_PROCESS: mon=0x7fac54000c00 buf={"id": "libvirt-6", "error": {"class": "CommandNotFound", "desc": "The command qom-list has not been found", "data": {"name": "qom-list"}}} len=141 2014-02-04 15:50:27.350+0000: 9081: debug : qemuMonitorJSONIOProcessLine:157 : Line [{"id": "libvirt-6", "error": {"class": "CommandNotFound", "desc": "The command qom-list has not been found", "data": {"name": "qom-list"}}}] 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONValueFromString:975 : string={"id": "libvirt-6", "error": {"class": "CommandNotFound", "desc": "The command qom-list has not been found", "data": {"name": "qom-list"}}} 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleStartMap:853 : parser=0x7fffd5667f70 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleMapKey:835 : parser=0x7fffd5667f70 key=0x7fac7ce78d42 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleString:815 : parser=0x7fffd5667f70 str=0x7fac7ce78d48 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleMapKey:835 : parser=0x7fffd5667f70 key=0x7fac7ce78d55 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleStartMap:853 : parser=0x7fffd5667f70 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleMapKey:835 : parser=0x7fffd5667f70 key=0x7fac7ce78d5f 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleString:815 : parser=0x7fffd5667f70 str=0x7fac7ce78d68 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleMapKey:835 : parser=0x7fffd5667f70 key=0x7fac7ce78d7b 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleString:815 : parser=0x7fffd5667f70 str=0x7fac7ce78d83 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleMapKey:835 : parser=0x7fffd5667f70 key=0x7fac7ce78dae 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleStartMap:853 : parser=0x7fffd5667f70 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleMapKey:835 : parser=0x7fffd5667f70 key=0x7fac7ce78db7 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleString:815 : parser=0x7fffd5667f70 str=0x7fac7ce78dbf 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleEndMap:881 : parser=0x7fffd5667f70 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleEndMap:881 : parser=0x7fffd5667f70 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONParserHandleEndMap:881 : parser=0x7fffd5667f70 2014-02-04 15:50:27.350+0000: 9081: debug : virJSONValueFromString:1026 : result=0x7fac7ce6b9a0 2014-02-04 15:50:27.350+0000: 9081: debug : qemuMonitorJSONIOProcessLine:177 : QEMU_MONITOR_RECV_REPLY: mon=0x7fac54000c00 reply={"id": "libvirt-6", "error": {"class": "CommandNotFound", "desc": "The command qom-list has not been found", "data": {"name": "qom-list"}}} 2014-02-04 15:50:27.350+0000: 9081: debug : qemuMonitorJSONIOProcess:226 : Total used 141 bytes out of 141 available in buffer 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=10 events=13 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollInterruptLocked:713 : Skip interrupt, 1 140378773645312 2014-02-04 15:50:27.350+0000: 9081: debug : virObjectUnref:256 : OBJECT_UNREF: obj=0x7fac54000c00 2014-02-04 15:50:27.350+0000: 9082: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=10 events=13 2014-02-04 15:50:27.350+0000: 9081: debug : virEventPollDispatchHandles:485 : i=10 w=11 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollDispatchHandles:485 : i=11 w=12 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollDispatchHandles:485 : i=12 w=13 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollDispatchHandles:485 : i=13 w=14 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollDispatchHandles:485 : i=14 w=58 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.351+0000: 9081: debug : virEventRunDefaultImpl:271 : running default event implementation 2014-02-04 15:50:27.351+0000: 9082: debug : virEventPollInterruptLocked:713 : Skip interrupt, 0 140378773645312 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollCleanupTimeouts:517 : Cleanup 5 2014-02-04 15:50:27.351+0000: 9082: debug : qemuMonitorJSONCommandWithFd:269 : Receive command reply ret=0 rxObject=0x7fac7ce6b9a0 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollCleanupHandles:565 : Cleanup 15 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToString:1106 : object=0x7fac44000a50 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=0 w=1, f=5 e=1 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac44000a50 type=0 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=1 w=2, f=7 e=1 d=0 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=2 w=3, f=12 e=1 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac44000a70 type=2 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=3 w=4, f=13 e=1 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac44000bf0 type=0 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=4 w=5, f=14 e=1 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac44000c10 type=2 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=5 w=6, f=15 e=1 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac44000ce0 type=2 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=6 w=7, f=16 e=1 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToString:1139 : result={"execute":"qom-list","arguments":{"path":"/"},"id":"libvirt-6"} 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=7 w=8, f=17 e=1 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToString:1106 : object=0x7fac7ce6b9a0 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=8 w=9, f=19 e=1 d=0 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=9 w=10, f=23 e=25 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac7ce6b9a0 type=0 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=10 w=11, f=25 e=25 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac7ce6b8a0 type=2 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=11 w=12, f=24 e=25 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac7ce67660 type=0 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=12 w=13, f=26 e=25 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac7ce83f30 type=2 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=13 w=14, f=27 e=1 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac7ce61930 type=2 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollMakePollFDs:394 : Prepare n=14 w=58, f=28 e=1 d=0 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac7ce6ce30 type=0 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 5 timers 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToStringOne:1037 : object=0x7fac7ce80230 type=2 gen=0x7fac44001000 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529031312 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollCalculateTimeout:340 : Got a timeout scheduled for 1391529032349 2014-02-04 15:50:27.351+0000: 9082: debug : virJSONValueToString:1139 : result={"id":"libvirt-6","error":{"class":"CommandNotFound","desc":"The command qom-list has not been found","data":{"name":"qom-list"}}} 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollCalculateTimeout:353 : Schedule timeout then=1391529031312 now=1391529027351 2014-02-04 15:50:27.351+0000: 9082: debug : qemuMonitorJSONCheckError:343 : unable to execute QEMU command {"execute":"qom-list","arguments":{"path":"/"},"id":"libvirt-6"}: {"id":"libvirt-6","error":{"class":"CommandNotFound","desc":"The command qom-list has not been found","data":{"name":"qom-list"}}} 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollCalculateTimeout:362 : Timeout at 1391529031312 due in 3961 ms 2014-02-04 15:50:27.351+0000: 9081: debug : virEventPollRunOnce:630 : EVENT_POLL_RUN: nhandles=15 timeout=3961 2014-02-04 15:50:27.351+0000: 9082: error : qemuMonitorJSONCheckError:354 : internal error: unable to execute QEMU command 'qom-list': The command qom-list has not been found ====== end of log ===== Segmentation fault (core dumped)
On 2014-02-04 17:02, Franky Van Liedekerke wrote:
Hi,
using libvirt 1.2.0 on a up-to-date Centos6.5 machine leads to occasional segmentation faults (see below). Sometimes it runs for 5 minutes, sometimes for an hour, but after that the result is always the same: segfault after some weird qom-list, that apparently the qemu version on centos doesn't know. Has 1.2.1 a known fix for this?
Franky (debug log of last crash is below the dotted line)
To reply to my own question: 1.2.1 shows the same problem. Since it *seems* to have something to do with ballooning, I'll try disabling that now. Franky
On 02/04/2014 09:02 AM, Franky Van Liedekerke wrote:
Hi,
using libvirt 1.2.0 on a up-to-date Centos6.5 machine leads to occasional segmentation faults (see below). Sometimes it runs for 5 minutes, sometimes for an hour, but after that the result is always the same: segfault after some weird qom-list, that apparently the qemu version on centos doesn't know. Has 1.2.1 a known fix for this?
Franky (debug log of last crash is below the dotted line)
-------------------------------------------------
2014-02-04 15:50:27.351+0000: 9082: error : qemuMonitorJSONCheckError:354 : internal error: unable to execute QEMU command 'qom-list': The command qom-list has not been found Caught Segmentation violation dumping internal log buffer:
Sounds to me like poor fallback - a patch in libvirt was tested against a newer version of qemu that provides qom-list, but doesn't gracefully handle older qemu where it doesn't work. Are you in a position to bisect which libvirt patch introduced the problem? It looks like our first use of qom-list was in 1.1.1, with commit d76a897.
2014-02-04 15:50:27.351+0000: 9082: error : qemuMonitorJSONCheckError:354 : internal error: unable to execute QEMU command 'qom-list': The command qom-list has not been found
-- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
On Tue, 04 Feb 2014 10:19:56 -0700 Eric Blake <eblake@redhat.com> wrote:
On 02/04/2014 09:02 AM, Franky Van Liedekerke wrote:
Hi,
using libvirt 1.2.0 on a up-to-date Centos6.5 machine leads to occasional segmentation faults (see below). Sometimes it runs for 5 minutes, sometimes for an hour, but after that the result is always the same: segfault after some weird qom-list, that apparently the qemu version on centos doesn't know. Has 1.2.1 a known fix for this?
Franky (debug log of last crash is below the dotted line)
-------------------------------------------------
2014-02-04 15:50:27.351+0000: 9082: error : qemuMonitorJSONCheckError:354 : internal error: unable to execute QEMU command 'qom-list': The command qom-list has not been found Caught Segmentation violation dumping internal log buffer:
Sounds to me like poor fallback - a patch in libvirt was tested against a newer version of qemu that provides qom-list, but doesn't gracefully handle older qemu where it doesn't work.
Are you in a position to bisect which libvirt patch introduced the problem? It looks like our first use of qom-list was in 1.1.1, with commit d76a897.
Errr ... I don't really know what you mean with bisect ... but tell me what to do, and I'll try my best tomorrow. Franky
On 02/04/2014 11:28 AM, Franky Van Liedekerke wrote:
Are you in a position to bisect which libvirt patch introduced the problem? It looks like our first use of qom-list was in 1.1.1, with commit d76a897.
Errr ... I don't really know what you mean with bisect ... but tell me what to do, and I'll try my best tomorrow.
'git bisect' is a powerful driver that lets you do a binary search through git history to find which patch changed a particular behavior. If you are comfortable using git and building your own libvirt, I can help you come up with a command line to drive the test for looking for where this behavior started. But even if you are not, it would be nice if you could test a build of libvirt 1.1.0 vs. libvirt 1.1.1; if my guess above was correct, 1.1.0 will not have the problem. Or, if you are comfortable using gdb, it might be nice to step through program execution at the point where qemuMonitorJSONGetObjectListPaths returns failure because qemu didn't support the qom-list command. And if not, the fact that you reported it means that one of the regular developers will hopefully have some time in the near future to further investigate, based on what we've learned so far. At any rate, we should have a fix before releasing libvirt 1.2.2. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
On Tue, Feb 04, 2014 at 11:34:39AM -0700, Eric Blake wrote:
On 02/04/2014 11:28 AM, Franky Van Liedekerke wrote:
Are you in a position to bisect which libvirt patch introduced the problem? It looks like our first use of qom-list was in 1.1.1, with commit d76a897.
Errr ... I don't really know what you mean with bisect ... but tell me what to do, and I'll try my best tomorrow.
'git bisect' is a powerful driver that lets you do a binary search through git history to find which patch changed a particular behavior. If you are comfortable using git and building your own libvirt, I can help you come up with a command line to drive the test for looking for where this behavior started.
I wonder if we should not add a small section on bugs.html.in about how git bissect can help locating the bug and the simpler alternatives like below:
But even if you are not, it would be nice if you could test a build of libvirt 1.1.0 vs. libvirt 1.1.1; if my guess above was correct, 1.1.0 will not have the problem. Or, if you are comfortable using gdb, it might be nice to step through program execution at the point where qemuMonitorJSONGetObjectListPaths returns failure because qemu didn't support the qom-list command. And if not, the fact that you reported it means that one of the regular developers will hopefully have some time in the near future to further investigate, based on what we've learned so far. At any rate, we should have a fix before releasing libvirt 1.2.2.
3 weeks to find the problem and get a fix :-) Daniel -- Daniel Veillard | Open Source and Standards, Red Hat veillard@redhat.com | libxml Gnome XML XSLT toolkit http://xmlsoft.org/ http://veillard.com/ | virtualization library http://libvirt.org/
On Tue, Feb 04, 2014 at 17:02:41 +0100, Franky Van Liedekerke wrote:
Hi,
using libvirt 1.2.0 on a up-to-date Centos6.5 machine leads to occasional segmentation faults (see below). Sometimes it runs for 5 minutes, sometimes for an hour, but after that the result is always the same: segfault after some weird qom-list, that apparently the qemu version on centos doesn't know. Has 1.2.1 a known fix for this?
I believe the following patch should fix the crash. I'll do some testing tomorrow and send it as a proper patch afterwards: diff --git i/src/qemu/qemu_monitor.c w/src/qemu/qemu_monitor.c index a968901..cdd817f 100644 --- i/src/qemu/qemu_monitor.c +++ w/src/qemu/qemu_monitor.c @@ -1019,7 +1019,9 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, virDomainObjPtr vm, const char *curpath) { - size_t i, j, npaths = 0, nprops = 0; + size_t i, j; + int npaths = 0; + int nprops = 0; int ret = 0; char *nextpath = NULL; qemuMonitorJSONListPathPtr *paths = NULL; @@ -1045,6 +1047,8 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, VIR_DEBUG("Searching for Balloon Object Path starting at %s", curpath); npaths = qemuMonitorJSONGetObjectListPaths(mon, curpath, &paths); + if (npaths < 0) + return -1; for (i = 0; i < npaths && ret == 0; i++) { @@ -1061,6 +1065,11 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, * then this version of qemu/kvm does not support the feature. */ nprops = qemuMonitorJSONGetObjectListPaths(mon, nextpath, &bprops); + if (nprops < 0) { + ret = -1; + goto cleanup; + } + for (j = 0; j < nprops; j++) { if (STREQ(bprops[j]->name, "guest-stats-polling-interval")) { VIR_DEBUG("Found Balloon Object Path %s", nextpath);
On 02/04/2014 11:23 PM, Jiri Denemark wrote:
On Tue, Feb 04, 2014 at 17:02:41 +0100, Franky Van Liedekerke wrote:
Hi,
using libvirt 1.2.0 on a up-to-date Centos6.5 machine leads to occasional segmentation faults (see below). Sometimes it runs for 5 minutes, sometimes for an hour, but after that the result is always the same: segfault after some weird qom-list, that apparently the qemu version on centos doesn't know. Has 1.2.1 a known fix for this?
I believe the following patch should fix the crash. I'll do some testing tomorrow and send it as a proper patch afterwards:
diff --git i/src/qemu/qemu_monitor.c w/src/qemu/qemu_monitor.c index a968901..cdd817f 100644 --- i/src/qemu/qemu_monitor.c +++ w/src/qemu/qemu_monitor.c @@ -1019,7 +1019,9 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, virDomainObjPtr vm, const char *curpath) { - size_t i, j, npaths = 0, nprops = 0; + size_t i, j; + int npaths = 0; + int nprops = 0; int ret = 0; char *nextpath = NULL; qemuMonitorJSONListPathPtr *paths = NULL; @@ -1045,6 +1047,8 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, VIR_DEBUG("Searching for Balloon Object Path starting at %s", curpath);
npaths = qemuMonitorJSONGetObjectListPaths(mon, curpath, &paths); + if (npaths < 0) + return -1;
for (i = 0; i < npaths && ret == 0; i++) {
@@ -1061,6 +1065,11 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, * then this version of qemu/kvm does not support the feature. */ nprops = qemuMonitorJSONGetObjectListPaths(mon, nextpath, &bprops); + if (nprops < 0) { + ret = -1; + goto cleanup; + } + for (j = 0; j < nprops; j++) { if (STREQ(bprops[j]->name, "guest-stats-polling-interval")) { VIR_DEBUG("Found Balloon Object Path %s", nextpath);
npaths and nprops are also compared against size_t in the cleanup section. Jan
On 02/04/2014 05:23 PM, Jiri Denemark wrote:
On Tue, Feb 04, 2014 at 17:02:41 +0100, Franky Van Liedekerke wrote:
Hi,
using libvirt 1.2.0 on a up-to-date Centos6.5 machine leads to occasional segmentation faults (see below). Sometimes it runs for 5 minutes, sometimes for an hour, but after that the result is always the same: segfault after some weird qom-list, that apparently the qemu version on centos doesn't know. Has 1.2.1 a known fix for this?
I believe the following patch should fix the crash. I'll do some testing tomorrow and send it as a proper patch afterwards:
diff --git i/src/qemu/qemu_monitor.c w/src/qemu/qemu_monitor.c index a968901..cdd817f 100644 --- i/src/qemu/qemu_monitor.c +++ w/src/qemu/qemu_monitor.c @@ -1019,7 +1019,9 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, virDomainObjPtr vm, const char *curpath) { - size_t i, j, npaths = 0, nprops = 0; + size_t i, j; + int npaths = 0; + int nprops = 0;
Reading into what the contention of the issue is, then these are perhaps all that's needed since the conflict is I assume the difference in size between 'int' and 'size_t'. Perhaps something Eric Blake understands best. My simple testing shows while difference in size (4 bytes vs. 8 bytes), the compiler seems to have done the right thing on the return value (eg, assigning 'size_t' value to a function returning int of -1). I know when I implemented this http://www.redhat.com/archives/libvir-list/2013-July/msg00770.html that I had tested without qom-list available. Curious to know if the issue was seen in a provided or built libvirt. It should be very simple to create a small C program that exhibits the issue - just have a variable of size_t initialized to 0 that gets set by a function that returns int, then print the result.
int ret = 0; char *nextpath = NULL; qemuMonitorJSONListPathPtr *paths = NULL; @@ -1045,6 +1047,8 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, VIR_DEBUG("Searching for Balloon Object Path starting at %s", curpath);
npaths = qemuMonitorJSONGetObjectListPaths(mon, curpath, &paths); + if (npaths < 0) + return -1;
for (i = 0; i < npaths && ret == 0; i++) {
We wouldn't enter the loop in the 0 < -1 case, but would if 0 < 0x0000ffff
@@ -1061,6 +1065,11 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, * then this version of qemu/kvm does not support the feature. */ nprops = qemuMonitorJSONGetObjectListPaths(mon, nextpath, &bprops); + if (nprops < 0) { + ret = -1; + goto cleanup; + } + for (j = 0; j < nprops; j++) {
same here.
if (STREQ(bprops[j]->name, "guest-stats-polling-interval")) { VIR_DEBUG("Found Balloon Object Path %s", nextpath);
-- libvir-list mailing list libvir-list@redhat.com https://www.redhat.com/mailman/listinfo/libvir-list
On Wed, Feb 05, 2014 at 07:02:38 -0500, John Ferlan wrote:
On 02/04/2014 05:23 PM, Jiri Denemark wrote:
On Tue, Feb 04, 2014 at 17:02:41 +0100, Franky Van Liedekerke wrote:
Hi,
using libvirt 1.2.0 on a up-to-date Centos6.5 machine leads to occasional segmentation faults (see below). Sometimes it runs for 5 minutes, sometimes for an hour, but after that the result is always the same: segfault after some weird qom-list, that apparently the qemu version on centos doesn't know. Has 1.2.1 a known fix for this?
I believe the following patch should fix the crash. I'll do some testing tomorrow and send it as a proper patch afterwards:
diff --git i/src/qemu/qemu_monitor.c w/src/qemu/qemu_monitor.c index a968901..cdd817f 100644 --- i/src/qemu/qemu_monitor.c +++ w/src/qemu/qemu_monitor.c @@ -1019,7 +1019,9 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, virDomainObjPtr vm, const char *curpath) { - size_t i, j, npaths = 0, nprops = 0; + size_t i, j; + int npaths = 0; + int nprops = 0;
Reading into what the contention of the issue is, then these are perhaps all that's needed since the conflict is I assume the difference in size between 'int' and 'size_t'. Perhaps something Eric Blake understands best. My simple testing shows while difference in size (4 bytes vs. 8 bytes), the compiler seems to have done the right thing on the return value (eg, assigning 'size_t' value to a function returning int of -1).
I know when I implemented this
http://www.redhat.com/archives/libvir-list/2013-July/msg00770.html
that I had tested without qom-list available.
Curious to know if the issue was seen in a provided or built libvirt. It should be very simple to create a small C program that exhibits the issue - just have a variable of size_t initialized to 0 that gets set by a function that returns int, then print the result.
int ret = 0; char *nextpath = NULL; qemuMonitorJSONListPathPtr *paths = NULL; @@ -1045,6 +1047,8 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, VIR_DEBUG("Searching for Balloon Object Path starting at %s", curpath);
npaths = qemuMonitorJSONGetObjectListPaths(mon, curpath, &paths); + if (npaths < 0) + return -1;
for (i = 0; i < npaths && ret == 0; i++) {
We wouldn't enter the loop in the 0 < -1 case, but would if 0 < 0x0000ffff
Sure, we wouldn't but then we would just return 0 from this function, which would be wrong.
@@ -1061,6 +1065,11 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, * then this version of qemu/kvm does not support the feature. */ nprops = qemuMonitorJSONGetObjectListPaths(mon, nextpath, &bprops); + if (nprops < 0) { + ret = -1; + goto cleanup; + } + for (j = 0; j < nprops; j++) {
same here.
And here we would overwrite the error from qemuMonitorJSONGetObjectListPaths with a different one. Jirka
On Tue, Feb 04, 2014 at 11:23:42PM +0100, Jiri Denemark wrote:
On Tue, Feb 04, 2014 at 17:02:41 +0100, Franky Van Liedekerke wrote:
Hi,
using libvirt 1.2.0 on a up-to-date Centos6.5 machine leads to occasional segmentation faults (see below). Sometimes it runs for 5 minutes, sometimes for an hour, but after that the result is always the same: segfault after some weird qom-list, that apparently the qemu version on centos doesn't know. Has 1.2.1 a known fix for this?
I believe the following patch should fix the crash. I'll do some testing tomorrow and send it as a proper patch afterwards:
diff --git i/src/qemu/qemu_monitor.c w/src/qemu/qemu_monitor.c index a968901..cdd817f 100644 --- i/src/qemu/qemu_monitor.c +++ w/src/qemu/qemu_monitor.c @@ -1019,7 +1019,9 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, virDomainObjPtr vm, const char *curpath) { - size_t i, j, npaths = 0, nprops = 0; + size_t i, j; + int npaths = 0; + int nprops = 0; int ret = 0; char *nextpath = NULL; qemuMonitorJSONListPathPtr *paths = NULL; @@ -1045,6 +1047,8 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, VIR_DEBUG("Searching for Balloon Object Path starting at %s", curpath);
npaths = qemuMonitorJSONGetObjectListPaths(mon, curpath, &paths); + if (npaths < 0) + return -1;
for (i = 0; i < npaths && ret == 0; i++) {
@@ -1061,6 +1065,11 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, * then this version of qemu/kvm does not support the feature. */ nprops = qemuMonitorJSONGetObjectListPaths(mon, nextpath, &bprops); + if (nprops < 0) { + ret = -1; + goto cleanup; + } + for (j = 0; j < nprops; j++) { if (STREQ(bprops[j]->name, "guest-stats-polling-interval")) { VIR_DEBUG("Found Balloon Object Path %s", nextpath);
It would be desirable to extend the qemujsonmonitor test suite to exercise the crash scenario too. Regards, Daniel -- |: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :| |: http://libvirt.org -o- http://virt-manager.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|
On 02/04/2014 05:23 PM, Jiri Denemark wrote:
On Tue, Feb 04, 2014 at 17:02:41 +0100, Franky Van Liedekerke wrote:
Hi,
using libvirt 1.2.0 on a up-to-date Centos6.5 machine leads to occasional segmentation faults (see below). Sometimes it runs for 5 minutes, sometimes for an hour, but after that the result is always the same: segfault after some weird qom-list, that apparently the qemu version on centos doesn't know. Has 1.2.1 a known fix for this? I believe the following patch should fix the crash. I'll do some testing tomorrow and send it as a proper patch afterwards:
I just wanted to add to this thread, that I also ran into this issue. While investigating a solution, I came across this patch. I then tried it, and this also corrected the crash issue I was getting. The environment causing the problem for me was: CentOS 6 machine; 3 QEMU/KVM instances. 1 was using standard "stock" CentOS qemu package, the other two QEMU 1.6.2. Libvirt version: 1.2.1. After applying this patch, the crash issue is solved. Hopefully this is a somewhat useful data point to add. Thanks for your work Jiri! I'll be following this thread for the "final" solution and will be sure to update to 1.2.2 if that version includes the final agreed upon solution. But this patch does solve the crash issue I was running into.
diff --git i/src/qemu/qemu_monitor.c w/src/qemu/qemu_monitor.c index a968901..cdd817f 100644 --- i/src/qemu/qemu_monitor.c +++ w/src/qemu/qemu_monitor.c @@ -1019,7 +1019,9 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, virDomainObjPtr vm, const char *curpath) { - size_t i, j, npaths = 0, nprops = 0; + size_t i, j; + int npaths = 0; + int nprops = 0; int ret = 0; char *nextpath = NULL; qemuMonitorJSONListPathPtr *paths = NULL; @@ -1045,6 +1047,8 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, VIR_DEBUG("Searching for Balloon Object Path starting at %s", curpath);
npaths = qemuMonitorJSONGetObjectListPaths(mon, curpath, &paths); + if (npaths < 0) + return -1;
for (i = 0; i < npaths && ret == 0; i++) {
@@ -1061,6 +1065,11 @@ qemuMonitorFindBalloonObjectPath(qemuMonitorPtr mon, * then this version of qemu/kvm does not support the feature. */ nprops = qemuMonitorJSONGetObjectListPaths(mon, nextpath, &bprops); + if (nprops < 0) { + ret = -1; + goto cleanup; + } + for (j = 0; j < nprops; j++) { if (STREQ(bprops[j]->name, "guest-stats-polling-interval")) { VIR_DEBUG("Found Balloon Object Path %s", nextpath);
-- libvir-list mailing list libvir-list@redhat.com https://www.redhat.com/mailman/listinfo/libvir-list
participants (8)
-
Daniel P. Berrange -
Daniel Veillard -
Eric Blake -
Franky Van Liedekerke -
Jiri Denemark -
John Ferlan -
Ján Tomko -
Scott Sullivan