You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@vcl.apache.org by "Hayashi, Daiyu" <dh...@Exchange.FULLERTON.EDU> on 2011/01/26 23:54:49 UTC
Image Capture issue
Help - need assistance with VCL 2.2
vHost on ESXi4.1
Issue with Image Capture for Base Image using Windows XP
Error message below-
Thank you,
Daiyu Hayashi
Information Technology Consultant
Mihaylo College of Business and Economics
California State University at Fullerton
dhayashi@fullerton.edu
------------------------------------------------------------------------------------------------------------------------
[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]: 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): xpbase1
Computer to be captured: xpbase1 (ID: 8)
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): xpbase1
Added new image to database: 'xpbase1'
image.name: vmwarewinxp-xpbase17-v0
image.id: 7
imagerevision.id: 7
imagemeta.id: 4
resource.id: 20
----------------------------------------------------------------------------
Inserted imaging request to the database:
request ID: 3
reservation ID: 3
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 '3:3'
----------------------------------------------------------------------------
2011-01-26 14:15:01|3906|utils.pm:setup_get_array_choice(9986)|choices argument:
|3906| x86
|3906| x86_64
2011-01-26 14:15:02|3906|utils.pm:setup_get_array_choice(9986)|choices argument:
|3906| Yes
|3906| No
2011-01-26 14:15:02|3514|vcld:main(166)|lastcheckin time updated for management node 1: 2011-01-26 14:15:02
2011-01-26 14:15:07|3514|vcld:main(166)|lastcheckin time updated for management node 1: 2011-01-26 14:15:07
2011-01-26 14:15:10|3906|utils.pm:insert_request(8443)|inserted new reload request into request table, request id=3
2011-01-26 14:15:10|3906|utils.pm:insert_request(8474)|inserted new reload request into reservation table, reservation id=3
2011-01-26 14:15:12|3514|vcld:main(166)|lastcheckin time updated for management node 1: 2011-01-26 14:15:12
2011-01-26 14:15:12|3514|3:3|image|utils.pm:reservation_being_processed(9010)|computerloadlog 'begin' entry does NOT exist for reservation 3
2011-01-26 14:15:13|3514|3:3|image|utils.pm:run_command(9082)|executed command: pgrep -fl 'vcld [0-9]+:3 ', pid: 3912, exit status: 1, output:
2011-01-26 14:15:13|3514|3:3|image|utils.pm:is_management_node_process_running(9259)|process is NOT running, identifier: 'vcld [0-9]+:3 '
2011-01-26 14:15:13|3514|3:3|image|utils.pm:reservation_being_processed(9031)|reservation is NOT currently being processed
2011-01-26 14:15:13|3514|3:3|image|vcld:main(277)|reservation 3 is NOT already being processed
2011-01-26 14:15:13|3514|3:3|image|utils.pm:get_request_info(4589)|standalone affiliation found: Local
2011-01-26 14:15:13|3514|3:3|image|vcld:main(282)|retrieved request information from database
2011-01-26 14:15:13|3514|3:3|image|DataStructure.pm:is_parent_reservation(943)|returning true: parent reservation ID for this request: 3
2011-01-26 14:15:13|3514|3:3|image|utils.pm:update_request_state(2049)|request 3 state updated to: pending, laststate to: image
2011-01-26 14:15:13|3514|3:3|image|utils.pm:insertloadlog(3933)|inserted computer=8, begin, beginning to process, state is image
2011-01-26 14:15:13|3514|3:3|image|vcld:make_new_child(510)|loaded VCL::image module
2011-01-26 14:15:13|3914|3:3|image|vcld:make_new_child(583)|vcld environment variable set to 0 for this process
2011-01-26 14:15:13|3914|3:3|image|Module.pm:new(134)|constructor called, class=VCL::image
2011-01-26 14:15:13|3914|3:3|image|Module.pm:new(156)|VCL::image object created
2011-01-26 14:15:13|3514|3:3|image|vcld:make_new_child(567)|current number of forked kids: 1
2011-01-26 14:15:13|3914|3:3|image|State.pm:initialize(85)|obtained a database handle for this state process, stored as $ENV{dbh}
2011-01-26 14:15:13|3914|3:3|image|State.pm:check_image_os(836)|no corrections need to be made to image OS: vmwarewinxp
2011-01-26 14:15:13|3914|3:3|image|DataStructure.pm:is_parent_reservation(943)|returning true: parent reservation ID for this request: 3
2011-01-26 14:15:13|3914|3:3|image|utils.pm:rename_vcld_process(7183)|reservation count: 1
2011-01-26 14:15:13|3914|3:3|image|utils.pm:rename_vcld_process(7202)|PARENTIMAGE: 1
2011-01-26 14:15:13|3914|3:3|image|utils.pm:rename_vcld_process(7203)|SUBIMAGE: 0
2011-01-26 14:15:13|3914|3:3|image|utils.pm:rename_vcld_process(7221)|renamed process to 'vcld 3:3 image xpbase1 vmwarewinxp-xpbase17-v0 admin'
2011-01-26 14:15:13|3914|3:3|image|DataStructure.pm:is_parent_reservation(943)|returning true: parent reservation ID for this request: 3
2011-01-26 14:15:13|3914|3:3|image|DataStructure.pm:is_parent_reservation(943)|returning true: parent reservation ID for this request: 3
2011-01-26 14:15:13|3914|3:3|image|State.pm:initialize(118)|attempting to load provisioning module: VCL::Module::Provisioning::VMware::VMware
2011-01-26 14:15:13|3914|3:3|image|State.pm:initialize(124)|VCL::Module::Provisioning::VMware::VMware module loaded
2011-01-26 14:15:13|3914|3:3|image|Module.pm:new(134)|constructor called, class=VCL::Module::Provisioning::VMware::VMware
2011-01-26 14:15:13|3914|3:3|image|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VMware object created
|3914|3:3|image| ---- WARNING ----
|3914|3:3|image| 2011-01-26 14:15:13|3914|3:3|image|DataStructure.pm:_automethod(764)|corresponding data has not been initialized for get_vmhost_computer_id: $self->request_data->{reservation}{3}{computer}{vmhost}{computerid}
|3914|3:3|image| ( 0) utils.pm, notify (line: 630)
|3914|3:3|image| (-1) DataStructure.pm, _automethod (line: 764)
|3914|3:3|image| (-2) Autoload.pm, __ANON__ (line: 80)
|3914|3:3|image| (-3) VMware.pm, get_vmhost_datastructure (line: 894)
|3914|3:3|image| (-4) VMware.pm, initialize (line: 216)
|3914|3:3|image| (-5) Module.pm, new (line: 159)
|3914|3:3|image| (-6) State.pm, initialize (line: 127)
|3914|3:3|image| ---- WARNING ----
|3914|3:3|image| 2011-01-26 14:15:13|3914|3:3|image|State.pm:initialize(132)|provisioning object could not be created, returning 0
|3914|3:3|image| ( 0) utils.pm, notify (line: 630)
|3914|3:3|image| (-1) State.pm, initialize (line: 132)
|3914|3:3|image| (-2) Module.pm, new (line: 159)
|3914|3:3|image| (-3) vcld, make_new_child (line: 591)
|3914|3:3|image| (-4) vcld, main (line: 342)
2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(902)|destructor called, ref($self)=VCL::image
2011-01-26 14:15:13|3914|3:3|image|utils.pm:delete_computerloadlog_reservation(6829)|removing computerloadlog entries matching loadstate = begin
2011-01-26 14:15:13|3914|3:3|image|utils.pm:delete_computerloadlog_reservation(6876)|deleted rows from computerloadlog for reservation id=3
2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(909)|removed computerloadlog rows with loadstate=begin for reservation
2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(921)|number of database handles state process created: 1
2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(930)|process has a database handle stored in $ENV{dbh}, attempting disconnect
2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(932)|$ENV{dbh}: database disconnect successful
2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(946)|VCL::image process 3914 exiting
2011-01-26 14:15:13|3914|3:3|image|utils.pm:mail(1247)|SUCCESS -- Sending mail To: 0, PROBLEM -- vcld
|3914|3:3|image| ---- CRITICAL ----
|3914|3:3|image| 2011-01-26 14:15:13|3914|3:3|image|vcld:make_new_child(598)|VCL::image object could not be created and initialized
|3914|3:3|image| ( 0) utils.pm, notify (line: 630)
|3914|3:3|image| (-1) vcld, make_new_child (line: 598)
|3914|3:3|image| (-2) vcld, main (line: 342)
2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7338)|called from VCL::vcld::make_new_child(599)
2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7374)|parent: parent reservation ID for this request: 3
2011-01-26 14:15:13|3914|3:3|image|utils.pm:getnewdbh(2761)|unable to use database handle stored in $ENV{dbh}
2011-01-26 14:15:13|3914|3:3|image|utils.pm:getnewdbh(2818)|database handle stored in $ENV{dbh}
2011-01-26 14:15:13|3914|3:3|image|utils.pm:insertloadlog(3933)|inserted computer=8, info, VCL::vcld: switching request state to failed
2011-01-26 14:15:13|3914|3:3|image|utils.pm:update_request_state(2049)|request 3 state updated to: failed, laststate to: image
2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7398)|req=3: request state changed: image->failed, laststate: image->image
2011-01-26 14:15:13|3914|3:3|image|utils.pm:insertloadlog(3933)|inserted computer=8, info, VCL::vcld: request state changed to failed, laststate to image
2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7408)|req=3: computer state not specified, xpbase1 state not changed
2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7426)|req=3: log table id=0, ending set to failed
2011-01-26 14:15:13|3914|3:3|image|utils.pm:insertloadlog(3933)|inserted computer=8, info, VCL::vcld: process exiting
2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7442)|req=3: process exiting
2011-01-26 14:15:13|3514|vcld:REAPER(745)|VCL process exited for reservation 3, PID: 3914, signal: CHLD
2011-01-26 14:15:13|3514|vcld:main(166)|lastcheckin time updated for management node 1: 2011-01-26 14:15:13
2011-01-26 14:15:13|3514|3:3|failed|vcld:main(251)|request deleted
2011-01-26 14:15:18|3514|vcld:main(166)|lastcheckin time updated for management node 1: 2011-01-26 14:15:18
2011-01-26 14:15:23|3514|vcld:main(166)|lastcheckin time updated for management node 1: 2011-01-26 14:15:23
2011-01-26 14:15:28|3514|vcld:main(166)|lastcheckin time updated for management node 1: 2011-01-26 14:15:28
Re: Image Capture issue
Posted by Andy Kurth <an...@ncsu.edu>.
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
> dhayashi@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_kurth@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
>
>
RE: Image Capture issue
Posted by "Hayashi, Daiyu" <dh...@Exchange.FULLERTON.EDU>.
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
dhayashi@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_kurth@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
Re: Image Capture issue
Posted by Andy Kurth <an...@ncsu.edu>.
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
On 1/26/2011 5:54 PM, Hayashi, Daiyu wrote:
> Help – need assistance with VCL 2.2
>
> vHost on ESXi4.1
>
> Issue with Image Capture for Base Image using Windows XP
>
> Error message below-
>
> Thank you,
>
> Daiyu Hayashi
>
> Information Technology Consultant
>
> Mihaylo College of Business and Economics
>
> California State University at Fullerton
>
> dhayashi@fullerton.edu
>
> ------------------------------------------------------------------------------------------------------------------------
>
> [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]: 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): xpbase1
>
> Computer to be captured: xpbase1 (ID: 8)
>
> 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): xpbase1
>
> Added new image to database: 'xpbase1'
>
> image.name: vmwarewinxp-xpbase17-v0
>
> image.id: 7
>
> imagerevision.id: 7
>
> imagemeta.id: 4
>
> resource.id: 20
>
> ----------------------------------------------------------------------------
>
> Inserted imaging request to the database:
>
> request ID: 3
>
> reservation ID: 3
>
> 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 '3:3'
>
> ----------------------------------------------------------------------------
>
> 2011-01-26 14:15:01|3906|utils.pm:setup_get_array_choice(9986)|choices
> argument:
>
> |3906| x86
>
> |3906| x86_64
>
> 2011-01-26 14:15:02|3906|utils.pm:setup_get_array_choice(9986)|choices
> argument:
>
> |3906| Yes
>
> |3906| No
>
> 2011-01-26 14:15:02|3514|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-01-26 14:15:02
>
> 2011-01-26 14:15:07|3514|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-01-26 14:15:07
>
> 2011-01-26 14:15:10|3906|utils.pm:insert_request(8443)|inserted new
> reload request into request table, request id=3
>
> 2011-01-26 14:15:10|3906|utils.pm:insert_request(8474)|inserted new
> reload request into reservation table, reservation id=3
>
> 2011-01-26 14:15:12|3514|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-01-26 14:15:12
>
> 2011-01-26
> 14:15:12|3514|3:3|image|utils.pm:reservation_being_processed(9010)|computerloadlog
> 'begin' entry does NOT exist for reservation 3
>
> 2011-01-26 14:15:13|3514|3:3|image|utils.pm:run_command(9082)|executed
> command: pgrep -fl 'vcld [0-9]+:3 ', pid: 3912, exit status: 1, output:
>
> 2011-01-26
> 14:15:13|3514|3:3|image|utils.pm:is_management_node_process_running(9259)|process
> is NOT running, identifier: 'vcld [0-9]+:3 '
>
> 2011-01-26
> 14:15:13|3514|3:3|image|utils.pm:reservation_being_processed(9031)|reservation
> is NOT currently being processed
>
> 2011-01-26 14:15:13|3514|3:3|image|vcld:main(277)|reservation 3 is NOT
> already being processed
>
> 2011-01-26
> 14:15:13|3514|3:3|image|utils.pm:get_request_info(4589)|standalone
> affiliation found: Local
>
> 2011-01-26 14:15:13|3514|3:3|image|vcld:main(282)|retrieved request
> information from database
>
> 2011-01-26
> 14:15:13|3514|3:3|image|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2011-01-26
> 14:15:13|3514|3:3|image|utils.pm:update_request_state(2049)|request 3
> state updated to: pending, laststate to: image
>
> 2011-01-26 14:15:13|3514|3:3|image|utils.pm:insertloadlog(3933)|inserted
> computer=8, begin, beginning to process, state is image
>
> 2011-01-26 14:15:13|3514|3:3|image|vcld:make_new_child(510)|loaded
> VCL::image module
>
> 2011-01-26 14:15:13|3914|3:3|image|vcld:make_new_child(583)|vcld
> environment variable set to 0 for this process
>
> 2011-01-26 14:15:13|3914|3:3|image|Module.pm:new(134)|constructor
> called, class=VCL::image
>
> 2011-01-26 14:15:13|3914|3:3|image|Module.pm:new(156)|VCL::image object
> created
>
> 2011-01-26 14:15:13|3514|3:3|image|vcld:make_new_child(567)|current
> number of forked kids: 1
>
> 2011-01-26 14:15:13|3914|3:3|image|State.pm:initialize(85)|obtained a
> database handle for this state process, stored as $ENV{dbh}
>
> 2011-01-26 14:15:13|3914|3:3|image|State.pm:check_image_os(836)|no
> corrections need to be made to image OS: vmwarewinxp
>
> 2011-01-26
> 14:15:13|3914|3:3|image|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2011-01-26
> 14:15:13|3914|3:3|image|utils.pm:rename_vcld_process(7183)|reservation
> count: 1
>
> 2011-01-26
> 14:15:13|3914|3:3|image|utils.pm:rename_vcld_process(7202)|PARENTIMAGE: 1
>
> 2011-01-26
> 14:15:13|3914|3:3|image|utils.pm:rename_vcld_process(7203)|SUBIMAGE: 0
>
> 2011-01-26
> 14:15:13|3914|3:3|image|utils.pm:rename_vcld_process(7221)|renamed
> process to 'vcld 3:3 image xpbase1 vmwarewinxp-xpbase17-v0 admin'
>
> 2011-01-26
> 14:15:13|3914|3:3|image|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2011-01-26
> 14:15:13|3914|3:3|image|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2011-01-26 14:15:13|3914|3:3|image|State.pm:initialize(118)|attempting
> to load provisioning module: VCL::Module::Provisioning::VMware::VMware
>
> 2011-01-26
> 14:15:13|3914|3:3|image|State.pm:initialize(124)|VCL::Module::Provisioning::VMware::VMware
> module loaded
>
> 2011-01-26 14:15:13|3914|3:3|image|Module.pm:new(134)|constructor
> called, class=VCL::Module::Provisioning::VMware::VMware
>
> 2011-01-26
> 14:15:13|3914|3:3|image|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VMware
> object created
>
> |3914|3:3|image| ---- WARNING ----
>
> |3914|3:3|image| 2011-01-26
> 14:15:13|3914|3:3|image|DataStructure.pm:_automethod(764)|corresponding
> data has not been initialized for get_vmhost_computer_id:
> $self->request_data->{reservation}{3}{computer}{vmhost}{computerid}
>
> |3914|3:3|image| ( 0) utils.pm, notify (line: 630)
>
> |3914|3:3|image| (-1) DataStructure.pm, _automethod (line: 764)
>
> |3914|3:3|image| (-2) Autoload.pm, __ANON__ (line: 80)
>
> |3914|3:3|image| (-3) VMware.pm, get_vmhost_datastructure (line: 894)
>
> |3914|3:3|image| (-4) VMware.pm, initialize (line: 216)
>
> |3914|3:3|image| (-5) Module.pm, new (line: 159)
>
> |3914|3:3|image| (-6) State.pm, initialize (line: 127)
>
> |3914|3:3|image| ---- WARNING ----
>
> |3914|3:3|image| 2011-01-26
> 14:15:13|3914|3:3|image|State.pm:initialize(132)|provisioning object
> could not be created, returning 0
>
> |3914|3:3|image| ( 0) utils.pm, notify (line: 630)
>
> |3914|3:3|image| (-1) State.pm, initialize (line: 132)
>
> |3914|3:3|image| (-2) Module.pm, new (line: 159)
>
> |3914|3:3|image| (-3) vcld, make_new_child (line: 591)
>
> |3914|3:3|image| (-4) vcld, main (line: 342)
>
> 2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(902)|destructor
> called, ref($self)=VCL::image
>
> 2011-01-26
> 14:15:13|3914|3:3|image|utils.pm:delete_computerloadlog_reservation(6829)|removing
> computerloadlog entries matching loadstate = begin
>
> 2011-01-26
> 14:15:13|3914|3:3|image|utils.pm:delete_computerloadlog_reservation(6876)|deleted
> rows from computerloadlog for reservation id=3
>
> 2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(909)|removed
> computerloadlog rows with loadstate=begin for reservation
>
> 2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(921)|number of
> database handles state process created: 1
>
> 2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(930)|process has a
> database handle stored in $ENV{dbh}, attempting disconnect
>
> 2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(932)|$ENV{dbh}:
> database disconnect successful
>
> 2011-01-26 14:15:13|3914|3:3|image|State.pm:DESTROY(946)|VCL::image
> process 3914 exiting
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:mail(1247)|SUCCESS --
> Sending mail To: 0, PROBLEM -- vcld
>
> |3914|3:3|image| ---- CRITICAL ----
>
> |3914|3:3|image| 2011-01-26
> 14:15:13|3914|3:3|image|vcld:make_new_child(598)|VCL::image object could
> not be created and initialized
>
> |3914|3:3|image| ( 0) utils.pm, notify (line: 630)
>
> |3914|3:3|image| (-1) vcld, make_new_child (line: 598)
>
> |3914|3:3|image| (-2) vcld, main (line: 342)
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7338)|called
> from VCL::vcld::make_new_child(599)
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7374)|parent:
> parent reservation ID for this request: 3
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:getnewdbh(2761)|unable to
> use database handle stored in $ENV{dbh}
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:getnewdbh(2818)|database
> handle stored in $ENV{dbh}
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:insertloadlog(3933)|inserted
> computer=8, info, VCL::vcld: switching request state to failed
>
> 2011-01-26
> 14:15:13|3914|3:3|image|utils.pm:update_request_state(2049)|request 3
> state updated to: failed, laststate to: image
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7398)|req=3:
> request state changed: image->failed, laststate: image->image
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:insertloadlog(3933)|inserted
> computer=8, info, VCL::vcld: request state changed to failed, laststate
> to image
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7408)|req=3:
> computer state not specified, xpbase1 state not changed
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7426)|req=3:
> log table id=0, ending set to failed
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:insertloadlog(3933)|inserted
> computer=8, info, VCL::vcld: process exiting
>
> 2011-01-26 14:15:13|3914|3:3|image|utils.pm:switch_state(7442)|req=3:
> process exiting
>
> 2011-01-26 14:15:13|3514|vcld:REAPER(745)|VCL process exited for
> reservation 3, PID: 3914, signal: CHLD
>
> 2011-01-26 14:15:13|3514|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-01-26 14:15:13
>
> 2011-01-26 14:15:13|3514|3:3|failed|vcld:main(251)|request deleted
>
> 2011-01-26 14:15:18|3514|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-01-26 14:15:18
>
> 2011-01-26 14:15:23|3514|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-01-26 14:15:23
>
> 2011-01-26 14:15:28|3514|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-01-26 14:15:28
>