I don't think it's a naming issue. Your "xphost2" VM must be responding to SSH before attempting the capture. You should be able to connect to it via "ssh -i /etc/vcl/vcl.key xphost2". You'll need to troubleshoot this if it doesn't connect.

Also, you don't need to run "vcld -setup" each time you encounter a problem like this. After troubleshooting, just change the request.stateid value in the database from 10 (maintenance) to 16 (image). If vcld is running, it will automatically pick up the reservation again and attempt the image capture.


FYI, the new VMware code is pretty flexible regarding the paths to the VM being captured. It does the following to determine where the VM files reside for an image capture:
-SSH in to the VM
-Retrieve the MAC addresses being used according to the guest OS
-Get a list of all .vmx files on the host
-Check each .vmx file, try to find the one containing matching MAC addresses
-Once found, make sure this is indeed the correct .vmx file by making sure the .vmx is registered and powered on -Get the .vmdk path from the .vmx file and perform virtual disk operations on this .vmdk

-Andy



On 1/28/2011 2:56 PM, Hayashi, Daiyu wrote:
Hi Andy,

Thank you for helping.
I tried your fix - I got a little further - now a new error message.
I think it cannot find my vm when it searches through the local disk on the ESX 
server.
How does the script determine the vmdk file name?
Is there a strict naming convention when making the vm on the ESX server or do 
I need to name the vmdk a specific file name?

Error below:

Thank you,


Daiyu Hayashi
Information Technology Consultant - Lead
Mihaylo College of Business and Economics
California State University at Fullerton
dhaya...@fullerton.edu
Phone: 657-278-7347

-new error-

[root@vcl-manage bin]# ./vcld -setup
VCL Management Node Setup
----------------------------------------------------------------------------
Select a module to configure:
1. VCL Base Module
2. VCL Image State Module
3. Windows OS Module

[vcld]
Make a selection (1-3, 'c' to cancel): 2
----------------------------------------------------------------------------
Choose an operation:
1. Capture Base Image

[vcld/Image]
Make a selection (1, 'c' to cancel): 1

Enter the VCL login name or ID of the user who will own the image: [admin]:

User who will own the image: admin (ID: 1)

Enter the hostname or IP address of the computer to be captured: ('c' to 
cancel): xphost2

Computer to be captured: xphost2 (ID: 9)
Provisioning module: provisioning_vmware
Install type: vmware

Select the OS to be captured (install type: vmware):
1. Generic Linux (VMware)
2. Windows 2003 Server (VMware)
3. Windows 7 (VMware)
4. Windows Server 2008 (VMware)
5. Windows Vista (VMware)
6. Windows XP (VMware)

[vcld/Image/Capture Base Image]
Make a selection (1-6, 'c' to cancel): 6

Selected OS: Windows XP (VMware)

Image architecture:
1. x86
2. x86_64

[vcld/Image/Capture Base Image]
Make a selection (1-2, 'c' to cancel): 1

Image architecture: x86

Use Sysprep:
1. Yes
2. No

[vcld/Image/Capture Base Image]
Make a selection (1-2, 'c' to cancel): 2

Use Sysprep: No

Enter the name of the image to be captured: ('c' to cancel): xpbase2

Added new image to database: 'xpbase2'
    image.name: vmwarewinxp-xpbase29-v0
    image.id: 9
    imagerevision.id: 9
    imagemeta.id: 7
    resource.id: 23

----------------------------------------------------------------------------
Inserted imaging request to the database:
request ID: 1
reservation ID: 1

This process will now display the contents of the vcld.log file if the vcld
daemon is running. If you do not see many lines of additional output, exit this
process, start the vcld daemon, and monitor the image capture process by running
the command:
tail -f /var/log/vcld.log | grep '1:1'

