[libvirt] libvirtd crash upon virsh destroy

[Scott Sullivan]

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 =====
>
>