thr3ads.net - libvirt users - [libvirt-users] create vm timeout [Nov 2018]

If this information is useful, please help other people find it:
Share via:

netsurfed

2018-Nov-13 15:18 UTC

[libvirt-users] create vm timeout

Hi all:
I create VM on most hypervisors very quickly, about 2 seconds. But some
hypervisors are slow, taking more than 10 seconds. I started the debug log for
libvirtd and found that some threads had timed out. Thread 95205 has two
5-second timeouts, but I don't know why?
Below some information about my hypervisor:
[root@node1 datapool]# virsh -v
3.4.0
[root@node1 datapool]# qemu-x86_64 --version
qemu-x86_64 version 2.9.0
Copyright (c) 2003-2017 Fabrice Bellard and the QEMU Project developers
[root@node1 datapool]# uname -a
Linux node1 3.10.0-693.el7.x86_64 #1 SMP Tue Aug 22 21:09:27 UTC 2017 x86_64
x86_64 x86_64 GNU/Linux
Here are some log fragments:
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
0 event(s)
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:39.942+0000: 95205: info : virEventPollDispatchTimeouts:455 :
EVENT_POLL_DISPATCH_TIMEOUT: timer=2
2018-11-13 14:21:39.942+0000: 95205: info : virObjectRef:296 : OBJECT_REF:
obj=0x561dca9e7b60
2018-11-13 14:21:39.942+0000: 95205: info : virKeepAliveTimerInternal:136 :
RPC_KEEPALIVE_TIMEOUT: ka=0x561dca9e7b60 client=0x561dca9e6e60 countToDeath=5
idle=5
2018-11-13 14:21:39.942+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e2880 tracked=0
2018-11-13 14:21:39.942+0000: 95205: debug : virNetMessageEncodePayloadEmpty:492
: Encode length as 28
2018-11-13 14:21:39.942+0000: 95205: debug : virKeepAliveMessage:104 : Sending
keepalive request to client 0x561dca9e6e60
2018-11-13 14:21:39.942+0000: 95205: info : virKeepAliveMessage:107 :
RPC_KEEPALIVE_SEND: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=1
2018-11-13 14:21:39.942+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118904942
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.942+0000: 95205: debug :
virNetServerClientSendMessageLocked:1480 : msg=0x561dca9e2880 proc=1 len=28
offset=0
2018-11-13 14:21:39.942+0000: 95205: info :
virNetServerClientSendMessageLocked:1488 : RPC_SERVER_CLIENT_MSG_TX_QUEUE:
client=0x561dca9e6e60 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0
serial=0
2018-11-13 14:21:39.942+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=0x561dca9e2880
2018-11-13 14:21:39.942+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=3
2018-11-13 14:21:39.942+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=3
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.942+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e7b60
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.942+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=5 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118904942
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118904942 now=1542118899943
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118904942 due in 4999 ms
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=4999
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=2
2018-11-13 14:21:39.943+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e2880 nfds=0 cb=(nil)
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118904942
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118904942 now=1542118899943
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118904942 due in 4999 ms
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=4999
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=1
2018-11-13 14:21:39.943+0000: 95205: debug : virNetMessageDecodeLength:161 : Got
length, now need 28 total (24 more)
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.943+0000: 95205: info : virNetServerClientDispatchRead:1231
: RPC_SERVER_CLIENT_MSG_RX: client=0x561dca9e6e60 len=28 prog=1801807216 vers=1
proc=2 type=2 status=0 serial=0
2018-11-13 14:21:39.943+0000: 95205: debug : virKeepAliveCheckMessage:374 :
ka=0x561dca9e7b60, client=0x561dca9e6e60, msg=0x561dca9e1050
2018-11-13 14:21:39.943+0000: 95205: info : virKeepAliveCheckMessage:391 :
RPC_KEEPALIVE_RECEIVED: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=2
2018-11-13 14:21:39.943+0000: 95205: debug : virKeepAliveCheckMessage:400 : Got
keepalive response from client 0x561dca9e6e60
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118904943
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.943+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e1050 nfds=0 cb=(nil)
2018-11-13 14:21:39.943+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e1050 tracked=1
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118904943
2018-11-13 14:21:39.944+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118904943 now=1542118899944
2018-11-13 14:21:39.944+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118904943 due in 4999 ms
2018-11-13 14:21:39.944+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=4999
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
0 event(s)
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollDispatchTimeouts:455 :
EVENT_POLL_DISPATCH_TIMEOUT: timer=2
2018-11-13 14:21:44.948+0000: 95205: info : virObjectRef:296 : OBJECT_REF:
obj=0x561dca9e7b60
2018-11-13 14:21:44.948+0000: 95205: info : virKeepAliveTimerInternal:136 :
RPC_KEEPALIVE_TIMEOUT: ka=0x561dca9e7b60 client=0x561dca9e6e60 countToDeath=5
idle=5
2018-11-13 14:21:44.948+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e06b0 tracked=0
2018-11-13 14:21:44.948+0000: 95205: debug : virNetMessageEncodePayloadEmpty:492
: Encode length as 28
2018-11-13 14:21:44.948+0000: 95205: debug : virKeepAliveMessage:104 : Sending
keepalive request to client 0x561dca9e6e60
2018-11-13 14:21:44.948+0000: 95205: info : virKeepAliveMessage:107 :
RPC_KEEPALIVE_SEND: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=1
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118909948
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.948+0000: 95205: debug :
virNetServerClientSendMessageLocked:1480 : msg=0x561dca9e06b0 proc=1 len=28
offset=0
2018-11-13 14:21:44.948+0000: 95205: info :
virNetServerClientSendMessageLocked:1488 : RPC_SERVER_CLIENT_MSG_TX_QUEUE:
client=0x561dca9e6e60 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0
serial=0
2018-11-13 14:21:44.948+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=0x561dca9e06b0
2018-11-13 14:21:44.948+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=3
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=3
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.948+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e7b60
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=5 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118909948
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118909948 now=1542118904948
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118909948 due in 5000 ms
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=2
2018-11-13 14:21:44.948+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e06b0 nfds=0 cb=(nil)
2018-11-13 14:21:44.948+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:44.948+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118909948
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118909948 now=1542118904948
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118909948 due in 5000 ms
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:21:44.949+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=1
2018-11-13 14:21:44.949+0000: 95205: debug : virNetMessageDecodeLength:161 : Got
length, now need 28 total (24 more)
2018-11-13 14:21:44.949+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:44.949+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:44.949+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.949+0000: 95205: info : virNetServerClientDispatchRead:1231
: RPC_SERVER_CLIENT_MSG_RX: client=0x561dca9e6e60 len=28 prog=1801807216 vers=1
proc=2 type=2 status=0 serial=0
2018-11-13 14:21:44.949+0000: 95205: debug : virKeepAliveCheckMessage:374 :
ka=0x561dca9e7b60, client=0x561dca9e6e60, msg=0x561dca9e1050
2018-11-13 14:21:44.949+0000: 95205: info : virKeepAliveCheckMessage:391 :
RPC_KEEPALIVE_RECEIVED: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=2
2018-11-13 14:21:44.949+0000: 95205: debug : virKeepAliveCheckMessage:400 : Got
keepalive response from client 0x561dca9e6e60
2018-11-13 14:21:44.949+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118909949
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.949+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e1050 nfds=0 cb=(nil)
2018-11-13 14:21:44.949+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e1050 tracked=1
2018-11-13 14:21:44.949+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:44.949+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:44.949+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.949+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118909949
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118909949 now=1542118904949
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118909949 due in 5000 ms
2018-11-13 14:21:44.949+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
0 event(s)
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:49.954+0000: 95205: info : virEventPollDispatchTimeouts:455 :
EVENT_POLL_DISPATCH_TIMEOUT: timer=2
2018-11-13 14:21:49.954+0000: 95205: info : virObjectRef:296 : OBJECT_REF:
obj=0x561dca9e7b60
2018-11-13 14:21:49.954+0000: 95205: info : virKeepAliveTimerInternal:136 :
RPC_KEEPALIVE_TIMEOUT: ka=0x561dca9e7b60 client=0x561dca9e6e60 countToDeath=5
idle=5
2018-11-13 14:21:49.954+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9d9d90 tracked=0
2018-11-13 14:21:49.954+0000: 95205: debug : virNetMessageEncodePayloadEmpty:492
: Encode length as 28
2018-11-13 14:21:49.954+0000: 95205: debug : virKeepAliveMessage:104 : Sending
keepalive request to client 0x561dca9e6e60
2018-11-13 14:21:49.954+0000: 95205: info : virKeepAliveMessage:107 :
RPC_KEEPALIVE_SEND: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=1
2018-11-13 14:21:49.954+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118914954
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:49.954+0000: 95205: debug :
virNetServerClientSendMessageLocked:1480 : msg=0x561dca9d9d90 proc=1 len=28
offset=0
2018-11-13 14:21:49.954+0000: 95205: info :
virNetServerClientSendMessageLocked:1488 : RPC_SERVER_CLIENT_MSG_TX_QUEUE:
client=0x561dca9e6e60 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0
serial=0
2018-11-13 14:21:49.954+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=0x561dca9d9d90
2018-11-13 14:21:49.954+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=3
2018-11-13 14:21:49.954+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=3
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:49.954+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e7b60
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:49.954+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=5 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118914954
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118914954 now=1542118909954
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118914954 due in 5000 ms
2018-11-13 14:21:49.955+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:21:49.955+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=2
2018-11-13 14:21:49.955+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9d9d90 nfds=0 cb=(nil)
2018-11-13 14:21:49.955+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:49.955+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:49.955+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:49.955+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118914954
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118914954 now=1542118909955
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118914954 due in 4999 ms
2018-11-13 14:21:49.955+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=4999