----------------------------------------------------------------------------
2011-01-28 11:31:42|3982|utils.pm:setup_get_array_choice(9986)|choices argument:
2011-01-28 11:31:42|3520|vcld:main(166)|lastcheckin time updated for management 
node 1: 2011-01-28 11:31:42
2011-01-28 11:31:43|3982|utils.pm:setup_get_array_choice(9986)|choices argument:
2011-01-28 11:31:47|3520|vcld:main(166)|lastcheckin time updated for management 
node 1: 2011-01-28 11:31:47
2011-01-28 11:31:51|3982|utils.pm:insert_request(8443)|inserted new reload 
request into request table, request id=1
2011-01-28 11:31:51|3982|utils.pm:insert_request(8474)|inserted new reload 
request into reservation table, reservation id=1
2011-01-28 11:31:52|3520|vcld:main(166)|lastcheckin time updated for management 
node 1: 2011-01-28 11:31:52
2011-01-28 
11:31:52|3520|1:1|image|utils.pm:reservation_being_processed(9010)|computerloadlog
 'begin' entry does NOT exist for reservation 1
2011-01-28 11:31:52|3520|1:1|image|utils.pm:run_command(9082)|executed command: 
pgrep -fl 'vcld [0-9]+:1 ', pid: 4024, exit status: 1, output:
2011-01-28 
11:31:52|3520|1:1|image|utils.pm:is_management_node_process_running(9259)|process
 is NOT running, identifier: 'vcld [0-9]+:1 '
2011-01-28 
11:31:52|3520|1:1|image|utils.pm:reservation_being_processed(9031)|reservation 
is NOT currently being processed
2011-01-28 11:31:52|3520|1:1|image|vcld:main(277)|reservation 1 is NOT already 
being processed
2011-01-28 11:31:52|3520|1:1|image|utils.pm:get_request_info(4589)|standalone 
affiliation found: Local
2011-01-28 11:31:52|3520|1:1|image|vcld:main(282)|retrieved request information 
from database
2011-01-28 
11:31:52|3520|1:1|image|DataStructure.pm:is_parent_reservation(943)|returning 
true: parent reservation ID for this request: 1
2011-01-28 11:31:52|3520|1:1|image|utils.pm:update_request_state(2049)|request 
1 state updated to: pending, laststate to: image
2011-01-28 11:31:52|3520|1:1|image|utils.pm:insertloadlog(3933)|inserted 
computer=9, begin, beginning to process, state is image
2011-01-28 11:31:52|3520|1:1|image|vcld:make_new_child(510)|loaded VCL::image 
module
2011-01-28 11:31:52|4026|1:1|image|vcld:make_new_child(583)|vcld environment 
variable set to 0 for this process
2011-01-28 11:31:52|4026|1:1|image|Module.pm:new(134)|constructor called, 
class=VCL::image
2011-01-28 11:31:52|4026|1:1|image|Module.pm:new(156)|VCL::image object created
2011-01-28 11:31:52|3520|1:1|image|vcld:make_new_child(567)|current number of 
forked kids: 1
2011-01-28 11:31:52|4026|1:1|image|State.pm:initialize(85)|obtained a database 
handle for this state process, stored as $ENV{dbh}
2011-01-28 11:31:52|4026|1:1|image|State.pm:check_image_os(836)|no corrections 
need to be made to image OS: vmwarewinxp
2011-01-28 
11:31:52|4026|1:1|image|DataStructure.pm:is_parent_reservation(943)|returning 
true: parent reservation ID for this request: 1
2011-01-28 
11:31:52|4026|1:1|image|utils.pm:rename_vcld_process(7183)|reservation count: 1
2011-01-28 
11:31:52|4026|1:1|image|utils.pm:rename_vcld_process(7202)|PARENTIMAGE: 1
2011-01-28 11:31:52|4026|1:1|image|utils.pm:rename_vcld_process(7203)|SUBIMAGE: 0
2011-01-28 11:31:52|4026|1:1|image|utils.pm:rename_vcld_process(7221)|renamed 
process to 'vcld 1:1 image xphost2 vmwarewinxp-xpbase29-v0 admin'
2011-01-28 
11:31:52|4026|1:1|image|DataStructure.pm:is_parent_reservation(943)|returning 
true: parent reservation ID for this request: 1
2011-01-28 
11:31:52|4026|1:1|image|DataStructure.pm:is_parent_reservation(943)|returning 
true: parent reservation ID for this request: 1
2011-01-28 11:31:52|4026|1:1|image|State.pm:initialize(118)|attempting to load 
provisioning module: VCL::Module::Provisioning::VMware::VMware
2011-01-28 
11:31:52|4026|1:1|image|State.pm:initialize(124)|VCL::Module::Provisioning::VMware::VMware
 module loaded
