[libvirt] libvirtd crash upon virsh destroy
Scott Sullivan
ssullivan at liquidweb.com
Fri Dec 14 15:48:54 UTC 2012
I believe I have reproduced this problem in a GDB session. I followed
these basic steps:
1.) Installed libvirt-debuginfo, started libvirtd under gdb.
2.) Started a loop like this in two screen sessions:
while [ 1 ]; do virsh destroy INSTANCE; sleep 5 && virsh create
/configs/INSTANCE.cfg && sleep 30 ;done
3.) Waited about ~4 hours
4.) Got below apparent segfault in the GDB session:
Detaching after fork from child process 944.
Detaching after fork from child process 975.
Detaching after fork from child process 1025.
2012-12-14 15:01:33.418+0000: 30447: error : qemuMonitorIORead:514 :
Unable to read from monitor: Connection reset by peer
2012-12-14 15:01:33.497+0000: 30454: error :
qemuProcessWaitForMonitor:1695 : internal error process exited while
connecting to monitor: char device redirected to /dev/pts/4
qemu: terminating on signal 15 from pid 30447
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffff1100700 (LWP 30451)]
qemuDomainObjBeginJobInternal (driver=0x7fffe40112f0,
driver_locked=true, obj=0x7fffe40918d0, job=QEMU_JOB_DESTROY,
asyncJob=QEMU_ASYNC_JOB_NONE) at qemu/qemu_domain.c:768
768 priv->jobs_queued++;
Missing separate debuginfos, use: debuginfo-install
audit-libs-2.1.3-3.el6.x86_64 augeas-libs-0.9.0-1.el6.x86_64
avahi-libs-0.6.25-11.el6.x86_64 cyrus-sasl-gssapi-2.1.23-13.el6.x86_64
cyrus-sasl-lib-2.1.23-13.el6.x86_64 cyrus-sasl-md5-2.1.23-13.el6.x86_64
cyrus-sasl-plain-2.1.23-13.el6.x86_64 db4-4.7.25-16.el6.x86_64
dbus-libs-1.2.24-5.el6_1.x86_64 device-mapper-libs-1.02.66-6.el6.x86_64
glibc-2.12-1.47.el6.x86_64 gnutls-2.8.5-4.el6.x86_64
keyutils-libs-1.4-3.el6.x86_64 krb5-libs-1.9-22.el6_2.1.x86_64
libblkid-2.17.2-12.4.el6.x86_64 libcap-ng-0.6.4-3.el6_0.1.x86_64
libcom_err-1.41.12-11.el6.x86_64 libcurl-7.19.7-26.el6_1.2.x86_64
libgcrypt-1.4.5-9.el6.x86_64 libgpg-error-1.7-4.el6.x86_64
libidn-1.18-2.el6.x86_64 libnl-1.1-14.el6.x86_64
libpcap-1.0.0-6.20091201git117cb5.el6.x86_64
libpciaccess-0.12.1-1.el6.x86_64 libselinux-2.0.94-5.2.el6.x86_64
libsepol-2.0.41-4.el6.x86_64 libtasn1-2.3-3.el6.x86_64
libudev-147-2.40.el6.x86_64 libuuid-2.17.2-12.4.el6.x86_64
libxml2-2.7.6-4.el6.x86_64 libxslt-1.1.26-2.el6.x86_64
netcf-libs-0.1.9-2.el6.x86_64 nspr-4.8.8-3.el6.x86_64
nss-3.12.10-17.el6_2.x86_64 nss-softokn-freebl-3.12.9-11.el6.x86_64
nss-util-3.12.10-2.el6.x86_64 numactl-2.0.3-9.el6.x86_64
openldap-2.4.23-20.el6.x86_64 openssl-1.0.0-20.el6.x86_64
yajl-1.0.7-3.el6.x86_64 zlib-1.2.3-27.el6.x86_64
(gdb)
5.) Ran 'thread apply all bt full', output below:
(gdb) thread apply all bt full
Thread 11 (Thread 0x7fffec0f8700 (LWP 30459)):
#0 0x000000300a20b3dc in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007ffff7a0feb6 in virCondWait (c=<value optimized out>, m=<value
optimized out>) at util/threads-pthread.c:117
ret = <value optimized out>
#2 0x00007ffff7a10483 in virThreadPoolWorker (opaque=<value optimized
out>) at util/threadpool.c:103
data = 0x0
pool = 0x677f00
cond = 0x677ff8
priority = true
job = <value optimized out>
#3 0x00007ffff7a0fcd9 in virThreadHelper (data=<value optimized out>)
at util/threads-pthread.c:161
args = 0x0
local = {func = 0x7ffff7a102d0 <virThreadPoolWorker>, opaque =
0x677af0}
#4 0x000000300a2077f1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#5 0x0000003009ae570d in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 10 (Thread 0x7fffecaf9700 (LWP 30458)):
#0 0x000000300a20b3dc in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007ffff7a0feb6 in virCondWait (c=<value optimized out>, m=<value
optimized out>) at util/threads-pthread.c:117
ret = <value optimized out>
#2 0x00007ffff7a10483 in virThreadPoolWorker (opaque=<value optimized
out>) at util/threadpool.c:103
data = 0x0
pool = 0x677f00
cond = 0x677ff8
priority = true
job = <value optimized out>
---Type <return> to continue, or q <return> to quit---
#3 0x00007ffff7a0fcd9 in virThreadHelper (data=<value optimized out>)
at util/threads-pthread.c:161
args = 0x0
local = {func = 0x7ffff7a102d0 <virThreadPoolWorker>, opaque =
0x656070}
#4 0x000000300a2077f1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#5 0x0000003009ae570d in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 9 (Thread 0x7fffed4fa700 (LWP 30457)):
#0 0x000000300a20b3dc in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007ffff7a0feb6 in virCondWait (c=<value optimized out>, m=<value
optimized out>) at util/threads-pthread.c:117
ret = <value optimized out>
#2 0x00007ffff7a10483 in virThreadPoolWorker (opaque=<value optimized
out>) at util/threadpool.c:103
data = 0x0
pool = 0x677f00
cond = 0x677ff8
priority = true
job = <value optimized out>
#3 0x00007ffff7a0fcd9 in virThreadHelper (data=<value optimized out>)
at util/threads-pthread.c:161
args = 0x0
local = {func = 0x7ffff7a102d0 <virThreadPoolWorker>, opaque =
0x677af0}
#4 0x000000300a2077f1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#5 0x0000003009ae570d in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 8 (Thread 0x7fffedefb700 (LWP 30456)):
#0 0x000000300a20b3dc in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007ffff7a0feb6 in virCondWait (c=<value optimized out>, m=<value
optimized out>) at util/threads-pthread.c:117
ret = <value optimized out>
#2 0x00007ffff7a10483 in virThreadPoolWorker (opaque=<value optimized
out>) at util/threadpool.c:103
data = 0x0
pool = 0x677f00
cond = 0x677ff8
priority = true
job = <value optimized out>
#3 0x00007ffff7a0fcd9 in virThreadHelper (data=<value optimized out>)
at util/threads-pthread.c:161
args = 0x0
local = {func = 0x7ffff7a102d0 <virThreadPoolWorker>, opaque =
0x656070}
#4 0x000000300a2077f1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#5 0x0000003009ae570d in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 7 (Thread 0x7fffee8fc700 (LWP 30455)):
#0 0x000000300a20b3dc in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007ffff7a0feb6 in virCondWait (c=<value optimized out>, m=<value
optimized out>) at util/threads-pthread.c:117
ret = <value optimized out>
#2 0x00007ffff7a10483 in virThreadPoolWorker (opaque=<value optimized
out>) at util/threadpool.c:103
data = 0x0
pool = 0x677f00
cond = 0x677ff8
priority = true
job = <value optimized out>
#3 0x00007ffff7a0fcd9 in virThreadHelper (data=<value optimized out>)
at util/threads-pthread.c:161
args = 0x0
local = {func = 0x7ffff7a102d0 <virThreadPoolWorker>, opaque =
0x677af0}
#4 0x000000300a2077f1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#5 0x0000003009ae570d in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 6 (Thread 0x7fffef2fd700 (LWP 30454)):
#0 0x000000300a20b3dc in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007ffff7a0feb6 in virCondWait (c=<value optimized out>, m=<value
optimized out>) at util/threads-pthread.c:117
ret = <value optimized out>
#2 0x00007ffff7a10483 in virThreadPoolWorker (opaque=<value optimized
out>) at util/threadpool.c:103
data = 0x0
pool = 0x677f00
cond = 0x677f60
priority = false
job = <value optimized out>
#3 0x00007ffff7a0fcd9 in virThreadHelper (data=<value optimized out>)
at util/threads-pthread.c:161
args = 0x0
local = {func = 0x7ffff7a102d0 <virThreadPoolWorker>, opaque =
0x656070}
#4 0x000000300a2077f1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#5 0x0000003009ae570d in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 5 (Thread 0x7fffefcfe700 (LWP 30453)):
#0 0x000000300a20b3dc in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007ffff7a0feb6 in virCondWait (c=<value optimized out>, m=<value
optimized out>) at util/threads-pthread.c:117
ret = <value optimized out>
#2 0x00007ffff7a10483 in virThreadPoolWorker (opaque=<value optimized
out>) at util/threadpool.c:103
data = 0x0
pool = 0x677f00
cond = 0x677f60
priority = false
job = <value optimized out>
#3 0x00007ffff7a0fcd9 in virThreadHelper (data=<value optimized out>)
at util/threads-pthread.c:161
args = 0x0
local = {func = 0x7ffff7a102d0 <virThreadPoolWorker>, opaque =
0x677af0}
#4 0x000000300a2077f1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#5 0x0000003009ae570d in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 4 (Thread 0x7ffff06ff700 (LWP 30452)):
#0 0x000000300a20b3dc in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007ffff7a0feb6 in virCondWait (c=<value optimized out>, m=<value
optimized out>) at util/threads-pthread.c:117
ret = <value optimized out>
#2 0x00007ffff7a10483 in virThreadPoolWorker (opaque=<value optimized
out>) at util/threadpool.c:103
data = 0x0
pool = 0x677f00
cond = 0x677f60
priority = false
job = <value optimized out>
#3 0x00007ffff7a0fcd9 in virThreadHelper (data=<value optimized out>)
at util/threads-pthread.c:161
args = 0x0
local = {func = 0x7ffff7a102d0 <virThreadPoolWorker>, opaque =
0x656070}
#4 0x000000300a2077f1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#5 0x0000003009ae570d in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 3 (Thread 0x7ffff1100700 (LWP 30451)):
#0 qemuDomainObjBeginJobInternal (driver=0x7fffe40112f0,
driver_locked=true, obj=0x7fffe40918d0, job=QEMU_JOB_DESTROY,
asyncJob=QEMU_ASYNC_JOB_NONE) at qemu/qemu_domain.c:768
priv = 0x0
now = 140737125149304
then = <value optimized out>
nested = false
__func__ = "qemuDomainObjBeginJobInternal"
__FUNCTION__ = "qemuDomainObjBeginJobInternal"
#1 0x00007fffea5e4223 in qemuDomainDestroyFlags (dom=<value optimized
out>, flags=<value optimized out>) at qemu/qemu_driver.c:2052
driver = 0x7fffe40112f0
vm = 0x7fffe40918d0
ret = -1
event = 0x0
priv = 0x7fffe40d5ab0
__FUNCTION__ = "qemuDomainDestroyFlags"
#2 0x00007ffff7aa57df in virDomainDestroy (domain=0x7fffd8031bb0) at
libvirt.c:2201
ret = <value optimized out>
conn = 0x7fffd4056710
__func__ = "virDomainDestroy"
__FUNCTION__ = "virDomainDestroy"
#3 0x0000000000428e22 in remoteDispatchDomainDestroy (server=<value
optimized out>, client=<value optimized out>, msg=<value optimized out>,
rerr=0x7ffff10ffbe0, args=<value optimized out>, ret=<value optimized out>)
at remote_dispatch.h:1277
dom = 0x7fffd8031bb0
priv = <value optimized out>
#4 remoteDispatchDomainDestroyHelper (server=<value optimized out>,
client=<value optimized out>, msg=<value optimized out>,
rerr=0x7ffff10ffbe0, args=<value optimized out>, ret=<value optimized
out>) at remote_dispatch.h:1255
__func__ = "remoteDispatchDomainDestroyHelper"
#5 0x00007ffff7af2152 in virNetServerProgramDispatchCall
(prog=0x6804d0, server=0x677df0, client=0x686fc0, msg=0x6862d0) at
rpc/virnetserverprogram.c:431
ret = 0x7fffd80327d0 ""
rv = -1
i = <value optimized out>
arg = 0x7fffd8031bf0 "\300%\003\330\377\177"
dispatcher = 0x6496c0
rerr = {code = 0, domain = 0, message = 0x0, level = 0, dom =
0x0, str1 = 0x0, str2 = 0x0, str3 = 0x0, int1 = 0, int2 = 0, net = 0x0}
#6 virNetServerProgramDispatch (prog=0x6804d0, server=0x677df0,
client=0x686fc0, msg=0x6862d0) at rpc/virnetserverprogram.c:304
ret = -1
rerr = {code = 0, domain = 0, message = 0x0, level = 0, dom =
0x0, str1 = 0x0, str2 = 0x0, str3 = 0x0, int1 = 0, int2 = 0, net = 0x0}
__func__ = "virNetServerProgramDispatch"
__FUNCTION__ = "virNetServerProgramDispatch"
#7 0x00007ffff7aeffee in virNetServerProcessMsg (srv=<value optimized
out>, client=0x686fc0, prog=<value optimized out>, msg=0x6862d0) at
rpc/virnetserver.c:171
ret = -1
__func__ = "virNetServerProcessMsg"
#8 0x00007ffff7af0a8b in virNetServerHandleJob (jobOpaque=<value
optimized out>, opaque=<value optimized out>) at rpc/virnetserver.c:192
srv = 0x677df0
job = 0x679030
__func__ = "virNetServerHandleJob"
#9 0x00007ffff7a103ec in virThreadPoolWorker (opaque=<value optimized
out>) at util/threadpool.c:144
data = 0x0
pool = 0x677f00
cond = 0x677f60
priority = false
job = 0x678fb0
#10 0x00007ffff7a0fcd9 in virThreadHelper (data=<value optimized out>)
at util/threads-pthread.c:161
args = 0x0
local = {func = 0x7ffff7a102d0 <virThreadPoolWorker>, opaque =
0x677af0}
#11 0x000000300a2077f1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#12 0x0000003009ae570d in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 2 (Thread 0x7ffff1b01700 (LWP 30450)):
#0 0x000000300a20b3dc in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007ffff7a0feb6 in virCondWait (c=<value optimized out>, m=<value
optimized out>) at util/threads-pthread.c:117
ret = <value optimized out>
#2 0x00007ffff7a10483 in virThreadPoolWorker (opaque=<value optimized
out>) at util/threadpool.c:103
data = 0x0
pool = 0x677f00
cond = 0x677f60
priority = false
job = <value optimized out>
#3 0x00007ffff7a0fcd9 in virThreadHelper (data=<value optimized out>)
at util/threads-pthread.c:161
args = 0x0
local = {func = 0x7ffff7a102d0 <virThreadPoolWorker>, opaque =
0x677af0}
#4 0x000000300a2077f1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#5 0x0000003009ae570d in clone () from /lib64/libc.so.6
No symbol table info available.
Thread 1 (Thread 0x7ffff7993800 (LWP 30447)):
#0 0x0000003009a73912 in _IO_default_xsputn_internal () from
/lib64/libc.so.6
No symbol table info available.
#1 0x0000003009a675f8 in _IO_padn_internal () from /lib64/libc.so.6
No symbol table info available.
#2 0x0000003009a449ab in vfprintf () from /lib64/libc.so.6
No symbol table info available.
#3 0x0000003009afc970 in __vsnprintf_chk () from /lib64/libc.so.6
No symbol table info available.
#4 0x0000003009afc8aa in __snprintf_chk () from /lib64/libc.so.6
No symbol table info available.
#5 0x00007ffff7a2d44a in snprintf (when=<value optimized out>,
buf=0x7fffffffd470 "2012-12-14 15:01:33.498+0000") at
/usr/include/bits/stdio2.h:65
No locals.
#6 virTimeStringThenRaw (when=<value optimized out>, buf=0x7fffffffd470
"2012-12-14 15:01:33.498+0000") at util/virtime.c:219
fields = {tm_sec = 33, tm_min = 1, tm_hour = 15, tm_mday = 14,
tm_mon = 12, tm_year = 2012, tm_wday = 5, tm_yday = 348, tm_isdst =
-11304, tm_gmtoff = 140737347401400, tm_zone = 0x1 <Address 0x1 out of
bounds>}
#7 0x00007ffff7a2d67a in virTimeStringNowRaw (buf=0x7fffffffd470
"2012-12-14 15:01:33.498+0000") at util/virtime.c:195
now = 1355497293498
#8 0x00007ffff7a0434b in virLogVMessage (source=VIR_LOG_FROM_FILE,
priority=<value optimized out>, filename=0x7ffff7b5970b
"util/event_poll.c", linenr=378, funcname=0x7ffff7b59cc0
"virEventPollMakePollFDs", fmt=<value optimized out>,
vargs=0x7fffffffd4f0) at util/logging.c:822
logVersionStderr = true
str = 0x685b60 "Prepare n=2 w=3, f=14 e=1 d=0"
msg = 0x684ec0 "30447: debug : virEventPollMakePollFDs:378 :
Prepare n=2 w=3, f=14 e=1 d=0\n"
timestamp = "2012-12-14 15:01:33.498+0000"
fprio = <value optimized out>
i = <value optimized out>
ret = <value optimized out>
saved_errno = 104
emit = <value optimized out>
filterflags = <value optimized out>
__func__ = "virLogVMessage"
#9 0x00007ffff7a046ec in virLogMessage (source=<value optimized out>,
priority=<value optimized out>, filename=<value optimized out>,
linenr=<value optimized out>, funcname=<value optimized out>, fmt=<value
optimized out>)
at util/logging.c:753
ap = {{gp_offset = 48, fp_offset = 48, overflow_arg_area =
0x7fffffffd5f8, reg_save_area = 0x7fffffffd510}}
#10 0x00007ffff79fe241 in virEventPollMakePollFDs () at
util/event_poll.c:374
fds = 0x686420
i = <value optimized out>
#11 virEventPollRunOnce () at util/event_poll.c:605
fds = 0x0
ret = <value optimized out>
timeout = <value optimized out>
nfds = <value optimized out>
__func__ = "virEventPollRunOnce"
__FUNCTION__ = "virEventPollRunOnce"
#12 0x00007ffff79fd666 in virEventRunDefaultImpl () at util/event.c:247
__func__ = "virEventRunDefaultImpl"
#13 0x00007ffff7aef7dd in virNetServerRun (srv=0x677df0) at
rpc/virnetserver.c:1004
timerid = -1
timerActive = 0
i = <value optimized out>
__FUNCTION__ = "virNetServerRun"
__func__ = "virNetServerRun"
#14 0x000000000040c5a3 in main (argc=<value optimized out>, argv=<value
optimized out>) at libvirtd.c:1354
srv = 0x677df0
remote_config_file = 0x677840 "/etc/libvirt/libvirtd.conf"
statuswrite = -1
ret = 1
pid_file_fd = 8
pid_file = 0x650e40 "/var/run/libvirtd.pid"
sock_file = 0x6832d0 "/var/run/libvirt/libvirt-sock"
sock_file_ro = 0x6832a0 "/var/run/libvirt/libvirt-sock-ro"
timeout = -1
verbose = 0
godaemon = 0
ipsock = 0
config = 0x677b10
privileged = true
implicit_conf = <value optimized out>
run_dir = 0x656190 "/var/run/libvirt"
old_umask = <value optimized out>
opts = {{name = 0x4350ec "verbose", has_arg = 0, flag =
0x7fffffffd8f4, val = 1}, {name = 0x4350f4 "daemon", has_arg = 0, flag =
0x7fffffffd8f0, val = 1}, {name = 0x4350fb "listen", has_arg = 0, flag =
0x7fffffffd8ec, val = 1},
{name = 0x435240 "config", has_arg = 1, flag = 0x0, val =
102}, {name = 0x435197 "timeout", has_arg = 1, flag = 0x0, val = 116},
{name = 0x435102 "pid-file", has_arg = 1, flag = 0x0, val = 112}, {name
= 0x43510b "version",
has_arg = 0, flag = 0x0, val = 129}, {name = 0x435113
"help", has_arg = 0, flag = 0x0, val = 63}, {name = 0x0, has_arg = 0,
flag = 0x0, val = 0}}
__func__ = "main"
__FUNCTION__ = "main"
(gdb)
On 12/04/2012 10:38 AM, Scott Sullivan wrote:
> Running libvirt v1.0.0, with f0e72b2f5c675f927d04545dc5095f9e5998f171
> applied. The problem (which I cannot reproduce reliably), is that
> libvirtd crashes sometimes on a destroy (sequence of events and crash
> log below).
>
> I was wondering if anyone had any insights as to the cause of this
> crash, or even if any commits after v1.0.0 might address this. If I
> can provide anymore information to help debug this I would be happy to
> try and provide it. At the time of this crash, the instance being
> destroyed did not have any RBD attachments, it was just running off
> its local LVM.
>
> Sequence of events:
>
> 1.) virsh destroy ID
> End of file while reading data: Input/output error ; error: Failed to
> reconnect to the hypervisor
>
> (libvirtd at this point has crashed)
>
> 2.) Resulting crash entry from /var/log/libvirt/libvirtd.log:
>
> 2012-11-26 17:37:13.239+0000: 10314: error : qemuMonitorIO:614 :
> internal error End of file from monitor
> 2012-11-27 16:48:56.195+0000: 10314: error : qemuMonitorIO:614 :
> internal error End of file from monitor
> Caught Segmentation violation dumping internal log buffer:
>
>
> ====== start of log =====
>
> ^@patchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1
> events=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.078+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=5 d=0
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941072
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941072 due in
> 4994 ms
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=4994
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE:
> watch=50563 events=2
> 2012-11-27 16:48:56.078+000010314: debug : virNetMessageFree:73 :
> msg=0x888520 nfds=0 cb=(nil)
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x88cd10 tx=(nil)
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetServerClientCalculateHandleMode:184 : mode=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.078+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941072
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941072 due in
> 4994 ms
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=4994
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE:
> watch=50563 events=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x88cd10 tx=(nil)
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetServerClientCalculateHandleMode:184 : mode=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetServerClientDispatchRead:1007 : RPC_SERVER_CLIENT_MSG_RX:
> client=0x88d980 len=28 prog=536903814 vers=1 proc=110 type=0 status=0
> serial=3
> 2012-11-27 16:48:56.078+000010314: debug :
> virKeepAliveCheckMessage:384 : ka=0x887c00, client=0x88d980, msg=0x88cd10
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollUpdateTimeout:254 : EVENT_POLL_UPDATE_TIMEOUT:
> timer=101086 frequency=5000
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.078+000010314: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x88d980
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetServerDispatchNewMessage:219 : server=0x879d80 client=0x88d980
> message=0x88cd10
> 2012-11-27 16:48:56.078+000010314: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x882540
> 2012-11-27 16:48:56.078+000010314: debug : virNetMessageNew:45 :
> msg=0x87af70 tracked=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x87af70 tx=(nil)
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetServerClientCalculateHandleMode:184 : mode=1
> 2012-11-27 16:48:56.078+000010318: debug : virNetServerHandleJob:190 :
> server=0x879d80 client=0x88d980 message=0x88cd10 prog=0x882540
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.078+000010318: debug :
> virNetServerProgramDispatch:284 : prog=536903814 ver=1 type=0 status=0
> serial=3 proc=110
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.078+000010318: debug :
> remoteDispatchGetURIHelper:7297 : server=0x879d80 client=0x88d980
> msg=0x88cd10 rerr=0x7f642e214be0 args=0x7f6400000cf0 ret=0x7f6400000c80
> 2012-11-27 16:48:56.078+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.078+000010318: debug : virConnectGetURI:1711 :
> conn=0x7f641c0728f0
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.078+000010318: debug :
> virNetMessageEncodePayload:358 : Encode length as 48
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.078+000010318: debug :
> virNetServerClientSendMessageLocked:1251 : msg=0x88cd10 proc=110
> len=48 offset=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.078+000010318: debug :
> virNetServerClientSendMessageLocked:1259 :
> RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x88d980 len=48 prog=536903814
> vers=1 proc=110 type=1 status=0 serial=3
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.078+000010318: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x87af70 tx=0x88cd10
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.078+000010318: debug :
> virNetServerClientCalculateHandleMode:184 : mode=3
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.078+000010318: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=3
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941078
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941078 due in
> 5000 ms
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=5000
> 2012-11-27 16:48:56.078+000010318: debug :
> virEventPollInterruptLocked:701 : Interrupting
> 2012-11-27 16:48:56.078+000010318: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x882540
> 2012-11-27 16:48:56.078+000010318: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x88d980
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1
> events=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.078+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=5 d=0
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941078
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941078 due in
> 5000 ms
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=5000
> 2012-11-27 16:48:56.078+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE:
> watch=50563 events=2
> 2012-11-27 16:48:56.078+000010314: debug : virNetMessageFree:73 :
> msg=0x88cd10 nfds=0 cb=(nil)
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x87af70 tx=(nil)
> 2012-11-27 16:48:56.078+000010314: debug :
> virNetServerClientCalculateHandleMode:184 : mode=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=1
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.078+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.078+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941078
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941078 due in
> 4999 ms
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=4999
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE:
> watch=50563 events=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetMessageDecodeLength:152 : Got length, now need 40 total (36 more)
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x87af70 tx=(nil)
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerClientCalculateHandleMode:184 : mode=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerClientDispatchRead:1007 : RPC_SERVER_CLIENT_MSG_RX:
> client=0x88d980 len=40 prog=536903814 vers=1 proc=23 type=0 status=0
> serial=4
> 2012-11-27 16:48:56.079+000010314: debug :
> virKeepAliveCheckMessage:384 : ka=0x887c00, client=0x88d980, msg=0x87af70
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollUpdateTimeout:254 : EVENT_POLL_UPDATE_TIMEOUT:
> timer=101086 frequency=5000
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.079+000010314: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x88d980
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerDispatchNewMessage:219 : server=0x879d80 client=0x88d980
> message=0x87af70
> 2012-11-27 16:48:56.079+000010314: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x882540
> 2012-11-27 16:48:56.079+000010314: debug : virNetMessageNew:45 :
> msg=0x888590 tracked=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x888590 tx=(nil)
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerClientCalculateHandleMode:184 : mode=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerClientDispatchRead:1007 : RPC_SERVER_CLIENT_MSG_RX:
> client=0x88d980 len=40 prog=536903814 vers=1 proc=23 type=0 status=0
> serial=4
> 2012-11-27 16:48:56.079+000010314: debug :
> virKeepAliveCheckMessage:384 : ka=0x887c00, client=0x88d980, msg=0x87af70
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollUpdateTimeout:254 : EVENT_POLL_UPDATE_TIMEOUT:
> timer=101086 frequency=5000
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.079+000010314: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x88d980
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerDispatchNewMessage:219 : server=0x879d80 client=0x88d980
> message=0x87af70
> 2012-11-27 16:48:56.079+000010314: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x882540
> 2012-11-27 16:48:56.079+000010314: debug : virNetMessageNew:45 :
> msg=0x888590 tracked=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x888590 tx=(nil)
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerClientCalculateHandleMode:184 : mode=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.079+000010315: debug : virNetServerHandleJob:190 :
> server=0x879d80 client=0x88d980 message=0x87af70 prog=0x882540
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.079+000010315: debug :
> virNetServerProgramDispatch:284 : prog=536903814 ver=1 type=0 status=0
> serial=4 proc=23
> 2012-11-27 16:48:56.079+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.079+000010315: debug :
> remoteDispatchDomainLookupByNameHelper:3084 : server=0x879d80
> client=0x88d980 msg=0x87af70 rerr=0x7f6430017be0 args=0x7f640800f550
> ret=0x7f640800f610
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.079+000010315: debug : virDomainLookupByName:2128
> : conn=0x7f641c0728f0, name=4274X8
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.079+000010315: debug : virObjectNew:110 :
> OBJECT_NEW: obj=0x7f640800f5d0 classname=virDomain
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.079+000010315: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x7f641c0728f0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.079+000010315: debug : virDomainFree:2292 :
> dom=0x7f640800f5d0, (VM: name=4274X8,
> uuid=3b14a4c4-19e0-11e2-ad58-8ccdadf125ba)
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.079+000010315: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x7f640800f5d0
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.079+000010315: debug : virObjectUnref:137 :
> OBJECT_DISPOSE: obj=0x7f640800f5d0
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941079
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941079 due in
> 5000 ms
> 2012-11-27 16:48:56.079+000010315: debug : virDomainDispose:225 :
> release domain 0x7f640800f5d0 4274X8 3b14a4c4-19e0-11e2-ad58-8ccdadf125ba
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=5000
> 2012-11-27 16:48:56.079+000010315: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x7f641c0728f0
> 2012-11-27 16:48:56.079+000010315: debug :
> virNetMessageEncodePayload:358 : Encode length as 60
> 2012-11-27 16:48:56.079+000010315: debug :
> virNetServerClientSendMessageLocked:1251 : msg=0x87af70 proc=23 len=60
> offset=0
> 2012-11-27 16:48:56.079+000010315: debug :
> virNetServerClientSendMessageLocked:1259 :
> RPC_SERVER_CLIENT_MSG_TX_QUEUE: client=0x88d980 len=60 prog=536903814
> vers=1 proc=23 type=1 status=0 serial=4
> 2012-11-27 16:48:56.079+000010315: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x888590 tx=0x87af70
> 2012-11-27 16:48:56.079+000010315: debug :
> virNetServerClientCalculateHandleMode:184 : mode=3
> 2012-11-27 16:48:56.079+000010315: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=3
> 2012-11-27 16:48:56.079+000010315: debug :
> virEventPollInterruptLocked:701 : Interrupting
> 2012-11-27 16:48:56.079+000010315: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x882540
> 2012-11-27 16:48:56.079+000010315: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x88d980
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1
> events=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.079+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=5 d=0
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941079
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941079 due in
> 5000 ms
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=5000
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE:
> watch=50563 events=2
> 2012-11-27 16:48:56.079+000010314: debug : virNetMessageFree:73 :
> msg=0x87af70 nfds=0 cb=(nil)
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x888590 tx=(nil)
> 2012-11-27 16:48:56.079+000010314: debug :
> virNetServerClientCalculateHandleMode:184 : mode=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.079+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941079
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941079 due in
> 5000 ms
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=5000
> 2012-11-27 16:48:56.079+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.079+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE:
> watch=50563 events=1
> 2012-11-27 16:48:56.080+000010314: debug :
> virNetMessageDecodeLength:152 : Got length, now need 60 total (56 more)
> 2012-11-27 16:48:56.080+000010314: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x888590 tx=(nil)
> 2012-11-27 16:48:56.080+000010314: debug :
> virNetServerClientCalculateHandleMode:184 : mode=1
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=1
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.080+000010314: debug :
> virNetServerClientDispatchRead:1007 : RPC_SERVER_CLIENT_MSG_RX:
> client=0x88d980 len=60 prog=536903814 vers=1 proc=12 type=0 status=0
> serial=5
> 2012-11-27 16:48:56.080+000010314: debug :
> virKeepAliveCheckMessage:384 : ka=0x887c00, client=0x88d980, msg=0x888590
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollUpdateTimeout:254 : EVENT_POLL_UPDATE_TIMEOUT:
> timer=101086 frequency=5000
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.080+000010314: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x88d980
> 2012-11-27 16:48:56.080+000010314: debug :
> virNetServerDispatchNewMessage:219 : server=0x879d80 client=0x88d980
> message=0x888590
> 2012-11-27 16:48:56.080+000010314: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x882540
> 2012-11-27 16:48:56.080+000010314: debug : virNetMessageNew:45 :
> msg=0x88cd10 tracked=1
> 2012-11-27 16:48:56.080+000010314: debug :
> virNetServerClientCalculateHandleMode:153 : tls=(nil) hs=-1,
> rx=0x88cd10 tx=(nil)
> 2012-11-27 16:48:56.080+000010314: debug :
> virNetServerClientCalculateHandleMode:184 : mode=1
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=50563
> events=1
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.080+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.080+000010319: debug : virNetServerHandleJob:190 :
> server=0x879d80 client=0x88d980 message=0x888590 prog=0x882540
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.080+000010319: debug :
> virNetServerProgramDispatch:284 : prog=536903814 ver=1 type=0 status=0
> serial=5 proc=12
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.080+000010319: debug :
> remoteDispatchDomainDestroyHelper:1254 : server=0x879d80
> client=0x88d980 msg=0x888590 rerr=0x7f642d813be0 args=0x7f64180021c0
> ret=0x7f6418002bc0
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.080+000010319: debug : virObjectNew:110 :
> OBJECT_NEW: obj=0x7f6418002180 classname=virDomain
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.080+000010319: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x7f641c0728f0
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941080
> 2012-11-27 16:48:56.080+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941080 due in
> 5000 ms
> 2012-11-27 16:48:56.080+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=5000
> 2012-11-27 16:48:56.080+000010319: debug : virDomainDestroy:2183 :
> dom=0x7f6418002180, (VM: name=4274X8,
> uuid=3b14a4c4-19e0-11e2-ad58-8ccdadf125ba)
> 2012-11-27 16:48:56.080+000010319: debug : qemuProcessKill:3941 :
> vm=4274X8 pid=22404 flags=1
> 2012-11-27 16:48:56.080+000010319: debug : virProcessKillPainfully:253
> : vpid=22404 force=1
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=6
> events=1
> 2012-11-27 16:48:56.097+000010314: debug : virNetlinkEventCallback:346
> : dispatching to max 0 clients, called from event watch 6
> 2012-11-27 16:48:56.097+000010314: debug : virNetlinkEventCallback:359
> : event not handled.
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.097+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941080
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941080 due in
> 4983 ms
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=4983
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=6
> events=1
> 2012-11-27 16:48:56.097+000010314: debug : virNetlinkEventCallback:346
> : dispatching to max 0 clients, called from event watch 6
> 2012-11-27 16:48:56.097+000010314: debug : virNetlinkEventCallback:359
> : event not handled.
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.097+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941080
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941080 due in
> 4983 ms
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=4983
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollRunOnce:625 :
> Poll got 2 event(s)
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=6
> events=1
> 2012-11-27 16:48:56.097+000010314: debug : virNetlinkEventCallback:346
> : dispatching to max 0 clients, called from event watch 6
> 2012-11-27 16:48:56.097+000010314: debug : virNetlinkEventCallback:359
> : event not handled.
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=7
> events=1
> 2012-11-27 16:48:56.097+000010314: debug :
> udevEventHandleCallback:1467 : udev action: 'remove'
> 2012-11-27 16:48:56.097+000010314: debug : udevRemoveOneDevice:1218 :
> Failed to find device to remove that has udev name
> '/sys/devices/virtual/net/4274X8_0/queues/tx-0'
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.097+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941080
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941080 due in
> 4983 ms
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=4983
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=7
> events=1
> 2012-11-27 16:48:56.097+000010314: debug :
> udevEventHandleCallback:1467 : udev action: 'remove'
> 2012-11-27 16:48:56.097+000010314: debug : udevRemoveOneDevice:1218 :
> Failed to find device to remove that has udev name
> '/sys/devices/virtual/net/4274X8_0/queues/rx-0'
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.097+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941080
> 2012-11-27 16:48:56.097+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941080 due in
> 4983 ms
> 2012-11-27 16:48:56.097+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=4983
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=7
> events=1
> 2012-11-27 16:48:56.126+000010314: debug :
> udevEventHandleCallback:1467 : udev action: 'remove'
> 2012-11-27 16:48:56.126+000010314: debug : udevRemoveOneDevice:1214 :
> Removing device 'net_4274X8_0_fe_54_00_4b_82_15' with sysfs path
> '/sys/devices/virtual/net/4274X8_0'
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.126+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=8, f=20 e=25 d=0
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=9 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941080
> 2012-11-27 16:48:56.126+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941080 due in
> 4954 ms
> 2012-11-27 16:48:56.126+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=10 timeout=4954
> 2012-11-27 16:48:56.194+000010314: debug : virEventPollRunOnce:625 :
> Poll got 1 event(s)
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchTimeouts:410 : Dispatch 2
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchHandles:455 : Dispatch 10
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchHandles:469 : i=0 w=1
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchHandles:469 : i=1 w=2
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchHandles:469 : i=2 w=3
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchHandles:469 : i=3 w=4
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchHandles:469 : i=4 w=5
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchHandles:469 : i=5 w=6
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchHandles:469 : i=6 w=7
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchHandles:469 : i=7 w=8
> 2012-11-27 16:48:56.194+000010314: debug :
> virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=8
> events=9
> 2012-11-27 16:48:56.194+000010314: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x7f6418000a10
> 2012-11-27 16:48:56.195+000010314: error : qemuMonitorIO:614 :
> internal error End of file from monitor
> 2012-11-27 16:48:56.195+000010314: debug : qemuMonitorIO:647 : Error
> on monitor internal error End of file from monitor
> 2012-11-27 16:48:56.195+000010314: debug :
> virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=8
> events=12
> 2012-11-27 16:48:56.195+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.195+000010314: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x7f6418000a10
> 2012-11-27 16:48:56.195+000010314: debug : qemuMonitorIO:670 :
> Triggering EOF callback
> 2012-11-27 16:48:56.195+000010314: debug :
> qemuProcessHandleMonitorEOF:283 : Received EOF on 0x7f64200072f0 '4274X8'
> 2012-11-27 16:48:56.280+000010319: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x7f64200072f0
> 2012-11-27 16:48:56.280+000010314: debug : qemuProcessStop:3992 :
> Shutting down VM '4274X8' pid=22404 flags=0
> 2012-11-27 16:48:56.280+000010314: debug : virFileClose:72 : Closed fd 22
> 2012-11-27 16:48:56.280+000010314: debug : qemuMonitorClose:838 :
> QEMU_MONITOR_CLOSE: mon=0x7f6418000a10 refs=2
> 2012-11-27 16:48:56.280+000010314: debug :
> virEventPollRemoveHandle:175 : EVENT_POLL_REMOVE_HANDLE: watch=8
> 2012-11-27 16:48:56.280+000010314: debug :
> virEventPollRemoveHandle:188 : mark delete 7 20
> 2012-11-27 16:48:56.280+000010314: debug :
> virEventPollInterruptLocked:697 : Skip interrupt, 1 904570880
> 2012-11-27 16:48:56.280+000010314: debug : virFileClose:72 : Closed fd 20
> 2012-11-27 16:48:56.280+000010314: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x7f6418000a10
> 2012-11-27 16:48:56.280+000010314: debug : qemuProcessKill:3941 :
> vm=4274X8 pid=22404 flags=5
> 2012-11-27 16:48:56.280+000010314: debug : virProcessKillPainfully:253
> : vpid=22404 force=1
> 2012-11-27 16:48:56.280+000010314: debug : virObjectRef:168 :
> OBJECT_REF: obj=0x7f64200072f0
> 2012-11-27 16:48:56.280+000010314: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x7f64200072f0
> 2012-11-27 16:48:56.280+000010314: debug : qemuDomainCleanupRun:1996 :
> driver=0x7f642001bd70, vm=4274X8
> 2012-11-27 16:48:56.280+000010314: debug :
> qemuProcessAutoDestroyRemove:4463 : vm=4274X8
> 2012-11-27 16:48:56.280+000010314: debug :
> qemuDriverCloseCallbackUnset:661 : vm=4274X8,
> uuid=3b14a4c4-19e0-11e2-ad58-8ccdadf125ba, cb=0x7f6428cd7800
> 2012-11-27 16:48:56.280+000010314: debug :
> virSecurityDACRestoreSecurityAllLabel:726 : Restoring security label
> on 4274X8 migrated=0
> 2012-11-27 16:48:56.280+000010314: info :
> virSecurityDACRestoreSecurityFileLabel:315 : Restoring DAC user and
> group on '/dev/LVM/4274X8'
> 2012-11-27 16:48:56.280+000010314: info :
> virSecurityDACSetOwnership:271 : Setting DAC user and group on
> '/dev/dm-4' to '0:0'
> 2012-11-27 16:48:56.280+000010314: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x7f64200a24a0
> 2012-11-27 16:48:56.280+000010314: debug : virObjectUnref:137 :
> OBJECT_DISPOSE: obj=0x7f64200a24a0
> 2012-11-27 16:48:56.280+000010314: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x7f64200072f0
> 2012-11-27 16:48:56.280+000010314: debug :
> virEventPollDispatchHandles:469 : i=8 w=42213
> 2012-11-27 16:48:56.280+000010314: debug :
> virEventPollDispatchHandles:469 : i=9 w=50563
> 2012-11-27 16:48:56.280+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.280+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 10
> 2012-11-27 16:48:56.280+000010314: debug :
> virEventPollCleanupHandles:562 : EVENT_POLL_PURGE_HANDLE: watch=8
> 2012-11-27 16:48:56.280+000010314: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x7f6418000a10
> 2012-11-27 16:48:56.280+000010314: debug : virObjectUnref:137 :
> OBJECT_DISPOSE: obj=0x7f6418000a10
> 2012-11-27 16:48:56.280+000010314: debug : qemuMonitorDispose:247 :
> mon=0x7f6418000a10
> 2012-11-27 16:48:56.280+000010314: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x7f64200072f0
> 2012-11-27 16:48:56.280+000010314: debug : virEventRunDefaultImpl:244
> : running default event implementation
> 2012-11-27 16:48:56.280+000010314: debug :
> virEventPollCleanupTimeouts:501 : Cleanup 2
> 2012-11-27 16:48:56.280+000010314: debug :
> virEventPollCleanupHandles:549 : Cleanup 9
> 2012-11-27 16:48:56.280+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=0 w=1, f=7 e=1 d=0
> 2012-11-27 16:48:56.280+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=1 w=2, f=9 e=1 d=0
> 2012-11-27 16:48:56.280+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=2 w=3, f=12 e=1 d=0
> 2012-11-27 16:48:56.281+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=3 w=4, f=13 e=1 d=0
> 2012-11-27 16:48:56.281+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=4 w=5, f=6 e=1 d=0
> 2012-11-27 16:48:56.281+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=5 w=6, f=14 e=1 d=0
> 2012-11-27 16:48:56.281+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=6 w=7, f=16 e=1 d=0
> 2012-11-27 16:48:56.281+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=7 w=42213, f=24 e=25 d=0
> 2012-11-27 16:48:56.281+000010314: debug : virEventPollMakePollFDs:378
> : Prepare n=8 w=50563, f=18 e=1 d=0
> 2012-11-27 16:48:56.281+000010314: debug :
> virEventPollCalculateTimeout:320 : Calculate expiry of 2 timers
> 2012-11-27 16:48:56.281+000010314: debug :
> virEventPollCalculateTimeout:326 : Got a timeout scheduled for
> 1354034941080
> 2012-11-27 16:48:56.281+000010314: debug :
> virEventPollCalculateTimeout:346 : Timeout at 1354034941080 due in
> 4799 ms
> 2012-11-27 16:48:56.281+000010314: debug : virEventPollRunOnce:614 :
> EVENT_POLL_RUN: nhandles=9 timeout=4799
> 2012-11-27 16:48:56.281+000010319: debug : virObjectUnref:135 :
> OBJECT_UNREF: obj=0x7f64200072f0
> 2012-11-27 16:48:56.281+000010319: debug : virObjectUnref:137 :
> OBJECT_DISPOSE: obj=0x7f64200072f0
> 2012-11-27 16:48:56.281+000010319: debug : virDomainObjDispose:1746 :
> obj=0x7f64200072f0
>
>
> ====== end of log =====
>
>
More information about the libvir-list
mailing list