Hi all, We have developed Online storage driver and Offline storage driver for Libvirt, which are located here. Online one: http://cloudxy.googlecode.com/svn/branches/hlfs/person/harry/hlfs/patches/hl... Offline one: http://cloudxy.googlecode.com/svn/branches/hlfs/person/harry/hlfs/patches/hl... HLFS(HDFS-based Log-structured FileSystem) has two modes, which are local mode and HDFS mode. We have tested HLFS driver for Libvirt with local way succesfully. However, when we test HDFS mode with HLFS driver for Libvirt network disk(Online storage Management), which needs "CLASSPATH" environment varaible, we must modify Libvirt source codes like following to set "CLASSPATH" environment variable. First location: Modify qemuBuildCommandLine func in src/qemu/qemu_command.c [...] 5731 if (deviceFlagMasked) 5732 qemuCapsSet(caps, QEMU_CAPS_DEVICE); 5733 if (!optstr) 5734 goto error; 5735 virCommandAddArg(cmd, optstr); 5736 VIR_FREE(optstr); 5737 /*TODO: submit this to Libvirt community, add this line!!!*/ 5738 virCommandAddEnvPass(cmd, "CLASSPATH"); ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 5739 5740 if (!emitBootindex) 5741 bootindex = 0; 5742 else if (disk->info.bootIndex) 5743 bootindex = disk->info.bootIndex; [...] Second location: Modify virNetSocketForkDaemon func in /src/rpc/virnetsocket.c [...] 118 static int virNetSocketForkDaemon(const char *binary) 119 { 120 int ret; 121 virCommandPtr cmd = virCommandNewArgList(binary, 122 "--timeout=30", 123 NULL); 124 125 virCommandAddEnvPassCommon(cmd); 126 virCommandAddEnvPass(cmd, "XDG_CACHE_HOME"); 127 virCommandAddEnvPass(cmd, "XDG_CONFIG_HOME"); 128 virCommandAddEnvPass(cmd, "XDG_RUNTIME_DIR"); 129 /*TODO: submit this to libvirt community, add this line!!!!*/ 130 virCommandAddEnvPass(cmd, "CLASSPATH"); ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 131 virCommandClearCaps(cmd); 132 virCommandDaemonize(cmd); 133 ret = virCommandRun(cmd, NULL); 134 virCommandFree(cmd); 135 return ret; 136 } [...] I boot VM with HLFS volume like following two ways. First way: Only execute "virsh create hlfs_hdfs.xml" ---------------------------------------------------------------------------- This way fails and i find this way just calls func virNetSocketForkDaemon but qemuBuildCommandLine func. Second way: first start "libvirtd" daemon, then execute "virsh create hlfs_hdfs.xml" ----------------------------------------------------------------------------------------------------------------------- This way works well. It calls qemuBuildCommandLine func, which need not call func virNetSocketForkDaemon. NOTE: hlfs_hdfs.xml is like this. $ cat hlfs_hdfs.xml <domain type='qemu'> <name>testvm</name> <memory>1048576</memory> <os> <type arch='x86_64'>hvm</type> </os> <devices> <disk type='network'> <source protocol="hlfs" name="hdfs:///tmp/testenv/testfs"/> <target dev='hda' bus='ide'/> </disk> <graphics type='vnc' port='-1' autoport='yes'/> </devices> </domain> I have some questions about up stuffs. 1, I wonder why first way (Only execute "virsh create hlfs_hdfs.xml") do not call qemuBuildCommandLine func, which may lead to fail to start VM with HLFS volume, right? 2, Maybe i have some understanding mistakes. You may also give other perfect ways to solve my prolems. After first way (Only execute "virsh create hlfs_hdfs.xml"), i get following logs(ALL). $ ./virsh create hlfs_hdfs.xml 2013-02-14 03:32:04.311+0000: 23205: info : libvirt version: 1.0.1 2013-02-14 03:32:04.311+0000: 23205: debug : virGlobalInit:417 : register drivers 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDriver:747 : driver=0x3c87e0 name=Test 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDriver:759 : registering Test as driver 0 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterNetworkDriver:594 : registering Test as network driver 0 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterInterfaceDriver:621 : registering Test as interface driver 0 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterStorageDriver:648 : registering Test as storage driver 0 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDeviceMonitor:675 : registering Test as device driver 0 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterSecretDriver:702 : registering Test as secret driver 0 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterNWFilterDriver:729 : registering Test as network filter driver 0 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDriver:747 : driver=0x3c9120 name=OPENVZ 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDriver:759 : registering OPENVZ as driver 1 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDriver:747 : driver=0x3c9420 name=VMWARE 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDriver:759 : registering VMWARE as driver 2 2013-02-14 03:32:04.311+0000: 23205: debug : vboxRegister:131 : VBoxCGlueInit failed, using dummy driver 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDriver:747 : driver=0x3c9740 name=VBOX 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDriver:759 : registering VBOX as driver 3 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterNetworkDriver:594 : registering VBOX as network driver 1 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterStorageDriver:648 : registering VBOX as storage driver 1 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDriver:747 : driver=0x3c8be0 name=remote 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDriver:759 : registering remote as driver 4 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterNetworkDriver:594 : registering remote as network driver 2 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterInterfaceDriver:621 : registering remote as interface driver 1 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterStorageDriver:648 : registering remote as storage driver 2 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterDeviceMonitor:675 : registering remote as device driver 1 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterSecretDriver:702 : registering remote as secret driver 1 2013-02-14 03:32:04.311+0000: 23205: debug : virRegisterNWFilterDriver:729 : registering remote as network filter driver 1 2013-02-14 03:32:04.312+0000: 23205: debug : virEventRegisterDefaultImpl:204 : registering default event implementation 2013-02-14 03:32:04.312+0000: 23205: debug : virEventPollAddHandle:111 : Used 0 handle slots, adding at least 10 more 2013-02-14 03:32:04.312+0000: 23205: debug : virEventPollInterruptLocked:712 : Skip interrupt, 0 0 2013-02-14 03:32:04.312+0000: 23205: debug : virEventPollAddHandle:136 : EVENT_POLL_ADD_HANDLE: watch=1 fd=4 events=1 cb=0x1502c7 opaque=(nil) ff=(nil) 2013-02-14 03:32:04.312+0000: 23205: debug : virEventRegisterImpl:177 : addHandle=0x14e3f4 updateHandle=0x14e67b removeHandle=0x14e81f addTimeout=0x14ea15 updateTimeout=0x14ec7d removeTimeout=0x14eec1 2013-02-14 03:32:04.312+0000: 23205: debug : virConnectOpenAuth:1430 : name=(null), auth=0x3c84e0, flags=0 2013-02-14 03:32:04.312+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:04.312+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:04.312+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:04.312+0000: 23205: debug : virObjectNew:110 : OBJECT_NEW: obj=0x8d186b0 classname=virConnect 2013-02-14 03:32:04.312+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 1 2013-02-14 03:32:04.312+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:04.312+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:04.312+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:04.312+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2013-02-14 03:32:04.313+0000: 23205: debug : do_open:1149 : no name, allowing driver auto-select 2013-02-14 03:32:04.313+0000: 23205: debug : do_open:1191 : trying driver 0 (Test) ... 2013-02-14 03:32:04.313+0000: 23205: debug : do_open:1197 : driver 0 Test returned DECLINED 2013-02-14 03:32:04.313+0000: 23205: debug : do_open:1191 : trying driver 1 (OPENVZ) ... 2013-02-14 03:32:04.313+0000: 23205: debug : do_open:1197 : driver 1 OPENVZ returned DECLINED 2013-02-14 03:32:04.313+0000: 23205: debug : do_open:1191 : trying driver 2 (VMWARE) ... 2013-02-14 03:32:04.313+0000: 23205: debug : do_open:1197 : driver 2 VMWARE returned DECLINED 2013-02-14 03:32:04.313+0000: 23205: debug : do_open:1191 : trying driver 3 (VBOX) ... 2013-02-14 03:32:04.313+0000: 23205: debug : do_open:1197 : driver 3 VBOX returned DECLINED 2013-02-14 03:32:04.313+0000: 23205: debug : do_open:1191 : trying driver 4 (remote) ... 2013-02-14 03:32:04.313+0000: 23205: debug : remoteOpen:958 : Auto-probe remote URI 2013-02-14 03:32:04.313+0000: 23205: debug : remoteOpen:961 : Auto-spawn user daemon instance 2013-02-14 03:32:04.313+0000: 23205: debug : doRemoteOpen:586 : proceeding with name = 2013-02-14 03:32:04.313+0000: 23205: debug : doRemoteOpen:595 : Connecting with transport 1 2013-02-14 03:32:04.313+0000: 23205: debug : doRemoteOpen:671 : Proceeding with sockname /home/jiawei/.cache/libvirt/libvirt-sock 2013-02-14 03:32:04.313+0000: 23205: debug : virNetSocketNewConnectUNIX:562 : Connection refused for /home/jiawei/.cache/libvirt/libvirt-sock, trying to spawn /usr/local/sbin/libvirtd 999 enter func virNetSocketForkDaemon---------- 2013-02-14 03:32:04.313+0000: 23205: debug : virCommandRunAsync:2200 : About to run LC_ALL=C LD_LIBRARY_PATH=/usr/lib/jvm/java-6-sun/jre/lib/i386/server/:/home/jiawei/workshop3/hlfs/3part/hadoop/lib32/:/home/jiawei/workshop3/hlfs/3part/log/lib32/:/home/jiawei/workshop3/hlfs/3part/snappy/lib32/:/home/jiawei/workshop3/hlfs/output/lib32/:/usr/lib/ PATH=/usr/bin/:/usr/local/bin/:/bin/:/usr/sbin/:/sbin/:/usr/lib/jvm/java-6-sun/bin/ HOME=/home/jiawei USER=jiawei LOGNAME=jiawei CLASSPATH=.:/usr/lib/jvm/java-6-sun/jre/lib/:/usr/lib/jvm/java-6-sun/lib/:/usr/lib/hadoop-0.20/conf:/usr/lib/jvm/java-6-sun/lib/tools.jar:/usr/lib/hadoop-0.20:/usr/lib/hadoop-0.20/hadoop-core-0.20.2-cdh3u2.jar:/usr/lib/hadoop-0.20/lib/ant-contrib-1.0b3.jar:/usr/lib/hadoop-0.20/lib/aspectjrt-1.6.5.jar:/usr/lib/hadoop-0.20/lib/aspectjtools-1.6.5.jar:/usr/lib/hadoop-0.20/lib/commons-cli-1.2.jar:/usr/lib/hadoop-0.20/lib/commons-codec-1.4.jar:/usr/lib/hadoop-0.20/lib/commons-daemon-1.0.1.jar:/usr/lib/hadoop-0.20/lib/commons-el-1.0.jar:/usr/lib/hadoop-0.20/lib/commons-httpclient-3.1.jar:/usr/lib/hadoop-0.20/lib/commons-logging-1.0.4.jar:/usr/lib/hadoop-0.20/lib/commons-logging-api-1.0.4.jar:/usr/lib/hadoop-0.20/lib/commons-net-1.4.1.jar:/usr/lib/hadoop-0.20/lib/core-3.1.1.jar:/usr/lib/hadoop-0.20/lib/hadoop-fairscheduler-0.20.2-cdh3u2.jar:/usr/lib/hadoop-0.20/lib/hsqldb-1.8.0.10.jar:/usr/lib/hadoop-0.20/lib/jackson-core-asl-1.5.2.jar:/usr/lib/hadoop-0.20/lib/jackson-mapper-asl-1.5.2.jar:/usr/lib/hadoop-0.20/lib/jasper-compiler-5.5.12.jar:/usr/lib/hadoo-0.20/lib/jasper-runtime-5.5.12.jar:/usr/lib/hadoop-0.20/lib/jets3t-0.6.1.jar:/usr/lib/hadoop-0.20/lib/jetty-6.1.26.cloudera.1.jar:/usr/lib/hadoop-0.20/lib/jetty-servlet-tester-6.1.26.cloudera.1.jar:/usr/lib/hadoop-0.20/lib/jetty-util-6.1.26.cloudera.1.jar:/usr/lib/hadoop-0.20/lib/jsch-0.1.42.jar:/usr/lib/hadoop-0.20/lib/junit-4.5.jar:/usr/lib/hadoop-0.20/lib/kfs-0.2.2.jar:/usr/lib/hadoop-0.20/lib/log4j-1.2.15.jar:/usr/lib/hadoop-0.20/lib/mockito-all-1.8.2.jar:/usr/lib/hadoop-0.20/lib/oro-2.0.8.jar:/usr/lib/hadoop-0.20/lib/servlet-api-2.5-20081211.jar:/usr/lib/hadoop-0.20/lib/servlet-api-2.5-6.1.14.jar:/usr/lib/hadoop-0.20/lib/slf4j-api-1.4.3.jar:/usr/lib/hadoop-0.20/lib/slf4j-log4j12-1.4.3.jar:/usr/lib/hadoop-0.20/lib/xmlenc-0.52.jar:/usr/lib/hadoop-0.20/lib/jsp-2.1/jsp-2.1.jar:/usr/lib/hadoop-0.20/lib/jsp-2.1/jsp-api-2.1.jar /usr/local/sbin/libvirtd --timeout=30 2013-02-14 03:32:04.317+0000: 23205: debug : virFileClose:72 : Closed fd 7 2013-02-14 03:32:04.317+0000: 23205: debug : virCommandRunAsync:2218 : Command result 0, with PID 23221 2013-02-14 03:32:04.317+0000: 23221: debug : virFileClose:72 : Closed fd 3 2013-02-14 03:32:04.317+0000: 23221: debug : virFileClose:72 : Closed fd 4 2013-02-14 03:32:04.317+0000: 23221: debug : virFileClose:72 : Closed fd 5 2013-02-14 03:32:04.317+0000: 23221: debug : virFileClose:72 : Closed fd 6 2013-02-14 03:32:04.318+0000: 23205: debug : virCommandRun:2016 : Result status 0, stdout: '(null)' stderr: '(null)' 999 leave func virNetSocketForkDaemon-----ret is 0----- 2013-02-14 03:32:04.418+0000: 23205: debug : virNetSocketNewConnectUNIX:562 : Connection refused for /home/jiawei/.cache/libvirt/libvirt-sock, trying to spawn /usr/local/sbin/libvirtd 2013-02-14 03:32:04.618+0000: 23205: debug : virNetSocketNew:155 : localAddr=0xbff192d8 remoteAddr=0xbff19254 fd=6 errfd=-1 pid=0 2013-02-14 03:32:04.618+0000: 23205: debug : virObjectNew:110 : OBJECT_NEW: obj=0xb6d005e0 classname=virNetSocket 2013-02-14 03:32:04.618+0000: 23205: debug : virNetSocketNew:212 : RPC_SOCKET_NEW: sock=0xb6d005e0 fd=6 errfd=-1 pid=0 localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0 2013-02-14 03:32:04.618+0000: 23205: debug : virObjectNew:110 : OBJECT_NEW: obj=0xb6d01cd8 classname=virNetClient 2013-02-14 03:32:04.618+0000: 23205: debug : virNetClientNew:342 : RPC_CLIENT_NEW: client=0xb6d01cd8 sock=0xb6d005e0 2013-02-14 03:32:04.618+0000: 23205: debug : virObjectRef:168 : OBJECT_REF: obj=0xb6d01cd8 2013-02-14 03:32:04.618+0000: 23205: debug : virObjectRef:168 : OBJECT_REF: obj=0xb6d005e0 2013-02-14 03:32:04.618+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:04.618+0000: 23205: debug : virEventPollAddHandle:136 : EVENT_POLL_ADD_HANDLE: watch=2 fd=6 events=1 cb=0x27f8f5 opaque=0xb6d005e0 ff=0x27f960 2013-02-14 03:32:04.618+0000: 23205: debug : virKeepAliveNew:212 : client=0xb6d01cd8, interval=-1, count=0 2013-02-14 03:32:04.618+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:04.618+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:04.618+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 1 2013-02-14 03:32:04.618+0000: 23205: debug : virObjectNew:110 : OBJECT_NEW: obj=0xb6d00480 classname=virKeepAlive 2013-02-14 03:32:04.618+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:04.618+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:04.618+0000: 23205: debug : virKeepAliveNew:236 : RPC_KEEPALIVE_NEW: ka=0xb6d00480 client=0xb6d01cd8 2013-02-14 03:32:04.618+0000: 23205: debug : virObjectRef:168 : OBJECT_REF: obj=0xb6d01cd8 2013-02-14 03:32:04.618+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:04.619+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:04.619+0000: 23205: debug : virObjectNew:110 : OBJECT_NEW: obj=0xb6d00568 classname=virNetClientProgram 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:04.619+0000: 23205: debug : virObjectNew:110 : OBJECT_NEW: obj=0xb6d00590 classname=virNetClientProgram 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:04.619+0000: 23205: debug : virObjectRef:168 : OBJECT_REF: obj=0xb6d00568 2013-02-14 03:32:04.619+0000: 23205: debug : virObjectRef:168 : OBJECT_REF: obj=0xb6d00590 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:04.619+0000: 23205: debug : doRemoteOpen:772 : Trying authentication 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=1 d=0 2013-02-14 03:32:04.619+0000: 23205: debug : virNetMessageNew:45 : msg=0xb6d00520 tracked=0 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=2 timeout=-1 2013-02-14 03:32:04.619+0000: 23205: debug : virNetMessageEncodePayload:358 : Encode length as 28 2013-02-14 03:32:04.619+0000: 23205: debug : virNetClientSendInternal:1955 : RPC_CLIENT_MSG_TX_QUEUE: client=0xb6d01cd8 len=28 prog=536903814 vers=1 proc=66 type=0 status=0 serial=0 2013-02-14 03:32:04.619+0000: 23205: debug : virNetClientCallNew:1908 : New call 0xb6d01d88: msg=0xb6d00520, expectReply=1, nonBlock=0 2013-02-14 03:32:04.619+0000: 23205: debug : virNetClientIO:1718 : Outgoing message prog=536903814 version=1 serial=0 proc=66 type=0 length=28 dispatch=(nil) 2013-02-14 03:32:04.619+0000: 23205: debug : virNetClientIO:1777 : We have the buck head=0xb6d01d88 call=0xb6d01d88 2013-02-14 03:32:04.619+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0 2013-02-14 03:32:04.619+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 2 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:04.619+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:04.619+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=0 d=0 2013-02-14 03:32:04.624+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:04.624+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:04.624+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2013-02-14 03:32:07.411+0000: 23205: debug : virNetMessageDecodeLength:152 : Got length, now need 36 total (32 more) 2013-02-14 03:32:07.411+0000: 23205: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0xb6d01cd8 len=36 prog=536903814 vers=1 proc=66 type=1 status=0 serial=0 2013-02-14 03:32:07.411+0000: 23205: debug : virKeepAliveCheckMessage:384 : ka=0xb6d00480, client=0xb6d01cd8, msg=0xb6d01d14 2013-02-14 03:32:07.411+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1424 : Giving up the buck 0xb6d01d88 2013-02-14 03:32:07.411+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1438 : No thread to pass the buck to 2013-02-14 03:32:07.411+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1 2013-02-14 03:32:07.411+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.411+0000: 23205: debug : virNetClientIO:1807 : All done with our call head=(nil) call=0xb6d01d88 rv=0 2013-02-14 03:32:07.411+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:07.411+0000: 23205: debug : virNetMessageFree:73 : msg=0xb6d00520 nfds=0 cb=(nil) 2013-02-14 03:32:07.411+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:07.411+0000: 23205: debug : virNetMessageNew:45 : msg=0xb6d00520 tracked=0 2013-02-14 03:32:07.411+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 1 2013-02-14 03:32:07.411+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:07.411+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:07.411+0000: 23205: debug : virNetMessageEncodePayload:358 : Encode length as 32 2013-02-14 03:32:07.411+0000: 23205: debug : virNetClientSendInternal:1955 : RPC_CLIENT_MSG_TX_QUEUE: client=0xb6d01cd8 len=32 prog=536903814 vers=1 proc=60 type=0 status=0 serial=1 2013-02-14 03:32:07.411+0000: 23205: debug : virNetClientCallNew:1908 : New call 0xb6d01db8: msg=0xb6d00520, expectReply=1, nonBlock=0 2013-02-14 03:32:07.411+0000: 23205: debug : virNetClientIO:1718 : Outgoing message prog=536903814 version=1 serial=1 proc=60 type=0 length=32 dispatch=(nil) 2013-02-14 03:32:07.411+0000: 23205: debug : virNetClientIO:1777 : We have the buck head=0xb6d01db8 call=0xb6d01db8 2013-02-14 03:32:07.411+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0 2013-02-14 03:32:07.411+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.412+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.412+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.412+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:07.412+0000: 23205: debug : virEventPollInterruptLocked:712 : Skip interrupt, 0 -1218303120 2013-02-14 03:32:07.412+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.412+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.412+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.412+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:07.412+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=0 d=0 2013-02-14 03:32:07.412+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:07.412+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:07.412+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2013-02-14 03:32:07.412+0000: 23205: debug : virNetMessageDecodeLength:152 : Got length, now need 32 total (28 more) 2013-02-14 03:32:07.412+0000: 23205: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0xb6d01cd8 len=32 prog=536903814 vers=1 proc=60 type=1 status=0 serial=1 2013-02-14 03:32:07.412+0000: 23205: debug : virKeepAliveCheckMessage:384 : ka=0xb6d00480, client=0xb6d01cd8, msg=0xb6d01d14 2013-02-14 03:32:07.412+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1424 : Giving up the buck 0xb6d01db8 2013-02-14 03:32:07.412+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1438 : No thread to pass the buck to 2013-02-14 03:32:07.412+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1 2013-02-14 03:32:07.413+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.413+0000: 23205: debug : virNetClientIO:1807 : All done with our call head=(nil) call=0xb6d01db8 rv=0 2013-02-14 03:32:07.413+0000: 23205: debug : virNetMessageFree:73 : msg=0xb6d00520 nfds=0 cb=(nil) 2013-02-14 03:32:07.413+0000: 23205: debug : doRemoteOpen:798 : Trying to open URI 2013-02-14 03:32:07.413+0000: 23205: debug : virNetMessageNew:45 : msg=0xb6d00520 tracked=0 2013-02-14 03:32:07.413+0000: 23205: debug : virNetMessageEncodePayload:358 : Encode length as 40 2013-02-14 03:32:07.413+0000: 23205: debug : virNetClientSendInternal:1955 : RPC_CLIENT_MSG_TX_QUEUE: client=0xb6d01cd8 len=40 prog=536903814 vers=1 proc=1 type=0 status=0 serial=2 2013-02-14 03:32:07.413+0000: 23205: debug : virNetClientCallNew:1908 : New call 0xb6d01d88: msg=0xb6d00520, expectReply=1, nonBlock=0 2013-02-14 03:32:07.413+0000: 23205: debug : virNetClientIO:1718 : Outgoing message prog=536903814 version=1 serial=2 proc=1 type=0 length=40 dispatch=(nil) 2013-02-14 03:32:07.413+0000: 23205: debug : virNetClientIO:1777 : We have the buck head=0xb6d01d88 call=0xb6d01d88 2013-02-14 03:32:07.413+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0 2013-02-14 03:32:07.413+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 1 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.413+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=0 d=0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 1 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.413+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=0 d=0 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:07.413+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2013-02-14 03:32:07.414+0000: 23205: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more) 2013-02-14 03:32:07.414+0000: 23205: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0xb6d01cd8 len=28 prog=536903814 vers=1 proc=1 type=1 status=0 serial=2 2013-02-14 03:32:07.414+0000: 23205: debug : virKeepAliveCheckMessage:384 : ka=0xb6d00480, client=0xb6d01cd8, msg=0xb6d01d14 2013-02-14 03:32:07.414+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1424 : Giving up the buck 0xb6d01d88 2013-02-14 03:32:07.414+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1438 : No thread to pass the buck to 2013-02-14 03:32:07.417+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1 2013-02-14 03:32:07.417+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.417+0000: 23205: debug : virNetClientIO:1807 : All done with our call head=(nil) call=0xb6d01d88 rv=0 2013-02-14 03:32:07.417+0000: 23205: debug : virNetMessageFree:73 : msg=0xb6d00520 nfds=0 cb=(nil) 2013-02-14 03:32:07.417+0000: 23205: debug : doRemoteOpen:809 : Trying to query remote URI 2013-02-14 03:32:07.417+0000: 23205: debug : virNetMessageNew:45 : msg=0xb6d01df0 tracked=0 2013-02-14 03:32:07.417+0000: 23205: debug : virNetMessageEncodePayload:358 : Encode length as 28 2013-02-14 03:32:07.417+0000: 23205: debug : virNetClientSendInternal:1955 : RPC_CLIENT_MSG_TX_QUEUE: client=0xb6d01cd8 len=28 prog=536903814 vers=1 proc=110 type=0 status=0 serial=3 2013-02-14 03:32:07.417+0000: 23205: debug : virNetClientCallNew:1908 : New call 0xb6d00520: msg=0xb6d01df0, expectReply=1, nonBlock=0 2013-02-14 03:32:07.417+0000: 23205: debug : virNetClientIO:1718 : Outgoing message prog=536903814 version=1 serial=3 proc=110 type=0 length=28 dispatch=(nil) 2013-02-14 03:32:07.417+0000: 23205: debug : virNetClientIO:1777 : We have the buck head=0xb6d00520 call=0xb6d00520 2013-02-14 03:32:07.417+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0 2013-02-14 03:32:07.417+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 1 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.417+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=0 d=0 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 1 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:07.417+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.418+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=0 d=0 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2013-02-14 03:32:07.418+0000: 23205: debug : virNetMessageDecodeLength:152 : Got length, now need 48 total (44 more) 2013-02-14 03:32:07.418+0000: 23205: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0xb6d01cd8 len=48 prog=536903814 vers=1 proc=110 type=1 status=0 serial=3 2013-02-14 03:32:07.418+0000: 23205: debug : virKeepAliveCheckMessage:384 : ka=0xb6d00480, client=0xb6d01cd8, msg=0xb6d01d14 2013-02-14 03:32:07.418+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1424 : Giving up the buck 0xb6d00520 2013-02-14 03:32:07.418+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1438 : No thread to pass the buck to 2013-02-14 03:32:07.418+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1 2013-02-14 03:32:07.418+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.418+0000: 23205: debug : virNetClientIO:1807 : All done with our call head=(nil) call=0xb6d00520 rv=0 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:07.418+0000: 23205: debug : virNetMessageFree:73 : msg=0xb6d01df0 nfds=0 cb=(nil) 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 1 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:07.418+0000: 23205: debug : doRemoteOpen:817 : Auto-probed URI is qemu:///session 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.418+0000: 23205: debug : do_open:1197 : driver 4 remote returned SUCCESS 2013-02-14 03:32:07.418+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.418+0000: 23205: debug : do_open:1221 : network driver 0 Test returned DECLINED 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.418+0000: 23205: debug : do_open:1221 : network driver 1 VBOX returned DECLINED 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.418+0000: 23205: debug : do_open:1221 : network driver 2 remote returned SUCCESS 2013-02-14 03:32:07.418+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:07.421+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=1 d=0 2013-02-14 03:32:07.421+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:07.421+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1237 : interface driver 0 Test returned DECLINED 2013-02-14 03:32:07.421+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=2 timeout=-1 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1237 : interface driver 1 remote returned SUCCESS 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1254 : storage driver 0 Test returned DECLINED 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1254 : storage driver 1 VBOX returned DECLINED 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1254 : storage driver 2 remote returned SUCCESS 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1271 : node driver 0 Test returned DECLINED 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1271 : node driver 1 remote returned SUCCESS 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1288 : secret driver 0 Test returned DECLINED 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1288 : secret driver 1 remote returned SUCCESS 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1305 : nwfilter driver 0 Test returned DECLINED 2013-02-14 03:32:07.421+0000: 23205: debug : do_open:1305 : nwfilter driver 1 remote returned SUCCESS 2013-02-14 03:32:07.421+0000: 23205: debug : virConnectRegisterCloseCallback:19823 : conn=0x8d186b0 2013-02-14 03:32:07.421+0000: 23205: debug : virConnectIsAlive:19771 : conn=0x8d186b0 2013-02-14 03:32:07.421+0000: 23205: debug : virFileClose:72 : Closed fd 9 2013-02-14 03:32:07.421+0000: 23205: debug : virDomainCreateXML:1962 : conn=0x8d186b0, xmlDesc=<domain type='qemu'> <name>testvm</name> <memory>1048576</memory> <os> <type arch='x86_64'>hvm</type> </os> <devices> <disk type='network'> <source protocol="hlfs" name="hdfs:///tmp/testenv/testfs"/> <target dev='hda' bus='ide'/> </disk> <graphics type='vnc' port='-1' autoport='yes'/> </devices> </domain> , flags=0 2013-02-14 03:32:07.421+0000: 23205: debug : virNetMessageNew:45 : msg=0xb6d03de0 tracked=0 2013-02-14 03:32:07.422+0000: 23205: debug : virNetMessageEncodePayload:358 : Encode length as 344 2013-02-14 03:32:07.422+0000: 23205: debug : virNetClientSendInternal:1955 : RPC_CLIENT_MSG_TX_QUEUE: client=0xb6d01cd8 len=344 prog=536903814 vers=1 proc=10 type=0 status=0 serial=4 2013-02-14 03:32:07.422+0000: 23205: debug : virNetClientCallNew:1908 : New call 0xb6d03e28: msg=0xb6d03de0, expectReply=1, nonBlock=0 2013-02-14 03:32:07.422+0000: 23205: debug : virNetClientIO:1718 : Outgoing message prog=536903814 version=1 serial=4 proc=10 type=0 length=344 dispatch=(nil) 2013-02-14 03:32:07.422+0000: 23205: debug : virNetClientIO:1777 : We have the buck head=0xb6d03e28 call=0xb6d03e28 2013-02-14 03:32:07.422+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0 2013-02-14 03:32:07.422+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 2 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.422+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=0 d=0 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:07.422+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2013-02-14 03:32:07.692+0000: 23205: debug : virNetMessageDecodeLength:152 : Got length, now need 2168 total (2164 more) 2013-02-14 03:32:07.692+0000: 23205: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0xb6d01cd8 len=2168 prog=536903814 vers=1 proc=10 type=1 status=1 serial=4 2013-02-14 03:32:07.692+0000: 23205: debug : virKeepAliveCheckMessage:384 : ka=0xb6d00480, client=0xb6d01cd8, msg=0xb6d01d14 2013-02-14 03:32:07.692+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1424 : Giving up the buck 0xb6d03e28 2013-02-14 03:32:07.692+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1438 : No thread to pass the buck to 2013-02-14 03:32:07.692+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1 2013-02-14 03:32:07.692+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.692+0000: 23205: debug : virNetClientIO:1807 : All done with our call head=(nil) call=0xb6d03e28 rv=0 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 1 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:07.692+0000: 23205: debug : virNetMessageFree:73 : msg=0xb6d03de0 nfds=0 cb=(nil) 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 Error：2013-02-14 03:32:07.692+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 Create domain failure from hlfs_hdfs.xml Error：2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 internal error process exited while connecting to monitor: ** Message: enter func bdrv_hlbs_init ** Message: leave func bdrv_hlbs_init enter func bdrv_new leave func bdrv_new 999 enter func bdrv_open 999$$ filename is hlfs:hdfs:///tmp/testenv/testfs 999 enter func find_image_format enter func bdrv_new leave func bdrv_new ** Message: enter func hlbs_open ** Message: 999 filename is hlfs:hdfs:///tmp/testenv/testfs ** Message: 999 filename is hdfs:///tmp/testenv/testfs ** Message: enter func parse_vdiname ** Message: 999 filename is hdfs:///tmp/testenv/testfs ** Message: leave func parse_vdiname enter func init_storage_handler loc [fs:testfs], uri:hdfs:///tmp/testenv/testfs,head:hdfs,dir:/tmp/testenv,fsname:testfs,hostname:default,port:0,user:kanghua Environment variable CLASSPATH not set! fs is null, hdfsConnect error! ret is not 0, so error happened leave func init_storage_handler [uri:hdfs:///tmp/testenv/testfs] can not accessable init raw hlfs ctrl failed enter func hlfs_open error params :flag 1 ** ERROR:block/hlfs.c: 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=1 d=0 2013-02-14 03:32:07.692+0000: 23205: debug : virConnectClose:1474 : conn=0x8d186b0 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:07.692+0000: 23205: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0x8d186b0 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:07.692+0000: 23205: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0x8d186b0 2013-02-14 03:32:07.692+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=2 timeout=-1 2013-02-14 03:32:07.692+0000: 23205: debug : virNetMessageNew:45 : msg=0xb6d046e8 tracked=0 2013-02-14 03:32:07.693+0000: 23205: debug : virNetMessageEncodePayload:358 : Encode length as 28 2013-02-14 03:32:07.693+0000: 23205: debug : virNetClientSendInternal:1955 : RPC_CLIENT_MSG_TX_QUEUE: client=0xb6d01cd8 len=28 prog=536903814 vers=1 proc=2 type=0 status=0 serial=5 2013-02-14 03:32:07.693+0000: 23205: debug : virNetClientCallNew:1908 : New call 0xb6d04660: msg=0xb6d046e8, expectReply=1, nonBlock=0 2013-02-14 03:32:07.693+0000: 23205: debug : virNetClientIO:1718 : Outgoing message prog=536903814 version=1 serial=5 proc=2 type=0 length=28 dispatch=(nil) 2013-02-14 03:32:07.693+0000: 23205: debug : virNetClientIO:1777 : We have the buck head=0xb6d04660 call=0xb6d04660 2013-02-14 03:32:07.693+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=0 2013-02-14 03:32:07.693+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.693+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:07.693+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 0 2013-02-14 03:32:07.693+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 2 2013-02-14 03:32:07.693+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:07.693+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:07.693+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.693+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.693+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.696+0000: 23220: debug : virEventRunDefaultImpl:244 : running default event implementation 2013-02-14 03:32:07.696+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 0 2013-02-14 03:32:07.696+0000: 23220: debug : virEventPollCleanupTimeouts:552 : Found 0 out of 0 timeout slots used, releasing 0 2013-02-14 03:32:07.696+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.696+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=0 w=1, f=4 e=1 d=0 2013-02-14 03:32:07.696+0000: 23220: debug : virEventPollMakePollFDs:393 : Prepare n=1 w=2, f=6 e=0 d=0 2013-02-14 03:32:07.696+0000: 23220: debug : virEventPollCalculateTimeout:332 : Calculate expiry of 0 timers 2013-02-14 03:32:07.696+0000: 23220: debug : virEventPollCalculateTimeout:361 : Timeout at 0 due in -1 ms 2013-02-14 03:32:07.696+0000: 23220: debug : virEventPollRunOnce:629 : EVENT_POLL_RUN: nhandles=1 timeout=-1 2013-02-14 03:32:07.696+0000: 23205: debug : virNetMessageDecodeLength:152 : Got length, now need 28 total (24 more) 2013-02-14 03:32:07.696+0000: 23205: debug : virNetClientCallDispatch:1127 : RPC_CLIENT_MSG_RX: client=0xb6d01cd8 len=28 prog=536903814 vers=1 proc=2 type=1 status=0 serial=5 2013-02-14 03:32:07.696+0000: 23205: debug : virKeepAliveCheckMessage:384 : ka=0xb6d00480, client=0xb6d01cd8, msg=0xb6d01d14 2013-02-14 03:32:07.696+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1424 : Giving up the buck 0xb6d04660 2013-02-14 03:32:07.696+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1438 : No thread to pass the buck to 2013-02-14 03:32:07.696+0000: 23205: debug : virEventPollUpdateHandle:147 : EVENT_POLL_UPDATE_HANDLE: watch=2 events=1 2013-02-14 03:32:07.696+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.696+0000: 23205: debug : virNetClientIO:1807 : All done with our call head=(nil) call=0xb6d04660 rv=0 2013-02-14 03:32:07.696+0000: 23205: debug : virNetMessageFree:73 : msg=0xb6d046e8 nfds=0 cb=(nil) 2013-02-14 03:32:07.696+0000: 23205: debug : virNetClientCloseInternal:698 : client=0xb6d01cd8 wantclose=0 2013-02-14 03:32:07.696+0000: 23205: debug : virNetClientMarkClose:646 : client=0xb6d01cd8, reason=3 2013-02-14 03:32:07.696+0000: 23205: debug : virEventPollRemoveHandle:180 : EVENT_POLL_REMOVE_HANDLE: watch=2 2013-02-14 03:32:07.696+0000: 23205: debug : virEventPollRemoveHandle:193 : mark delete 1 6 2013-02-14 03:32:07.696+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.696+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1424 : Giving up the buck (nil) 2013-02-14 03:32:07.696+0000: 23205: debug : virNetClientIOEventLoopPassTheBuck:1438 : No thread to pass the buck to 2013-02-14 03:32:07.696+0000: 23205: debug : virNetClientCloseLocked:659 : client=0xb6d01cd8, sock=0xb6d005e0, reason=3 2013-02-14 03:32:07.696+0000: 23205: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d005e0 2013-02-14 03:32:07.696+0000: 23205: debug : virObjectRef:168 : OBJECT_REF: obj=0xb6d01cd8 2013-02-14 03:32:07.696+0000: 23205: debug : virKeepAliveStop:320 : RPC_KEEPALIVE_STOP: ka=0xb6d00480 client=0xb6d01cd8 2013-02-14 03:32:07.696+0000: 23205: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d00480 2013-02-14 03:32:07.696+0000: 23205: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0xb6d00480 2013-02-14 03:32:07.696+0000: 23205: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d01cd8 2013-02-14 03:32:07.696+0000: 23205: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d01cd8 2013-02-14 03:32:07.696+0000: 23205: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d01cd8 2013-02-14 03:32:07.696+0000: 23205: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d00568 2013-02-14 03:32:07.696+0000: 23205: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d00590 2013-02-14 03:32:07.697+0000: 23205: debug : virEventPollAddTimeout:225 : Used 0 timeout slots, adding at least 10 more 2013-02-14 03:32:07.697+0000: 23205: debug : virEventPollInterruptLocked:716 : Interrupting 2013-02-14 03:32:07.697+0000: 23205: debug : virEventPollAddTimeout:248 : EVENT_POLL_ADD_TIMEOUT: timer=1 frequency=0 cb=0x8055ee3 opaque=(nil) ff=(nil) 2013-02-14 03:32:07.697+0000: 23220: debug : virEventPollRunOnce:640 : Poll got 1 event(s) 2013-02-14 03:32:07.697+0000: 23220: debug : virEventPollDispatchTimeouts:425 : Dispatch 1 2013-02-14 03:32:07.697+0000: 23220: debug : virEventPollDispatchTimeouts:448 : EVENT_POLL_DISPATCH_TIMEOUT: timer=1 2013-02-14 03:32:07.697+0000: 23220: debug : virEventPollDispatchHandles:470 : Dispatch 1 2013-02-14 03:32:07.697+0000: 23220: debug : virEventPollDispatchHandles:484 : i=0 w=1 2013-02-14 03:32:07.697+0000: 23220: debug : virEventPollDispatchHandles:498 : EVENT_POLL_DISPATCH_HANDLE: watch=1 events=1 2013-02-14 03:32:07.697+0000: 23220: debug : virEventPollCleanupTimeouts:516 : Cleanup 1 2013-02-14 03:32:07.697+0000: 23220: debug : virEventPollCleanupHandles:564 : Cleanup 2 2013-02-14 03:32:07.697+0000: 23220: debug : virEventPollCleanupHandles:577 : EVENT_POLL_PURGE_HANDLE: watch=2 2013-02-14 03:32:07.697+0000: 23220: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d01cd8 2013-02-14 03:32:07.697+0000: 23220: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0xb6d01cd8 2013-02-14 03:32:07.697+0000: 23220: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d00568 2013-02-14 03:32:07.697+0000: 23220: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0xb6d00568 2013-02-14 03:32:07.697+0000: 23220: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d00590 2013-02-14 03:32:07.697+0000: 23220: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0xb6d00590 2013-02-14 03:32:07.697+0000: 23220: debug : virFileClose:72 : Closed fd 8 2013-02-14 03:32:07.697+0000: 23220: debug : virFileClose:72 : Closed fd 7 2013-02-14 03:32:07.697+0000: 23220: debug : virNetMessageClear:56 : msg=0xb6d01d14 nfds=0 2013-02-14 03:32:07.697+0000: 23220: debug : virObjectUnref:135 : OBJECT_UNREF: obj=0xb6d005e0 2013-02-14 03:32:07.697+0000: 23220: debug : virObjectUnref:137 : OBJECT_DISPOSE: obj=0xb6d005e0 2013-02-14 03:32:07.697+0000: 23220: debug : virNetSocketDispose:1005 : sock=0xb6d005e0 fd=6 2013-02-14 03:32:07.697+0000: 23220: debug : virEventPollRemoveHandle:180 : EVENT_POLL_REMOVE_HANDLE: watch=2 2013-02-14 03:32:07.697+0000: 23220: debug : virFileClose:72 : Closed fd 6 2013-02-14 03:32:07.697+0000: 23205: debug : virEventPollRemoveTimeout:300 : EVENT_POLL_REMOVE_TIMEOUT: timer=1 2013-02-14 03:32:07.697+0000: 23205: debug : virEventPollInterruptLocked:712 : Skip interrupt, 0 -1218303120 -- Thanks Harry Wei