It looks like you're using relatively new post-2.2.1 code but not the
latest in trunk. The problem is due to a bug that has been fixed.
The code is trying to run a command such as:
cat "blah" >> "~/currentimage.txt"
The ~ variable isn't translated properly if the path is in quotes:
"~/currentimage.txt".
Are you running a checked out copy of trunk from Subversion? If so,
you can do an svn update to get the latest code. If you just want to
fix this specific problem, edit OS.pm and find the create_text_file
subroutine. Edit the $command variable to the quotes from the output
file path, change:
>> \"$file_path\"
to
>> $file_path
If you have trouble with this please send the contents of the
create_text_file subroutine. I'm not sure exactly what your version
looks like.
After making the changes, restart vcld. You don't have to run vcld
--setup again. I would recommend against it or you'll wind up with
extra, useless entries in your database. To reattempt the capture,
edit the request table in the database. There should be an entry with
stateid = 10 (maintenance), laststateid = 16 (image). Change stateid
to 16 and vcld should automatically reattempt the capture.
-Andy
On Mon, May 14, 2012 at 8:09 PM, n.johnson10
<n.johnso...@saints.mhcc.edu> wrote:
> I followed the steps outlined in the VCL Documentation for creating a
> Windows 7 base image and everything goes fine until I attempt to capture it.
>
> It appears to be an issue with executing a command when creating
> 'currentimage.txt' on the Windows 7 VM...
>
> Windows Version: Windows 7 Enterprise
> Web/Database/Management Node: CentOS 6.2
> Hypervisor: VMware ESXI 5.0
>
> Thank you
>
> Error log:
>
> vmwarewin7-Windows7Base235-v0 image creation failed
> ------------------------------
> ------------------------------------------
> time: 2012-05-14 16:42:25
> caller: image.pm:reservation_failed(385)
> ( 0) image.pm, reservation_failed (line: 385)
> (-1) image.pm, process (line: 167)
> (-2) vcld, make_new_child (line: 572)
> (-3) vcld, main (line: 350)
> ------------------------------------------------------------------------
> management node: vclweb.vcl.mhcc.edu
> reservation PID: 8482
> parent vcld PID: 7692
>
> request ID: 26
> reservation ID: 5
> request state/laststate: image/image
> request start time: 2012-05-14 16:42:01
> request end time: 2012-05-14 17:42:01
> for imaging: no
> log ID: none
>
> computer: vclbaseimage
> computer id: 55
> computer type: virtualmachine
> computer eth0 MAC address: 00:50:56:00:00:a1
> computer eth1 MAC address: 00:50:56:00:00:a2
> computer private IP address: 172.16.0.149
> computer public IP address: 172.16.0.148
> computer in block allocation: no
> provisioning module: VCL::Module::Provisioning::VMware::VMware
>
> vm host: HVS2
> vm host ID: 2
> vm host computer ID: 2
> vm profile: VMware ESX - local storage
> vm profile VM path: /vmfs/volumes/datastore1/workingvm
> vm profile repository path: /vmfs/volumes/datastore1/imagerepo
> vm profile datastore path: /vmfs/volumes/datastore1/masterimage
> vm profile disk type: localdisk
>
> image: vmwarewin7-Windows7Base235-v0
> image display name: Windows7Base2
> image ID: 35
> image revision ID: 34
> image size: 1450 MB
> use Sysprep: no
> root access: yes
> image owner ID: 1
> image owner affiliation: Local
> image revision date created: 2012-05-14 16:42:09
> 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:
> |8482|26:5|image| shared vmdk directory path:
> '/vmfs/volumes/datastore1/masterimage/vmwarewin7-Windows7Base235-v0'
> |8482|26:5|image| shared vmdk directory name:
> 'vmwarewin7-Windows7Base235-v0'
> 2012-05-14 16:42:20|8482|26:5|image|VMware.pm:set_vmdk_file_path(3968)|set
> overridden vmdk file path: '/vmfs/volumes/datastore1/Windows 7
> Base/windows7base.vmdk'
> 2012-05-14 16:42:20|8482|26:5|image|VMware.pm:capture(682)|mode of vmdk to
> be captured is valid: persistent
> 2012-05-14 16:42:21|8482|26:5|image|utils.pm:run_ssh_command(5198)|executing
> SSH command on vclbaseimage:
> |8482|26:5|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 vclbaseimage
> 'chown root currentimage.txt; chmod 777 currentimage.txt' 2>&1
> 2012-05-14
> 16:42:21|8482|26:5|image|utils.pm:run_ssh_command(5316)|run_ssh_command
> output:
> 2012-05-14 16:42:21|8482|26:5|image|utils.pm:run_ssh_command(5330)|SSH
> command executed on vclbaseimage, returning (0, "")
> 2012-05-14
> 16:42:21|8482|26:5|image|utils.pm:write_currentimage_txt(5538)|updated
> ownership and permissions on currentimage.txt
> 2012-05-14 16:42:21|8482|26:5|image|utils.pm:run_ssh_command(5198)|executing
> SSH command on vclbaseimage:
> |8482|26:5|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 vclbaseimage 'echo
> -e
> "vmwarewin7-Windows7Base235-v0\r\nid=35\r\nprettyname=Windows7Base2\r\nimagerevision_id=34\r\nimagerevision_datecreated=2012-05-14
> 16:42:09\r\ncomputer_id=55\r\ncomputer_hostname=vclbaseimage" >
> currentimage.txt && cat currentimage.txt' 2>&1
> 2012-05-14
> 16:42:22|8482|26:5|image|utils.pm:run_ssh_command(5316)|run_ssh_command
> output:
> |8482|26:5|image| vmwarewin7-Windows7Base235-v0
> |8482|26:5|image| id=35
> |8482|26:5|image| prettyname=Windows7Base2
> |8482|26:5|image| imagerevision_id=34
> |8482|26:5|image| imagerevision_datecreated=2012-05-14 16:42:09
> |8482|26:5|image| computer_id=55
> |8482|26:5|image| computer_hostname=vclbaseimage
> 2012-05-14 16:42:22|8482|26:5|image|utils.pm:run_ssh_command(5330)|SSH
> command executed on vclbaseimage, returning (0,
> "vmwarewin7-Windows7Base235-v0 ...")
> 2012-05-14
> 16:42:22|8482|26:5|image|utils.pm:write_currentimage_txt(5556)|created
> currentimage.txt file on vclbaseimage:
> |8482|26:5|image| vmwarewin7-Windows7Base235-v0
> |8482|26:5|image| id=35
> |8482|26:5|image| prettyname=Windows7Base2
> |8482|26:5|image| imagerevision_id=34
> |8482|26:5|image| imagerevision_datecreated=2012-05-14 16:42:09
> |8482|26:5|image| computer_id=55
> |8482|26:5|image| computer_hostname=vclbaseimage
> 2012-05-14 16:42:22|8482|26:5|image|DataStructure.pm:_automethod(839)|data
> structure updated, hash path:
> $self->request_data->{reservation}{5}{image}{imagemeta}{sysprep}, data
> identifier: imagemeta_sysprep, data:
> |8482|26:5|image| : 0
> 2012-05-14 16:42:22|8482|26:5|image|7.pm:pre_capture(99)|calling parent
> class pre_capture() subroutine
> 2012-05-14 16:42:22|8482|26:5|image|Version_6.pm:pre_capture(113)|calling
> parent class pre_capture() subroutine
> 2012-05-14 16:42:22|8482|26:5|image|OS.pm:pre_capture(89)|beginning common
> image capture preparation tasks
> 2012-05-14 16:42:23|8482|26:5|image|utils.pm:(eval)(5213)|waiting up to 30
> seconds for SSH process to finish
> 2012-05-14
> 16:42:24|8482|26:5|image|OS.pm:is_ssh_responding(631)|vclbaseimage is
> responding to SSH, port 22: open, port 24: closed
> |8482|26:5|image| ---- WARNING ----
> |8482|26:5|image| 2012-05-14
> 16:42:25|8482|26:5|image|OS.pm:create_text_file(1737)|failed to execute
> command to create a file on vclbaseimage:
> |8482|26:5|image| command: 'echo -n -e
> "\x76\x6d\x77\x61\x72\x65\x77\x69\x6e\x37\x2d\x57\x69\x6e\x64\x6f\x77\x73\x37\x42\x61\x73\x65\x32\x33\x35\x2d\x76\x30\xd\xa\x69\x64\x3d\x33\x35\xd\xa\x70\x72\x65\x74\x74\x79\x6e\x61\x6d\x65\x3d\x57\x69\x6e\x64\x6f\x77\x73\x37\x42\x61\x73\x65\x32\xd\xa\x69\x6d\x61\x67\x65\x72\x65\x76\x69\x73\x69\x6f\x6e\x5f\x69\x64\x3d\x33\x34\xd\xa\x69\x6d\x61\x67\x65\x72\x65\x76\x69\x73\x69\x6f\x6e\x5f\x64\x61\x74\x65\x63\x72\x65\x61\x74\x65\x64\x3d\x32\x30\x31\x32\x2d\x30\x35\x2d\x31\x34\x20\x31\x36\x3a\x34\x32\x3a\x30\x39\xd\xa\x63\x6f\x6d\x70\x75\x74\x65\x72\x5f\x69\x64\x3d\x35\x35\xd\xa\x63\x6f\x6d\x70\x75\x74\x65\x72\x5f\x68\x6f\x73\x74\x6e\x61\x6d\x65\x3d\x76\x63\x6c\x62\x61\x73\x65\x69\x6d\x61\x67\x65\xd\xa"
>> "~/currentimage.txt"', exit status: 1, output:
> |8482|26:5|image| bash: ~/currentimage.txt: No such file or directory
> |8482|26:5|image| ( 0) OS.pm, create_text_file (line: 1737)
> |8482|26:5|image| (-1) OS.pm, create_currentimage_txt (line: 233)
> |8482|26:5|image| (-2) OS.pm, pre_capture (line: 120)
> |8482|26:5|image| (-3) Windows.pm, pre_capture (line: 233)
> |8482|26:5|image| (-4) Version_6.pm, pre_capture (line: 114)
> |8482|26:5|image| (-5) 7.pm, pre_capture (line: 100)
> |8482|26:5|image| ---- WARNING ----
> |8482|26:5|image| 2012-05-14
> 16:42:25|8482|26:5|image|OS.pm:create_currentimage_txt(237)|failed to create
> currentimage.txt file on vclbaseimage
> |8482|26:5|image| ( 0) OS.pm, create_currentimage_txt (line: 237)
> |8482|26:5|image| (-1) OS.pm, pre_capture (line: 120)
> |8482|26:5|image| (-2) Windows.pm, pre_capture (line: 233)
> |8482|26:5|image| (-3) Version_6.pm, pre_capture (line: 114)
> |8482|26:5|image| (-4) 7.pm, pre_capture (line: 100)
> |8482|26:5|image| (-5) VMware.pm, capture (line: 712)
> |8482|26:5|image| ---- WARNING ----
> |8482|26:5|image| 2012-05-14
> 16:42:25|8482|26:5|image|OS.pm:pre_capture(121)|failed to create
> currentimage.txt on vclbaseimage
> |8482|26:5|image| ( 0) OS.pm, pre_capture (line: 121)
> |8482|26:5|image| (-1) Windows.pm, pre_capture (line: 233)
> |8482|26:5|image| (-2) Version_6.pm, pre_capture (line: 114)
> |8482|26:5|image| (-3) 7.pm, pre_capture (line: 100)
> |8482|26:5|image| (-4) VMware.pm, capture (line: 712)
> |8482|26:5|image| (-5) image.pm, process (line: 162)
> |8482|26:5|image| ---- WARNING ----
> |8482|26:5|image| 2012-05-14
> 16:42:25|8482|26:5|image|Windows.pm:pre_capture(234)|failed to execute
> parent class pre_capture() subroutine
> |8482|26:5|image| ( 0) Windows.pm, pre_capture (line: 234)
> |8482|26:5|image| (-1) Version_6.pm, pre_capture (line: 114)
> |8482|26:5|image| (-2) 7.pm, pre_capture (line: 100)
> |8482|26:5|image| (-3) VMware.pm, capture (line: 712)
> |8482|26:5|image| (-4) image.pm, process (line: 162)
> |8482|26:5|image| (-5) vcld, make_new_child (line: 572)
> |8482|26:5|image| ---- WARNING ----
> |8482|26:5|image| 2012-05-14
> 16:42:25|8482|26:5|image|Version_6.pm:pre_capture(118)|failed to execute
> parent class pre_capture() subroutine
> |8482|26:5|image| ( 0) Version_6.pm, pre_capture (line: 118)
> |8482|26:5|image| (-1) 7.pm, pre_capture (line: 100)
> |8482|26:5|image| (-2) VMware.pm, capture (line: 712)
> |8482|26:5|image| (-3) image.pm, process (line: 162)
> |8482|26:5|image| (-4) vcld, make_new_child (line: 572)
> |8482|26:5|image| (-5) vcld, main (line: 350)
> |8482|26:5|image| ---- WARNING ----
> |8482|26:5|image| 2012-05-14
> 16:42:25|8482|26:5|image|7.pm:pre_capture(104)|failed to execute parent
> class pre_capture() subroutine
> |8482|26:5|image| ( 0) 7.pm, pre_capture (line: 104)
> |8482|26:5|image| (-1) VMware.pm, capture (line: 712)
> |8482|26:5|image| (-2) image.pm, process (line: 162)
> |8482|26:5|image| (-3) vcld, make_new_child (line: 572)
> |8482|26:5|image| (-4) vcld, main (line: 350)
> |8482|26:5|image| ---- WARNING ----
> |8482|26:5|image| 2012-05-14
> 16:42:25|8482|26:5|image|VMware.pm:capture(713)|failed to complete OS
> module's pre_capture tasks
> |8482|26:5|image| ( 0) VMware.pm, capture (line: 713)
> |8482|26:5|image| (-1) image.pm, process (line: 162)
> |8482|26:5|image| (-2) vcld, make_new_child (line: 572)
> |8482|26:5|image| (-3) vcld, main (line: 350)
> |8482|26:5|image| ---- WARNING ----
> |8482|26:5|image| 2012-05-14
> 16:42:25|8482|26:5|image|image.pm:process(166)|vmwarewin7-Windows7Base235-v0
> image failed to be captured by provisioning module
> |8482|26:5|image| ( 0) image.pm, process (line: 166)
> |8482|26:5|image| (-1) vcld, make_new_child (line: 572)
> |8482|26:5|image| (-2) vcld, main (line: 350)
> 2012-05-14
> 16:42:25|8482|26:5|image|DataStructure.pm:get_computer_private_ip_address(1609)|returning
> private IP address previously retrieved: 172.16.0.149
> 2012-05-14 16:42:25|8482|26:5|image|utils.pm:is_inblockrequest(6056)|zero
> rows were returned from database select
> 2012-05-14
> 16:42:25|8482|26:5|image|DataStructure.pm:get_image_affiliation_name(2121)|image
> owner id: 1
> 2012-05-14
> 16:42:25|8482|26:5|image|DataStructure.pm:retrieve_user_data(1404)|attempting
> to retrieve and store data for user: user.id = '1'
> 2012-05-14
> 16:42:25|8482|26:5|image|DataStructure.pm:retrieve_user_data(1467)|data has
> been retrieved for user: admin (id: 1)
>
