[one-users] Create VM Fail: error: disk I/O error

張德勤 cinmex91047 at gmail.com
Sun Mar 11 05:07:48 PDT 2012


Dear all:

Sorry to trouble to everyone again.
I have some ERROR in my oned.log file.
I tried to create a VM on my ONE + CentOS +XEN system.
But the VM log shows Error copying
server:/srv/cloud/one/cinmex1/cinmex1.img to
client1:/srv/cloud/one/var/22/images/disk.0
So I check the oned.log file.
It shows error: disk I/O error as following.
Sun Mar 11 18:58:50 2012 [ONE][E]: SQL command was: REPLACE INTO vm_pool
(oid, name, body, uid, gid, last_poll, state, lcm_state) VALUES
(22,'test3','<VM><ID>22</ID><UID>0</UID><GID>0</GID><UNAME>oneadmin</UNAME><GNAME>oneadmin</GNAME><NAME>test3</NAME><LAST_POLL>0</LAST_POLL><STATE>3</STATE><LCM_STATE>1</LCM_STATE><STIME>1331463452</STIME><ETIME>0</ETIME><DEPLOY_ID></DEPLOY_ID><MEMORY>0</MEMORY><CPU>0</CPU><NET_TX>0</NET_TX><NET_RX>0</NET_RX><TEMPLATE><CPU><![CDATA[0.5]]></CPU><DISK><DISK_ID><![CDATA[0]]></DISK_ID><READONLY><![CDATA[no]]></READONLY><SOURCE><![CDATA[/srv/cloud/one/cinmex1/cinmex1.img]]></SOURCE><TARGET><![CDATA[hda]]></TARGET></DISK><ERROR><MESSAGE><![CDATA[Error
excuting image transfer script: Error copying
server:/srv/cloud/one/cinmex1/cinmex1.img to
client1:/srv/cloud/one/var/22/images/disk.0]]></MESSAGE><TIMESTAMP><![CDATA[Sun
Mar 11 18:58:47
2012]]></TIMESTAMP></ERROR><MEMORY><![CDATA[512]]></MEMORY><NAME><![CDATA[test3]]></NAME><OS><INITRD><![CDATA[/boot//initramfs-2.6.32-220.el6.x86_64.img]]></INITRD><KERNEL><![CDATA[/boot/vmlinuz-2.6.32-220.el6.x86_64]]></KERNEL><KERNEL_CMD><![CDATA[ro
xencons=tty
console=tty1]]></KERNEL_CMD><ROOT><![CDATA[sda1]]></ROOT></OS><RAW><TYPE><![CDATA[xen]]></TYPE></RAW><TEMPLATE_ID><![CDATA[2]]></TEMPLATE_ID><VCPU><![CDATA[1]]></VCPU><VMID><![CDATA[22]]></VMID></TEMPLATE><HISTORY_RECORDS><HISTORY><SEQ>0</SEQ><HOSTNAME>client1</HOSTNAME><VM_DIR>/srv/cloud/one/var</VM_DIR><HID>5</HID><STIME>1331463461</STIME><ETIME>0</ETIME><VMMMAD>vmm_xen</VMMMAD><TMMAD>tm_shared</TMMAD><PSTIME>1331463461</PSTIME><PETIME>0</PETIME><RSTIME>0</RSTIME><RETIME>0</RETIME><ESTIME>0</ESTIME><EETIME>0</EETIME><REASON>0</REASON></HISTORY></HISTORY_RECORDS></VM>',0,0,0,3,1),
error: disk I/O error
The following are oned.log file and VM.log file.

-------------------------------------------oned.log-------------------------------------------

Sun Mar 11 18:57:11 2012 [ONE][I]: Init OpenNebula Log system

Sun Mar 11 18:57:11 2012 [ONE][I]: Log Level: 3
[0=ERROR,1=WARNING,2=INFO,3=DEBUG]

Sun Mar 11 18:57:11 2012 [ONE][I]: ----------------------------------------

Sun Mar 11 18:57:11 2012 [ONE][I]:      OpenNebula Configuration File

Sun Mar 11 18:57:11 2012 [ONE][I]: ----------------------------------------

Sun Mar 11 18:57:11 2012 [ONE][I]:

----------------------------------

AUTH_MAD=ARGUMENTS=--authz quota --authn
plain,ssh,x509,EXECUTABLE=one_auth_mad

