Hi, I was trying to create a new image and now it gives me an error. Any clues ? I have lot of space in both:
~ # df -h Filesystem Size Used Available Use% Mounted on NFS 150.0G 133.7G 16.3G 89% /vmfs/volumes/nas:isos NFS 3.1T 2.3T 749.5G 76% /vmfs/volumes/nas:vm-backups NFS 983.2G 211.6G 771.6G 22% /vmfs/volumes/vcl_images VMFS-5 4.3T 2.3T 2.0T 54% /vmfs/volumes/datastore1 vfat 4.0G 25.9M 4.0G 1% /vmfs/volumes/52d422c0-c505318e-9038-0025905aa03c vfat 249.7M 157.0M 92.7M 63% /vmfs/volumes/fd17657e-443d0989-0ad6-8fe725643b5d vfat 249.7M 8.0K 249.7M 0% /vmfs/volumes/2d1a7278-096eb83e-bf00-f727d3ce63da vfat 285.8M 191.3M 94.6M 67% /vmfs/volumes/52d42299-a598680f-7d85-0025905aa03c It complains about cloning. Thanks. ---------- Forwarded message ---------- From: <[email protected]> Date: 2015-09-23 15:10 GMT+01:00 Subject: PROBLEM -- vclnode1|263:263|image|image.pm|vm18> servidor12.di.uminho.pt|vmwarewin7-WIN7_20150923_VMWARE_0000191-v0|admin To: [email protected] vmwarewin7-WIN7_20150923_VMWARE_0000191-v0 image creation failed ------------------------------------------------------------------------ time: 2015-09-23 15:09:50 caller: image.pm:reservation_failed(387) ( 0) image.pm, reservation_failed (line: 387) (-1) image.pm, process (line: 167) (-2) vcld, make_new_child (line: 571) (-3) vcld, main (line: 350) ------------------------------------------------------------------------ management node: vclnode1.apachevcl.di.uminho.pt reservation PID: 22474 parent vcld PID: 1826 request ID: 263 reservation ID: 263 request state/laststate: image/reserved request start time: 2015-09-23 13:15:00 request end time: 2015-09-23 21:30:00 for imaging: yes log ID: 227 computer: vm18.apachevcl.di.uminho.pt computer id: 22 computer type: virtualmachine computer eth0 MAC address: 00:50:56:00:00:22 computer eth1 MAC address: 00:50:56:00:00:23 computer private IP address: 10.100.0.118 computer public IP address: 192.168.93.118 computer in block allocation: no provisioning module: VCL::Module::Provisioning::VMware::VMware vm host: servidor12.di.uminho.pt vm host ID: 1 vm host computer ID: 1 vm profile: vmhostprofile1 vm profile VM path: /vmfs/volumes/datastore1/ vm profile repository path: /vmfs/volumes/vcl_images/ vm profile datastore path: /vmfs/volumes/datastore1/ vm profile disk type: shared image: vmwarewin7-WIN7_20150923_VMWARE_0000191-v0 image display name: WIN7_20150923_VMWARE_00001 image ID: 91 image revision ID: 88 image size: 1450 MB use Sysprep: no root access: yes image owner ID: 1 image owner affiliation: Local image revision date created: 2015-09-23 13:33:27 image revision production: yes OS module: VCL::Module::OS::Windows::Version_6::7 user: admin user name: vcl admin user ID: 1 user affiliation: Local ------------------------------------------------------------------------ RECENT LOG ENTRIES FOR THIS PROCESS: |22474|263:263|image| returning (1, "stat: can't stat '/vmfs/volume...") 2015-09-23 15:09:07|22474|263:263|image|utils.pm:run_ssh_command(4902)|executing SSH command on servidor12: |22474|263:263|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x servidor12 'ls -d --color=never "/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0" 2>&1 || mkdir -p "/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0" 2>&1 && ls -d --color=never "/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0"' 2>&1 2015-09-23 15:09:07|22474|263:263|image|utils.pm:run_ssh_command(5020)|run_ssh_command output: |22474|263:263|image| ls: /vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0: No such file or directory |22474|263:263|image| /vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0 2015-09-23 15:09:07|22474|263:263|image|utils.pm:run_ssh_command(5034)|SSH command executed on servidor12, returning (0, "ls: /vmfs/volumes/vcl_images/v...") 2015-09-23 15:09:07|22474|263:263|image|Linux.pm:create_directory(1569)|directory created on servidor12: '/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0' 2015-09-23 15:09:07|22474|263:263|image|VMware.pm:copy_vmdk(5861)|attempting to copy virtual disk using vmkfstools, disk type: 2gbsparse: |22474|263:263|image| '/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk' --> '/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk' 2015-09-23 15:09:08|22474|263:263|image|utils.pm:run_ssh_command(4902)|executing SSH command on servidor12: |22474|263:263|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x servidor12 'vmkfstools -i "/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk" "/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk" -d 2gbsparse' 2>&1 2015-09-23 15:09:33|22474|263:263|image|OS.pm:execute(1994)|executed command: 'vmkfstools -i "/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk" "/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk" -d 2gbsparse', exit status: 255, output: |22474|263:263|image| Failed to clone disk: The system cannot find the file specified (25). |22474|263:263|image| Destination disk format: sparse with 2GB maximum extent size |22474|263:263|image| Cloning disk '/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk'... |22474|263:263|image| ---- WARNING ---- |22474|263:263|image| 2015-09-23 15:09:33|22474|263:263|image|VMware.pm:copy_vmdk(5865)|failed to copy virtual disk |22474|263:263|image| command: 'vmkfstools -i "/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk" "/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk" -d 2gbsparse' |22474|263:263|image| output: |22474|263:263|image| Failed to clone disk: The system cannot find the file specified (25). |22474|263:263|image| Destination disk format: sparse with 2GB maximum extent size |22474|263:263|image| Cloning disk '/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk'... |22474|263:263|image| ( 0) VMware.pm, copy_vmdk (line: 5865) |22474|263:263|image| (-1) VMware.pm, capture (line: 774) |22474|263:263|image| (-2) image.pm, process (line: 162) |22474|263:263|image| (-3) vcld, make_new_child (line: 571) |22474|263:263|image| (-4) vcld, main (line: 350) 2015-09-23 15:09:33|22474|263:263|image|VMware.pm:copy_vmdk(5918)|attempting to copy virtual disk using vmware-vdiskmanager, disk type: 2gbsparse: |22474|263:263|image| '/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk' --> '/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk' 2015-09-23 15:09:33|22474|263:263|image|utils.pm:run_ssh_command(4902)|executing SSH command on servidor12: |22474|263:263|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x servidor12 'vmware-vdiskmanager -r "/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk" -t 1 "/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk"' 2>&1 2015-09-23 15:09:33|22474|263:263|image|OS.pm:execute(1994)|executed command: 'vmware-vdiskmanager -r "/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk" -t 1 "/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk"', exit status: 127, output: |22474|263:263|image| sh: vmware-vdiskmanager: not found |22474|263:263|image| ---- WARNING ---- |22474|263:263|image| 2015-09-23 15:09:33|22474|263:263|image|VMware.pm:copy_vmdk(5990)|failed to copy virtual disk on VM host servidor12, output does not contain '100% done' or 'success', command: 'vmware-vdiskmanager -r "/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk" -t 1 "/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk"', output: |22474|263:263|image| sh: vmware-vdiskmanager: not found |22474|263:263|image| ( 0) VMware.pm, copy_vmdk (line: 5990) |22474|263:263|image| (-1) VMware.pm, capture (line: 774) |22474|263:263|image| (-2) image.pm, process (line: 162) |22474|263:263|image| (-3) vcld, make_new_child (line: 571) |22474|263:263|image| (-4) vcld, main (line: 350) |22474|263:263|image| ---- WARNING ---- |22474|263:263|image| 2015-09-23 15:09:33|22474|263:263|image|VMware.pm:copy_vmdk(6055)|failed to copy virtual disk on VM host servidor12 using any available methods: |22474|263:263|image| '/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk' --> '/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk' |22474|263:263|image| ( 0) VMware.pm, copy_vmdk (line: 6055) |22474|263:263|image| (-1) VMware.pm, capture (line: 774) |22474|263:263|image| (-2) image.pm, process (line: 162) |22474|263:263|image| (-3) vcld, make_new_child (line: 571) |22474|263:263|image| (-4) vcld, main (line: 350) 2015-09-23 15:09:33|22474|263:263|image|utils.pm:run_ssh_command(4902)|executing SSH command on servidor12: |22474|263:263|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x servidor12 'rm -rfv /vmfs/volumes/vcl_images/vmwarewin7\-WIN7_20150923_VMWARE_0000191\-v0' 2>&1 2015-09-23 15:09:33|22474|263:263|image|utils.pm:run_ssh_command(5020)|run_ssh_command output: 2015-09-23 15:09:33|22474|263:263|image|utils.pm:run_ssh_command(5034)|SSH command executed on servidor12, returning (0, "") 2015-09-23 15:09:33|22474|263:263|image|Linux.pm:delete_file(1504)|deleted '/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0' on servidor12 2015-09-23 15:09:33|22474|263:263|image|utils.pm:run_ssh_command(4902)|executing SSH command on servidor12: |22474|263:263|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x servidor12 'stat /vmfs/volumes/vcl_images/vmwarewin7\-WIN7_20150923_VMWARE_0000191\-v0' 2>&1 2015-09-23 15:09:34|22474|263:263|image|utils.pm:run_ssh_command(5020)|run_ssh_command output: |22474|263:263|image| stat: can't stat '/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0': No such file or directory 2015-09-23 15:09:34|22474|263:263|image|utils.pm:run_ssh_command(5030)|SSH command executed on servidor12, command: |22474|263:263|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x servidor12 'stat /vmfs/volumes/vcl_images/vmwarewin7\-WIN7_20150923_VMWARE_0000191\-v0' 2>&1 |22474|263:263|image| returning (1, "stat: can't stat '/vmfs/volume...") |22474|263:263|image| ---- WARNING ---- |22474|263:263|image| 2015-09-23 15:09:34|22474|263:263|image|VMware.pm:capture(778)|failed to copy the vmdk files to the repository mounted on the VM host after the VM was powered off: '/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk' --> '/vmfs/volumes/vcl_images/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0.vmdk' |22474|263:263|image| ( 0) VMware.pm, capture (line: 778) |22474|263:263|image| (-1) image.pm, process (line: 162) |22474|263:263|image| (-2) vcld, make_new_child (line: 571) |22474|263:263|image| (-3) vcld, main (line: 350) 2015-09-23 15:09:34|22474|263:263|image|VMware.pm:capture(870)|attempting to delete directory where moved vmdk resided before reverting the name back to the original: /vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0 2015-09-23 15:09:34|22474|263:263|image|utils.pm:run_ssh_command(4902)|executing SSH command on servidor12: |22474|263:263|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x servidor12 'rm -rfv /vmfs/volumes/datastore1/vmwarewin7\-WIN7_20150923_VMWARE_0000191\-v0' 2>&1 2015-09-23 15:09:35|22474|263:263|image|utils.pm:run_ssh_command(5020)|run_ssh_command output: 2015-09-23 15:09:35|22474|263:263|image|utils.pm:run_ssh_command(5034)|SSH command executed on servidor12, returning (0, "") 2015-09-23 15:09:35|22474|263:263|image|Linux.pm:delete_file(1504)|deleted '/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0' on servidor12 2015-09-23 15:09:35|22474|263:263|image|utils.pm:run_ssh_command(4902)|executing SSH command on servidor12: |22474|263:263|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x servidor12 'stat /vmfs/volumes/datastore1/vmwarewin7\-WIN7_20150923_VMWARE_0000191\-v0' 2>&1 2015-09-23 15:09:36|22474|263:263|image|utils.pm:run_ssh_command(5020)|run_ssh_command output: |22474|263:263|image| stat: can't stat '/vmfs/volumes/datastore1/vmwarewin7-WIN7_20150923_VMWARE_0000191-v0': No such file or directory 2015-09-23 15:09:36|22474|263:263|image|utils.pm:run_ssh_command(5030)|SSH command executed on servidor12, command: |22474|263:263|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x servidor12 'stat /vmfs/volumes/datastore1/vmwarewin7\-WIN7_20150923_VMWARE_0000191\-v0' 2>&1 |22474|263:263|image| returning (1, "stat: can't stat '/vmfs/volume...") 2015-09-23 15:09:36|22474|263:263|image|VMware.pm:capture(876)|attempting to power the VM back on so that it can be captured again 2015-09-23 15:09:37|22474|263:263|image|VIM_SSH.pm:_run_vim_cmd(210)|executed command on VM host servidor12: vim-cmd vmsvc/getallvms 2015-09-23 15:09:45|22474|263:263|image|VIM_SSH.pm:_run_vim_cmd(210)|executed command on VM host servidor12: vim-cmd vmsvc/power.on 311 2015-09-23 15:09:46|22474|263:263|image|VIM_SSH.pm:_run_vim_cmd(210)|executed command on VM host servidor12: vim-cmd vmsvc/getallvms 2015-09-23 15:09:48|22474|263:263|image|VIM_SSH.pm:_run_vim_cmd(210)|executed command on VM host servidor12: vim-cmd vmsvc/get.tasklist 311 2015-09-23 15:09:48|22474|263:263|image|VIM_SSH.pm:_wait_for_task(750)|checking status of task: haTask-311-vim.VirtualMachine.powerOn-187793592 2015-09-23 15:09:50|22474|263:263|image|VIM_SSH.pm:_run_vim_cmd(210)|executed command on VM host servidor12: vim-cmd vimsvc/task_info haTask-311-vim.VirtualMachine.powerOn-187793592 2015-09-23 15:09:50|22474|263:263|image|VIM_SSH.pm:_wait_for_task(773)|task completed successfully: haTask-311-vim.VirtualMachine.powerOn-187793592 2015-09-23 15:09:50|22474|263:263|image|VIM_SSH.pm:vm_power_on(972)|powered on VM: /vmfs/volumes/datastore1/vm18_67-v0/vm18_67-v0.vmx |22474|263:263|image| ---- WARNING ---- |22474|263:263|image| 2015-09-23 15:09:50|22474|263:263|image|image.pm:process(166)|vmwarewin7-WIN7_20150923_VMWARE_0000191-v0 image failed to be captured by provisioning module |22474|263:263|image| ( 0) image.pm, process (line: 166) |22474|263:263|image| (-1) vcld, make_new_child (line: 571) |22474|263:263|image| (-2) vcld, main (line: 350) 2015-09-23 15:09:50|22474|263:263|image|DataStructure.pm:get_computer_private_ip_address(1617)|returning private IP address previously retrieved: 10.100.0.118 2015-09-23 15:09:50|22474|263:263|image|utils.pm:is_inblockrequest(5760)|zero rows were returned from database select 2015-09-23 15:09:50|22474|263:263|image|DataStructure.pm:get_image_affiliation_name(2121)|image owner id: 1 2015-09-23 15:09:50|22474|263:263|image|DataStructure.pm:retrieve_user_data(1412)|attempting to retrieve and store data for user: user.id = '1' 2015-09-23 15:09:50|22474|263:263|image|DataStructure.pm:retrieve_user_data(1475)|data has been retrieved for user: admin (id: 1) --
