image failed to be captured

[Tyler Hardesty <th...@gmail.com>]

Sorry to repost this issue but I still haven't been able to figure out how
to resolve it.. does anyone have any ideas?? I can post any more information
that might be needed like log files and what not... Thanks so much to
everyone who has already helped out!!!

|16014|14:14|image| ---- WARNING ----
|16014|14:14|image| 2011-03-15
16:00:38|16014|14:14|image|VMware.pm:copy_vmdk(4750)|destination vmdk file
path already exists on VM host localvmhost: /var/lib/vmware/Virtual
Machines/vmwarewinxp-vm2xp18-v0/vmwarewinxp-vm2xp18-v0.vmdk
|16014|14:14|image| ( 0) VMware.pm, copy_vmdk (line: 4750)
|16014|14:14|image| (-1) VMware.pm, capture (line: 597)
|16014|14:14|image| (-2) image.pm, process (line: 165)
|16014|14:14|image| (-3) vcld, make_new_child (line: 568)
|16014|14:14|image| (-4) vcld, main (line: 346)
|16014|14:14|image| ---- WARNING ----
|16014|14:14|image| 2011-03-15
16:00:38|16014|14:14|image|VMware.pm:capture(601)|failed to copy the vmdk
files after the VM was powered off: '/var/lib/vmware/Virtual
Machines/vmwarewinxp-vm2xp18-v0/vmwarewinxp-vm2xp18-v0.vmdk' -->
'/var/lib/vmware/Virtual
Machines/vmwarewinxp-vm2xp18-v0/vmwarewinxp-vm2xp18-v0.vmdk'
|16014|14:14|image| ( 0) VMware.pm, capture (line: 601)
|16014|14:14|image| (-1) image.pm, process (line: 165)
|16014|14:14|image| (-2) vcld, make_new_child (line: 568)
|16014|14:14|image| (-3) vcld, main (line: 346)
2011-03-15
16:00:38|16014|14:14|image|Linux.pm:file_exists(1382)|'/var/lib/vmware/Virtual
Machines/vmwarewinxp-vm2xp18-v0/vmwarewinxp-vm2xp18-v0.vmdk' exists on
localvmhost, files: 1, directories: 0, links: 0
2011-03-15 16:00:39|16014|14:14|image|Linux.pm:file_exists(1368)|file or
directory does not exist on localvmhost: '/var/lib/vmware/Virtual
Machines/vm2_1/vm2.vmdk'
2011-03-15 16:00:39|16014|14:14|image|VMware.pm:rename_vmdk(4995)|attempting
to rename vmdk: '/var/lib/vmware/Virtual
Machines/vmwarewinxp-vm2xp18-v0/vmwarewinxp-vm2xp18-v0.vmdk' -->
'/var/lib/vmware/Virtual Machines/vm2_1/vm2.vmdk'
2011-03-15
16:00:39|16014|14:14|image|Linux.pm:create_directory(1502)|directory already
exists on localvmhost: '/var/lib/vmware/Virtual Machines/vm2_1'
2011-03-15
16:00:39|16014|14:14|image|VMware.pm:rename_vmdk(5018)|'move_virtual_disk'
subroutine has not been implemented by the API:
VCL::Module::Provisioning::VMware::VIM_SSH
2011-03-15 16:00:39|16014|14:14|image|VMware.pm:rename_vmdk(5025)|attempting
to rename vmdk file using vmware-vdiskmanager: /var/lib/vmware/Virtual
Machines/vmwarewinxp-vm2xp18-v0/vmwarewinxp-vm2xp18-v0.vmdk -->
/var/lib/vmware/Virtual Machines/vm2_1/vm2.vmdk
2011-03-15 16:00:39|16014|14:14|image|VMware.pm:rename_vmdk(5032)|renamed
vmdk file by executing 'vmware-vdiskmanager' command on VM host:
|16014|14:14|image| command: vmware-vdiskmanager -n "/var/lib/vmware/Virtual
Machines/vmwarewinxp-vm2xp18-v0/vmwarewinxp-vm2xp18-v0.vmdk"
"/var/lib/vmware/Virtual Machines/vm2_1/vm2.vmdk"
|16014|14:14|image| output: Renaming completed successfully.
2011-03-15 16:00:39|16014|14:14|image|VMware.pm:capture(690)|attempting to
delete directory where renamed vmdk resided before reverting the name back
to the original: /var/lib/vmware/Virtual Machines/vmwarewinxp-vm2xp18-v0
2011-03-15 16:00:39|16014|14:14|image|Linux.pm:delete_file(1437)|deleted
'/var/lib/vmware/Virtual Machines/vmwarewinxp-vm2xp18-v0' on localvmhost
2011-03-15 16:00:40|16014|14:14|image|Linux.pm:file_exists(1368)|file or
directory does not exist on localvmhost: '/var/lib/vmware/Virtual
Machines/vmwarewinxp-vm2xp18-v0'
2011-03-15 16:00:40|16014|14:14|image|Linux.pm:delete_file(1451)|confirmed
file does not exist on localvmhost: '/var/lib/vmware/Virtual
Machines/vmwarewinxp-vm2xp18-v0'
2011-03-15 16:00:40|16014|14:14|image|VMware.pm:capture(696)|attempting to
power the VM back on so that it can be captured again
2011-03-15 16:00:40|16014|14:14|image|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd
call count: 10 (vmsvc/getallvms)
2011-03-15 16:00:41|16014|14:14|image|VIM_SSH.pm:_run_vim_cmd(208)|executed
command on VM host localvmhost: vmware-vim-cmd vmsvc/getallvms
2011-03-15 16:00:41|16014|14:14|image|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd
call count: 11 (vmsvc/power.on 48)
2011-03-15 16:00:43|16014|14:14|image|VIM_SSH.pm:_run_vim_cmd(208)|executed
command on VM host localvmhost: vmware-vim-cmd vmsvc/power.on 48
2011-03-15 16:00:43|16014|14:14|image|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd
call count: 12 (vmsvc/getallvms)
2011-03-15 16:00:46|16014|14:14|image|VIM_SSH.pm:_run_vim_cmd(208)|executed
command on VM host localvmhost: vmware-vim-cmd vmsvc/getallvms
2011-03-15 16:00:46|16014|14:14|image|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd
call count: 13 (vmsvc/get.tasklist 48)
2011-03-15 16:00:48|16014|14:14|image|VIM_SSH.pm:_run_vim_cmd(208)|executed
command on VM host localvmhost: vmware-vim-cmd vmsvc/get.tasklist 48
2011-03-15
16:00:48|16014|14:14|image|VIM_SSH.pm:_wait_for_task(748)|checking status of
task: haTask-48-vim.VirtualMachine.powerOn-50331948
2011-03-15 16:00:48|16014|14:14|image|VIM_SSH.pm:_run_vim_cmd(193)|vim-cmd
call count: 14 (vimsvc/task_info
haTask-48-vim.VirtualMachine.powerOn-50331948)
2011-03-15 16:00:49|16014|14:14|image|VIM_SSH.pm:_run_vim_cmd(208)|executed
command on VM host localvmhost: vmware-vim-cmd vimsvc/task_info
haTask-48-vim.VirtualMachine.powerOn-50331948
2011-03-15 16:00:49|16014|14:14|image|VIM_SSH.pm:_wait_for_task(771)|task
completed successfully: haTask-48-vim.VirtualMachine.powerOn-50331948
2011-03-15 16:00:49|16014|14:14|image|VIM_SSH.pm:vm_power_on(970)|powered on
VM: /var/lib/vmware/Virtual Machines/vm2_1/vm2.vmx
|16014|14:14|image| ---- WARNING ----
|16014|14:14|image| 2011-03-15
16:00:49|16014|14:14|image|image.pm:process(169)|vmwarewinxp-vm2xp18-v0
image failed to be captured by provisioning module
|16014|14:14|image| ( 0) image.pm, process (line: 169)
|16014|14:14|image| (-1) vcld, make_new_child (line: 568)
|16014|14:14|image| (-2) vcld, main (line: 346)
2011-03-15
16:00:49|16014|14:14|image|DataStructure.pm:get_computer_private_ip_address(1558)|returning
private IP address previously retrieved from /etc/hosts: 192.168.128.0
2011-03-15 16:00:49|16014|14:14|image|utils.pm:is_inblockrequest(6147)|zero
rows were returned from database select
2011-03-15
16:00:49|16014|14:14|image|DataStructure.pm:get_image_affiliation_name(2029)|image
owner id: 1
2011-03-15 16:00:49|16014|14:14|image|utils.pm:getnewdbh(2709)|database
requested (information_schema) does not match handle stored in $ENV{dbh}
(vcl:127.0.0.1)
2011-03-15 16:00:49|16014|14:14|image|utils.pm:getnewdbh(2760)|database
handle stored in $ENV{dbh}
2011-03-15
16:00:50|16014|14:14|image|DataStructure.pm:retrieve_user_data(1353)|attempting
to retrieve and store data for user: user.id = '1'
2011-03-15 16:00:50|16014|14:14|image|utils.pm:getnewdbh(2709)|database
requested (vcl) does not match handle stored in $ENV{dbh}
(information_schema:127.0.0.1)
2011-03-15 16:00:50|16014|14:14|image|utils.pm:getnewdbh(2760)|database
handle stored in $ENV{dbh}
2011-03-15
16:00:50|16014|14:14|image|DataStructure.pm:retrieve_user_data(1416)|data
has been retrieved for user: admin (id: 1)
2011-03-15 16:00:51|16014|14:14|image|utils.pm:mail(1268)|SUCCESS -- Sending
mail To: thardesty@tylerhardesty.info, PROBLEM -- 14:14|image|image.pm
|vm2>localvmhost|vmwarewinxp-vm2xp18-v0|admin
|16014|14:14|image| ---- CRITICAL ----
|16014|14:14|image| 2011-03-15
16:00:49|16014|14:14|image|image.pm:reservation_failed(393)|vmwarewinxp-vm2xp18-v0
image creation failed
|16014|14:14|image| ( 0) image.pm, reservation_failed (line: 393)
|16014|14:14|image| (-1) image.pm, process (line: 170)
|16014|14:14|image| (-2) vcld, make_new_child (line: 568)
|16014|14:14|image| (-3) vcld, main (line: 346)
2011-03-15 16:00:51|16014|14:14|image|utils.pm:mail(1268)|SUCCESS -- Sending
mail To: root@localhost, VCL -- NOTICE DELAY Image Creation vm2xp
2011-03-15 16:00:51|16014|14:14|image|utils.pm:mail(1268)|SUCCESS -- Sending
mail To: thardesty@tylerhardesty.info, VCL -- NOTICE FAILED Image Creation
vm2xp
2011-03-15 16:00:51|16014|14:14|image|utils.pm:update_request_state(1991)|request
14 state updated to: maintenance, laststate to: image
2011-03-15 16:00:51|16014|14:14|image|image.pm:reservation_failed(445)|request
state set to maintenance, laststate to image
2011-03-15 16:00:51|16014|14:14|image|utils.pm:update_computer_state(2033)|computer
3 state updated to: maintenance
2011-03-15 16:00:51|16014|14:14|image|image.pm:reservation_failed(453)|vm2
state set to maintenance
2011-03-15 16:00:51|16014|14:14|image|image.pm:
reservation_failed(460)|exiting
2011-03-15 16:00:51|16014|14:14|image|State.pm:DESTROY(839)|VCL::image
destructor called, address: a795030
2011-03-15 16:00:51|16014|14:14|image|utils.pm:delete_computerloadlog_reservation(6726)|removing
computerloadlog entries matching loadstate = begin
2011-03-15 16:00:51|16014|14:14|image|utils.pm:delete_computerloadlog_reservation(6773)|deleted
rows from computerloadlog for reservation id=14
2011-03-15 16:00:51|16014|14:14|image|State.pm:DESTROY(858)|number of
database handles state process created: 3
2011-03-15 16:00:51|16014|14:14|image|State.pm:DESTROY(886)|VCL::image
process duration: 503 seconds
2011-03-15 16:00:51|16014|14:14|image|VIM_SSH.pm:DESTROY(1685)|vim-cmd call
count: 14
2011-03-15 16:00:51|1183|vcld:REAPER(718)|VCL process exited for reservation
14, PID: 16014, signal: CHLD

Those don't seem to be a lot to go off of so I'm not quite sure how to fix
it... I've checked the path that it says already exists, but it doesn't
exist when I look for it so I don't know!?

Thanks again,

-Tyler