2011-01-28 11:31:52|4026|1:1|image|Module.pm:new(134)|constructor called, 
class=VCL::Module::Provisioning::VMware::VMware
2011-01-28 
11:31:52|4026|1:1|image|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VMware
 object created
2011-01-28 11:31:52|4026|1:1|image|DataStructure.pm:_initialize(594)|computer 
ID argument was specified, retrieving data for computer ID: 3
2011-01-28 
11:31:53|4026|1:1|image|VMware.pm:get_vmhost_datastructure(923)|created 
DataStructure object for VM host: esx1
2011-01-28 11:31:53|4026|1:1|image|DataStructure.pm:_initialize(594)|computer 
ID argument was specified, retrieving data for computer ID: 3
2011-01-28 
11:31:53|4026|1:1|image|VMware.pm:get_vmhost_datastructure(923)|created 
DataStructure object for VM host: esx1
2011-01-28 
11:31:53|4026|1:1|image|VMware.pm:get_vmhost_api_object(1027)|attempting to 
load VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
2011-01-28 11:31:53|4026|1:1|image|VMware.pm:get_vmhost_api_object(1033)|loaded 
VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
2011-01-28 11:31:53|4026|1:1|image|Module.pm:new(134)|constructor called, 
class=VCL::Module::Provisioning::VMware::vSphere_SDK
2011-01-28 
11:31:53|4026|1:1|image|Module.pm:new(156)|VCL::Module::Provisioning::VMware::vSphere_SDK
 object created
2011-01-28 11:31:53|4026|1:1|image|vSphere_SDK.pm:initialize(1816)|attempting 
to connect to VM host: https://esx1/sdk
2011-01-28 11:31:53|4026|1:1|image|vSphere_SDK.pm:initialize(1826)|connected to 
VM host: https://esx1/sdk
2011-01-28 
11:31:53|4026|1:1|image|VMware.pm:get_vmhost_api_object(1046)|created API 
object: VCL::Module::Provisioning::VMware::vSphere_SDK
2011-01-28 11:31:54|4026|1:1|image|vSphere_SDK.pm:is_restricted(1079)|access to 
the VM host via the vSphere SDK is NOT restricted due to the license
2011-01-28 11:31:54|4026|1:1|image|VMware.pm:initialize(229)|vSphere SDK object 
will be used to control the VM: xphost2, and to control the OS of the VM host: 
esx1
2011-01-28 
11:31:56|4026|1:1|image|vSphere_SDK.pm:get_vmware_product_name(955)|VMware 
product being used on VM host esx1: 'VMware ESXi 4.1.0 build-260247'
2011-01-28 11:31:57|3520|vcld:main(166)|lastcheckin time updated for management 
node 1: 2011-01-28 11:31:57
2011-01-28 11:31:59|4026|1:1|image|vSphere_SDK.pm:file_exists(1558)|file 
(datastore root) exists: [datastore1]
2011-01-28 11:31:59|4026|1:1|image|VMware.pm:initialize(294)|VMware 
provisioning object initialized:
|4026|1:1|image| VM host OS object type: 
VCL::Module::Provisioning::VMware::vSphere_SDK
|4026|1:1|image| API object type: VCL::Module::Provisioning::VMware::vSphere_SDK
2011-01-28 
11:31:59|4026|1:1|image|State.pm:initialize(128)|VCL::Module::Provisioning::VMware::VMware
 provisioner object created
2011-01-28 11:31:59|4026|1:1|image|State.pm:initialize(142)|attempting to load 
OS module: VCL::Module::OS::Windows::Version_5::XP
2011-01-28 
11:31:59|4026|1:1|image|State.pm:initialize(148)|VCL::Module::OS::Windows::Version_5::XP
 module loaded
2011-01-28 11:31:59|4026|1:1|image|Module.pm:new(134)|constructor called, 
class=VCL::Module::OS::Windows::Version_5::XP
2011-01-28 
11:31:59|4026|1:1|image|Module.pm:new(156)|VCL::Module::OS::Windows::Version_5::XP
 object created
2011-01-28 
11:31:59|4026|1:1|image|State.pm:initialize(151)|VCL::Module::OS::Windows::Version_5::XP
 OS object created