netsurfed

2018-Nov-14 07:58 UTC

head link

Re: [libvirt-users] create vm timeout

Hi all:


Thread 95225 from 14:22:30 begin to create the vm, but not return until 14:22:40
success.


The last email log can't performance problems, please refer to the following
log:


2018-11-13 14:22:30.146+0000: 95225: debug : virCommandRun:2299 : Result status
0, stdout: '' stderr: '2018-11-13 14:22:30.136+0000: 95350: debug :
virFileClose:110 : Closed fd 27
2018-11-13 14:22:30.136+0000: 95350: debug : virFileClose:110 : Closed fd 29
2018-11-13 14:22:30.136+0000: 95350: debug : virFileClose:110 : Closed fd 25
'
2018-11-13 14:22:30.146+0000: 95225: debug : virFileClose:110 : Closed fd 26
2018-11-13 14:22:30.146+0000: 95225: debug : virFileClose:110 : Closed fd 28
2018-11-13 14:22:30.147+0000: 95225: debug : virFileClose:110 : Closed fd 25
2018-11-13 14:22:30.147+0000: 95225: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x7f81f80166f0
2018-11-13 14:22:30.147+0000: 95225: debug : virFileClose:110 : Closed fd 25
2018-11-13 14:22:30.147+0000: 95225: info : virObjectRef:296 : OBJECT_REF:
obj=0x7f81f80166f0
2018-11-13 14:22:30.147+0000: 95225: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x7f81f80166f0
2018-11-13 14:22:30.147+0000: 95225: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x7f81f80166f0
2018-11-13 14:22:35.123+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
0 event(s)
2018-11-13 14:22:35.123+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:35.123+0000: 95205: info : virEventPollDispatchTimeouts:455 :
EVENT_POLL_DISPATCH_TIMEOUT: timer=2
2018-11-13 14:22:35.123+0000: 95205: info : virObjectRef:296 : OBJECT_REF:
obj=0x561dca9e7b60
2018-11-13 14:22:35.123+0000: 95205: info : virKeepAliveTimerInternal:136 :
RPC_KEEPALIVE_TIMEOUT: ka=0x561dca9e7b60 client=0x561dca9e6e60 countToDeath=5
idle=5
2018-11-13 14:22:35.123+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e6030 tracked=0
2018-11-13 14:22:35.123+0000: 95205: debug : virNetMessageEncodePayloadEmpty:492
: Encode length as 28
2018-11-13 14:22:35.123+0000: 95205: debug : virKeepAliveMessage:104 : Sending
keepalive request to client 0x561dca9e6e60
2018-11-13 14:22:35.124+0000: 95205: info : virKeepAliveMessage:107 :
RPC_KEEPALIVE_SEND: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=1
2018-11-13 14:22:35.124+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118960124
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:35.124+0000: 95205: debug :
virNetServerClientSendMessageLocked:1480 : msg=0x561dca9e6030 proc=1 len=28
offset=0
2018-11-13 14:22:35.124+0000: 95205: info :
virNetServerClientSendMessageLocked:1488 : RPC_SERVER_CLIENT_MSG_TX_QUEUE:
client=0x561dca9e6e60 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0
serial=0
2018-11-13 14:22:35.124+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e2720
tx=0x561dca9e6030
2018-11-13 14:22:35.124+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=3
2018-11-13 14:22:35.124+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=3
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:35.124+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e7b60
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:35.124+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=5 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118955124
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 5000 ms
2018-11-13 14:22:35.124+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:35.124+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=2
2018-11-13 14:22:35.124+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e6030 nfds=0 cb=(nil)
2018-11-13 14:22:35.124+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e2720
tx=(nil)
2018-11-13 14:22:35.124+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:22:35.124+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:35.124+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118955124
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 5000 ms
2018-11-13 14:22:35.124+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:35.124+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=1
2018-11-13 14:22:35.124+0000: 95205: debug : virNetMessageDecodeLength:161 : Got
length, now need 28 total (24 more)
2018-11-13 14:22:35.124+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e2720
tx=(nil)
2018-11-13 14:22:35.124+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:22:35.124+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:35.124+0000: 95205: info : virNetServerClientDispatchRead:1231
: RPC_SERVER_CLIENT_MSG_RX: client=0x561dca9e6e60 len=28 prog=1801807216 vers=1
proc=2 type=2 status=0 serial=0
2018-11-13 14:22:35.124+0000: 95205: debug : virKeepAliveCheckMessage:374 :
ka=0x561dca9e7b60, client=0x561dca9e6e60, msg=0x561dca9e2720
2018-11-13 14:22:35.124+0000: 95205: info : virKeepAliveCheckMessage:391 :
RPC_KEEPALIVE_RECEIVED: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=2
2018-11-13 14:22:35.124+0000: 95205: debug : virKeepAliveCheckMessage:400 : Got
keepalive response from client 0x561dca9e6e60
2018-11-13 14:22:35.124+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118960124
2018-11-13 14:22:35.124+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:35.124+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e2720 nfds=0 cb=(nil)
2018-11-13 14:22:35.124+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e2720 tracked=1
2018-11-13 14:22:35.125+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e2720
tx=(nil)
2018-11-13 14:22:35.125+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:22:35.125+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:35.125+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118955125
2018-11-13 14:22:35.125+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 4999 ms
2018-11-13 14:22:35.125+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=4999
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.008+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
2018-11-13 14:22:39.008+0000: 95205: debug : virNetlinkEventCallback:707 :
dispatching to max 0 clients, called from event watch 9
2018-11-13 14:22:39.008+0000: 95205: debug : virNetlinkEventCallback:720 : event
not handled.
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.008+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959008
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1116 ms
2018-11-13 14:22:39.008+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1116
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.008+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.009+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
2018-11-13 14:22:39.009+0000: 95205: debug : virNetlinkEventCallback:707 :
dispatching to max 0 clients, called from event watch 9
2018-11-13 14:22:39.009+0000: 95205: debug : virNetlinkEventCallback:720 : event
not handled.
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.009+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959009
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1115 ms
2018-11-13 14:22:39.009+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1115
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.009+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
2018-11-13 14:22:39.009+0000: 95205: debug : virNetlinkEventCallback:707 :
dispatching to max 0 clients, called from event watch 9
2018-11-13 14:22:39.009+0000: 95205: debug : virNetlinkEventCallback:720 : event
not handled.
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.009+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959009
2018-11-13 14:22:39.009+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1115 ms
2018-11-13 14:22:39.009+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1115
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.046+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.046+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=10 events=1
2018-11-13 14:22:39.046+0000: 95205: debug : udevEventHandleCallback:1581 : udev
action: 'change'
2018-11-13 14:22:39.046+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'DRIVER' value '<null>' for device with
sysname 'sda'
2018-11-13 14:22:39.046+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'ID_BUS' value 'scsi' for device with sysname
'sda'
2018-11-13 14:22:39.046+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'ID_SERIAL' value
'36d0946607151810022e6f7981eefa6bc' for device with sysname
'sda'
2018-11-13 14:22:39.046+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'device/vendor' value 'DELL    ' for device with
sysname 'sda'
2018-11-13 14:22:39.046+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'device/model' value 'PERC H730P Adp  ' for
device with sysname 'sda'
2018-11-13 14:22:39.046+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'ID_TYPE' value 'disk' for device with sysname
'sda'
2018-11-13 14:22:39.046+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'size' value '584843264' for device with sysname
'sda'
2018-11-13 14:22:39.046+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'queue/logical_block_size' value '512' for
device with sysname 'sda'
2018-11-13 14:22:39.047+0000: 95205: debug : udevProcessStorage:1055 : Storage
ret=0
2018-11-13 14:22:39.047+0000: 95205: info : virObjectNew:202 : OBJECT_NEW:
obj=0x561dca9e0c30 classname=virNodeDeviceEventUpdate
2018-11-13 14:22:39.047+0000: 95205: debug : virObjectEventNew:640 :
obj=0x561dca9e0c30
2018-11-13 14:22:39.047+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e0c30
2018-11-13 14:22:39.047+0000: 95205: info : virObjectUnref:261 : OBJECT_DISPOSE:
obj=0x561dca9e0c30
2018-11-13 14:22:39.047+0000: 95205: debug : virNodeDeviceEventUpdateDispose:112
: obj=0x561dca9e0c30
2018-11-13 14:22:39.047+0000: 95205: debug : virNodeDeviceEventDispose:96 :
obj=0x561dca9e0c30
2018-11-13 14:22:39.047+0000: 95205: debug : virObjectEventDispose:134 :
obj=0x561dca9e0c30
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.047+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959047
2018-11-13 14:22:39.047+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1077 ms
2018-11-13 14:22:39.047+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1077
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.049+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=10 events=1
2018-11-13 14:22:39.049+0000: 95205: debug : udevEventHandleCallback:1581 : udev
action: 'change'
2018-11-13 14:22:39.049+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'DRIVER' value '<null>' for device with
sysname 'sda1'
2018-11-13 14:22:39.049+0000: 95205: debug : udevGetDeviceType:1225 : Could not
determine device type for device with sysfs name 'sda1'
2018-11-13 14:22:39.049+0000: 95205: debug : udevAddOneDevice:1414 : Discarding
device -1 0x561dca9e1ea0
/sys/devices/pci0000:00/0000:00:02.0/0000:02:00.0/host0/target0:2:0/0:2:0:0/block/sda/sda1
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.049+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.049+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959050
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1074 ms
2018-11-13 14:22:39.050+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1074
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.050+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=10 events=1
2018-11-13 14:22:39.050+0000: 95205: debug : udevEventHandleCallback:1581 : udev
action: 'change'
2018-11-13 14:22:39.050+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'DRIVER' value '<null>' for device with
sysname 'sda2'
2018-11-13 14:22:39.050+0000: 95205: debug : udevGetDeviceType:1225 : Could not
determine device type for device with sysfs name 'sda2'
2018-11-13 14:22:39.050+0000: 95205: debug : udevAddOneDevice:1414 : Discarding
device -1 0x561dca9e1ea0
/sys/devices/pci0000:00/0000:00:02.0/0000:02:00.0/host0/target0:2:0/0:2:0:0/block/sda/sda2
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.050+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.050+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959051
2018-11-13 14:22:39.051+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1073 ms
2018-11-13 14:22:39.051+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1073
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.081+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
2018-11-13 14:22:39.081+0000: 95205: debug : virNetlinkEventCallback:707 :
dispatching to max 0 clients, called from event watch 9
2018-11-13 14:22:39.081+0000: 95205: debug : virNetlinkEventCallback:720 : event
not handled.
2018-11-13 14:22:39.081+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959082
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1042 ms
2018-11-13 14:22:39.082+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1042
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.082+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
2018-11-13 14:22:39.082+0000: 95205: debug : virNetlinkEventCallback:707 :
dispatching to max 0 clients, called from event watch 9
2018-11-13 14:22:39.082+0000: 95205: debug : virNetlinkEventCallback:720 : event
not handled.
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959082
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1042 ms
2018-11-13 14:22:39.082+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1042
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.082+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
2018-11-13 14:22:39.082+0000: 95205: debug : virNetlinkEventCallback:707 :
dispatching to max 0 clients, called from event watch 9
2018-11-13 14:22:39.082+0000: 95205: debug : virNetlinkEventCallback:720 : event
not handled.
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959082
2018-11-13 14:22:39.082+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1042 ms
2018-11-13 14:22:39.082+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1042
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.088+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.088+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=10 events=1
2018-11-13 14:22:39.088+0000: 95205: debug : udevEventHandleCallback:1581 : udev
action: 'change'
2018-11-13 14:22:39.088+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'DRIVER' value '<null>' for device with
sysname 'sda'
2018-11-13 14:22:39.088+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'ID_BUS' value 'scsi' for device with sysname
'sda'
2018-11-13 14:22:39.088+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'ID_SERIAL' value
'36d0946607151810022e6f7981eefa6bc' for device with sysname
'sda'
2018-11-13 14:22:39.089+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'device/vendor' value 'DELL    ' for device with
sysname 'sda'
2018-11-13 14:22:39.089+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'device/model' value 'PERC H730P Adp  ' for
device with sysname 'sda'
2018-11-13 14:22:39.089+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'ID_TYPE' value 'disk' for device with sysname
'sda'
2018-11-13 14:22:39.089+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'size' value '584843264' for device with sysname
'sda'
2018-11-13 14:22:39.089+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'queue/logical_block_size' value '512' for
device with sysname 'sda'
2018-11-13 14:22:39.089+0000: 95205: debug : udevProcessStorage:1055 : Storage
ret=0
2018-11-13 14:22:39.090+0000: 95205: info : virObjectNew:202 : OBJECT_NEW:
obj=0x561dca9e6970 classname=virNodeDeviceEventUpdate
2018-11-13 14:22:39.090+0000: 95205: debug : virObjectEventNew:640 :
obj=0x561dca9e6970
2018-11-13 14:22:39.090+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e6970
2018-11-13 14:22:39.090+0000: 95205: info : virObjectUnref:261 : OBJECT_DISPOSE:
obj=0x561dca9e6970
2018-11-13 14:22:39.090+0000: 95205: debug : virNodeDeviceEventUpdateDispose:112
: obj=0x561dca9e6970
2018-11-13 14:22:39.090+0000: 95205: debug : virNodeDeviceEventDispose:96 :
obj=0x561dca9e6970
2018-11-13 14:22:39.090+0000: 95205: debug : virObjectEventDispose:134 :
obj=0x561dca9e6970
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.090+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959090
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1034 ms
2018-11-13 14:22:39.090+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1034
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.090+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
2018-11-13 14:22:39.090+0000: 95205: debug : virNetlinkEventCallback:707 :
dispatching to max 0 clients, called from event watch 9
2018-11-13 14:22:39.090+0000: 95205: debug : virNetlinkEventCallback:720 : event
not handled.
2018-11-13 14:22:39.090+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959091
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1033 ms
2018-11-13 14:22:39.091+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1033
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.091+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
2018-11-13 14:22:39.091+0000: 95205: debug : virNetlinkEventCallback:707 :
dispatching to max 0 clients, called from event watch 9
2018-11-13 14:22:39.091+0000: 95205: debug : virNetlinkEventCallback:720 : event
not handled.
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959091
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1033 ms
2018-11-13 14:22:39.091+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1033
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.091+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=9 events=1
2018-11-13 14:22:39.091+0000: 95205: debug : virNetlinkEventCallback:707 :
dispatching to max 0 clients, called from event watch 9
2018-11-13 14:22:39.091+0000: 95205: debug : virNetlinkEventCallback:720 : event
not handled.
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959091
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1033 ms
2018-11-13 14:22:39.091+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1033
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.091+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.092+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=10 events=1
2018-11-13 14:22:39.092+0000: 95205: debug : udevEventHandleCallback:1581 : udev
action: 'change'
2018-11-13 14:22:39.092+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'DRIVER' value '<null>' for device with
sysname 'sda1'
2018-11-13 14:22:39.092+0000: 95205: debug : udevGetDeviceType:1225 : Could not
determine device type for device with sysfs name 'sda1'
2018-11-13 14:22:39.092+0000: 95205: debug : udevAddOneDevice:1414 : Discarding
device -1 0x561dca9e59f0
/sys/devices/pci0000:00/0000:00:02.0/0000:02:00.0/host0/target0:2:0/0:2:0:0/block/sda/sda1
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.092+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959092
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1032 ms
2018-11-13 14:22:39.092+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1032
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.092+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=10 events=1
2018-11-13 14:22:39.092+0000: 95205: debug : udevEventHandleCallback:1581 : udev
action: 'change'
2018-11-13 14:22:39.092+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'DRIVER' value '<null>' for device with
sysname 'sda2'
2018-11-13 14:22:39.092+0000: 95205: debug : udevGetDeviceType:1225 : Could not
determine device type for device with sysfs name 'sda2'
2018-11-13 14:22:39.092+0000: 95205: debug : udevAddOneDevice:1414 : Discarding
device -1 0x561dca9e7410
/sys/devices/pci0000:00/0000:00:02.0/0000:02:00.0/host0/target0:2:0/0:2:0:0/block/sda/sda2
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.092+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.092+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.093+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.093+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.093+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.093+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.093+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.093+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.093+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.093+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959093
2018-11-13 14:22:39.093+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1031 ms
2018-11-13 14:22:39.093+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1031
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.098+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.098+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=10 events=1
2018-11-13 14:22:39.098+0000: 95205: debug : udevEventHandleCallback:1581 : udev
action: 'change'
2018-11-13 14:22:39.098+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'DRIVER' value '<null>' for device with
sysname 'sda'
2018-11-13 14:22:39.098+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'ID_BUS' value 'scsi' for device with sysname
'sda'
2018-11-13 14:22:39.098+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'ID_SERIAL' value
'36d0946607151810022e6f7981eefa6bc' for device with sysname
'sda'
2018-11-13 14:22:39.098+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'device/vendor' value 'DELL    ' for device with
sysname 'sda'
2018-11-13 14:22:39.098+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'device/model' value 'PERC H730P Adp  ' for
device with sysname 'sda'
2018-11-13 14:22:39.098+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'ID_TYPE' value 'disk' for device with sysname
'sda'
2018-11-13 14:22:39.098+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'size' value '584843264' for device with sysname
'sda'
2018-11-13 14:22:39.098+0000: 95205: debug : udevGetDeviceSysfsAttr:146 : Found
sysfs attribute 'queue/logical_block_size' value '512' for
device with sysname 'sda'
2018-11-13 14:22:39.098+0000: 95205: debug : udevProcessStorage:1055 : Storage
ret=0
2018-11-13 14:22:39.098+0000: 95205: info : virObjectNew:202 : OBJECT_NEW:
obj=0x561dca9e71a0 classname=virNodeDeviceEventUpdate
2018-11-13 14:22:39.098+0000: 95205: debug : virObjectEventNew:640 :
obj=0x561dca9e71a0
2018-11-13 14:22:39.099+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e71a0
2018-11-13 14:22:39.099+0000: 95205: info : virObjectUnref:261 : OBJECT_DISPOSE:
obj=0x561dca9e71a0
2018-11-13 14:22:39.099+0000: 95205: debug : virNodeDeviceEventUpdateDispose:112
: obj=0x561dca9e71a0
2018-11-13 14:22:39.099+0000: 95205: debug : virNodeDeviceEventDispose:96 :
obj=0x561dca9e71a0
2018-11-13 14:22:39.099+0000: 95205: debug : virObjectEventDispose:134 :
obj=0x561dca9e71a0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.099+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959099
2018-11-13 14:22:39.099+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1025 ms
2018-11-13 14:22:39.099+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1025
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.100+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=10 events=1
2018-11-13 14:22:39.100+0000: 95205: debug : udevEventHandleCallback:1581 : udev
action: 'change'
2018-11-13 14:22:39.100+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'DRIVER' value '<null>' for device with
sysname 'sda2'
2018-11-13 14:22:39.100+0000: 95205: debug : udevGetDeviceType:1225 : Could not
determine device type for device with sysfs name 'sda2'
2018-11-13 14:22:39.100+0000: 95205: debug : udevAddOneDevice:1414 : Discarding
device -1 0x561dca9e06b0
/sys/devices/pci0000:00/0000:00:02.0/0000:02:00.0/host0/target0:2:0/0:2:0:0/block/sda/sda2
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.100+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959100
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1024 ms
2018-11-13 14:22:39.100+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1024
2018-11-13 14:22:39.100+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:39.101+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=10 events=1
2018-11-13 14:22:39.101+0000: 95205: debug : udevEventHandleCallback:1581 : udev
action: 'change'
2018-11-13 14:22:39.101+0000: 95205: debug : udevGetDeviceProperty:82 : Found
property key 'DRIVER' value '<null>' for device with
sysname 'sda1'
2018-11-13 14:22:39.101+0000: 95205: debug : udevGetDeviceType:1225 : Could not
determine device type for device with sysfs name 'sda1'
2018-11-13 14:22:39.101+0000: 95205: debug : udevAddOneDevice:1414 : Discarding
device -1 0x561dca9e06b0
/sys/devices/pci0000:00/0000:00:02.0/0000:02:00.0/host0/target0:2:0/0:2:0:0/block/sda/sda1
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.101+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118960124
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118960124 now=1542118959101
2018-11-13 14:22:39.101+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118960124 due in 1023 ms
2018-11-13 14:22:39.101+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=1023
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
0 event(s)
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:40.125+0000: 95205: info : virEventPollDispatchTimeouts:455 :
EVENT_POLL_DISPATCH_TIMEOUT: timer=2
2018-11-13 14:22:40.125+0000: 95205: info : virObjectRef:296 : OBJECT_REF:
obj=0x561dca9e7b60
2018-11-13 14:22:40.125+0000: 95205: info : virKeepAliveTimerInternal:136 :
RPC_KEEPALIVE_TIMEOUT: ka=0x561dca9e7b60 client=0x561dca9e6e60 countToDeath=5
idle=5
2018-11-13 14:22:40.125+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9df350 tracked=0
2018-11-13 14:22:40.125+0000: 95205: debug : virNetMessageEncodePayloadEmpty:492
: Encode length as 28
2018-11-13 14:22:40.125+0000: 95205: debug : virKeepAliveMessage:104 : Sending
keepalive request to client 0x561dca9e6e60
2018-11-13 14:22:40.125+0000: 95205: info : virKeepAliveMessage:107 :
RPC_KEEPALIVE_SEND: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=1
2018-11-13 14:22:40.125+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118965125
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:40.125+0000: 95205: debug :
virNetServerClientSendMessageLocked:1480 : msg=0x561dca9df350 proc=1 len=28
offset=0
2018-11-13 14:22:40.125+0000: 95205: info :
virNetServerClientSendMessageLocked:1488 : RPC_SERVER_CLIENT_MSG_TX_QUEUE:
client=0x561dca9e6e60 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0
serial=0
2018-11-13 14:22:40.125+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e2720
tx=0x561dca9df350
2018-11-13 14:22:40.125+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=3
2018-11-13 14:22:40.125+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=3
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:40.125+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e7b60
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:40.125+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=5 d=0
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118965125
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118965125 now=1542118960125
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118965125 due in 5000 ms
2018-11-13 14:22:40.125+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:40.125+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:40.126+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=2
2018-11-13 14:22:40.126+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9df350 nfds=0 cb=(nil)
2018-11-13 14:22:40.126+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e2720
tx=(nil)
2018-11-13 14:22:40.126+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:22:40.126+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:40.126+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118965125
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118965125 now=1542118960126
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118965125 due in 4999 ms
2018-11-13 14:22:40.126+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=4999
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:22:40.126+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=1
2018-11-13 14:22:40.126+0000: 95205: debug : virNetMessageDecodeLength:161 : Got
length, now need 28 total (24 more)
2018-11-13 14:22:40.126+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e2720
tx=(nil)
2018-11-13 14:22:40.126+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:22:40.126+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:40.126+0000: 95205: info : virNetServerClientDispatchRead:1231
: RPC_SERVER_CLIENT_MSG_RX: client=0x561dca9e6e60 len=28 prog=1801807216 vers=1
proc=2 type=2 status=0 serial=0
2018-11-13 14:22:40.126+0000: 95205: debug : virKeepAliveCheckMessage:374 :
ka=0x561dca9e7b60, client=0x561dca9e6e60, msg=0x561dca9e2720
2018-11-13 14:22:40.126+0000: 95205: info : virKeepAliveCheckMessage:391 :
RPC_KEEPALIVE_RECEIVED: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=2
2018-11-13 14:22:40.126+0000: 95205: debug : virKeepAliveCheckMessage:400 : Got
keepalive response from client 0x561dca9e6e60
2018-11-13 14:22:40.126+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118965126
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:40.126+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e2720 nfds=0 cb=(nil)
2018-11-13 14:22:40.126+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e2720 tracked=1
2018-11-13 14:22:40.126+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e2720
tx=(nil)
2018-11-13 14:22:40.126+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:22:40.126+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:40.126+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118965126
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118965126 now=1542118960126
2018-11-13 14:22:40.126+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118965126 due in 5000 ms
2018-11-13 14:22:40.126+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:22:40.161+0000: 95225: info : virObjectRef:296 : OBJECT_REF:
obj=0x7f81f80166f0
2018-11-13 14:22:40.161+0000: 95225: warning : qemuDomainObjTaint:4415 : Domain
id=1 name='6efd749c-3162-4ac4-90e6-b3fca6fde9bc'
uuid=6efd749c-3162-4ac4-90e6-b3fca6fde9bc is tainted: high-privileges