DB=BACKEND=sqlite

DEBUG_LEVEL=3

DEFAULT_DEVICE_PREFIX=hd

DEFAULT_IMAGE_TYPE=OS

HM_MAD=EXECUTABLE=one_hm

HOST_MONITORING_INTERVAL=50

HOST_PER_INTERVAL=15

IMAGE_MAD=ARGUMENTS=fs -t 15,EXECUTABLE=one_image

IM_MAD=ARGUMENTS=xen,EXECUTABLE=one_im_ssh,NAME=im_xen

MAC_PREFIX=02:00

MANAGER_TIMER=15

NETWORK_SIZE=254

PORT=2633

SCRIPTS_REMOTE_DIR=/var/tmp/one

TM_MAD=ARGUMENTS=tm_shared/tm_shared.conf,EXECUTABLE=one_tm,NAME=tm_shared

VM_DIR=/srv/cloud/one/var

VM_MAD=ARGUMENTS=-t 15 -r 0
xen,DEFAULT=vmm_exec/vmm_exec_xen.conf,EXECUTABLE=one_vmm_exec,NAME=vmm_xen,TYPE=xen

VM_PER_INTERVAL=5

VM_POLLING_INTERVAL=10

VNC_BASE_PORT=5900

----------------------------------

Sun Mar 11 18:57:11 2012 [ONE][I]: Checking database version.

Sun Mar 11 18:57:11 2012 [VMM][I]: Starting Virtual Machine Manager...

Sun Mar 11 18:57:11 2012 [LCM][I]: Starting Life-cycle Manager...

Sun Mar 11 18:57:11 2012 [VMM][I]: Virtual Machine Manager started.

Sun Mar 11 18:57:11 2012 [InM][I]: Starting Information Manager...

Sun Mar 11 18:57:11 2012 [LCM][I]: Life-cycle Manager started.

Sun Mar 11 18:57:11 2012 [InM][I]: Information Manager started.

Sun Mar 11 18:57:11 2012 [TrM][I]: Starting Transfer Manager...

Sun Mar 11 18:57:11 2012 [DiM][I]: Starting Dispatch Manager...

Sun Mar 11 18:57:11 2012 [TrM][I]: Transfer Manager started.

Sun Mar 11 18:57:11 2012 [DiM][I]: Dispatch Manager started.

Sun Mar 11 18:57:11 2012 [HKM][I]: Starting Hook Manager...

Sun Mar 11 18:57:11 2012 [HKM][I]: Hook Manager started.

Sun Mar 11 18:57:11 2012 [AuM][I]: Starting Auth Manager...

Sun Mar 11 18:57:11 2012 [AuM][I]: Authorization Manager started.

Sun Mar 11 18:57:11 2012 [ImM][I]: Starting Image Manager...

Sun Mar 11 18:57:11 2012 [ImM][I]: Image Manager started.

Sun Mar 11 18:57:11 2012 [ReM][I]: Starting Request Manager...

Sun Mar 11 18:57:11 2012 [ReM][I]: Starting XML-RPC server, port 2633 ...

Sun Mar 11 18:57:11 2012 [ReM][I]: Request Manager started.

Sun Mar 11 18:57:13 2012 [VMM][I]: Loading Virtual Machine Manager drivers.

Sun Mar 11 18:57:13 2012 [VMM][I]:      Loading driver: vmm_xen (XEN)

Sun Mar 11 18:57:13 2012 [VMM][I]:      Driver vmm_xen loaded.

Sun Mar 11 18:57:13 2012 [InM][I]: Loading Information Manager drivers.

Sun Mar 11 18:57:13 2012 [InM][I]:      Loading driver: im_xen

Sun Mar 11 18:57:13 2012 [InM][I]:      Driver im_xen loaded

Sun Mar 11 18:57:13 2012 [TM][I]: Loading Transfer Manager drivers.

Sun Mar 11 18:57:13 2012 [VMM][I]:      Loading driver: tm_shared

Sun Mar 11 18:57:13 2012 [TM][I]:       Driver tm_shared loaded.

Sun Mar 11 18:57:13 2012 [HKM][I]: Loading Hook Manager driver.

Sun Mar 11 18:57:13 2012 [HKM][I]:      Hook Manager loaded

Sun Mar 11 18:57:13 2012 [ImM][I]: Loading Image Manager driver.