2011-01-28 11:31:59|4026|1:1|image|State.pm:initialize(166)|returning 1
2011-01-28 11:31:59|4026|1:1|image|vcld:make_new_child(592)|VCL::image object 
created and initialized
|4026|1:1|image| ---- WARNING ----
|4026|1:1|image| 2011-01-28 
11:31:59|4026|1:1|image|DataStructure.pm:_automethod(764)|corresponding data 
has not been initialized for get_management_node_sysadmin_email: 
$ENV{management_node_info}{SYSADMIN_EMAIL}
|4026|1:1|image| ( 0) utils.pm, notify (line: 630)
|4026|1:1|image| (-1) DataStructure.pm, _automethod (line: 764)
|4026|1:1|image| (-2) Autoload.pm, __ANON__ (line: 80)
|4026|1:1|image| (-3) image.pm, process (line: 108)
|4026|1:1|image| (-4) vcld, make_new_child (line: 595)
|4026|1:1|image| (-5) vcld, main (line: 342)
2011-01-28 11:32:01|4026|1:1|image|vSphere_SDK.pm:get_file_info(1937)|searching 
for matching file paths: base directory path: '[datastore1] 
vmwarewinxp-xpbase29-v0', search pattern: 'vmwarewinxp-xpbase29-v0.vmdk'
2011-01-28 11:32:02|3520|vcld:main(166)|lastcheckin time updated for management 
node 1: 2011-01-28 11:32:02
2011-01-28 11:32:03|4026|1:1|image|vSphere_SDK.pm:get_file_info(1948)|base 
directory does not exist: '[datastore1] vmwarewinxp-xpbase29-v0'
2011-01-28 11:32:03|4026|1:1|image|vSphere_SDK.pm:find_files(1705)|matching 
file count: 0
2011-01-28 11:32:03|4026|1:1|image|vSphere_SDK.pm:file_exists(1577)|file does 
not exist: [datastore1] vmwarewinxp-xpbase29-v0/vmwarewinxp-xpbase29-v0.vmdk
2011-01-28 11:32:03|4026|1:1|image|VMware.pm:does_image_exist(2940)|image does 
not exist in the non-persistent directory on the VM host, checking the image 
repository
2011-01-28 
11:32:03|4026|1:1|image|VMware.pm:get_repository_vmdk_base_directory_path(2650)|retrieved
 repository path from the VM profile: /images/vmware_images