At 2018-11-13 23:18:12, "netsurfed" <zhuohaofan@126.com> wrote:

Hi all:
I create VM on most hypervisors very quickly, about 2 seconds. But some
hypervisors are slow, taking more than 10 seconds. I started the debug log for
libvirtd and found that some threads had timed out. Thread 95205 has two
5-second timeouts, but I don't know why?
Below some information about my hypervisor:
[root@node1 datapool]# virsh -v
3.4.0
[root@node1 datapool]# qemu-x86_64 --version
qemu-x86_64 version 2.9.0
Copyright (c) 2003-2017 Fabrice Bellard and the QEMU Project developers
[root@node1 datapool]# uname -a
Linux node1 3.10.0-693.el7.x86_64 #1 SMP Tue Aug 22 21:09:27 UTC 2017 x86_64
x86_64 x86_64 GNU/Linux
Here are some log fragments:
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
0 event(s)
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:39.942+0000: 95205: info : virEventPollDispatchTimeouts:455 :
EVENT_POLL_DISPATCH_TIMEOUT: timer=2
2018-11-13 14:21:39.942+0000: 95205: info : virObjectRef:296 : OBJECT_REF:
obj=0x561dca9e7b60
2018-11-13 14:21:39.942+0000: 95205: info : virKeepAliveTimerInternal:136 :
RPC_KEEPALIVE_TIMEOUT: ka=0x561dca9e7b60 client=0x561dca9e6e60 countToDeath=5
idle=5
2018-11-13 14:21:39.942+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e2880 tracked=0
2018-11-13 14:21:39.942+0000: 95205: debug : virNetMessageEncodePayloadEmpty:492
: Encode length as 28
2018-11-13 14:21:39.942+0000: 95205: debug : virKeepAliveMessage:104 : Sending
keepalive request to client 0x561dca9e6e60
2018-11-13 14:21:39.942+0000: 95205: info : virKeepAliveMessage:107 :
RPC_KEEPALIVE_SEND: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=1
2018-11-13 14:21:39.942+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118904942
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.942+0000: 95205: debug :
virNetServerClientSendMessageLocked:1480 : msg=0x561dca9e2880 proc=1 len=28
offset=0
2018-11-13 14:21:39.942+0000: 95205: info :
virNetServerClientSendMessageLocked:1488 : RPC_SERVER_CLIENT_MSG_TX_QUEUE:
client=0x561dca9e6e60 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0
serial=0
2018-11-13 14:21:39.942+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=0x561dca9e2880
2018-11-13 14:21:39.942+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=3
2018-11-13 14:21:39.942+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=3
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.942+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e7b60
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.942+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.942+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=5 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118904942
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118904942 now=1542118899943
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118904942 due in 4999 ms
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=4999
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=2
2018-11-13 14:21:39.943+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e2880 nfds=0 cb=(nil)
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118904942
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118904942 now=1542118899943
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118904942 due in 4999 ms
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=4999
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=1
2018-11-13 14:21:39.943+0000: 95205: debug : virNetMessageDecodeLength:161 : Got
length, now need 28 total (24 more)
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.943+0000: 95205: info : virNetServerClientDispatchRead:1231
: RPC_SERVER_CLIENT_MSG_RX: client=0x561dca9e6e60 len=28 prog=1801807216 vers=1
proc=2 type=2 status=0 serial=0
2018-11-13 14:21:39.943+0000: 95205: debug : virKeepAliveCheckMessage:374 :
ka=0x561dca9e7b60, client=0x561dca9e6e60, msg=0x561dca9e1050
2018-11-13 14:21:39.943+0000: 95205: info : virKeepAliveCheckMessage:391 :
RPC_KEEPALIVE_RECEIVED: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=2
2018-11-13 14:21:39.943+0000: 95205: debug : virKeepAliveCheckMessage:400 : Got
keepalive response from client 0x561dca9e6e60
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118904943
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.943+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e1050 nfds=0 cb=(nil)
2018-11-13 14:21:39.943+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e1050 tracked=1
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:39.943+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:39.943+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:39.943+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118904943
2018-11-13 14:21:39.944+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118904943 now=1542118899944
2018-11-13 14:21:39.944+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118904943 due in 4999 ms
2018-11-13 14:21:39.944+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=4999
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
0 event(s)
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollDispatchTimeouts:455 :
EVENT_POLL_DISPATCH_TIMEOUT: timer=2
2018-11-13 14:21:44.948+0000: 95205: info : virObjectRef:296 : OBJECT_REF:
obj=0x561dca9e7b60
2018-11-13 14:21:44.948+0000: 95205: info : virKeepAliveTimerInternal:136 :
RPC_KEEPALIVE_TIMEOUT: ka=0x561dca9e7b60 client=0x561dca9e6e60 countToDeath=5
idle=5
2018-11-13 14:21:44.948+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e06b0 tracked=0
2018-11-13 14:21:44.948+0000: 95205: debug : virNetMessageEncodePayloadEmpty:492
: Encode length as 28
2018-11-13 14:21:44.948+0000: 95205: debug : virKeepAliveMessage:104 : Sending
keepalive request to client 0x561dca9e6e60
2018-11-13 14:21:44.948+0000: 95205: info : virKeepAliveMessage:107 :
RPC_KEEPALIVE_SEND: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=1
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118909948
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.948+0000: 95205: debug :
virNetServerClientSendMessageLocked:1480 : msg=0x561dca9e06b0 proc=1 len=28
offset=0
2018-11-13 14:21:44.948+0000: 95205: info :
virNetServerClientSendMessageLocked:1488 : RPC_SERVER_CLIENT_MSG_TX_QUEUE:
client=0x561dca9e6e60 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0
serial=0
2018-11-13 14:21:44.948+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=0x561dca9e06b0
2018-11-13 14:21:44.948+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=3
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=3
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.948+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e7b60
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=5 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118909948
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118909948 now=1542118904948
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118909948 due in 5000 ms
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=2
2018-11-13 14:21:44.948+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e06b0 nfds=0 cb=(nil)
2018-11-13 14:21:44.948+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:44.948+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118909948
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118909948 now=1542118904948
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118909948 due in 5000 ms
2018-11-13 14:21:44.948+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:21:44.948+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:21:44.949+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=1
2018-11-13 14:21:44.949+0000: 95205: debug : virNetMessageDecodeLength:161 : Got
length, now need 28 total (24 more)
2018-11-13 14:21:44.949+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:44.949+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:44.949+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.949+0000: 95205: info : virNetServerClientDispatchRead:1231
: RPC_SERVER_CLIENT_MSG_RX: client=0x561dca9e6e60 len=28 prog=1801807216 vers=1
proc=2 type=2 status=0 serial=0
2018-11-13 14:21:44.949+0000: 95205: debug : virKeepAliveCheckMessage:374 :
ka=0x561dca9e7b60, client=0x561dca9e6e60, msg=0x561dca9e1050
2018-11-13 14:21:44.949+0000: 95205: info : virKeepAliveCheckMessage:391 :
RPC_KEEPALIVE_RECEIVED: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=2
2018-11-13 14:21:44.949+0000: 95205: debug : virKeepAliveCheckMessage:400 : Got
keepalive response from client 0x561dca9e6e60
2018-11-13 14:21:44.949+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118909949
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.949+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9e1050 nfds=0 cb=(nil)
2018-11-13 14:21:44.949+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9e1050 tracked=1
2018-11-13 14:21:44.949+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:44.949+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:44.949+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.949+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118909949
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118909949 now=1542118904949
2018-11-13 14:21:44.949+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118909949 due in 5000 ms
2018-11-13 14:21:44.949+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
0 event(s)
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:49.954+0000: 95205: info : virEventPollDispatchTimeouts:455 :
EVENT_POLL_DISPATCH_TIMEOUT: timer=2
2018-11-13 14:21:49.954+0000: 95205: info : virObjectRef:296 : OBJECT_REF:
obj=0x561dca9e7b60
2018-11-13 14:21:49.954+0000: 95205: info : virKeepAliveTimerInternal:136 :
RPC_KEEPALIVE_TIMEOUT: ka=0x561dca9e7b60 client=0x561dca9e6e60 countToDeath=5
idle=5
2018-11-13 14:21:49.954+0000: 95205: debug : virNetMessageNew:46 :
msg=0x561dca9d9d90 tracked=0
2018-11-13 14:21:49.954+0000: 95205: debug : virNetMessageEncodePayloadEmpty:492
: Encode length as 28
2018-11-13 14:21:49.954+0000: 95205: debug : virKeepAliveMessage:104 : Sending
keepalive request to client 0x561dca9e6e60
2018-11-13 14:21:49.954+0000: 95205: info : virKeepAliveMessage:107 :
RPC_KEEPALIVE_SEND: ka=0x561dca9e7b60 client=0x561dca9e6e60 prog=1801807216
vers=1 proc=1
2018-11-13 14:21:49.954+0000: 95205: info : virEventPollUpdateTimeout:265 :
EVENT_POLL_UPDATE_TIMEOUT: timer=2 frequency=5000
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollUpdateTimeout:282 : Set
timer freq=5000 expires=1542118914954
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:49.954+0000: 95205: debug :
virNetServerClientSendMessageLocked:1480 : msg=0x561dca9d9d90 proc=1 len=28
offset=0
2018-11-13 14:21:49.954+0000: 95205: info :
virNetServerClientSendMessageLocked:1488 : RPC_SERVER_CLIENT_MSG_TX_QUEUE:
client=0x561dca9e6e60 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0
serial=0
2018-11-13 14:21:49.954+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=0x561dca9d9d90
2018-11-13 14:21:49.954+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=3
2018-11-13 14:21:49.954+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=3
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:49.954+0000: 95205: info : virObjectUnref:259 : OBJECT_UNREF:
obj=0x561dca9e7b60
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:49.954+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=5 d=0
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118914954
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118914954 now=1542118909954
2018-11-13 14:21:49.954+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118914954 due in 5000 ms
2018-11-13 14:21:49.955+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=5000
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollRunOnce:650 : Poll got
1 event(s)
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchTimeouts:432 :
Dispatch 2
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:478 :
Dispatch 12
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=0 w=1
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=1 w=2
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=2 w=3
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=3 w=4
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=4 w=5
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=5 w=6
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=6 w=7
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=7 w=8
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=8 w=9
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=9 w=10
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=10 w=11
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollDispatchHandles:492 :
i=11 w=12
2018-11-13 14:21:49.955+0000: 95205: info : virEventPollDispatchHandles:506 :
EVENT_POLL_DISPATCH_HANDLE: watch=12 events=2
2018-11-13 14:21:49.955+0000: 95205: debug : virNetMessageFree:87 :
msg=0x561dca9d9d90 nfds=0 cb=(nil)
2018-11-13 14:21:49.955+0000: 95205: debug :
virNetServerClientCalculateHandleMode:166 : tls=(nil) hs=-1, rx=0x561dca9e1050
tx=(nil)
2018-11-13 14:21:49.955+0000: 95205: debug :
virNetServerClientCalculateHandleMode:201 : mode=1
2018-11-13 14:21:49.955+0000: 95205: info : virEventPollUpdateHandle:152 :
EVENT_POLL_UPDATE_HANDLE: watch=12 events=1
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollInterruptLocked:722 :
Skip interrupt, 1 140197681715264
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:49.955+0000: 95205: debug : virEventRunDefaultImpl:311 :
running default event implementation
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCleanupTimeouts:525 :
Cleanup 2
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCleanupHandles:574 :
Cleanup 12
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=0 w=1, f=5 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=1 w=2, f=7 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=2 w=3, f=9 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=3 w=4, f=10 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=4 w=5, f=11 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=5 w=6, f=12 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=6 w=7, f=13 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=7 w=8, f=14 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=8 w=9, f=15 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=9 w=10, f=17 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=10 w=11, f=18 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollMakePollFDs:401 :
Prepare n=11 w=12, f=19 e=1 d=0
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCalculateTimeout:338 :
Calculate expiry of 2 timers
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCalculateTimeout:346 :
Got a timeout scheduled for 1542118914954
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCalculateTimeout:359 :
Schedule timeout then=1542118914954 now=1542118909955
2018-11-13 14:21:49.955+0000: 95205: debug : virEventPollCalculateTimeout:369 :
Timeout at 1542118914954 due in 4999 ms
2018-11-13 14:21:49.955+0000: 95205: info : virEventPollRunOnce:640 :
EVENT_POLL_RUN: nhandles=12 timeout=4999

Possibly Parallel Threads

Search for more apparently analagous threads

libvirt users - Nov 2018 - create vm timeout

[libvirt-users] create vm timeout

Re: [libvirt-users] create vm timeout

Possibly Parallel Threads