Sun Mar 11 18:57:13 2012 [ImM][I]:      Image Manager loaded

Sun Mar 11 18:57:13 2012 [AuM][I]: Loading Auth. Manager driver.

Sun Mar 11 18:57:13 2012 [AuM][I]:      Auth Manager loaded

Sun Mar 11 18:57:15 2012 [ReM][D]: VirtualNetworkPoolInfo method invoked

Sun Mar 11 18:57:15 2012 [AuM][D]: Message received: LOG I 0 ExitCode: 0


Sun Mar 11 18:58:45 2012 [ReM][D]: TemplatePoolInfo method invoked

Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG I 22 Command
execution fail: /srv/cloud/one/lib/tm_commands/shared/tm_clone.sh
server:/srv/cloud/one/cinmex1/cinmex1.img
client1:/srv/cloud/one/var/22/images/disk.0


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG D 22 tm_clone.sh:
server:/srv/cloud/one/cinmex1/cinmex1.img
client1:/srv/cloud/one/var/22/images/disk.0


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG D 22 tm_clone.sh:
DST: /srv/cloud/one/var/22/images/disk.0


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG I 22 tm_clone.sh:
Creating directory /srv/cloud/one/var/22/images


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG I 22 tm_clone.sh:
Executed "mkdir -p /srv/cloud/one/var/22/images".


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG I 22 tm_clone.sh:
Executed "chmod a+w /srv/cloud/one/var/22/images".


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG I 22 tm_clone.sh:
Cloning /srv/cloud/one/cinmex1/cinmex1.img


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG E 22 tm_clone.sh:
Command "cp -r /srv/cloud/one/cinmex1/cinmex1.img
/srv/cloud/one/var/22/images/disk.0" failed.


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG E 22 tm_clone.sh:
cp: writing `/srv/cloud/one/var/22/images/disk.0': No space left on device


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG E 22 Error copying
server:/srv/cloud/one/cinmex1/cinmex1.img to
client1:/srv/cloud/one/var/22/images/disk.0


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: LOG I 22 ExitCode: 1


Sun Mar 11 18:58:47 2012 [TM][D]: Message received: TRANSFER FAILURE 22
Error copying server:/srv/cloud/one/cinmex1/cinmex1.img to
client1:/srv/cloud/one/var/22/images/disk.0


Sun Mar 11 18:58:47 2012 [AuM][D]: Message received: LOG I 22 ExitCode: 0


Sun Mar 11 18:58:47 2012 [AuM][I]: ExitCode: 0

Sun Mar 11 18:58:47 2012 [AuM][D]: Message received: AUTHENTICATE SUCCESS
22 -


Sun Mar 11 18:58:47 2012 [InM][I]: Monitoring host client1 (5)

Sun Mar 11 18:58:47 2012 [VMM][I]: Monitoring VM 12.

Sun Mar 11 18:58:49 2012 [ReM][D]: UserPoolInfo method invoked

Sun Mar 11 18:58:49 2012 [AuM][D]: Message received: LOG I 23 ExitCode: 0


Sun Mar 11 18:58:49 2012 [AuM][I]: ExitCode: 0

Sun Mar 11 18:58:49 2012 [AuM][D]: Message received: AUTHENTICATE SUCCESS
23 -


Sun Mar 11 18:58:50 2012 [ONE][E]: SQL command was: REPLACE INTO vm_pool
(oid, name, body, uid, gid, last_poll, state, lcm_state) VALUES
(22,'test3','<VM><ID>22</ID><UID>0</UID><GID>0</GID><UNAME>oneadmin</UNAME><GNAME>oneadmin</GNAME><NAME>test3</NAME><LAST_POLL>0</LAST_POLL><STATE>3</STATE><LCM_STATE>1</LCM_STATE><STIME>1331463452</STIME><ETIME>0</ETIME><DEPLOY_ID></DEPLOY_ID><MEMORY>0</MEMORY><CPU>0</CPU><NET_TX>0</NET_TX><NET_RX>0</NET_RX><TEMPLATE><CPU><![CDATA[0.5]]></CPU><DISK><DISK_ID><![CDATA[0]]></DISK_ID><READONLY><![CDATA[no]]></READONLY><SOURCE><![CDATA[/srv/cloud/one/cinmex1/cinmex1.img]]></SOURCE><TARGET><![CDATA[hda]]></TARGET></DISK><ERROR><MESSAGE><![CDATA[Error
excuting image transfer script: Error copying
server:/srv/cloud/one/cinmex1/cinmex1.img to
client1:/srv/cloud/one/var/22/images/disk.0]]></MESSAGE><TIMESTAMP><![CDATA[Sun
Mar 11 18:58:47
2012]]></TIMESTAMP></ERROR><MEMORY><![CDATA[512]]></MEMORY><NAME><![CDATA[test3]]></NAME><OS><INITRD><![CDATA[/boot//initramfs-2.6.32-220.el6.x86_64.img]]></INITRD><KERNEL><![CDATA[/boot/vmlinuz-2.6.32-220.el6.x86_64]]></KERNEL><KERNEL_CMD><![CDATA[ro
xencons=tty
console=tty1]]></KERNEL_CMD><ROOT><![CDATA[sda1]]></ROOT></OS><RAW><TYPE><![CDATA[xen]]></TYPE></RAW><TEMPLATE_ID><![CDATA[2]]></TEMPLATE_ID><VCPU><![CDATA[1]]></VCPU><VMID><![CDATA[22]]></VMID></TEMPLATE><HISTORY_RECORDS><HISTORY><SEQ>0</SEQ><HOSTNAME>client1</HOSTNAME><VM_DIR>/srv/cloud/one/var</VM_DIR><HID>5</HID><STIME>1331463461</STIME><ETIME>0</ETIME><VMMMAD>vmm_xen</VMMMAD><TMMAD>tm_shared</TMMAD><PSTIME>1331463461</PSTIME><PETIME>0</PETIME><RSTIME>0</RSTIME><RETIME>0</RETIME><ESTIME>0</ESTIME><EETIME>0</EETIME><REASON>0</REASON></HISTORY></HISTORY_RECORDS></VM>',0,0,0,3,1),
error: disk I/O error

Sun Mar 11 18:58:51 2012 [VMM][D]: Message received: LOG I 12 ExitCode: 0


Sun Mar 11 18:58:51 2012 [InM][I]: ExitCode: 0

Sun Mar 11 18:58:52 2012 [ONE][E]: SQL command was: REPLACE INTO host_pool
(oid, name, body, state, last_mon_time) VALUES
(5,'client1','<HOST><ID>5</ID><NAME>client1</NAME><STATE>1</STATE><IM_MAD>im_xen</IM_MAD><VM_MAD>vmm_xen</VM_MAD><TM_MAD>tm_shared</TM_MAD><LAST_MON_TIME>1331463449</LAST_MON_TIME><HOST_SHARE><DISK_USAGE>0</DISK_USAGE><MEM_USAGE>1048576</MEM_USAGE><CPU_USAGE>100</CPU_USAGE><MAX_DISK>0</MAX_DISK><MAX_MEM>4023296</MAX_MEM><MAX_CPU>400</MAX_CPU><FREE_DISK>0</FREE_DISK><FREE_MEM>2914304</FREE_MEM><FREE_CPU>399</FREE_CPU><USED_DISK>0</USED_DISK><USED_MEM>1108992</USED_MEM><USED_CPU>1</USED_CPU><RUNNING_VMS>2</RUNNING_VMS></HOST_SHARE><TEMPLATE><ARCH><![CDATA[x86_64]]></ARCH><CPUSPEED><![CDATA[2826]]></CPUSPEED><FREECPU><![CDATA[399]]></FREECPU><FREEMEMORY><![CDATA[2914304]]></FREEMEMORY><HOSTNAME><![CDATA[client1]]></HOSTNAME><HYPERVISOR><![CDATA[xen]]></HYPERVISOR><MODELNAME><![CDATA[Intel(R)
Core(TM)2 Quad CPU Q9550 @
2.83GHz]]></MODELNAME><NETRX><![CDATA[0]]></NETRX><NETTX><![CDATA[0]]></NETTX><TOTALCPU><![CDATA[400]]></TOTALCPU><TOTALMEMORY><![CDATA[4023296]]></TOTALMEMORY><USEDCPU><![CDATA[1]]></USEDCPU><USEDMEMORY><![CDATA[1108992]]></USEDMEMORY></TEMPLATE></HOST>',1,1331463449),
error: disk I/O error

Sun Mar 11 18:58:52 2012 [InM][D]: Host 5 successfully monitored.

Sun Mar 11 18:58:55 2012 [ONE][E]: SQL command was: REPLACE INTO vm_pool
(oid, name, body, uid, gid, last_poll, state, lcm_state) VALUES
(12,'test','<VM><ID>12</ID><UID>0</UID><GID>0</GID><UNAME>oneadmin</UNAME><GNAME>oneadmin</GNAME><NAME>test</NAME><LAST_POLL>1331463509</LAST_POLL><STATE>3</STATE><LCM_STATE>16</LCM_STATE><STIME>1331388168</STIME><ETIME>0</ETIME><DEPLOY_ID>one-12</DEPLOY_ID><MEMORY>524288</MEMORY><CPU>3</CPU><NET_TX>0</NET_TX><NET_RX>0</NET_RX><TEMPLATE><CPU><![CDATA[0.5]]></CPU><MEMORY><![CDATA[512]]></MEMORY><NAME><![CDATA[one-12]]></NAME><OS><INITRD><![CDATA[/boot//initramfs-2.6.32-220.el6.x86_64.img]]></INITRD><KERNEL><![CDATA[/boot/vmlinuz-2.6.32-220.eSun
Mar 11 18:59:19 2012 [ReM][D]: VirtualMachinePoolInfo method invoked

Sun Mar 11 18:59:19 2012 [AuM][D]: Message received: LOG I 27 ExitCode: 0

-----------------------------------END-------------------------------
================VM.log===============
Sun Mar 11 18:57:41 2012 [DiM][I]: New VM state is ACTIVE.
Sun Mar 11 18:57:41 2012 [LCM][I]: New VM state is PROLOG.
Sun Mar 11 18:57:41 2012 [VM][I]: Virtual Machine has no context
Sun Mar 11 18:58:47 2012 [TM][I]: Command execution fail:
/srv/cloud/one/lib/tm_commands/shared/tm_clone.sh
server:/srv/cloud/one/cinmex1/cinmex1.img
client1:/srv/cloud/one/var/22/images/disk.0
Sun Mar 11 18:58:47 2012 [TM][D]: tm_clone.sh:
server:/srv/cloud/one/cinmex1/cinmex1.img
client1:/srv/cloud/one/var/22/images/disk.0
Sun Mar 11 18:58:47 2012 [TM][D]: tm_clone.sh: DST:
/srv/cloud/one/var/22/images/disk.0
Sun Mar 11 18:58:47 2012 [TM][I]: tm_clone.sh: Creating directory
/srv/cloud/one/var/22/images
Sun Mar 11 18:58:47 2012 [TM][I]: tm_clone.sh: Executed "mkdir -p
/srv/cloud/one/var/22/images".
Sun Mar 11 18:58:47 2012 [TM][I]: tm_clone.sh: Executed "chmod a+w
/srv/cloud/one/var/22/images".
Sun Mar 11 18:58:47 2012 [TM][I]: tm_clone.sh: Cloning
/srv/cloud/one/cinmex1/cinmex1.img
Sun Mar 11 18:58:47 2012 [TM][E]: tm_clone.sh: Command "cp -r
/srv/cloud/one/cinmex1/cinmex1.img /srv/cloud/one/var/22/images/disk.0"
failed.
Sun Mar 11 18:58:47 2012 [TM][E]: tm_clone.sh: cp: writing
`/srv/cloud/one/var/22/images/disk.0': No space left on device
Sun Mar 11 18:58:47 2012 [TM][E]: Error copying
server:/srv/cloud/one/cinmex1/cinmex1.img to
client1:/srv/cloud/one/var/22/images/disk.0
Sun Mar 11 18:58:47 2012 [TM][I]: ExitCode: 1
Sun Mar 11 18:58:50 2012 [TM][E]: Error excuting image transfer script:
Error copying server:/srv/cloud/one/cinmex1/cinmex1.img to
client1:/srv/cloud/one/var/22/images/disk.0
Sun Mar 11 18:59:12 2012 [DiM][I]: New VM state is FAILED
==================END=================



What detail should I attend??
Please help.



-- 
Regards,

Te - Chin, Chang (張德勤), +886-3-4227151 #57968
Networklab, Computer Science & Information Engineering,
National Central University, Jhongli, Taiwan, R.O.C
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opennebula.org/pipermail/users-opennebula.org/attachments/20120311/c73d5a71/attachment-0002.htm>


More information about the Users mailing list