2011-01-28 11:32:03|4026|1:1|image|utils.pm:run_command(9082)|executed command: find 
"/images/vmware_images/vmwarewinxp-xpbase29-v0" -iname 
"vmwarewinxp-xpbase29-v0.vmdk", pid: 4027, exit status: 1, output:
|4026|1:1|image| find: /images/vmware_images: No such file or directory
2011-01-28 11:32:03|4026|1:1|image|VMware.pm:does_image_exist(2967)|image does 
not exist in image repository: 
/images/vmware_images/vmwarewinxp-xpbase29-v0/vmwarewinxp-xpbase29-v0.vmdk
2011-01-28 11:32:03|4026|1:1|image|image.pm:process(148)|image 
vmwarewinxp-xpbase29-v0 does not exist in the repository
2011-01-28 11:32:03|4026|1:1|image|DataStructure.pm:_automethod(786)|data structure 
updated: $self->request_data->{reservation}{1}{image}{lastupdate}
|4026|1:1|image| image_lastupdate = 2011-01-28 11:32:03
2011-01-28 11:32:03|4026|1:1|image|DataStructure.pm:_automethod(786)|data structure 
updated: $self->request_data->{reservation}{1}{imagerevision}{datecreated}
|4026|1:1|image| imagerevision_date_created = 2011-01-28 11:32:03
2011-01-28 11:32:03|4026|1:1|image|image.pm:process(164)|calling provisioning 
module's capture() subroutine
2011-01-28 11:32:04|4026|1:1|image|utils.pm:nmap_port(2707)|port 22 is closed 
on xphost2
2011-01-28 11:32:04|4026|1:1|image|utils.pm:nmap_port(2707)|port 24 is closed 
on xphost2
2011-01-28 11:32:04|4026|1:1|image|OS.pm:is_ssh_responding(416)|xphost2 is NOT 
responding to SSH, ports 22 or 24 are both closed
|4026|1:1|image| ---- WARNING ----
|4026|1:1|image| 2011-01-28 
11:32:04|4026|1:1|image|VMware.pm:capture(403)|unable to capture image, VM 
xphost2 is not responding to SSH
|4026|1:1|image| ( 0) utils.pm, notify (line: 630)
|4026|1:1|image| (-1) VMware.pm, capture (line: 403)
|4026|1:1|image| (-2) image.pm, process (line: 165)
|4026|1:1|image| (-3) vcld, make_new_child (line: 595)
|4026|1:1|image| (-4) vcld, main (line: 342)
|4026|1:1|image| ---- WARNING ----
|4026|1:1|image| 2011-01-28 
11:32:04|4026|1:1|image|image.pm:process(169)|vmwarewinxp-xpbase29-v0 image 
failed to be captured by provisioning module
|4026|1:1|image| ( 0) utils.pm, notify (line: 630)
|4026|1:1|image| (-1) image.pm, process (line: 169)
|4026|1:1|image| (-2) vcld, make_new_child (line: 595)
|4026|1:1|image| (-3) vcld, main (line: 342)
|4026|1:1|image| ---- WARNING ----
|4026|1:1|image| 2011-01-28 
11:32:04|4026|1:1|image|DataStructure.pm:_automethod(764)|corresponding data 
has not been initialized for get_management_node_sysadmin_email: 
$ENV{management_node_info}{SYSADMIN_EMAIL}
|4026|1:1|image| ( 0) utils.pm, notify (line: 630)
|4026|1:1|image| (-1) DataStructure.pm, _automethod (line: 764)
|4026|1:1|image| (-2) Autoload.pm, __ANON__ (line: 80)
|4026|1:1|image| (-3) image.pm, reservation_failed (line: 390)
|4026|1:1|image| (-4) image.pm, process (line: 170)
|4026|1:1|image| (-5) vcld, make_new_child (line: 595)
|4026|1:1|image| (-6) vcld, main (line: 342)
2011-01-28 11:32:04|4026|1:1|image|utils.pm:mail(1247)|SUCCESS -- Sending mail 
To: 0, PROBLEM -- image.pm
|4026|1:1|image| ---- CRITICAL ----
|4026|1:1|image| 2011-01-28 
11:32:04|4026|1:1|image|image.pm:reservation_failed(393)|vmwarewinxp-xpbase29-v0
 image creation failed
