Attachment 608065 Details for Bug 852984 – backtrace of hung libvirtd

backtrace of hung libvirtd

ovs.trace (text/plain), 83.00 KB, created by Alex Jia on 2012-08-30 07:50:21 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Alex Jia

Created: 2012-08-30 07:50:21 UTC

Size: 83.00 KB

patch

obsolete

>258	    err = virNetDevTapCreateInBridgePort(brname, &net->ifname, &net->mac,
>(gdb) n
>Detaching after fork from child process 23670.
>n
>^C
>Program received signal SIGINT, Interrupt.
>[Switching to Thread 0x7ff87b4f8860 (LWP 23469)]
>0x00000033f68dc053 in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:87
>87	  int result = INLINE_SYSCALL (poll, 3, CHECK_N (fds, nfds), nfds, timeout);
>(gdb) thread apply all bt full
>
>Thread 11 (Thread 0x7ff875666700 (LWP 23470)):
>#0  0x00000033f68dc053 in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:87
>        __arg2 = 2
>        _a3 = -1
>        _a1 = 140705098253696
>        resultvar = <value optimized out>
>        __arg3 = -1
>        __arg1 = 140705098253696
>        _a2 = 2
>        resultvar = <value optimized out>
>        oldtype = 0
>        result = <value optimized out>
>#1  0x00000032ef447fc5 in virCommandProcessIO (cmd=0x7ff868301280, exitstatus=0x0) at util/command.c:1753
>        i = <value optimized out>
>        fds = {{fd = 27, events = 1, revents = 0}, {fd = 29, events = 1, revents = 0}, {fd = 40, events = 48, revents = 0}}
>        nfds = 2
>        outfd = 27
>        errfd = 29
>        inlen = 0
>        outlen = 0
>        errlen = 2403
>        ret = <value optimized out>
>        infd = -1
>        inoff = 0
>#2  virCommandRun (cmd=0x7ff868301280, exitstatus=0x0) at util/command.c:2002
>        ret = 0
>        outbuf = 0x7ff86815f970 ""
>        errbuf = 0x7ff8681217b0 "Aug 30 14:49:27|00002|stream_unix|ERR|/tmp/stream-unix.23670.0: connection to /var/run/openvswitch/db.sock failed: No such file or directory\nAug 30 14:49:27|00003|reconnect|WARN|unix:/var/run/openvswi"...
>        infd = {-1, -1}
>        st = {st_dev = 27, st_ino = 140703128617193, st_nlink = 210453397531, st_mode = 6, st_uid = 30, st_gid = 8, __pad0 = 2012, st_rdev = 1039382085636, st_size = 140705098253672, 
>          st_blksize = 140705098253792, st_blocks = 140705098261944, st_atim = {tv_sec = 77, tv_nsec = 1}, st_mtim = {tv_sec = 77, tv_nsec = 46}, st_ctim = {tv_sec = 218762663289, tv_nsec = 218763996092}, 
>          __unused = {140705098261944, 140705098253792, 218762658624}}
>        string_io = <value optimized out>
>        async_io = <value optimized out>
>        str = <value optimized out>
>        tmpfd = <value optimized out>
>        __FUNCTION__ = "virCommandRun"
>        __func__ = "virCommandRun"
>#3  0x00000032ef47364a in virNetDevOpenvswitchAddPort (brname=0x7ff868160460 "virbr0", ifname=0x7ff86808b440 "vnet1", macaddr=<value optimized out>, vmuuid=<value optimized out>, 
>    ovsport=<value optimized out>, virtVlan=<value optimized out>) at util/virnetdevopenvswitch.c:129
>        ret = -1
>        i = <value optimized out>
>        cmd = 0x7ff868301280
>        macaddrstr = "52:54:00:CA:B4:39"
>        ifuuidstr = "3e092f81-7e82-fc95-47a1-8f5a5d3c389d"
>        vmuuidstr = "492d9815-7eba-3d09-d857-63b1dc423ec7"
>        attachedmac_ex_id = 0x7ff8680b1970 "external-ids:attached-mac=\"52:54:00:CA:B4:39\""
>        ifaceid_ex_id = 0x7ff8682d0720 "external-ids:iface-id=\"3e092f81-7e82-fc95-47a1-8f5a5d3c389d\""
>        profile_ex_id = 0x0
>        vmid_ex_id = 0x7ff8682ec860 "external-ids:vm-id=\"492d9815-7eba-3d09-d857-63b1dc423ec7\""
>        buf = 0x7ff8680214e0
>        __FUNCTION__ = "virNetDevOpenvswitchAddPort"
>---Type <return> to continue, or q <return> to quit---
>#4  0x00000032ef4740dd in virNetDevTapCreateInBridgePort (brname=0x7ff868160460 "virbr0", ifname=0x7ff86819a4a8, macaddr=0x7ff86819a424, 
>    vmuuid=0x7ff868199f88 "I-\230\025~\272=\t\330Wc\261\334B>\307@\245\031h\370\177", tapfd=0x7ff875664d0c, virtPortProfile=0x7ff86819a790, virtVlan=0x7ff86819a510, flags=3) at util/virnetdevtap.c:327
>        tapmac = {addr = "\376T\000Ê´9"}
>        __FUNCTION__ = "virNetDevTapCreateInBridgePort"
>#5  0x0000000000478e8f in qemuNetworkIfaceConnect (def=0x7ff868199f80, conn=0x7ff864000bd0, driver=0x7ff868009eb0, net=0x7ff86819a420, qemuCaps=<value optimized out>) at qemu/qemu_command.c:258
>        brname = 0x7ff868160460 "virbr0"
>        err = <value optimized out>
>        tapfd = 25
>        tap_create_flags = <value optimized out>
>        template_ifname = true
>        actualType = <value optimized out>
>        __FUNCTION__ = "qemuNetworkIfaceConnect"
>#6  0x0000000000484364 in qemuBuildCommandLine (conn=0x7ff864000bd0, driver=0x7ff868009eb0, def=0x7ff868199f80, monitor_chr=0x7ff875665088, monitor_json=232, qemuCaps=0x7ff8682e7b20, migrateFrom=0x0, 
>    migrateFd=-1, snapshot=0x0, vmop=VIR_NETDEV_VPORT_PROFILE_OP_CREATE) at qemu/qemu_command.c:5311
>        tapfd = <value optimized out>
>        net = 0x7ff86819a420
>        host = 0x0
>        vhostfd_name = '\000' <repeats 49 times>
>        actualType = <value optimized out>
>        nic = 0x0
>        tapfd_name = '\000' <repeats 49 times>
>        vlan = -1
>        bootindex = 0
>        bootNet = 0
>        i = 1
>        ut = {sysname = "Linux", '\000' <repeats 59 times>, nodename = "201.nay.redhat.com", '\000' <repeats 46 times>, release = "2.6.32-288.el6.x86_64", '\000' <repeats 43 times>, 
>          version = "#1 SMP Thu Jul 19 23:09:22 EDT 2012", '\000' <repeats 29 times>, machine = "x86_64", '\000' <repeats 58 times>, domainname = "(none)", '\000' <repeats 58 times>}
>        disableKQEMU = 1969639552
>        enableKQEMU = 8
>        disableKVM = 1969639808
>        enableKVM = <value optimized out>
>        emulator = 0x7ff800000000 <Address 0x7ff800000000 out of bounds>
>        uuid = "492d9815-7eba-3d09-d857-63b1dc423ec7"
>        cpu = 0x0
>        smp = 0x0
>        last_good_net = 0
>        hasHwVirt = <value optimized out>
>        cmd = 0x7ff8680cdf40
>        emitBootindex = <value optimized out>
>        usbcontroller = 1
>        usblegacy = <value optimized out>
>        __FUNCTION__ = "qemuBuildCommandLine"
>#7  0x00000000004a7743 in qemuProcessStart (conn=0x7ff864000bd0, driver=0x7ff868009eb0, vm=0x7ff868182a00, migrateFrom=0x0, stdin_fd=-1, stdin_path=0x0, snapshot=0x0, 
>    vmop=VIR_NETDEV_VPORT_PROFILE_OP_CREATE, flags=1) at qemu/qemu_process.c:3643
>        ret = <value optimized out>
>        pos = -1
>        ebuf = "pWfu\370\177\000\000\360Tfu\370\177\000\000\001\000\000\000\000\000\000\000 Tfu\370\177\000\000\220Wfu\370\177\000\000\020Ufu\370\177\000\000\001\000\000\000\000\000\000\000\220Ufu\370\177\000\000\034\000\000\000\000\000\000\000\b\032Z\357\062\000\000\000\220Wfu\370\177\000\000pÉ\366\063\000\000\000\001\200\255\373\370\177\000\000\220Wfu\370\177\000\000\220Wfu\370\177\000\000\220Wfu\370\177\000\000\220Wfu\370\177\000\000\254Wfu\370\177\000\000\254Wfu\370\177\000\000\220Wfu\370\177\000\000\254Wfu\370\177\000\000 \000\000h\370\177\000\000t\000\000\000\000\000\000\000t\000\000\000\000\000\000\000\000I\nh\370\177\000\000\370Vfu\370\177\000\000t\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\000I\nh\370\177\000\000s\000\000\000\000\000\000\000"...
>        logfile = 22
>        timestamp = <value optimized out>
>        priv = 0x7ff8681952e0
>        cmd = 0x0
>---Type <return> to continue, or q <return> to quit---
>        hookData = {conn = 0x7ff864000bd0, vm = 0x7ff868182a00, driver = 0x7ff868009eb0, nodemask = 0x0}
>        cur_balloon = <value optimized out>
>        i = <value optimized out>
>        nodeset = 0x0
>        nodemask = 0x0
>        stop_flags = 2
>        __FUNCTION__ = "qemuProcessStart"
>        __func__ = "qemuProcessStart"
>#8  0x0000000000468fbe in qemuDomainObjStart (conn=0x7ff864000bd0, driver=0x7ff868009eb0, vm=0x7ff868182a00, flags=<value optimized out>) at qemu/qemu_driver.c:5364
>        ret = <value optimized out>
>        managed_save = 0x7ff8680a4ee0 "/var/lib/libvirt/qemu/save/foo-1.save"
>        start_paused = false
>        autodestroy = <value optimized out>
>        bypass_cache = <value optimized out>
>        force_boot = <value optimized out>
>        start_flags = <value optimized out>
>        __FUNCTION__ = "qemuDomainObjStart"
>        __func__ = "qemuDomainObjStart"
>#9  0x00000000004695b2 in qemuDomainStartWithFlags (dom=0x7ff8680ce070, flags=0) at qemu/qemu_driver.c:5421
>        driver = 0x7ff868009eb0
>        vm = 0x7ff868182a00
>        ret = -1
>        __FUNCTION__ = "qemuDomainStartWithFlags"
>#10 0x00000032ef4e7cb0 in virDomainCreate (domain=0x7ff8680ce070) at libvirt.c:8165
>        ret = <value optimized out>
>        conn = <value optimized out>
>        __func__ = "virDomainCreate"
>        __FUNCTION__ = "virDomainCreate"
>#11 0x000000000043cce2 in remoteDispatchDomainCreate (server=<value optimized out>, client=<value optimized out>, msg=<value optimized out>, rerr=0x7ff875665b80, args=<value optimized out>, 
>    ret=<value optimized out>) at remote_dispatch.h:874
>        dom = 0x7ff8680ce070
>        priv = <value optimized out>
>#12 remoteDispatchDomainCreateHelper (server=<value optimized out>, client=<value optimized out>, msg=<value optimized out>, rerr=0x7ff875665b80, args=<value optimized out>, ret=<value optimized out>)
>    at remote_dispatch.h:852
>        __func__ = "remoteDispatchDomainCreateHelper"
>#13 0x00000032ef531bed in virNetServerProgramDispatchCall (prog=0x1465e90, server=0x145ae30, client=0x1463eb0, msg=0x1464b10) at rpc/virnetserverprogram.c:424
>        ret = 0x7ff8680a7ae0 ""
>        rv = -1
>        i = <value optimized out>
>        arg = 0x7ff8680ce0b0 "\340x\nh\370\177"
>        dispatcher = 0x74dd50
>        rerr = {code = 0, domain = 0, message = 0x0, level = 0, dom = 0x0, str1 = 0x0, str2 = 0x0, str3 = 0x0, int1 = 0, int2 = 0, net = 0x0}
>#14 virNetServerProgramDispatch (prog=0x1465e90, server=0x145ae30, client=0x1463eb0, msg=0x1464b10) at rpc/virnetserverprogram.c:297
>        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"
>#15 0x00000032ef52f1be in virNetServerProcessMsg (srv=<value optimized out>, client=0x1463eb0, prog=<value optimized out>, msg=0x1464b10) at rpc/virnetserver.c:170
>        ret = -1
>        __func__ = "virNetServerProcessMsg"
>#16 0x00000032ef52f85c in virNetServerHandleJob (jobOpaque=<value optimized out>, opaque=0x145ae30) at rpc/virnetserver.c:191
>        srv = 0x145ae30
>        job = 0x1462ad0
>        __func__ = "virNetServerHandleJob"
>---Type <return> to continue, or q <return> to quit---
>#17 0x00000032ef45f39c in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:144
>        data = 0x0
>        pool = 0x145af40
>        cond = 0x145afa0
>        priority = false
>        job = 0x1462b30
>#18 0x00000032ef45ec89 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
>        args = 0x0
>        local = {func = 0x32ef45f280 <virThreadPoolWorker>, opaque = 0x1439e50}
>#19 0x00000038baa077f1 in start_thread (arg=0x7ff875666700) at pthread_create.c:301
>        __res = <value optimized out>
>        pd = 0x7ff875666700
>        now = <value optimized out>
>        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140705098262272, -608851389352739783, 140736009181856, 140705098262976, 0, 3, 611370450938788921, -577136248388289479}, mask_was_saved = 0}}, priv = {
>            pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>        not_first_call = <value optimized out>
>        pagesize_m1 = <value optimized out>
>        sp = <value optimized out>
>        freesize = <value optimized out>
>#20 0x00000033f68e570d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
>No locals.
>
>Thread 10 (Thread 0x7ff874c65700 (LWP 23471)):
>#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
>No locals.
>#1  0x00000032ef45ee66 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
>        ret = <value optimized out>
>#2  0x00000032ef45f433 in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
>        data = 0x0
>        pool = 0x145af40
>        cond = 0x145afa0
>        priority = false
>        job = <value optimized out>
>#3  0x00000032ef45ec89 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
>        args = 0x0
>        local = {func = 0x32ef45f280 <virThreadPoolWorker>, opaque = 0x1439d30}
>#4  0x00000038baa077f1 in start_thread (arg=0x7ff874c65700) at pthread_create.c:301
>        __res = <value optimized out>
>        pd = 0x7ff874c65700
>        now = <value optimized out>
>        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140705087772416, -608851389352739783, 140736009181856, 140705087773120, 0, 3, 611369626841939001, -577136248388289479}, mask_was_saved = 0}}, priv = {
>            pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>        not_first_call = <value optimized out>
>        pagesize_m1 = <value optimized out>
>        sp = <value optimized out>
>        freesize = <value optimized out>
>#5  0x00000033f68e570d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
>No locals.
>
>Thread 9 (Thread 0x7ff874264700 (LWP 23472)):
>#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
>No locals.
>#1  0x00000032ef45ee66 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
>        ret = <value optimized out>
>---Type <return> to continue, or q <return> to quit---
>#2  0x00000032ef45f433 in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
>        data = 0x0
>        pool = 0x145af40
>        cond = 0x145afa0
>        priority = false
>        job = <value optimized out>
>#3  0x00000032ef45ec89 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
>        args = 0x0
>        local = {func = 0x32ef45f280 <virThreadPoolWorker>, opaque = 0x1439c50}
>#4  0x00000038baa077f1 in start_thread (arg=0x7ff874264700) at pthread_create.c:301
>        __res = <value optimized out>
>        pd = 0x7ff874264700
>        now = <value optimized out>
>        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140705077282560, -608851389352739783, 140736009181856, 140705077283264, 0, 3, 611368800597605433, -577136248388289479}, mask_was_saved = 0}}, priv = {
>            pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>        not_first_call = <value optimized out>
>        pagesize_m1 = <value optimized out>
>        sp = <value optimized out>
>        freesize = <value optimized out>
>#5  0x00000033f68e570d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
>No locals.
>
>Thread 8 (Thread 0x7ff873863700 (LWP 23473)):
>#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
>No locals.
>#1  0x00000032ef45ee66 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
>        ret = <value optimized out>
>#2  0x00000032ef45f433 in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
>        data = 0x0
>        pool = 0x145af40
>        cond = 0x145afa0
>        priority = false
>        job = <value optimized out>
>#3  0x00000032ef45ec89 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
>        args = 0x0
>        local = {func = 0x32ef45f280 <virThreadPoolWorker>, opaque = 0x1439b10}
>#4  0x00000038baa077f1 in start_thread (arg=0x7ff873863700) at pthread_create.c:301
>        __res = <value optimized out>
>        pd = 0x7ff873863700
>        now = <value optimized out>
>        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140705066792704, -608851389352739783, 140736009181856, 140705066793408, 0, 3, 611376772593777721, -577136248388289479}, mask_was_saved = 0}}, priv = {
>            pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>        not_first_call = <value optimized out>
>        pagesize_m1 = <value optimized out>
>        sp = <value optimized out>
>        freesize = <value optimized out>
>#5  0x00000033f68e570d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
>No locals.
>
>Thread 7 (Thread 0x7ff872e62700 (LWP 23474)):
>#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
>No locals.
>#1  0x00000032ef45ee66 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
>        ret = <value optimized out>
>---Type <return> to continue, or q <return> to quit---
>#2  0x00000032ef45f433 in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
>        data = 0x0
>        pool = 0x145af40
>        cond = 0x145afa0
>        priority = false
>        job = <value optimized out>
>#3  0x00000032ef45ec89 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
>        args = 0x0
>        local = {func = 0x32ef45f280 <virThreadPoolWorker>, opaque = 0x1439a30}
>#4  0x00000038baa077f1 in start_thread (arg=0x7ff872e62700) at pthread_create.c:301
>        __res = <value optimized out>
>        pd = 0x7ff872e62700
>        now = <value optimized out>
>        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140705056302848, -608851389352739783, 140736009181856, 140705056303552, 0, 3, 611373747326188601, -577136248388289479}, mask_was_saved = 0}}, priv = {
>            pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>        not_first_call = <value optimized out>
>        pagesize_m1 = <value optimized out>
>        sp = <value optimized out>
>        freesize = <value optimized out>
>#5  0x00000033f68e570d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
>No locals.
>
>Thread 6 (Thread 0x7ff872461700 (LWP 23475)):
>#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
>No locals.
>#1  0x00000032ef45ee66 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
>        ret = <value optimized out>
>#2  0x00000032ef45f433 in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
>        data = 0x0
>        pool = 0x145af40
>        cond = 0x145b038
>        priority = true
>        job = <value optimized out>
>#3  0x00000032ef45ec89 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
>        args = 0x0
>        local = {func = 0x32ef45f280 <virThreadPoolWorker>, opaque = 0x14398f0}
>#4  0x00000038baa077f1 in start_thread (arg=0x7ff872461700) at pthread_create.c:301
>        __res = <value optimized out>
>        pd = 0x7ff872461700
>        now = <value optimized out>
>        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140705045812992, -608851389352739783, 140736009181856, 140705045813696, 0, 3, 611372923229338681, -577136248388289479}, mask_was_saved = 0}}, priv = {
>            pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>        not_first_call = <value optimized out>
>        pagesize_m1 = <value optimized out>
>        sp = <value optimized out>
>        freesize = <value optimized out>
>#5  0x00000033f68e570d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
>No locals.
>
>Thread 5 (Thread 0x7ff871a60700 (LWP 23476)):
>#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
>No locals.
>#1  0x00000032ef45ee66 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
>        ret = <value optimized out>
>---Type <return> to continue, or q <return> to quit---
>#2  0x00000032ef45f433 in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
>        data = 0x0
>        pool = 0x145af40
>        cond = 0x145b038
>        priority = true
>        job = <value optimized out>
>#3  0x00000032ef45ec89 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
>        args = 0x0
>        local = {func = 0x32ef45f280 <virThreadPoolWorker>, opaque = 0x1439810}
>#4  0x00000038baa077f1 in start_thread (arg=0x7ff871a60700) at pthread_create.c:301
>        __res = <value optimized out>
>        pd = 0x7ff871a60700
>        now = <value optimized out>
>        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140705035323136, -608851389352739783, 140736009181856, 140705035323840, 0, 3, 611380867308223545, -577136248388289479}, mask_was_saved = 0}}, priv = {
>            pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>        not_first_call = <value optimized out>
>        pagesize_m1 = <value optimized out>
>        sp = <value optimized out>
>        freesize = <value optimized out>
>#5  0x00000033f68e570d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
>No locals.
>
>Thread 4 (Thread 0x7ff87105f700 (LWP 23477)):
>#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
>No locals.
>#1  0x00000032ef45ee66 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
>        ret = <value optimized out>
>#2  0x00000032ef45f433 in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
>        data = 0x0
>        pool = 0x145af40
>        cond = 0x145b038
>        priority = true
>        job = <value optimized out>
>#3  0x00000032ef45ec89 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
>        args = 0x0
>        local = {func = 0x32ef45f280 <virThreadPoolWorker>, opaque = 0x14396d0}
>#4  0x00000038baa077f1 in start_thread (arg=0x7ff87105f700) at pthread_create.c:301
>        __res = <value optimized out>
>        pd = 0x7ff87105f700
>        now = <value optimized out>
>        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140705024833280, -608851389352739783, 140736009181856, 140705024833984, 0, 3, 611380043211373625, -577136248388289479}, mask_was_saved = 0}}, priv = {
>            pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>        not_first_call = <value optimized out>
>        pagesize_m1 = <value optimized out>
>        sp = <value optimized out>
>        freesize = <value optimized out>
>#5  0x00000033f68e570d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
>No locals.
>
>Thread 3 (Thread 0x7ff87065e700 (LWP 23478)):
>#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
>No locals.
>#1  0x00000032ef45ee66 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
>        ret = <value optimized out>
>---Type <return> to continue, or q <return> to quit---
>#2  0x00000032ef45f433 in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
>        data = 0x0
>        pool = 0x145af40
>        cond = 0x145b038
>        priority = true
>        job = <value optimized out>
>#3  0x00000032ef45ec89 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
>        args = 0x0
>        local = {func = 0x32ef45f280 <virThreadPoolWorker>, opaque = 0x14395f0}
>#4  0x00000038baa077f1 in start_thread (arg=0x7ff87065e700) at pthread_create.c:301
>        __res = <value optimized out>
>        pd = 0x7ff87065e700
>        now = <value optimized out>
>        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140705014343424, -608851389352739783, 140736009181856, 140705014344128, 0, 3, 611377017943784505, -577136248388289479}, mask_was_saved = 0}}, priv = {
>            pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>        not_first_call = <value optimized out>
>        pagesize_m1 = <value optimized out>
>        sp = <value optimized out>
>        freesize = <value optimized out>
>#5  0x00000033f68e570d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
>No locals.
>
>Thread 2 (Thread 0x7ff86fc5d700 (LWP 23479)):
>#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
>No locals.
>#1  0x00000032ef45ee66 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:117
>        ret = <value optimized out>
>#2  0x00000032ef45f433 in virThreadPoolWorker (opaque=<value optimized out>) at util/threadpool.c:103
>        data = 0x0
>        pool = 0x145af40
>        cond = 0x145b038
>        priority = true
>        job = <value optimized out>
>#3  0x00000032ef45ec89 in virThreadHelper (data=<value optimized out>) at util/threads-pthread.c:161
>        args = 0x0
>        local = {func = 0x32ef45f280 <virThreadPoolWorker>, opaque = 0x14394a0}
>#4  0x00000038baa077f1 in start_thread (arg=0x7ff86fc5d700) at pthread_create.c:301
>        __res = <value optimized out>
>        pd = 0x7ff86fc5d700
>        now = <value optimized out>
>        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140705003853568, -608851389352739783, 140736009181856, 140705003854272, 0, 3, 611420174312045625, -577136248388289479}, mask_was_saved = 0}}, priv = {
>            pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
>        not_first_call = <value optimized out>
>        pagesize_m1 = <value optimized out>
>        sp = <value optimized out>
>        freesize = <value optimized out>
>#5  0x00000033f68e570d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
>No locals.
>
>Thread 1 (Thread 0x7ff87b4f8860 (LWP 23469)):
>#0  0x00000033f68dc053 in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:87
>        __arg2 = 8
>        _a3 = 5000
>        _a1 = 21385984
>---Type <return> to continue, or q <return> to quit---
>        resultvar = <value optimized out>
>        __arg3 = 5000
>        __arg1 = 21385984
>        _a2 = 8
>        resultvar = <value optimized out>
>        oldtype = 0
>        result = <value optimized out>
>#1  0x00000032ef44e2bc in virEventPollRunOnce () at util/event_poll.c:615
>        fds = 0x1465300
>        ret = <value optimized out>
>        timeout = 5000
>        nfds = 8
>        __func__ = "virEventPollRunOnce"
>        __FUNCTION__ = "virEventPollRunOnce"
>#2  0x00000032ef44d4f7 in virEventRunDefaultImpl () at util/event.c:247
>        __func__ = "virEventRunDefaultImpl"
>#3  0x00000032ef52e9fd in virNetServerRun (srv=0x145ae30) at rpc/virnetserver.c:751
>        timerid = -1
>        timerActive = 0
>        i = <value optimized out>
>        __FUNCTION__ = "virNetServerRun"
>        __func__ = "virNetServerRun"
>#4  0x0000000000422311 in main (argc=<value optimized out>, argv=<value optimized out>) at libvirtd.c:1332
>        srv = 0x145ae30
>        remote_config_file = 0x145a690 "/etc/libvirt/libvirtd.conf"
>        statuswrite = -1
>        ret = 1
>        pid_file_fd = 5
>        pid_file = 0x1434190 "/var/run/libvirtd.pid"
>        sock_file = 0x1466070 "/var/run/libvirt/libvirt-sock"
>        sock_file_ro = 0x14660a0 "/var/run/libvirt/libvirt-sock-ro"
>        timeout = -1
>        verbose = 0
>        godaemon = 1
>        ipsock = 0
>        config = 0x145a9d0
>        privileged = true
>        implicit_conf = <value optimized out>
>        run_dir = 0x1439ee0 "/var/run/libvirt"
>        old_umask = <value optimized out>
>        opts = {{name = 0x4fd7a7 "verbose", has_arg = 0, flag = 0x7fffa7d59e54, val = 1}, {name = 0x4fd7af "daemon", has_arg = 0, flag = 0x7fffa7d59e50, val = 1}, {name = 0x51b796 "listen", has_arg = 0, 
>            flag = 0x7fffa7d59e4c, val = 1}, {name = 0x51942c "config", has_arg = 1, flag = 0x0, val = 102}, {name = 0x521b7e "timeout", has_arg = 1, flag = 0x0, val = 116}, {name = 0x529a1d "pid-file", 
>            has_arg = 1, flag = 0x0, val = 112}, {name = 0x51cee4 "version", has_arg = 0, flag = 0x0, val = 129}, {name = 0x51399e "help", has_arg = 0, flag = 0x0, val = 63}, {name = 0x0, has_arg = 0, 
>            flag = 0x0, val = 0}}
>        __func__ = "main"
>        __FUNCTION__ = "main"
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>[root@201 client]# LIBVIRT_DEBUG=1 virsh start foo-1
>2012-08-30 06:53:03.377+0000: 23937: info : libvirt version: 0.10.0, package: 1.el6 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2012-08-29-02:28:58, x86-012.build.bos.redhat.com)
>2012-08-30 06:53:03.377+0000: 23937: debug : virInitialize:421 : register drivers
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterDriver:729 : driver=0x32ef822d20 name=Test
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterDriver:744 : registering Test as driver 0
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterNetworkDriver:561 : registering Test as network driver 0
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterInterfaceDriver:591 : registering Test as interface driver 0
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterStorageDriver:621 : registering Test as storage driver 0
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterDeviceMonitor:651 : registering Test as device driver 0
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterSecretDriver:681 : registering Test as secret driver 0
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterNWFilterDriver:711 : registering Test as network filter driver 0
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterDriver:729 : driver=0x32ef824200 name=ESX
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterDriver:744 : registering ESX as driver 1
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterInterfaceDriver:591 : registering ESX as interface driver 1
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterNetworkDriver:561 : registering ESX as network driver 1
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterStorageDriver:621 : registering ESX as storage driver 1
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterDeviceMonitor:651 : registering ESX as device driver 1
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterSecretDriver:681 : registering ESX as secret driver 1
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterNWFilterDriver:711 : registering ESX as network filter driver 1
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterDriver:729 : driver=0x32ef823660 name=remote
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterDriver:744 : registering remote as driver 2
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterNetworkDriver:561 : registering remote as network driver 2
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterInterfaceDriver:591 : registering remote as interface driver 2
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterStorageDriver:621 : registering remote as storage driver 2
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterDeviceMonitor:651 : registering remote as device driver 2
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterSecretDriver:681 : registering remote as secret driver 2
>2012-08-30 06:53:03.377+0000: 23937: debug : virRegisterNWFilterDriver:711 : registering remote as network filter driver 2
>2012-08-30 06:53:03.377+0000: 23937: debug : virEventRegisterDefaultImpl:204 : registering default event implementation
>2012-08-30 06:53:03.377+0000: 23937: debug : virEventPollAddHandle:111 : Used 0 handle slots, adding at least 10 more
>2012-08-30 06:53:03.377+0000: 23937: debug : virEventPollInterruptLocked:697 : Skip interrupt, 0 0
>2012-08-30 06:53:03.377+0000: 23937: debug : virEventPollAddHandle:136 : EVENT_POLL_ADD_HANDLE: watch=1 fd=4 events=1 cb=0x32ef44d700 opaque=(nil) ff=(nil)
>2012-08-30 06:53:03.377+0000: 23937: debug : virEventRegisterImpl:177 : addHandle=0x32ef44e980 updateHandle=0x32ef44d9a0 removeHandle=0x32ef44d850 addTimeout=0x32ef44e7b0 updateTimeout=0x32ef44dac0 removeTimeout=0x32ef44d740
>2012-08-30 06:53:03.377+0000: 23937: debug : virConnectOpenAuth:1403 : name=(null), auth=0x32ef822c80, flags=0
>2012-08-30 06:53:03.377+0000: 23937: debug : virObjectNew:110 : OBJECT_NEW: obj=0x1af1210 classname=virConnect
>2012-08-30 06:53:03.378+0000: 23937: debug : virConnectGetConfigFile:953 : Loading config file '/etc/libvirt/libvirt.conf'
>2012-08-30 06:53:03.378+0000: 23937: debug : virFileClose:72 : Closed fd 6
>2012-08-30 06:53:03.378+0000: 23937: debug : do_open:1131 : no name, allowing driver auto-select
>2012-08-30 06:53:03.378+0000: 23937: debug : do_open:1174 : trying driver 0 (Test) ...
>2012-08-30 06:53:03.378+0000: 23937: debug : do_open:1180 : driver 0 Test returned DECLINED
>2012-08-30 06:53:03.378+0000: 23937: debug : do_open:1174 : trying driver 1 (ESX) ...
>2012-08-30 06:53:03.378+0000: 23937: debug : do_open:1180 : driver 1 ESX returned DECLINED
>2012-08-30 06:53:03.378+0000: 23937: debug : do_open:1174 : trying driver 2 (remote) ...
>2012-08-30 06:53:03.378+0000: 23937: debug : remoteOpen:945 : Auto-probe remote URI
>2012-08-30 06:53:03.378+0000: 23937: debug : doRemoteOpen:576 : proceeding with name = 
>2012-08-30 06:53:03.378+0000: 23937: debug : doRemoteOpen:585 : Connecting with transport 1
>2012-08-30 06:53:03.378+0000: 23937: debug : doRemoteOpen:661 : Proceeding with sockname /var/run/libvirt/libvirt-sock
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetSocketNew:146 : localAddr=0x7fffdade49e0 remoteAddr=0x7fffdade4950 fd=6 errfd=-1 pid=0
>2012-08-30 06:53:03.378+0000: 23937: debug : virObjectNew:110 : OBJECT_NEW: obj=0x1af1aa0 classname=virNetSocket
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetSocketNew:203 : RPC_SOCKET_NEW: sock=0x1af1aa0 fd=6 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0
>2012-08-30 06:53:03.378+0000: 23937: debug : virObjectNew:110 : OBJECT_NEW: obj=0x1af18e0 classname=virNetClient
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetClientNew:342 : RPC_CLIENT_NEW: client=0x1af18e0 sock=0x1af1aa0
>2012-08-30 06:53:03.378+0000: 23937: debug : virObjectRef:168 : OBJECT_REF: obj=0x1af18e0
>2012-08-30 06:53:03.378+0000: 23937: debug : virObjectRef:168 : OBJECT_REF: obj=0x1af1aa0
>2012-08-30 06:53:03.378+0000: 23937: debug : virEventPollInterruptLocked:697 : Skip interrupt, 0 0
>2012-08-30 06:53:03.378+0000: 23937: debug : virEventPollAddHandle:136 : EVENT_POLL_ADD_HANDLE: watch=2 fd=6 events=1 cb=0x32ef534db0 opaque=0x1af1aa0 ff=0x32ef5351a0
>2012-08-30 06:53:03.378+0000: 23937: debug : virKeepAliveNew:212 : client=0x1af18e0, interval=-1, count=0
>2012-08-30 06:53:03.378+0000: 23937: debug : virObjectNew:110 : OBJECT_NEW: obj=0x1af1e60 classname=virKeepAlive
>2012-08-30 06:53:03.378+0000: 23937: debug : virKeepAliveNew:236 : RPC_KEEPALIVE_NEW: ka=0x1af1e60 client=0x1af18e0
>2012-08-30 06:53:03.378+0000: 23937: debug : virObjectRef:168 : OBJECT_REF: obj=0x1af18e0
>2012-08-30 06:53:03.378+0000: 23937: debug : virObjectNew:110 : OBJECT_NEW: obj=0x1af1790 classname=virNetClientProgram
>2012-08-30 06:53:03.378+0000: 23937: debug : virObjectNew:110 : OBJECT_NEW: obj=0x1af1df0 classname=virNetClientProgram
>2012-08-30 06:53:03.378+0000: 23937: debug : virObjectRef:168 : OBJECT_REF: obj=0x1af1790
>2012-08-30 06:53:03.378+0000: 23937: debug : virObjectRef:168 : OBJECT_REF: obj=0x1af1df0
>2012-08-30 06:53:03.378+0000: 23937: debug : doRemoteOpen:759 : Trying authentication
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af20e0 tracked=0
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetMessageEncodePayload:358 : Encode length as 28
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetClientSendInternal:1952 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=536903814 vers=1 proc=66 type=0 status=0 serial=0
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af1a20: msg=0x1af20e0, expectReply=1, nonBlock=0
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetClientIO:1715 : Outgoing message prog=536903814 version=1 serial=0 proc=66 type=0 length=28 dispatch=(nil)
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetClientIO:1774 : We have the buck head=0x1af1a20 call=0x1af1a20
>2012-08-30 06:53:03.378+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
>2012-08-30 06:53:03.378+0000: 23937: debug : virEventPollInterruptLocked:697 : Skip interrupt, 0 0
>2012-08-30 06:53:03.378+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.378+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.378+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.378+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.378+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.378+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-08-30 06:53:03.378+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.378+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.378+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 36 total (32 more)
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=36 prog=536903814 vers=1 proc=66 type=1 status=0 serial=0
>2012-08-30 06:53:03.378+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetClientIOEventLoopPassTheBuck:1421 : Giving up the buck 0x1af1a20
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetClientIOEventLoopPassTheBuck:1435 : No thread to pass the buck to
>2012-08-30 06:53:03.378+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
>2012-08-30 06:53:03.378+0000: 23937: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetClientIO:1804 : All done with our call head=(nil) call=0x1af1a20 rv=0
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetMessageFree:73 : msg=0x1af20e0 nfds=0 cb=(nil)
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af20e0 tracked=0
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetMessageEncodePayload:358 : Encode length as 32
>2012-08-30 06:53:03.378+0000: 23937: debug : virNetClientSendInternal:1952 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=32 prog=536903814 vers=1 proc=60 type=0 status=0 serial=1
>2012-08-30 06:53:03.379+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af2150: msg=0x1af20e0, expectReply=1, nonBlock=0
>2012-08-30 06:53:03.379+0000: 23937: debug : virNetClientIO:1715 : Outgoing message prog=536903814 version=1 serial=1 proc=60 type=0 length=32 dispatch=(nil)
>2012-08-30 06:53:03.379+0000: 23937: debug : virNetClientIO:1774 : We have the buck head=0x1af2150 call=0x1af2150
>2012-08-30 06:53:03.379+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
>2012-08-30 06:53:03.379+0000: 23937: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollDispatchHandles:455 : Dispatch 1
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollDispatchHandles:455 : Dispatch 1
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.379+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-08-30 06:53:03.379+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 32 total (28 more)
>2012-08-30 06:53:03.379+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=32 prog=536903814 vers=1 proc=60 type=1 status=0 serial=1
>2012-08-30 06:53:03.379+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:03.385+0000: 23937: debug : virNetClientIOEventLoopPassTheBuck:1421 : Giving up the buck 0x1af2150
>2012-08-30 06:53:03.385+0000: 23937: debug : virNetClientIOEventLoopPassTheBuck:1435 : No thread to pass the buck to
>2012-08-30 06:53:03.385+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
>2012-08-30 06:53:03.385+0000: 23937: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-08-30 06:53:03.385+0000: 23937: debug : virNetClientIO:1804 : All done with our call head=(nil) call=0x1af2150 rv=0
>2012-08-30 06:53:03.385+0000: 23937: debug : virNetMessageFree:73 : msg=0x1af20e0 nfds=0 cb=(nil)
>2012-08-30 06:53:03.385+0000: 23937: debug : doRemoteOpen:785 : Trying to open URI 
>2012-08-30 06:53:03.385+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af1380 tracked=0
>2012-08-30 06:53:03.385+0000: 23937: debug : virNetMessageEncodePayload:358 : Encode length as 40
>2012-08-30 06:53:03.385+0000: 23937: debug : virNetClientSendInternal:1952 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=40 prog=536903814 vers=1 proc=1 type=0 status=0 serial=2
>2012-08-30 06:53:03.385+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af13f0: msg=0x1af1380, expectReply=1, nonBlock=0
>2012-08-30 06:53:03.385+0000: 23937: debug : virNetClientIO:1715 : Outgoing message prog=536903814 version=1 serial=2 proc=1 type=0 length=40 dispatch=(nil)
>2012-08-30 06:53:03.385+0000: 23937: debug : virNetClientIO:1774 : We have the buck head=0x1af13f0 call=0x1af13f0
>2012-08-30 06:53:03.385+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
>2012-08-30 06:53:03.385+0000: 23937: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollDispatchHandles:455 : Dispatch 1
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollDispatchHandles:455 : Dispatch 1
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.387+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-08-30 06:53:03.394+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:03.394+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=536903814 vers=1 proc=1 type=1 status=0 serial=2
>2012-08-30 06:53:03.394+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:03.394+0000: 23937: debug : virNetClientIOEventLoopPassTheBuck:1421 : Giving up the buck 0x1af13f0
>2012-08-30 06:53:03.394+0000: 23937: debug : virNetClientIOEventLoopPassTheBuck:1435 : No thread to pass the buck to
>2012-08-30 06:53:03.394+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
>2012-08-30 06:53:03.394+0000: 23937: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-08-30 06:53:03.394+0000: 23937: debug : virNetClientIO:1804 : All done with our call head=(nil) call=0x1af13f0 rv=0
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetMessageFree:73 : msg=0x1af1380 nfds=0 cb=(nil)
>2012-08-30 06:53:03.395+0000: 23937: debug : doRemoteOpen:796 : Trying to query remote URI
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af2060 tracked=0
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetMessageEncodePayload:358 : Encode length as 28
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetClientSendInternal:1952 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=536903814 vers=1 proc=110 type=0 status=0 serial=3
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af13f0: msg=0x1af2060, expectReply=1, nonBlock=0
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetClientIO:1715 : Outgoing message prog=536903814 version=1 serial=3 proc=110 type=0 length=28 dispatch=(nil)
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetClientIO:1774 : We have the buck head=0x1af13f0 call=0x1af13f0
>2012-08-30 06:53:03.395+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
>2012-08-30 06:53:03.395+0000: 23937: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollDispatchHandles:455 : Dispatch 1
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollDispatchHandles:455 : Dispatch 1
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.395+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 48 total (44 more)
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=48 prog=536903814 vers=1 proc=110 type=1 status=0 serial=3
>2012-08-30 06:53:03.395+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetClientIOEventLoopPassTheBuck:1421 : Giving up the buck 0x1af13f0
>2012-08-30 06:53:03.395+0000: 23937: debug : virNetClientIOEventLoopPassTheBuck:1435 : No thread to pass the buck to
>2012-08-30 06:53:03.404+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
>2012-08-30 06:53:03.404+0000: 23937: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-08-30 06:53:03.404+0000: 23937: debug : virNetClientIO:1804 : All done with our call head=(nil) call=0x1af13f0 rv=0
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollDispatchHandles:455 : Dispatch 1
>2012-08-30 06:53:03.404+0000: 23937: debug : virNetMessageFree:73 : msg=0x1af2060 nfds=0 cb=(nil)
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-08-30 06:53:03.404+0000: 23937: debug : doRemoteOpen:804 : Auto-probed URI is qemu:///system
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=1 d=0
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.404+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=2 timeout=-1
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1180 : driver 2 remote returned SUCCESS
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1202 : network driver 0 Test returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1202 : network driver 1 ESX returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1202 : network driver 2 remote returned SUCCESS
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1217 : interface driver 0 Test returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1217 : interface driver 1 ESX returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1217 : interface driver 2 remote returned SUCCESS
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1233 : storage driver 0 Test returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1233 : storage driver 1 ESX returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1233 : storage driver 2 remote returned SUCCESS
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1249 : node driver 0 Test returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1249 : node driver 1 ESX returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1249 : node driver 2 remote returned SUCCESS
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1265 : secret driver 0 Test returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1265 : secret driver 1 ESX returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1265 : secret driver 2 remote returned SUCCESS
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1281 : nwfilter driver 0 Test returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1281 : nwfilter driver 1 ESX returned DECLINED
>2012-08-30 06:53:03.404+0000: 23937: debug : do_open:1281 : nwfilter driver 2 remote returned SUCCESS
>2012-08-30 06:53:03.404+0000: 23937: debug : virConnectRegisterCloseCallback:18810 : conn=0x1af1210
>2012-08-30 06:53:03.404+0000: 23937: debug : virDomainLookupByName:2114 : conn=0x1af1210, name=foo-1
>2012-08-30 06:53:03.404+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af28b0 tracked=0
>2012-08-30 06:53:03.405+0000: 23937: debug : virNetMessageEncodePayload:358 : Encode length as 40
>2012-08-30 06:53:03.405+0000: 23937: debug : virNetClientSendInternal:1952 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=40 prog=536903814 vers=1 proc=23 type=0 status=0 serial=4
>2012-08-30 06:53:03.405+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af13f0: msg=0x1af28b0, expectReply=1, nonBlock=0
>2012-08-30 06:53:03.405+0000: 23937: debug : virNetClientIO:1715 : Outgoing message prog=536903814 version=1 serial=4 proc=23 type=0 length=40 dispatch=(nil)
>2012-08-30 06:53:03.405+0000: 23937: debug : virNetClientIO:1774 : We have the buck head=0x1af13f0 call=0x1af13f0
>2012-08-30 06:53:03.405+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
>2012-08-30 06:53:03.405+0000: 23937: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollDispatchHandles:455 : Dispatch 2
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.405+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-08-30 06:53:03.405+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 60 total (56 more)
>2012-08-30 06:53:03.405+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=60 prog=536903814 vers=1 proc=23 type=1 status=0 serial=4
>2012-08-30 06:53:03.434+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:03.434+0000: 23937: debug : virNetClientIOEventLoopPassTheBuck:1421 : Giving up the buck 0x1af13f0
>2012-08-30 06:53:03.434+0000: 23937: debug : virNetClientIOEventLoopPassTheBuck:1435 : No thread to pass the buck to
>2012-08-30 06:53:03.434+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1
>2012-08-30 06:53:03.434+0000: 23937: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-08-30 06:53:03.434+0000: 23937: debug : virNetClientIO:1804 : All done with our call head=(nil) call=0x1af13f0 rv=0
>2012-08-30 06:53:03.434+0000: 23938: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-08-30 06:53:03.434+0000: 23938: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
>2012-08-30 06:53:03.434+0000: 23937: debug : virNetMessageFree:73 : msg=0x1af28b0 nfds=0 cb=(nil)
>2012-08-30 06:53:03.434+0000: 23937: debug : virObjectNew:110 : OBJECT_NEW: obj=0x1af10b0 classname=virDomain
>2012-08-30 06:53:03.434+0000: 23937: debug : virObjectRef:168 : OBJECT_REF: obj=0x1af1210
>2012-08-30 06:53:03.434+0000: 23938: debug : virEventPollDispatchHandles:455 : Dispatch 1
>2012-08-30 06:53:03.434+0000: 23938: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-08-30 06:53:03.434+0000: 23937: debug : virDomainGetID:3468 : dom=0x1af10b0, (VM: name=foo-1, uuid=492d9815-7eba-3d09-d857-63b1dc423ec7)
>2012-08-30 06:53:03.434+0000: 23938: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-08-30 06:53:03.434+0000: 23937: debug : virDomainCreate:8148 : dom=0x1af10b0, (VM: name=foo-1, uuid=492d9815-7eba-3d09-d857-63b1dc423ec7)
>2012-08-30 06:53:03.434+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.434+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.434+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af20b0 tracked=0
>2012-08-30 06:53:03.434+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.434+0000: 23937: debug : virNetMessageEncodePayload:358 : Encode length as 60
>2012-08-30 06:53:03.434+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.435+0000: 23937: debug : virNetClientSendInternal:1952 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=60 prog=536903814 vers=1 proc=9 type=0 status=0 serial=5
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.435+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af13f0: msg=0x1af20b0, expectReply=1, nonBlock=0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.435+0000: 23937: debug : virNetClientIO:1715 : Outgoing message prog=536903814 version=1 serial=5 proc=9 type=0 length=60 dispatch=(nil)
>2012-08-30 06:53:03.435+0000: 23937: debug : virNetClientIO:1774 : We have the buck head=0x1af13f0 call=0x1af13f0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.435+0000: 23937: debug : virEventPollUpdateHandle:146 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=1 d=0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=2 timeout=-1
>2012-08-30 06:53:03.435+0000: 23937: debug : virEventPollInterruptLocked:701 : Interrupting
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollRunOnce:625 : Poll got 1 event(s)
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollDispatchTimeouts:410 : Dispatch 0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollDispatchHandles:455 : Dispatch 2
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollDispatchHandles:469 : i=0 w=1
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollDispatchHandles:483 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventRunDefaultImpl:244 : running default event implementation
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCleanupTimeouts:501 : Cleanup 0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCleanupTimeouts:537 : Found 0 out of 0 timeout slots used, releasing 0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCleanupHandles:549 : Cleanup 2
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=0 w=1, f=4 e=1 d=0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollMakePollFDs:378 : Prepare n=1 w=2, f=6 e=0 d=0
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCalculateTimeout:320 : Calculate expiry of 0 timers
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollCalculateTimeout:346 : Timeout at 0 due in -1 ms
>2012-08-30 06:53:03.435+0000: 23938: debug : virEventPollRunOnce:614 : EVENT_POLL_RUN: nhandles=1 timeout=-1
>2012-08-30 06:53:08.439+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:08.439+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:08.439+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:08.439+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:08.439+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:08.439+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:08.439+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:08.439+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:08.439+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:08.439+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:08.439+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af1a20: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:08.439+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af1a20
>2012-08-30 06:53:13.445+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:13.445+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:13.445+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:13.445+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:13.445+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:13.445+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:13.445+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:13.445+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:13.445+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:13.445+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:13.445+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af0950: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:13.445+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af0950
>2012-08-30 06:53:18.449+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:18.450+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:18.450+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:18.450+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:18.450+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:18.450+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:18.450+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:18.450+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:18.450+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:18.450+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:18.450+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af1a20: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:18.450+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af1a20
>2012-08-30 06:53:23.455+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:23.455+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:23.455+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:23.455+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:23.455+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:23.455+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:23.455+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:23.455+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:23.455+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:23.455+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:23.455+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af0950: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:23.455+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af0950
>2012-08-30 06:53:28.460+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:28.460+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:28.460+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:28.460+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:28.460+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:28.460+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:28.460+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:28.460+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:28.460+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:28.460+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:28.460+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af1a20: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:28.460+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af1a20
>2012-08-30 06:53:33.466+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:33.466+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:33.466+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:33.466+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:33.466+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:33.466+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:33.466+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:33.466+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:33.466+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:33.466+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:33.466+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af0950: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:33.466+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af0950
>2012-08-30 06:53:38.470+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:38.470+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:38.470+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:38.470+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:38.470+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:38.470+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:38.470+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:38.470+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:38.470+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:38.470+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:38.470+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af1a20: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:38.470+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af1a20
>2012-08-30 06:53:43.471+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:43.471+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:43.471+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:43.471+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:43.471+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:43.471+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:43.471+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:43.471+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:43.471+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:43.471+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:43.471+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af0950: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:43.471+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af0950
>2012-08-30 06:53:48.476+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:48.476+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:48.476+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:48.476+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:48.476+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:48.476+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:48.476+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:48.476+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:48.476+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:48.476+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:48.476+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af1a20: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:48.476+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af1a20
>2012-08-30 06:53:53.479+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:53.479+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:53.479+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:53.479+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:53.479+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:53.479+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:53.479+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:53.479+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:53.479+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:53.479+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:53.479+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af0950: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:53.479+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af0950
>2012-08-30 06:53:58.484+0000: 23937: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more)
>2012-08-30 06:53:58.484+0000: 23937: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=1 type=2 status=0 serial=0
>2012-08-30 06:53:58.484+0000: 23937: debug : virKeepAliveCheckMessage:384 : ka=0x1af1e60, client=0x1af18e0, msg=0x1af1948
>2012-08-30 06:53:58.484+0000: 23937: debug : virKeepAliveCheckMessage:401 : RPC_KEEPALIVE_RECEIVED: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=1
>2012-08-30 06:53:58.484+0000: 23937: debug : virKeepAliveCheckMessage:405 : Got keepalive request from client 0x1af18e0
>2012-08-30 06:53:58.484+0000: 23937: debug : virNetMessageNew:45 : msg=0x1af15b0 tracked=0
>2012-08-30 06:53:58.484+0000: 23937: debug : virNetMessageEncodePayloadEmpty:448 : Encode length as 28
>2012-08-30 06:53:58.484+0000: 23937: debug : virKeepAliveMessage:116 : Sending keepalive response to client 0x1af18e0
>2012-08-30 06:53:58.484+0000: 23937: debug : virKeepAliveMessage:119 : RPC_KEEPALIVE_SEND: ka=0x1af1e60 client=0x1af18e0 prog=1801807216 vers=1 proc=2
>2012-08-30 06:53:58.484+0000: 23937: debug : virNetClientQueueNonBlocking:1926 : RPC_CLIENT_MSG_TX_QUEUE: client=0x1af18e0 len=28 prog=1801807216 vers=1 proc=2 type=2 status=0 serial=0
>2012-08-30 06:53:58.485+0000: 23937: debug : virNetClientCallNew:1905 : New call 0x1af1a20: msg=0x1af15b0, expectReply=0, nonBlock=1
>2012-08-30 06:53:58.485+0000: 23937: debug : virNetClientIOEventLoopRemoveDone:1380 : Removing completed call 0x1af1a20
>
>

Actions: View

Attachments on bug 852984: 608065 | 608066