|4026|1:1|image| ( 0) utils.pm, notify (line: 630)
|4026|1:1|image| (-1) image.pm, reservation_failed (line: 393)
|4026|1:1|image| (-2) image.pm, process (line: 170)
|4026|1:1|image| (-3) vcld, make_new_child (line: 595)
|4026|1:1|image| (-4) vcld, main (line: 342)
2011-01-28 11:32:04|4026|1:1|image|utils.pm:mail(1247)|SUCCESS -- Sending mail 
To: root@localhost, VCL -- NOTICE DELAY Image Creation xpbase2
         /usr/lib/perl5/site_perl/5.8.8/Mail/Mailer/rfc822.pm line 22 (#1)
|4026|1:1|image| ---- WARNING ----
|4026|1:1|image| 2011-01-28 
11:32:04|4026|1:1|image|vcld:warning_handler(637)|Use of uninitialized value in 
substitution (s///) at /usr/lib/perl5/site_perl/5.8.8/Mail/Mailer/rfc822.pm 
line 22.
|4026|1:1|image| ( 0) utils.pm, notify (line: 630)
|4026|1:1|image| (-1) vcld, warning_handler (line: 637)
|4026|1:1|image| (-2) rfc822.pm, set_headers (line: 22)
|4026|1:1|image| (-3) Mailer.pm, open (line: 162)
|4026|1:1|image| (-4) utils.pm, mail (line: 1241)
|4026|1:1|image| (-5) image.pm, reservation_failed (line: 442)
|4026|1:1|image| (-6) image.pm, process (line: 170)
|4026|1:1|image| ---- WARNING ----
|4026|1:1|image| 2011-01-28 
11:32:04|4026|1:1|image|vcld:warning_handler(637)|Use of uninitialized value in 
concatenation (.) or string at 
/usr/lib/perl5/site_perl/5.8.8/Mail/Mailer/rfc822.pm line 23.
|4026|1:1|image| ( 0) utils.pm, notify (line: 630)
|4026|1:1|image| (-1) vcld, warning_handler (line: 637)
|4026|1:1|image| (-2) rfc822.pm, set_headers (line: 23)
|4026|1:1|image| (-3) Mailer.pm, open (line: 162)
|4026|1:1|image| (-4) utils.pm, mail (line: 1241)
|4026|1:1|image| (-5) image.pm, reservation_failed (line: 442)
|4026|1:1|image| (-6) image.pm, process (line: 170)
|4026|1:1|image| ---- WARNING ----
|4026|1:1|image| 2011-01-28 
11:32:04|4026|1:1|image|vcld:warning_handler(637)|Use of uninitialized value in 
concatenation (.) or string at /usr/local/vcl/bin/../lib/VCL/utils.pm line 1247.
|4026|1:1|image| ( 0) utils.pm, notify (line: 630)
|4026|1:1|image| (-1) vcld, warning_handler (line: 637)
|4026|1:1|image| (-2) utils.pm, mail (line: 1247)
|4026|1:1|image| (-3) image.pm, reservation_failed (line: 442)
|4026|1:1|image| (-4) image.pm, process (line: 170)
|4026|1:1|image| (-5) vcld, make_new_child (line: 595)
|4026|1:1|image| (-6) vcld, main (line: 342)
2011-01-28 11:32:04|4026|1:1|image|utils.pm:mail(1247)|SUCCESS -- Sending mail 
To: , VCL -- NOTICE FAILED Image Creation xpbase2
2011-01-28 11:32:04|4026|1:1|image|utils.pm:update_request_state(2049)|request 
1 state updated to: maintenance, laststate to: image
2011-01-28 11:32:04|4026|1:1|image|image.pm:reservation_failed(445)|request 
state set to maintenance, laststate to image
2011-01-28 
11:32:04|4026|1:1|image|utils.pm:update_computer_state(2091)|computer 9 state 
updated to: maintenance
2011-01-28 11:32:04|4026|1:1|image|image.pm:reservation_failed(453)|xphost2 
state set to maintenance
2011-01-28 11:32:04|4026|1:1|image|image.pm:reservation_failed(460)|exiting
2011-01-28 11:32:04|4026|1:1|image|State.pm:DESTROY(902)|destructor called, 
ref($self)=VCL::image
2011-01-28 
11:32:04|4026|1:1|image|utils.pm:delete_computerloadlog_reservation(6829)|removing
 computerloadlog entries matching loadstate = begin
2011-01-28 
11:32:04|4026|1:1|image|utils.pm:delete_computerloadlog_reservation(6876)|deleted
 rows from computerloadlog for reservation id=1
2011-01-28 11:32:04|4026|1:1|image|State.pm:DESTROY(909)|removed 
computerloadlog rows with loadstate=begin for reservation
2011-01-28 11:32:04|4026|1:1|image|State.pm:DESTROY(921)|number of database 
handles state process created: 1
2011-01-28 11:32:04|4026|1:1|image|State.pm:DESTROY(930)|process has a database 
handle stored in $ENV{dbh}, attempting disconnect
2011-01-28 11:32:04|4026|1:1|image|State.pm:DESTROY(932)|$ENV{dbh}: database 
disconnect successful
2011-01-28 11:32:04|4026|1:1|image|State.pm:DESTROY(946)|VCL::image process 
4026 exiting
2011-01-28 11:32:04|3520|vcld:REAPER(745)|VCL process exited for reservation 1, 
PID: 4026, signal: CHLD
2011-01-28 11:32:04|3520|vcld:main(166)|lastcheckin time updated for management 
node 1: 2011-01-28 11:32:04



-----Original Message-----
From: Andy Kurth [mailto:andy_ku...@ncsu.edu]
Sent: Friday, January 28, 2011 11:32 AM
To: vcl-user@incubator.apache.org
Subject: Re: Image Capture issue

It looks like your VM computer "xpbase1" hasn't been assigned to a VM
host.  Try assigning it via the "Virtual Hosts" link on the VCL website.

-Andy


Reply via email to