You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@vcl.apache.org by Hicham Gibet Tani <hg...@gmail.com> on 2011/01/06 13:26:03 UTC
Reservation failed
Hello everybody,
We did fix the problem of copying the VM images.
The image capture return an output describing that the image capture was
successfully using the provisioning engine but after that when the image is
being reloaded the reservation failed.
We tried to access the image from the web browser but it displays that there
is no selection currently available.
Please we need your help!!
Cordially,
Gibet Tani Hicham
Eloutouate Lamiae
Here is the output:
2010-12-27 10:41:04|7331|1:2|image|image.pm:process(165)|vmwarelinux-base9-v3
image was successfully captured by the provisioning module
2010-12-27 10:41:04|7331|1:2|image|image.pm:process(222)|vmwarelinux-base9-v3
image files successfully saved
2010-12-27 10:41:04|7331|1:2|image|utils.pm:update_request_state(2049)|request
1 state updated to: completed, laststate to: image
2010-12-27 10:41:04|7331|1:2|image|image.pm:process(225)|request state
updated to completed, laststate to image
2010-12-27
10:41:04|7331|1:2|image|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
path is not set for the VM profile, using management node install path:
/install/vmware_images
2010-12-27
10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2855)|checking size
of image in image repository:
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3*.vmdk
2010-12-27
10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2870)|retrieved size
of image in image repository: 3587376055
2010-12-27 10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2900)|size
of vmwarelinux-base9-v3 image: 3,587,376,055 bytes (3,421 MB, 3.34 GB)
2010-12-27 10:41:04|7331|1:2|image|image.pm:process(234)|size of
vmwarelinux-base9-v3: 3421
2010-12-27 10:41:04|7331|1:2|image|DataStructure.pm:_automethod(786)|data
structure updated: $self->request_data->{reservation}{2}{image}{size}
|7331|1:2|image| image_size = 3421
2010-12-27 10:41:04|7331|1:2|image|image.pm:process(263)|image and
imagerevision tables updated for image=9, imagerevision=10,
name=vmwarelinux-base9-v3, lastupdate=2010-12-27 10:24:54, deleted=0,
size=3421
|7331|1:2|image| ---- WARNING ----
|7331|1:2|image| 2010-12-27
10:41:04|7331|1:2|image|DataStructure.pm:_automethod(764)|corresponding data
has not been initialized for get_management_node_sysadmin_email:
$ENV{management_node_info}{SYSADMIN_EMAIL}
|7331|1:2|image| ( 0) utils.pm, notify (line: 630)
|7331|1:2|image| (-1) DataStructure.pm, _automethod (line: 764)
|7331|1:2|image| (-2) Autoload.pm, __ANON__ (line: 80)
|7331|1:2|image| (-3) image.pm, reservation_successful (line: 307)
|7331|1:2|image| (-4) image.pm, process (line: 273)
|7331|1:2|image| (-5) vcld, make_new_child (line: 595)
|7331|1:2|image| (-6) vcld, main (line: 342)
2010-12-27 10:41:04|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:04
2010-12-27 10:41:09|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:09
2010-12-27 10:41:14|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:14
2010-12-27 10:41:19|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:19
2010-12-27 10:41:25|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:24
2010-12-27 10:41:30|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:30
2010-12-27 10:41:35|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:35
2010-12-27 10:41:40|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:40
2010-12-27 10:41:45|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:45
2010-12-27 10:41:50|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:50
2010-12-27 10:41:55|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:41:55
2010-12-27 10:42:00|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:00
2010-12-27 10:42:05|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:05
2010-12-27 10:42:10|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:10
2010-12-27 10:42:15|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:15
2010-12-27 10:42:20|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:20
2010-12-27 10:42:25|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:25
2010-12-27 10:42:30|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:30
2010-12-27 10:42:35|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:35
2010-12-27 10:42:40|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:40
2010-12-27 10:42:45|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:45
2010-12-27 10:42:50|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:50
2010-12-27 10:42:55|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:42:55
2010-12-27 10:43:00|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:43:00
2010-12-27 10:43:05|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:43:05
2010-12-27 10:43:10|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:43:10
2010-12-27 10:43:15|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:43:15
2010-12-27 10:43:20|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:43:20
2010-12-27 10:43:22|7331|1:2|image|utils.pm:mail(1247)|SUCCESS -- Sending
mail To: root@localhost, VCL -- No Apps (Linux) Image Creation Succeeded
Use of uninitialized value in substitution (s///) at
/usr/lib/perl5/site_perl/5.8.8/Mail/Mailer/rfc822.pm line 22 (#1)
(W uninitialized) An undefined value was used as if it were already
defined. It was interpreted as a "" or a 0, but maybe it was a mistake.
To suppress this warning assign a defined value to your variables.
To help you figure out what was undefined, perl tells you what operation
you used the undefined value in. Note, however, that perl optimizes
your
program and the operation displayed in the warning may not necessarily
appear literally in your program. For example, "that $foo" is
usually optimized into "that " . $foo, and the warning will refer to
the concatenation (.) operator, even though there is no . in your
program.
|7331|1:2|image| ---- WARNING ----
|7331|1:2|image| 2010-12-27
10:43:22|7331|1:2|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.
|7331|1:2|image| ( 0) utils.pm, notify (line: 630)
|7331|1:2|image| (-1) vcld, warning_handler (line: 637)
|7331|1:2|image| (-2) rfc822.pm, set_headers (line: 22)
|7331|1:2|image| (-3) Mailer.pm, open (line: 162)
|7331|1:2|image| (-4) utils.pm, mail (line: 1241)
|7331|1:2|image| (-5) image.pm, reservation_successful (line: 347)
|7331|1:2|image| (-6) image.pm, process (line: 273)
|7331|1:2|image| ---- WARNING ----
|7331|1:2|image| 2010-12-27
10:43:22|7331|1:2|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.
|7331|1:2|image| ( 0) utils.pm, notify (line: 630)
|7331|1:2|image| (-1) vcld, warning_handler (line: 637)
|7331|1:2|image| (-2) rfc822.pm, set_headers (line: 23)
|7331|1:2|image| (-3) Mailer.pm, open (line: 162)
|7331|1:2|image| (-4) utils.pm, mail (line: 1241)
|7331|1:2|image| (-5) image.pm, reservation_successful (line: 347)
|7331|1:2|image| (-6) image.pm, process (line: 273)
No recipient addresses found in header
|7331|1:2|image| ---- WARNING ----
|7331|1:2|image| 2010-12-27
10:43:22|7331|1:2|image|vcld:warning_handler(637)|Use of uninitialized value
in concatenation (.) or string at
/usr/local/vcl/bin/../lib/VCL/utils.pmline 1247.
|7331|1:2|image| ( 0) utils.pm, notify (line: 630)
|7331|1:2|image| (-1) vcld, warning_handler (line: 637)
|7331|1:2|image| (-2) utils.pm, mail (line: 1247)
|7331|1:2|image| (-3) image.pm, reservation_successful (line: 347)
|7331|1:2|image| (-4) image.pm, process (line: 273)
|7331|1:2|image| (-5) vcld, make_new_child (line: 595)
|7331|1:2|image| (-6) vcld, main (line: 342)
2010-12-27 10:43:22|7331|1:2|image|utils.pm:mail(1247)|SUCCESS -- Sending
mail To: , VCL IMAGE Creation Completed: vmwarelinux-base9-v3
2010-12-27 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
computer=3, loadimagevmware, VCL::utils::insert_reload_request: switching
request state to reload
2010-12-27 10:43:22|7331|1:2|image|utils.pm:update_computer_state(2091)|computer
3 state updated to: reload
2010-12-27 10:43:22|7331|1:2|image|utils.pm:insert_reload_request(8540)|req=1:
setting computerid 3 into reload state
2010-12-27 10:43:22|7331|1:2|image|utils.pm:insert_request(8443)|inserted
new reload request into request table, request id=2
2010-12-27 10:43:22|7331|1:2|image|utils.pm:insert_request(8474)|inserted
new reload request into reservation table, reservation id=3
2010-12-27 10:43:22|7331|1:2|image|utils.pm:insert_reload_request(8550)|req=1:
inserted new reload request, id=3 nodeid=3, imageid=9, imagerevision_id=10
2010-12-27 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
computer=3, info, VCL::utils::insert_reload_request: created new reload
request
2010-12-27 10:43:22|7331|1:2|image|image.pm:reservation_successful(351)|inserted
reload request into database for computer id=3
2010-12-27 10:43:22|7331|1:2|image|utils.pm:switch_state(7338)|called from
VCL::image::reservation_successful(354)
2010-12-27 10:43:22|7331|1:2|image|utils.pm:switch_state(7374)|parent:
parent reservation ID for this request: 2
2010-12-27 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
computer=3, info, VCL::image: switching request state to complete
2010-12-27 10:43:22|7331|1:2|image|utils.pm:update_request_state(2049)|request
1 state updated to: complete, laststate to: image
2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7398)|req=1:
request state changed: image->complete, laststate: image->image
2010-12-27 10:43:23|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
computer=3, info, VCL::image: request state changed to complete, laststate
to image
2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7408)|req=1:
computer state not specified, vmguest-2 state not changed
2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7426)|req=1: log
table id=0, ending set to EOR
2010-12-27 10:43:23|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
computer=3, info, VCL::image: process exiting
2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7442)|req=1:
process exiting
2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(902)|destructor called,
ref($self)=VCL::image
2010-12-27 10:43:23|7331|1:2|image|utils.pm:delete_computerloadlog_reservation(6829)|removing
computerloadlog entries matching loadstate = begin
2010-12-27 10:43:23|7331|1:2|image|utils.pm:delete_computerloadlog_reservation(6876)|deleted
rows from computerloadlog for reservation id=2
2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(909)|removed
computerloadlog rows with loadstate=begin for reservation
2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(921)|number of database
handles state process created: 1
2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(930)|process has a
database handle stored in $ENV{dbh}, attempting disconnect
2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(932)|$ENV{dbh}: database
disconnect successful
2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(946)|VCL::image process
7331 exiting
End Disconnect
2010-12-27 10:43:23|4041|vcld:REAPER(745)|VCL process exited for reservation
2, PID: 7331, signal: CHLD
2010-12-27 10:43:23|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:43:23
2010-12-27 10:43:23|4041|1:2|complete|vcld:main(251)|request deleted
2010-12-27 10:43:23|4041|2:3|reload|utils.pm:reservation_being_processed(9010)|computerloadlog
'begin' entry does NOT exist for reservation 3
2010-12-27 10:43:23|4041|2:3|reload|utils.pm:run_command(9082)|executed
command: pgrep -fl 'vcld [0-9]+:3 ', pid: 8423, exit status: 1, output:
2010-12-27 10:43:23|4041|2:3|reload|utils.pm:is_management_node_process_running(9259)|process
is NOT running, identifier: 'vcld [0-9]+:3 '
2010-12-27 10:43:23|4041|2:3|reload|utils.pm:reservation_being_processed(9031)|reservation
is NOT currently being processed
2010-12-27 10:43:23|4041|2:3|reload|vcld:main(277)|reservation 3 is NOT
already being processed
2010-12-27 10:43:23|4041|2:3|reload|utils.pm:get_request_info(4589)|standalone
affiliation found: Local
2010-12-27 10:43:23|4041|2:3|reload|utils.pm:get_request_info(4596)|found
NULL uid setting standalone flag: vclreload, uid: NULL
2010-12-27 10:43:23|4041|2:3|reload|vcld:main(282)|retrieved request
information from database
2010-12-27
10:43:23|4041|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-27 10:43:23|4041|2:3|reload|utils.pm:update_request_state(2049)|request
2 state updated to: pending, laststate to: reload
2010-12-27 10:43:23|4041|2:3|reload|utils.pm:insertloadlog(3933)|inserted
computer=3, begin, beginning to process, state is reload
2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(502)|request will be
processed by new.pm
2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(510)|loaded VCL::new
module
2010-12-27 10:43:23|8437|2:3|reload|vcld:make_new_child(583)|vcld
environment variable set to 0 for this process
2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(567)|current number
of forked kids: 1
2010-12-27 10:43:23|8437|2:3|reload|Module.pm:new(134)|constructor called,
class=VCL::new
2010-12-27 10:43:23|8437|2:3|reload|Module.pm:new(156)|VCL::new object
created
2010-12-27 10:43:23|8437|2:3|reload|State.pm:initialize(85)|obtained a
database handle for this state process, stored as $ENV{dbh}
2010-12-27 10:43:23|8437|2:3|reload|State.pm:check_image_os(817)|no
corrections need to be made, not an imaging request, returning 1
2010-12-27
10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-27 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7183)|reservation
count: 1
2010-12-27 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7202)|PARENTIMAGE:
1
2010-12-27 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7203)|SUBIMAGE:
0
2010-12-27 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7221)|renamed
process to 'vcld 2:3 reload vmguest-2 vmwarelinux-base9-v3 vclreload'
2010-12-27
10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-27
10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-27 10:43:23|8437|2:3|reload|State.pm:initialize(118)|attempting to
load provisioning module: VCL::Module::Provisioning::VMware::VMware
2010-12-27
10:43:24|8437|2:3|reload|State.pm:initialize(124)|VCL::Module::Provisioning::VMware::VMware
module loaded
2010-12-27 10:43:24|8437|2:3|reload|Module.pm:new(134)|constructor called,
class=VCL::Module::Provisioning::VMware::VMware
2010-12-27
10:43:24|8437|2:3|reload|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VMware
object created
2010-12-27
10:43:24|8437|2:3|reload|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 1
2010-12-27
10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: localvmhost
2010-12-27
10:43:24|8437|2:3|reload|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 1
2010-12-27
10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: localvmhost
2010-12-27
10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1027)|attempting to
load VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
2010-12-27
10:43:25|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1033)|loaded VMware
control module: VCL::Module::Provisioning::VMware::vSphere_SDK
2010-12-27 10:43:25|8437|2:3|reload|Module.pm:new(134)|constructor called,
class=VCL::Module::Provisioning::VMware::vSphere_SDK
2010-12-27
10:43:25|8437|2:3|reload|Module.pm:new(156)|VCL::Module::Provisioning::VMware::vSphere_SDK
object created
2010-12-27
10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1816)|attempting to
connect to VM host: https://localvmhost/sdk
2010-12-27 10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1822)|unable
to connect to VM host: https://localvmhost/sdk, username: 'root', error:
|8437|2:3|reload| Error: Server version unavailable at '
https://localvmhost/sdk/vimService.wsdl'
2010-12-27
10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1816)|attempting to
connect to VM host: https://localvmhost:8333/sdk
2010-12-27 10:43:28|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:43:28
2010-12-27 10:43:33|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:43:33
2010-12-27
10:43:37|8437|2:3|reload|vSphere_SDK.pm:initialize(1826)|connected to VM
host: https://localvmhost:8333/sdk
2010-12-27
10:43:37|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1046)|created API
object: VCL::Module::Provisioning::VMware::vSphere_SDK
2010-12-27
10:43:37|8437|2:3|reload|vSphere_SDK.pm:is_restricted(1079)|access to the VM
host via the vSphere SDK is NOT restricted due to the license
2010-12-27 10:43:37|8437|2:3|reload|VMware.pm:initialize(229)|vSphere SDK
object will be used to control the VM: vmguest-2, and to control the OS of
the VM host: localvmhost
2010-12-27
10:43:37|8437|2:3|reload|vSphere_SDK.pm:get_vmware_product_name(955)|VMware
product being used on VM host localvmhost: 'VMware Server 2.0.2
build-203138'
2010-12-27 10:43:37|8437|2:3|reload|vSphere_SDK.pm:file_exists(1558)|file
(datastore root) exists: [standard]
2010-12-27 10:43:37|8437|2:3|reload|VMware.pm:initialize(294)|VMware
provisioning object initialized:
|8437|2:3|reload| VM host OS object type:
VCL::Module::Provisioning::VMware::vSphere_SDK
|8437|2:3|reload| API object type:
VCL::Module::Provisioning::VMware::vSphere_SDK
2010-12-27
10:43:37|8437|2:3|reload|State.pm:initialize(128)|VCL::Module::Provisioning::VMware::VMware
provisioner object created
2010-12-27 10:43:37|8437|2:3|reload|State.pm:initialize(142)|attempting to
load OS module: VCL::Module::OS::Linux
2010-12-27
10:43:38|8437|2:3|reload|State.pm:initialize(148)|VCL::Module::OS::Linux
module loaded
2010-12-27 10:43:38|8437|2:3|reload|Module.pm:new(134)|constructor called,
class=VCL::Module::OS::Linux
2010-12-27
10:43:38|8437|2:3|reload|Module.pm:new(156)|VCL::Module::OS::Linux object
created
2010-12-27
10:43:38|8437|2:3|reload|State.pm:initialize(151)|VCL::Module::OS::Linux OS
object created
2010-12-27 10:43:38|8437|2:3|reload|State.pm:initialize(166)|returning 1
2010-12-27 10:43:38|8437|2:3|reload|vcld:make_new_child(592)|VCL::new object
created and initialized
2010-12-27
10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-27
10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vmguest-2 from the database
2010-12-27
10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vmguest-2 from the database: reload
2010-12-27 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{3}{computer}{state}{name}
|8437|2:3|reload| computer_state_name = reload
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
variable: 1
2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(133)|reservation is
parent = 1
2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(134)|preload only = 0
2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(135)|originating request
state = reload
2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(136)|originating request
laststate = image
2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(137)|originating computer
state = reload
2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(138)|originating computer
type = virtualmachine
2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(167)|request_state_name
is not new
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:is_inblockrequest(6250)|zero
rows were returned from database select
2010-12-27
10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-27
10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vmguest-2 from the database
2010-12-27
10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vmguest-2 from the database: reload
2010-12-27 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{3}{computer}{state}{name}
|8437|2:3|reload| computer_state_name = reload
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
variable: 1
2010-12-27 10:43:38|8437|2:3|reload|new.pm:computer_not_being_used(787)|vmguest-2
state is reload
2010-12-27 10:43:38|8437|2:3|reload|new.pm:computer_not_being_used(797)|vmguest-2
is available, its state is reload
2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(186)|vmguest-2 is not
being used
2010-12-27
10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-27
10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vmguest-2 from the database
2010-12-27
10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vmguest-2 from the database: reload
2010-12-27 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{3}{computer}{state}{name}
|8437|2:3|reload| computer_state_name = reload
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
variable: 1
2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(529)|calling
VCL::Module::Provisioning::VMware::VMware->node_status()
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
computer=3, statuscheck, checking status of node
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vmguest-2
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vmguest-2
2010-12-27 10:43:38|8437|2:3|reload|OS.pm:is_ssh_responding(416)|vmguest-2
is NOT responding to SSH, ports 22 or 24 are both closed
2010-12-27 10:43:38|8437|2:3|reload|VMware.pm:node_status(738)|VM vmguest-2
is not responding to SSH, returning 'RELOAD'
2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(544)|node_status
returned a hash reference
2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(549)|node_status
hash reference contains key {status}=RELOAD
2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(591)|request state
is reload, node will be reloaded regardless of status
2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(624)|node status is
reload, vmguest-2 will be reloaded
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
computer=3, loadimageblade, vmguest-2 must be reloaded with
vmwarelinux-base9-v3
2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(638)|calling
VCL::Module::Provisioning::VMware::VMware->does_image_exist()
|8437|2:3|reload| ---- WARNING ----
|8437|2:3|reload| 2010-12-27
10:43:38|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
to determine relative datastore path: '/var/lib/vmware/Virtual\
Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk', path argument does
not begin with any of the following:
|8437|2:3|reload| '[standard]'
|8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
|8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path (line:
2584)
|8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
|8437|2:3|reload| (-3) vSphere_SDK.pm, file_exists (line: 1550)
|8437|2:3|reload| (-4) VMware.pm, does_image_exist (line: 2935)
|8437|2:3|reload| (-5) new.pm, reload_image (line: 640)
|8437|2:3|reload| (-6) new.pm, process (line: 282)
|8437|2:3|reload| ---- WARNING ----
|8437|2:3|reload| 2010-12-27
10:43:38|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable to
determine datastore path, failed to determine relative datastore path:
/var/lib/vmware/Virtual\
Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
|8437|2:3|reload| (-2) vSphere_SDK.pm, file_exists (line: 1550)
|8437|2:3|reload| (-3) VMware.pm, does_image_exist (line: 2935)
|8437|2:3|reload| (-4) new.pm, reload_image (line: 640)
|8437|2:3|reload| (-5) new.pm, process (line: 282)
|8437|2:3|reload| (-6) vcld, make_new_child (line: 595)
2010-12-27 10:43:38|8437|2:3|reload|VMware.pm:does_image_exist(2940)|image
does not exist in the non-persistent directory on the VM host, checking the
image repository
2010-12-27
10:43:38|8437|2:3|reload|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
path is not set for the VM profile, using management node install path:
/install/vmware_images
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:run_command(9082)|executed
command: find "/install/vmware_images/vmwarelinux-base9-v3" -iname
"vmwarelinux-base9-v3.vmdk", pid: 8453, exit status: 0, output:
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
2010-12-27 10:43:38|8437|2:3|reload|VMware.pm:does_image_exist(2959)|image
exists in the image repository:
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(641)|vmwarelinux-base9-v3
exists on this management node
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
computer=3, doesimageexists, confirmed image exists
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:update_computer_state(2091)|computer
3 state updated to: reloading
2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(674)|computer
vmguest-2 state set to reloading
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
computer=3, info, computer state updated to reloading
2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(685)|calling
VCL::Module::Provisioning::VMware::VMware->load() subroutine
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
computer=3, info, calling VCL::Module::Provisioning::VMware::VMware->load()
subroutine
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
computer=3, doesimageexists, image exists vmwarelinux-base9-v3
2010-12-27 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
computer=3, startload, vmguest-2 vmwarelinux-base9-v3
2010-12-27
10:43:38|8437|2:3|reload|VMware.pm:get_vmx_file_paths(3332)|attempting to
find existing vmx files on the VM host
2010-12-27 10:43:38|4041|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-27 10:43:38
2010-12-27
10:43:39|8437|2:3|reload|vSphere_SDK.pm:get_file_info(1937)|searching for
matching file paths: base directory path: '[standard]', search pattern:
'*.vmx'
2010-12-27 10:43:39|8437|2:3|reload|vSphere_SDK.pm:find_files(1705)|matching
file count: 1
2010-12-27
10:43:39|8437|2:3|reload|vSphere_SDK.pm:get_registered_vms(103)|found 1
registered VMs:
|8437|2:3|reload| /var/lib/vmware/Virtual
Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
2010-12-27 10:43:39|8437|2:3|reload|VMware.pm:get_vmx_file_paths(3343)|found
1 unique vmx files on VM host:
|8437|2:3|reload| /var/lib/vmware/Virtual
Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
2010-12-27
10:43:40|8437|2:3|reload|vSphere_SDK.pm:get_registered_vms(103)|found 1
registered VMs:
|8437|2:3|reload| /var/lib/vmware/Virtual
Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
2010-12-27
10:43:40|8437|2:3|reload|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vmwarelinux-base8-v1
2010-12-27
10:43:40|8437|2:3|reload|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
path is not set for the VM profile, using management node install path:
/install/vmware_images
|8437|2:3|reload| ---- WARNING ----
|8437|2:3|reload| 2010-12-27
10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
to determine relative datastore path: '/var/lib/vmware/Virtual\
Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk', path argument does
not begin with any of the following:
|8437|2:3|reload| '[standard]'
|8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
|8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path (line:
2584)
|8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
|8437|2:3|reload| (-3) vSphere_SDK.pm, file_exists (line: 1550)
|8437|2:3|reload| (-4) VMware.pm, prepare_vmdk (line: 1451)
|8437|2:3|reload| (-5) VMware.pm, load (line: 334)
|8437|2:3|reload| (-6) new.pm, reload_image (line: 687)
|8437|2:3|reload| ---- WARNING ----
|8437|2:3|reload| 2010-12-27
10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable to
determine datastore path, failed to determine relative datastore path:
/var/lib/vmware/Virtual\
Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
|8437|2:3|reload| (-2) vSphere_SDK.pm, file_exists (line: 1550)
|8437|2:3|reload| (-3) VMware.pm, prepare_vmdk (line: 1451)
|8437|2:3|reload| (-4) VMware.pm, load (line: 334)
|8437|2:3|reload| (-5) new.pm, reload_image (line: 687)
|8437|2:3|reload| (-6) new.pm, process (line: 282)
2010-12-27 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1468)|vmdk file
does NOT exist on VM host: /var/lib/vmware/Virtual\
Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
2010-12-27 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1554)|found 12
vmdk files in image repository directory:
'/install/vmware_images/vmwarelinux-base9-v3':
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s002.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s003.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s004.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s005.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s006.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s007.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s008.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s009.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s010.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s011.vmdk
|8437|2:3|reload|
/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
|8437|2:3|reload| ---- WARNING ----
|8437|2:3|reload| 2010-12-27
10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
to determine relative datastore path: '/var/lib/vmware/Virtual\
Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk', path argument
does not begin with any of the following:
|8437|2:3|reload| '[standard]'
|8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
|8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path (line:
2584)
|8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
|8437|2:3|reload| (-3) vSphere_SDK.pm, copy_file_to (line: 1296)
|8437|2:3|reload| (-4) VMware.pm, prepare_vmdk (line: 1560)
|8437|2:3|reload| (-5) VMware.pm, load (line: 334)
|8437|2:3|reload| (-6) new.pm, reload_image (line: 687)
|8437|2:3|reload| ---- WARNING ----
|8437|2:3|reload| 2010-12-27
10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable to
determine datastore path, failed to determine relative datastore path:
/var/lib/vmware/Virtual\
Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
|8437|2:3|reload| (-2) vSphere_SDK.pm, copy_file_to (line: 1296)
|8437|2:3|reload| (-3) VMware.pm, prepare_vmdk (line: 1560)
|8437|2:3|reload| (-4) VMware.pm, load (line: 334)
|8437|2:3|reload| (-5) new.pm, reload_image (line: 687)
|8437|2:3|reload| (-6) new.pm, process (line: 282)
|8437|2:3|reload| ---- WARNING ----
|8437|2:3|reload| 2010-12-27
10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1561)|failed to copy vmdk
file from the repository to the VM host:
'/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk'
--> '/var/lib/vmware/Virtual\
Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk'
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) VMware.pm, prepare_vmdk (line: 1561)
|8437|2:3|reload| (-2) VMware.pm, load (line: 334)
|8437|2:3|reload| (-3) new.pm, reload_image (line: 687)
|8437|2:3|reload| (-4) new.pm, process (line: 282)
|8437|2:3|reload| (-5) vcld, make_new_child (line: 595)
|8437|2:3|reload| (-6) vcld, main (line: 342)
|8437|2:3|reload| ---- WARNING ----
|8437|2:3|reload| 2010-12-27
10:43:40|8437|2:3|reload|VMware.pm:load(335)|failed to prepare vmdk file for
vmguest-2 on VM host: localvmhost
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) VMware.pm, load (line: 335)
|8437|2:3|reload| (-2) new.pm, reload_image (line: 687)
|8437|2:3|reload| (-3) new.pm, process (line: 282)
|8437|2:3|reload| (-4) vcld, make_new_child (line: 595)
|8437|2:3|reload| (-5) vcld, main (line: 342)
|8437|2:3|reload| ---- WARNING ----
|8437|2:3|reload| 2010-12-27
10:43:40|8437|2:3|reload|new.pm:reload_image(692)|vmwarelinux-base9-v3
failed to load on vmguest-2, returning
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) new.pm, reload_image (line: 692)
|8437|2:3|reload| (-2) new.pm, process (line: 282)
|8437|2:3|reload| (-3) vcld, make_new_child (line: 595)
|8437|2:3|reload| (-4) vcld, main (line: 342)
2010-12-27 10:43:40|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
computer=3, loadimagefailed, vmwarelinux-base9-v3 failed to load on
vmguest-2
|8437|2:3|reload| ---- WARNING ----
|8437|2:3|reload| 2010-12-27
10:43:40|8437|2:3|reload|new.pm:process(329)|failed
to load vmguest-2 with vmwarelinux-base9-v3
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) new.pm, process (line: 329)
|8437|2:3|reload| (-2) vcld, make_new_child (line: 595)
|8437|2:3|reload| (-3) vcld, main (line: 342)
2010-12-27
10:43:40|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vmguest-2 from the database
2010-12-27
10:43:40|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vmguest-2 from the database: reloading
2010-12-27 10:43:40|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{3}{computer}{state}{name}
|8437|2:3|reload| computer_state_name = reloading
2010-12-27 10:43:40|8437|2:3|reload|utils.pm:mail(1247)|SUCCESS -- Sending
mail To: 0, PROBLEM -- State.pm
|8437|2:3|reload| ---- CRITICAL ----
|8437|2:3|reload| 2010-12-27
10:43:40|8437|2:3|reload|State.pm:reservation_failed(287)|reservation failed
on vmguest-2: process failed after trying to load or make available
|8437|2:3|reload| ( 0) utils.pm, notify (line: 630)
|8437|2:3|reload| (-1) State.pm, reservation_failed (line: 287)
|8437|2:3|reload| (-2) new.pm, process (line: 332)
|8437|2:3|reload| (-3) vcld, make_new_child (line: 595)
|8437|2:3|reload| (-4) vcld, main (line: 342)
2010-12-27 10:43:40|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
computer=3, failed, process failed after trying to load or make available
2010-12-27
10:43:40|8437|2:3|reload|State.pm:reservation_failed(290)|inserted
computerloadlog entry
2010-12-27 10:43:40|8437|2:3|reload|utils.pm:update_computer_state(2091)|computer
3 state updated to: failed
2010-12-27
10:43:40|8437|2:3|reload|State.pm:reservation_failed(309)|computer vmguest-2
(3) state set to failed
2010-12-27 10:43:40|8437|2:3|reload|utils.pm:update_request_state(2049)|request
2 state updated to: failed, laststate to: image
2010-12-27 10:43:40|8437|2:3|reload|State.pm:reservation_failed(322)|set
request state to 'failed'/'image'
2010-12-27 10:43:40|8437|2:3|reload|utils.pm:is_inblockrequest(6250)|zero
rows were returned from database select
2010-12-27
10:43:40|8437|2:3|reload|State.pm:reservation_failed(340)|vmguest-2 is NOT
in blockcomputers table
2010-12-27 10:43:40|8437|2:3|reload|State.pm:reservation_failed(343)|exiting
1
2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(902)|destructor called,
ref($self)=VCL::new
2010-12-27 10:43:40|8437|2:3|reload|utils.pm:delete_computerloadlog_reservation(6829)|removing
computerloadlog entries matching loadstate = begin
2010-12-27 10:43:40|8437|2:3|reload|utils.pm:delete_computerloadlog_reservation(6876)|deleted
rows from computerloadlog for reservation id=3
2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(909)|removed
computerloadlog rows with loadstate=begin for reservation
2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(921)|number of database
handles state process created: 1
2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(930)|process has a
database handle stored in $ENV{dbh}, attempting disconnect
2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(932)|$ENV{dbh}:
database disconnect successful
2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(946)|VCL::new process
8437 exiting
End Disconnect
Re: Reservation failed
Posted by Hicham Gibet Tani <hg...@gmail.com>.
Andy,
We are using VMware Server 2.0.2.
Cordially,
GIBET TANI Hicham
Re: Reservation failed
Posted by Andy Kurth <an...@ncsu.edu>.
Hello,
Sorry for the delay. The "unable to determine datastore path" is a
problem. What version of VMware are you using?
-Andy
On 1/6/2011 7:26 AM, Hicham Gibet Tani wrote:
> Hello everybody,
>
> We did fix the problem of copying the VM images.
>
>
> The image capture return an output describing that the image capture was
> successfully using the provisioning engine but after that when the image
> is being reloaded the reservation failed.
>
>
> We tried to access the image from the web browser but it displays that
> there is no selection currently available.
>
>
> Please we need your help!!
>
>
> Cordially,
>
> Gibet Tani Hicham
>
> Eloutouate Lamiae
>
>
> Here is the output:
>
> 2010-12-27
> 10:41:04|7331|1:2|image|image.pm:process(165)|vmwarelinux-base9-v3 image
> was successfully captured by the provisioning module
>
> 2010-12-27
> 10:41:04|7331|1:2|image|image.pm:process(222)|vmwarelinux-base9-v3 image
> files successfully saved
>
> 2010-12-27
> 10:41:04|7331|1:2|image|utils.pm:update_request_state(2049)|request 1
> state updated to: completed, laststate to: image
>
> 2010-12-27 10:41:04|7331|1:2|image|image.pm:process(225)|request state
> updated to completed, laststate to image
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
> path is not set for the VM profile, using management node install path:
> /install/vmware_images
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2855)|checking
> size of image in image repository:
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3*.vmdk
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2870)|retrieved
> size of image in image repository: 3587376055
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2900)|size of
> vmwarelinux-base9-v3 image: 3,587,376,055 bytes (3,421 MB, 3.34 GB)
>
> 2010-12-27 10:41:04|7331|1:2|image|image.pm:process(234)|size of
> vmwarelinux-base9-v3: 3421
>
> 2010-12-27
> 10:41:04|7331|1:2|image|DataStructure.pm:_automethod(786)|data structure
> updated: $self->request_data->{reservation}{2}{image}{size}
>
> |7331|1:2|image| image_size = 3421
>
> 2010-12-27 10:41:04|7331|1:2|image|image.pm:process(263)|image and
> imagerevision tables updated for image=9, imagerevision=10,
> name=vmwarelinux-base9-v3, lastupdate=2010-12-27 10:24:54, deleted=0,
> size=3421
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:41:04|7331|1:2|image|DataStructure.pm:_automethod(764)|corresponding
> data has not been initialized for get_management_node_sysadmin_email:
> $ENV{management_node_info}{SYSADMIN_EMAIL}
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) DataStructure.pm, _automethod (line: 764)
>
> |7331|1:2|image| (-2) Autoload.pm, __ANON__ (line: 80)
>
> |7331|1:2|image| (-3) image.pm <http://image.pm/>,
> reservation_successful (line: 307)
>
> |7331|1:2|image| (-4) image.pm <http://image.pm/>, process (line: 273)
>
> |7331|1:2|image| (-5) vcld, make_new_child (line: 595)
>
> |7331|1:2|image| (-6) vcld, main (line: 342)
>
> 2010-12-27 10:41:04|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:04
>
> 2010-12-27 10:41:09|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:09
>
> 2010-12-27 10:41:14|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:14
>
> 2010-12-27 10:41:19|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:19
>
> 2010-12-27 10:41:25|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:24
>
> 2010-12-27 10:41:30|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:30
>
> 2010-12-27 10:41:35|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:35
>
> 2010-12-27 10:41:40|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:40
>
> 2010-12-27 10:41:45|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:45
>
> 2010-12-27 10:41:50|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:50
>
> 2010-12-27 10:41:55|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:55
>
> 2010-12-27 10:42:00|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:00
>
> 2010-12-27 10:42:05|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:05
>
> 2010-12-27 10:42:10|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:10
>
> 2010-12-27 10:42:15|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:15
>
> 2010-12-27 10:42:20|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:20
>
> 2010-12-27 10:42:25|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:25
>
> 2010-12-27 10:42:30|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:30
>
> 2010-12-27 10:42:35|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:35
>
> 2010-12-27 10:42:40|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:40
>
> 2010-12-27 10:42:45|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:45
>
> 2010-12-27 10:42:50|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:50
>
> 2010-12-27 10:42:55|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:55
>
> 2010-12-27 10:43:00|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:00
>
> 2010-12-27 10:43:05|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:05
>
> 2010-12-27 10:43:10|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:10
>
> 2010-12-27 10:43:15|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:15
>
> 2010-12-27 10:43:20|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:20
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:mail(1247)|SUCCESS --
> Sending mail To: root@localhost, VCL -- No Apps (Linux) Image Creation
> Succeeded
>
> Use of uninitialized value in substitution (s///) at
>
> /usr/lib/perl5/site_perl/5.8.8/Mail/Mailer/rfc822.pm <http://rfc822.pm/>
> line 22 (#1)
>
> (W uninitialized) An undefined value was used as if it were already
>
> defined.It was interpreted as a "" or a 0, but maybe it was a mistake.
>
> To suppress this warning assign a defined value to your variables.
>
> To help you figure out what was undefined, perl tells you what operation
>
> you used the undefined value in.Note, however, that perl optimizes your
>
> program and the operation displayed in the warning may not necessarily
>
> appear literally in your program.For example, "that $foo" is
>
> usually optimized into "that " . $foo, and the warning will refer to
>
> the concatenation (.) operator, even though there is no . in your
>
> program.
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:43:22|7331|1:2|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 <http://rfc822.pm/>
> line 22.
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) vcld, warning_handler (line: 637)
>
> |7331|1:2|image| (-2) rfc822.pm <http://rfc822.pm/>, set_headers (line: 22)
>
> |7331|1:2|image| (-3) Mailer.pm, open (line: 162)
>
> |7331|1:2|image| (-4) utils.pm <http://utils.pm/>, mail (line: 1241)
>
> |7331|1:2|image| (-5) image.pm <http://image.pm/>,
> reservation_successful (line: 347)
>
> |7331|1:2|image| (-6) image.pm <http://image.pm/>, process (line: 273)
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:43:22|7331|1:2|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 <http://rfc822.pm/>
> line 23.
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) vcld, warning_handler (line: 637)
>
> |7331|1:2|image| (-2) rfc822.pm <http://rfc822.pm/>, set_headers (line: 23)
>
> |7331|1:2|image| (-3) Mailer.pm, open (line: 162)
>
> |7331|1:2|image| (-4) utils.pm <http://utils.pm/>, mail (line: 1241)
>
> |7331|1:2|image| (-5) image.pm <http://image.pm/>,
> reservation_successful (line: 347)
>
> |7331|1:2|image| (-6) image.pm <http://image.pm/>, process (line: 273)
>
> No recipient addresses found in header
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:43:22|7331|1:2|image|vcld:warning_handler(637)|Use of uninitialized
> value in concatenation (.) or string at
> /usr/local/vcl/bin/../lib/VCL/utils.pm <http://utils.pm/> line 1247.
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) vcld, warning_handler (line: 637)
>
> |7331|1:2|image| (-2) utils.pm <http://utils.pm/>, mail (line: 1247)
>
> |7331|1:2|image| (-3) image.pm <http://image.pm/>,
> reservation_successful (line: 347)
>
> |7331|1:2|image| (-4) image.pm <http://image.pm/>, process (line: 273)
>
> |7331|1:2|image| (-5) vcld, make_new_child (line: 595)
>
> |7331|1:2|image| (-6) vcld, main (line: 342)
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:mail(1247)|SUCCESS --
> Sending mail To: , VCL IMAGE Creation Completed: vmwarelinux-base9-v3
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, loadimagevmware, VCL::utils::insert_reload_request:
> switching request state to reload
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:update_computer_state(2091)|computer 3
> state updated to: reload
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_reload_request(8540)|req=1:
> setting computerid 3 into reload state
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_request(8443)|inserted new
> reload request into request table, request id=2
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_request(8474)|inserted new
> reload request into reservation table, reservation id=3
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_reload_request(8550)|req=1:
> inserted new reload request, id=3 nodeid=3, imageid=9, imagerevision_id=10
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::utils::insert_reload_request: created new reload
> request
>
> 2010-12-27
> 10:43:22|7331|1:2|image|image.pm:reservation_successful(351)|inserted
> reload request into database for computer id=3
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:switch_state(7338)|called
> from VCL::image::reservation_successful(354)
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:switch_state(7374)|parent:
> parent reservation ID for this request: 2
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::image: switching request state to complete
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:update_request_state(2049)|request 1
> state updated to: complete, laststate to: image
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7398)|req=1:
> request state changed: image->complete, laststate: image->image
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::image: request state changed to complete,
> laststate to image
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7408)|req=1:
> computer state not specified, vmguest-2 state not changed
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7426)|req=1:
> log table id=0, ending set to EOR
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::image: process exiting
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7442)|req=1:
> process exiting
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(902)|destructor
> called, ref($self)=VCL::image
>
> 2010-12-27
> 10:43:23|7331|1:2|image|utils.pm:delete_computerloadlog_reservation(6829)|removing
> computerloadlog entries matching loadstate = begin
>
> 2010-12-27
> 10:43:23|7331|1:2|image|utils.pm:delete_computerloadlog_reservation(6876)|deleted
> rows from computerloadlog for reservation id=2
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(909)|removed
> computerloadlog rows with loadstate=begin for reservation
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(921)|number of
> database handles state process created: 1
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(930)|process has a
> database handle stored in $ENV{dbh}, attempting disconnect
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(932)|$ENV{dbh}:
> database disconnect successful
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(946)|VCL::image
> process 7331 exiting
>
> End Disconnect
>
> 2010-12-27 10:43:23|4041|vcld:REAPER(745)|VCL process exited for
> reservation 2, PID: 7331, signal: CHLD
>
> 2010-12-27 10:43:23|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:23
>
> 2010-12-27 10:43:23|4041|1:2|complete|vcld:main(251)|request deleted
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:reservation_being_processed(9010)|computerloadlog
> 'begin' entry does NOT exist for reservation 3
>
> 2010-12-27 10:43:23|4041|2:3|reload|utils.pm:run_command(9082)|executed
> command: pgrep -fl 'vcld [0-9]+:3 ', pid: 8423, exit status: 1, output:
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:is_management_node_process_running(9259)|process
> is NOT running, identifier: 'vcld [0-9]+:3 '
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:reservation_being_processed(9031)|reservation
> is NOT currently being processed
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:main(277)|reservation 3 is NOT
> already being processed
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:get_request_info(4589)|standalone
> affiliation found: Local
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:get_request_info(4596)|found NULL uid
> setting standalone flag: vclreload, uid: NULL
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:main(282)|retrieved request
> information from database
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:update_request_state(2049)|request 2
> state updated to: pending, laststate to: reload
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, begin, beginning to process, state is reload
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(502)|request
> will be processed by new.pm <http://new.pm/>
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(510)|loaded
> VCL::new module
>
> 2010-12-27 10:43:23|8437|2:3|reload|vcld:make_new_child(583)|vcld
> environment variable set to 0 for this process
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(567)|current
> number of forked kids: 1
>
> 2010-12-27 10:43:23|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::new
>
> 2010-12-27 10:43:23|8437|2:3|reload|Module.pm:new(156)|VCL::new object
> created
>
> 2010-12-27 10:43:23|8437|2:3|reload|State.pm:initialize(85)|obtained a
> database handle for this state process, stored as $ENV{dbh}
>
> 2010-12-27 10:43:23|8437|2:3|reload|State.pm:check_image_os(817)|no
> corrections need to be made, not an imaging request, returning 1
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7183)|reservation
> count: 1
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7202)|PARENTIMAGE: 1
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7203)|SUBIMAGE: 0
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7221)|renamed
> process to 'vcld 2:3 reload vmguest-2 vmwarelinux-base9-v3 vclreload'
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27 10:43:23|8437|2:3|reload|State.pm:initialize(118)|attempting
> to load provisioning module: VCL::Module::Provisioning::VMware::VMware
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|State.pm:initialize(124)|VCL::Module::Provisioning::VMware::VMware
> module loaded
>
> 2010-12-27 10:43:24|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::Module::Provisioning::VMware::VMware
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VMware
> object created
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|DataStructure.pm:_initialize(594)|computer ID
> argument was specified, retrieving data for computer ID: 1
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_datastructure(923)|created
> DataStructure object for VM host: localvmhost
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|DataStructure.pm:_initialize(594)|computer ID
> argument was specified, retrieving data for computer ID: 1
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_datastructure(923)|created
> DataStructure object for VM host: localvmhost
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1027)|attempting to
> load VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1033)|loaded
> VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27 10:43:25|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|Module.pm:new(156)|VCL::Module::Provisioning::VMware::vSphere_SDK
> object created
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1816)|attempting to
> connect to VM host: https://localvmhost/sdk
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1822)|unable to
> connect to VM host: https://localvmhost/sdk, username: 'root', error:
>
> |8437|2:3|reload| Error: Server version unavailable at
> 'https://localvmhost/sdk/vimService.wsdl'
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1816)|attempting to
> connect to VM host: https://localvmhost:8333/sdk
>
> 2010-12-27 10:43:28|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:28
>
> 2010-12-27 10:43:33|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:33
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:initialize(1826)|connected to VM
> host: https://localvmhost:8333/sdk
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1046)|created
> API object: VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:is_restricted(1079)|access to
> the VM host via the vSphere SDK is NOT restricted due to the license
>
> 2010-12-27 10:43:37|8437|2:3|reload|VMware.pm:initialize(229)|vSphere
> SDK object will be used to control the VM: vmguest-2, and to control the
> OS of the VM host: localvmhost
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:get_vmware_product_name(955)|VMware
> product being used on VM host localvmhost: 'VMware Server 2.0.2
> build-203138'
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:file_exists(1558)|file
> (datastore root) exists: [standard]
>
> 2010-12-27 10:43:37|8437|2:3|reload|VMware.pm:initialize(294)|VMware
> provisioning object initialized:
>
> |8437|2:3|reload| VM host OS object type:
> VCL::Module::Provisioning::VMware::vSphere_SDK
>
> |8437|2:3|reload| API object type:
> VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|State.pm:initialize(128)|VCL::Module::Provisioning::VMware::VMware
> provisioner object created
>
> 2010-12-27 10:43:37|8437|2:3|reload|State.pm:initialize(142)|attempting
> to load OS module: VCL::Module::OS::Linux
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|State.pm:initialize(148)|VCL::Module::OS::Linux
> module loaded
>
> 2010-12-27 10:43:38|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::Module::OS::Linux
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|Module.pm:new(156)|VCL::Module::OS::Linux
> object created
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|State.pm:initialize(151)|VCL::Module::OS::Linux
> OS object created
>
> 2010-12-27 10:43:38|8437|2:3|reload|State.pm:initialize(166)|returning 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|vcld:make_new_child(592)|VCL::new
> object created and initialized
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
> variable: 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(133)|reservation is
> parent = 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(134)|preload only = 0
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(135)|originating
> request state = reload
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(136)|originating
> request laststate = image
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(137)|originating
> computer state = reload
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(138)|originating
> computer type = virtualmachine
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:process(167)|request_state_name is not new
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:is_inblockrequest(6250)|zero rows were
> returned from database select
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
> variable: 1
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:computer_not_being_used(787)|vmguest-2
> state is reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:computer_not_being_used(797)|vmguest-2
> is available, its state is reload
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(186)|vmguest-2 is not
> being used
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
> variable: 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(529)|calling
> VCL::Module::Provisioning::VMware::VMware->node_status()
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, statuscheck, checking status of node
>
> 2010-12-27 10:43:38|8437|2:3|reload|utils.pm:nmap_port(2707)|port 22 is
> closed on vmguest-2
>
> 2010-12-27 10:43:38|8437|2:3|reload|utils.pm:nmap_port(2707)|port 24 is
> closed on vmguest-2
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|OS.pm:is_ssh_responding(416)|vmguest-2 is NOT
> responding to SSH, ports 22 or 24 are both closed
>
> 2010-12-27 10:43:38|8437|2:3|reload|VMware.pm:node_status(738)|VM
> vmguest-2 is not responding to SSH, returning 'RELOAD'
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(544)|node_status
> returned a hash reference
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(549)|node_status
> hash reference contains key {status}=RELOAD
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(591)|request
> state is reload, node will be reloaded regardless of status
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(624)|node status
> is reload, vmguest-2 will be reloaded
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, loadimageblade, vmguest-2 must be reloaded with
> vmwarelinux-base9-v3
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(638)|calling
> VCL::Module::Provisioning::VMware::VMware->does_image_exist()
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:38|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
> to determine relative datastore path: '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk', path argument
> does not begin with any of the following:
>
> |8437|2:3|reload| '[standard]'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path
> (line: 2584)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
>
> |8437|2:3|reload| (-3) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-4) VMware.pm, does_image_exist (line: 2935)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, reload_image (line: 640)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:38|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable
> to determine datastore path, failed to determine relative datastore
> path: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-3) VMware.pm, does_image_exist (line: 2935)
>
> |8437|2:3|reload| (-4) new.pm <http://new.pm/>, reload_image (line: 640)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-6) vcld, make_new_child (line: 595)
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:does_image_exist(2940)|image does not
> exist in the non-persistent directory on the VM host, checking the image
> repository
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
> path is not set for the VM profile, using management node install path:
> /install/vmware_images
>
> 2010-12-27 10:43:38|8437|2:3|reload|utils.pm:run_command(9082)|executed
> command: find "/install/vmware_images/vmwarelinux-base9-v3" -iname
> "vmwarelinux-base9-v3.vmdk", pid: 8453, exit status: 0, output:
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:does_image_exist(2959)|image exists
> in the image repository:
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:reload_image(641)|vmwarelinux-base9-v3
> exists on this management node
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, doesimageexists, confirmed image exists
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:update_computer_state(2091)|computer 3
> state updated to: reloading
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(674)|computer
> vmguest-2 state set to reloading
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, computer state updated to reloading
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(685)|calling
> VCL::Module::Provisioning::VMware::VMware->load() subroutine
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, calling
> VCL::Module::Provisioning::VMware::VMware->load() subroutine
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, doesimageexists, image exists vmwarelinux-base9-v3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, startload, vmguest-2 vmwarelinux-base9-v3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:get_vmx_file_paths(3332)|attempting
> to find existing vmx files on the VM host
>
> 2010-12-27 10:43:38|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:38
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|vSphere_SDK.pm:get_file_info(1937)|searching
> for matching file paths: base directory path: '[standard]', search
> pattern: '*.vmx'
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|vSphere_SDK.pm:find_files(1705)|matching file
> count: 1
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|vSphere_SDK.pm:get_registered_vms(103)|found 1
> registered VMs:
>
> |8437|2:3|reload| /var/lib/vmware/Virtual
> Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|VMware.pm:get_vmx_file_paths(3343)|found 1
> unique vmx files on VM host:
>
> |8437|2:3|reload| /var/lib/vmware/Virtual
> Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:get_registered_vms(103)|found 1
> registered VMs:
>
> |8437|2:3|reload| /var/lib/vmware/Virtual
> Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:remove_existing_vms(1129)|ignoring
> existing vmx directory: vmwarelinux-base8-v1
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
> path is not set for the VM profile, using management node install path:
> /install/vmware_images
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
> to determine relative datastore path: '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk', path argument
> does not begin with any of the following:
>
> |8437|2:3|reload| '[standard]'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path
> (line: 2584)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
>
> |8437|2:3|reload| (-3) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-4) VMware.pm, prepare_vmdk (line: 1451)
>
> |8437|2:3|reload| (-5) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable
> to determine datastore path, failed to determine relative datastore
> path: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-3) VMware.pm, prepare_vmdk (line: 1451)
>
> |8437|2:3|reload| (-4) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, process (line: 282)
>
> 2010-12-27 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1468)|vmdk
> file does NOT exist on VM host: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> 2010-12-27 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1554)|found
> 12 vmdk files in image repository directory:
> '/install/vmware_images/vmwarelinux-base9-v3':
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s002.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s003.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s004.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s005.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s006.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s007.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s008.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s009.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s010.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s011.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
> to determine relative datastore path: '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk', path
> argument does not begin with any of the following:
>
> |8437|2:3|reload| '[standard]'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path
> (line: 2584)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
>
> |8437|2:3|reload| (-3) vSphere_SDK.pm, copy_file_to (line: 1296)
>
> |8437|2:3|reload| (-4) VMware.pm, prepare_vmdk (line: 1560)
>
> |8437|2:3|reload| (-5) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable
> to determine datastore path, failed to determine relative datastore
> path: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, copy_file_to (line: 1296)
>
> |8437|2:3|reload| (-3) VMware.pm, prepare_vmdk (line: 1560)
>
> |8437|2:3|reload| (-4) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1561)|failed to copy
> vmdk file from the repository to the VM host:
> '/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk'
> --> '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) VMware.pm, prepare_vmdk (line: 1561)
>
> |8437|2:3|reload| (-2) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-3) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-4) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-5) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-6) vcld, main (line: 342)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:load(335)|failed to prepare vmdk file
> for vmguest-2 on VM host: localvmhost
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) VMware.pm, load (line: 335)
>
> |8437|2:3|reload| (-2) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-3) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-4) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-5) vcld, main (line: 342)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|new.pm:reload_image(692)|vmwarelinux-base9-v3
> failed to load on vmguest-2, returning
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) new.pm <http://new.pm/>, reload_image (line: 692)
>
> |8437|2:3|reload| (-2) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-3) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-4) vcld, main (line: 342)
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, loadimagefailed, vmwarelinux-base9-v3 failed to load on
> vmguest-2
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|new.pm:process(329)|failed to load vmguest-2
> with vmwarelinux-base9-v3
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) new.pm <http://new.pm/>, process (line: 329)
>
> |8437|2:3|reload| (-2) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-3) vcld, main (line: 342)
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reloading
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reloading
>
> 2010-12-27 10:43:40|8437|2:3|reload|utils.pm:mail(1247)|SUCCESS --
> Sending mail To: 0, PROBLEM -- State.pm
>
> |8437|2:3|reload| ---- CRITICAL ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(287)|reservation
> failed on vmguest-2: process failed after trying to load or make available
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) State.pm, reservation_failed (line: 287)
>
> |8437|2:3|reload| (-2) new.pm <http://new.pm/>, process (line: 332)
>
> |8437|2:3|reload| (-3) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-4) vcld, main (line: 342)
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, failed, process failed after trying to load or make available
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(290)|inserted
> computerloadlog entry
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:update_computer_state(2091)|computer 3
> state updated to: failed
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(309)|computer
> vmguest-2 (3) state set to failed
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:update_request_state(2049)|request 2
> state updated to: failed, laststate to: image
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:reservation_failed(322)|set
> request state to 'failed'/'image'
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:is_inblockrequest(6250)|zero rows were
> returned from database select
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(340)|vmguest-2 is
> NOT in blockcomputers table
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(343)|exiting 1
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(902)|destructor
> called, ref($self)=VCL::new
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:delete_computerloadlog_reservation(6829)|removing
> computerloadlog entries matching loadstate = begin
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:delete_computerloadlog_reservation(6876)|deleted
> rows from computerloadlog for reservation id=3
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(909)|removed
> computerloadlog rows with loadstate=begin for reservation
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(921)|number of
> database handles state process created: 1
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(930)|process has a
> database handle stored in $ENV{dbh}, attempting disconnect
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(932)|$ENV{dbh}:
> database disconnect successful
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(946)|VCL::new
> process 8437 exiting
>
> End Disconnect
>
Re: Reservation failed
Posted by Aaron Peeler <aa...@ncsu.edu>.
Hi Gibet,
That's good.
In your log output. Looks like it failed to ssh into localvmhost, to
transfer the image over. Is this machine resolvable and can you ssh to it?
As for selection not available here are some things to check:
- check the state of the your vmguest-x machines, make sure they are
available
- image grouping, make sure the new image is in an image group
- image mapping, make sure the image group is mapped to your vm computer
group
- computer grouping, make sure the vmguest-x machines are in vm couputer
group
- management node mapping, make sure management node group is mapped to
control vm computer group
Aaron
On 1/6/11 7:26 AM, Hicham Gibet Tani wrote:
>
> Hello everybody,
>
> We did fix the problem of copying the VM images.
>
>
> The image capture return an output describing that the image capture
> was successfully using the provisioning engine but after that when the
> image is being reloaded the reservation failed.
>
>
> We tried to access the image from the web browser but it displays that
> there is no selection currently available.
>
>
> Please we need your help!!
>
>
> Cordially,
>
> Gibet Tani Hicham
>
> Eloutouate Lamiae
>
>
> Here is the output:
>
> 2010-12-27
> 10:41:04|7331|1:2|image|image.pm:process(165)|vmwarelinux-base9-v3
> image was successfully captured by the provisioning module
>
> 2010-12-27
> 10:41:04|7331|1:2|image|image.pm:process(222)|vmwarelinux-base9-v3
> image files successfully saved
>
> 2010-12-27
> 10:41:04|7331|1:2|image|utils.pm:update_request_state(2049)|request 1
> state updated to: completed, laststate to: image
>
> 2010-12-27 10:41:04|7331|1:2|image|image.pm:process(225)|request state
> updated to completed, laststate to image
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
> path is not set for the VM profile, using management node install
> path: /install/vmware_images
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2855)|checking
> size of image in image repository:
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3*.vmdk
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2870)|retrieved
> size of image in image repository: 3587376055
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2900)|size of
> vmwarelinux-base9-v3 image: 3,587,376,055 bytes (3,421 MB, 3.34 GB)
>
> 2010-12-27 10:41:04|7331|1:2|image|image.pm:process(234)|size of
> vmwarelinux-base9-v3: 3421
>
> 2010-12-27
> 10:41:04|7331|1:2|image|DataStructure.pm:_automethod(786)|data
> structure updated: $self->request_data->{reservation}{2}{image}{size}
>
> |7331|1:2|image| image_size = 3421
>
> 2010-12-27 10:41:04|7331|1:2|image|image.pm:process(263)|image and
> imagerevision tables updated for image=9, imagerevision=10,
> name=vmwarelinux-base9-v3, lastupdate=2010-12-27 10:24:54, deleted=0,
> size=3421
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:41:04|7331|1:2|image|DataStructure.pm:_automethod(764)|corresponding data
> has not been initialized for get_management_node_sysadmin_email:
> $ENV{management_node_info}{SYSADMIN_EMAIL}
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) DataStructure.pm, _automethod (line: 764)
>
> |7331|1:2|image| (-2) Autoload.pm, __ANON__ (line: 80)
>
> |7331|1:2|image| (-3) image.pm <http://image.pm/>,
> reservation_successful (line: 307)
>
> |7331|1:2|image| (-4) image.pm <http://image.pm/>, process (line: 273)
>
> |7331|1:2|image| (-5) vcld, make_new_child (line: 595)
>
> |7331|1:2|image| (-6) vcld, main (line: 342)
>
> 2010-12-27 10:41:04|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:04
>
> 2010-12-27 10:41:09|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:09
>
> 2010-12-27 10:41:14|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:14
>
> 2010-12-27 10:41:19|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:19
>
> 2010-12-27 10:41:25|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:24
>
> 2010-12-27 10:41:30|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:30
>
> 2010-12-27 10:41:35|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:35
>
> 2010-12-27 10:41:40|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:40
>
> 2010-12-27 10:41:45|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:45
>
> 2010-12-27 10:41:50|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:50
>
> 2010-12-27 10:41:55|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:55
>
> 2010-12-27 10:42:00|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:00
>
> 2010-12-27 10:42:05|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:05
>
> 2010-12-27 10:42:10|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:10
>
> 2010-12-27 10:42:15|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:15
>
> 2010-12-27 10:42:20|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:20
>
> 2010-12-27 10:42:25|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:25
>
> 2010-12-27 10:42:30|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:30
>
> 2010-12-27 10:42:35|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:35
>
> 2010-12-27 10:42:40|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:40
>
> 2010-12-27 10:42:45|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:45
>
> 2010-12-27 10:42:50|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:50
>
> 2010-12-27 10:42:55|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:55
>
> 2010-12-27 10:43:00|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:00
>
> 2010-12-27 10:43:05|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:05
>
> 2010-12-27 10:43:10|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:10
>
> 2010-12-27 10:43:15|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:15
>
> 2010-12-27 10:43:20|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:20
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:mail(1247)|SUCCESS --
> Sending mail To: root@localhost, VCL -- No Apps (Linux) Image Creation
> Succeeded
>
> Use of uninitialized value in substitution (s///) at
>
> /usr/lib/perl5/site_perl/5.8.8/Mail/Mailer/rfc822.pm
> <http://rfc822.pm/> line 22 (#1)
>
> (W uninitialized) An undefined value was used as if it were already
>
> defined.It was interpreted as a "" or a 0, but maybe it was a mistake.
>
> To suppress this warning assign a defined value to your variables.
>
> To help you figure out what was undefined, perl tells you what operation
>
> you used the undefined value in.Note, however, that perl optimizes your
>
> program and the operation displayed in the warning may not necessarily
>
> appear literally in your program.For example, "that $foo" is
>
> usually optimized into "that " . $foo, and the warning will refer to
>
> the concatenation (.) operator, even though there is no . in your
>
> program.
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:43:22|7331|1:2|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
> <http://rfc822.pm/> line 22.
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) vcld, warning_handler (line: 637)
>
> |7331|1:2|image| (-2) rfc822.pm <http://rfc822.pm/>, set_headers
> (line: 22)
>
> |7331|1:2|image| (-3) Mailer.pm, open (line: 162)
>
> |7331|1:2|image| (-4) utils.pm <http://utils.pm/>, mail (line: 1241)
>
> |7331|1:2|image| (-5) image.pm <http://image.pm/>,
> reservation_successful (line: 347)
>
> |7331|1:2|image| (-6) image.pm <http://image.pm/>, process (line: 273)
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:43:22|7331|1:2|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
> <http://rfc822.pm/> line 23.
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) vcld, warning_handler (line: 637)
>
> |7331|1:2|image| (-2) rfc822.pm <http://rfc822.pm/>, set_headers
> (line: 23)
>
> |7331|1:2|image| (-3) Mailer.pm, open (line: 162)
>
> |7331|1:2|image| (-4) utils.pm <http://utils.pm/>, mail (line: 1241)
>
> |7331|1:2|image| (-5) image.pm <http://image.pm/>,
> reservation_successful (line: 347)
>
> |7331|1:2|image| (-6) image.pm <http://image.pm/>, process (line: 273)
>
> No recipient addresses found in header
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:43:22|7331|1:2|image|vcld:warning_handler(637)|Use of uninitialized
> value in concatenation (.) or string at
> /usr/local/vcl/bin/../lib/VCL/utils.pm <http://utils.pm/> line 1247.
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) vcld, warning_handler (line: 637)
>
> |7331|1:2|image| (-2) utils.pm <http://utils.pm/>, mail (line: 1247)
>
> |7331|1:2|image| (-3) image.pm <http://image.pm/>,
> reservation_successful (line: 347)
>
> |7331|1:2|image| (-4) image.pm <http://image.pm/>, process (line: 273)
>
> |7331|1:2|image| (-5) vcld, make_new_child (line: 595)
>
> |7331|1:2|image| (-6) vcld, main (line: 342)
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:mail(1247)|SUCCESS --
> Sending mail To: , VCL IMAGE Creation Completed: vmwarelinux-base9-v3
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, loadimagevmware, VCL::utils::insert_reload_request:
> switching request state to reload
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:update_computer_state(2091)|computer
> 3 state updated to: reload
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_reload_request(8540)|req=1:
> setting computerid 3 into reload state
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_request(8443)|inserted new
> reload request into request table, request id=2
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_request(8474)|inserted new
> reload request into reservation table, reservation id=3
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_reload_request(8550)|req=1:
> inserted new reload request, id=3 nodeid=3, imageid=9, imagerevision_id=10
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::utils::insert_reload_request: created new
> reload request
>
> 2010-12-27
> 10:43:22|7331|1:2|image|image.pm:reservation_successful(351)|inserted
> reload request into database for computer id=3
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:switch_state(7338)|called
> from VCL::image::reservation_successful(354)
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:switch_state(7374)|parent:
> parent reservation ID for this request: 2
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::image: switching request state to complete
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:update_request_state(2049)|request 1
> state updated to: complete, laststate to: image
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7398)|req=1:
> request state changed: image->complete, laststate: image->image
>
> 2010-12-27
> 10:43:23|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::image: request state changed to complete,
> laststate to image
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7408)|req=1:
> computer state not specified, vmguest-2 state not changed
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7426)|req=1:
> log table id=0, ending set to EOR
>
> 2010-12-27
> 10:43:23|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::image: process exiting
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7442)|req=1:
> process exiting
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(902)|destructor
> called, ref($self)=VCL::image
>
> 2010-12-27
> 10:43:23|7331|1:2|image|utils.pm:delete_computerloadlog_reservation(6829)|removing
> computerloadlog entries matching loadstate = begin
>
> 2010-12-27
> 10:43:23|7331|1:2|image|utils.pm:delete_computerloadlog_reservation(6876)|deleted
> rows from computerloadlog for reservation id=2
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(909)|removed
> computerloadlog rows with loadstate=begin for reservation
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(921)|number of
> database handles state process created: 1
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(930)|process has a
> database handle stored in $ENV{dbh}, attempting disconnect
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(932)|$ENV{dbh}:
> database disconnect successful
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(946)|VCL::image
> process 7331 exiting
>
> End Disconnect
>
> 2010-12-27 10:43:23|4041|vcld:REAPER(745)|VCL process exited for
> reservation 2, PID: 7331, signal: CHLD
>
> 2010-12-27 10:43:23|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:23
>
> 2010-12-27 10:43:23|4041|1:2|complete|vcld:main(251)|request deleted
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:reservation_being_processed(9010)|computerloadlog
> 'begin' entry does NOT exist for reservation 3
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:run_command(9082)|executed command:
> pgrep -fl 'vcld [0-9]+:3 ', pid: 8423, exit status: 1, output:
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:is_management_node_process_running(9259)|process
> is NOT running, identifier: 'vcld [0-9]+:3 '
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:reservation_being_processed(9031)|reservation
> is NOT currently being processed
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:main(277)|reservation 3 is
> NOT already being processed
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:get_request_info(4589)|standalone
> affiliation found: Local
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:get_request_info(4596)|found NULL
> uid setting standalone flag: vclreload, uid: NULL
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:main(282)|retrieved request
> information from database
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:update_request_state(2049)|request 2
> state updated to: pending, laststate to: reload
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, begin, beginning to process, state is reload
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(502)|request
> will be processed by new.pm <http://new.pm/>
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(510)|loaded
> VCL::new module
>
> 2010-12-27 10:43:23|8437|2:3|reload|vcld:make_new_child(583)|vcld
> environment variable set to 0 for this process
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(567)|current
> number of forked kids: 1
>
> 2010-12-27 10:43:23|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::new
>
> 2010-12-27 10:43:23|8437|2:3|reload|Module.pm:new(156)|VCL::new object
> created
>
> 2010-12-27 10:43:23|8437|2:3|reload|State.pm:initialize(85)|obtained a
> database handle for this state process, stored as $ENV{dbh}
>
> 2010-12-27 10:43:23|8437|2:3|reload|State.pm:check_image_os(817)|no
> corrections need to be made, not an imaging request, returning 1
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7183)|reservation count:
> 1
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7202)|PARENTIMAGE: 1
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7203)|SUBIMAGE: 0
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7221)|renamed
> process to 'vcld 2:3 reload vmguest-2 vmwarelinux-base9-v3 vclreload'
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|State.pm:initialize(118)|attempting to load
> provisioning module: VCL::Module::Provisioning::VMware::VMware
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|State.pm:initialize(124)|VCL::Module::Provisioning::VMware::VMware
> module loaded
>
> 2010-12-27 10:43:24|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::Module::Provisioning::VMware::VMware
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VMware
> object created
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|DataStructure.pm:_initialize(594)|computer ID
> argument was specified, retrieving data for computer ID: 1
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_datastructure(923)|created
> DataStructure object for VM host: localvmhost
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|DataStructure.pm:_initialize(594)|computer ID
> argument was specified, retrieving data for computer ID: 1
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_datastructure(923)|created
> DataStructure object for VM host: localvmhost
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1027)|attempting
> to load VMware control module:
> VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1033)|loaded
> VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27 10:43:25|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|Module.pm:new(156)|VCL::Module::Provisioning::VMware::vSphere_SDK
> object created
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1816)|attempting to
> connect to VM host: https://localvmhost/sdk
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1822)|unable to
> connect to VM host: https://localvmhost/sdk, username: 'root', error:
>
> |8437|2:3|reload| Error: Server version unavailable at
> 'https://localvmhost/sdk/vimService.wsdl'
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1816)|attempting to
> connect to VM host: https://localvmhost:8333/sdk
>
> 2010-12-27 10:43:28|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:28
>
> 2010-12-27 10:43:33|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:33
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:initialize(1826)|connected to
> VM host: https://localvmhost:8333/sdk
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1046)|created
> API object: VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:is_restricted(1079)|access to
> the VM host via the vSphere SDK is NOT restricted due to the license
>
> 2010-12-27 10:43:37|8437|2:3|reload|VMware.pm:initialize(229)|vSphere
> SDK object will be used to control the VM: vmguest-2, and to control
> the OS of the VM host: localvmhost
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:get_vmware_product_name(955)|VMware
> product being used on VM host localvmhost: 'VMware Server 2.0.2
> build-203138'
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:file_exists(1558)|file
> (datastore root) exists: [standard]
>
> 2010-12-27 10:43:37|8437|2:3|reload|VMware.pm:initialize(294)|VMware
> provisioning object initialized:
>
> |8437|2:3|reload| VM host OS object type:
> VCL::Module::Provisioning::VMware::vSphere_SDK
>
> |8437|2:3|reload| API object type:
> VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|State.pm:initialize(128)|VCL::Module::Provisioning::VMware::VMware
> provisioner object created
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|State.pm:initialize(142)|attempting to load
> OS module: VCL::Module::OS::Linux
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|State.pm:initialize(148)|VCL::Module::OS::Linux
> module loaded
>
> 2010-12-27 10:43:38|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::Module::OS::Linux
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|Module.pm:new(156)|VCL::Module::OS::Linux
> object created
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|State.pm:initialize(151)|VCL::Module::OS::Linux
> OS object created
>
> 2010-12-27 10:43:38|8437|2:3|reload|State.pm:initialize(166)|returning 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|vcld:make_new_child(592)|VCL::new
> object created and initialized
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
> variable: 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(133)|reservation is
> parent = 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(134)|preload only = 0
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(135)|originating
> request state = reload
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(136)|originating
> request laststate = image
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(137)|originating
> computer state = reload
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(138)|originating
> computer type = virtualmachine
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:process(167)|request_state_name is not new
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:is_inblockrequest(6250)|zero rows
> were returned from database select
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
> variable: 1
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:computer_not_being_used(787)|vmguest-2
> state is reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:computer_not_being_used(797)|vmguest-2
> is available, its state is reload
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(186)|vmguest-2 is
> not being used
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
> variable: 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(529)|calling
> VCL::Module::Provisioning::VMware::VMware->node_status()
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, statuscheck, checking status of node
>
> 2010-12-27 10:43:38|8437|2:3|reload|utils.pm:nmap_port(2707)|port 22
> is closed on vmguest-2
>
> 2010-12-27 10:43:38|8437|2:3|reload|utils.pm:nmap_port(2707)|port 24
> is closed on vmguest-2
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|OS.pm:is_ssh_responding(416)|vmguest-2 is NOT
> responding to SSH, ports 22 or 24 are both closed
>
> 2010-12-27 10:43:38|8437|2:3|reload|VMware.pm:node_status(738)|VM
> vmguest-2 is not responding to SSH, returning 'RELOAD'
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:reload_image(544)|node_status returned
> a hash reference
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:reload_image(549)|node_status hash
> reference contains key {status}=RELOAD
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(591)|request
> state is reload, node will be reloaded regardless of status
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(624)|node
> status is reload, vmguest-2 will be reloaded
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, loadimageblade, vmguest-2 must be reloaded with
> vmwarelinux-base9-v3
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(638)|calling
> VCL::Module::Provisioning::VMware::VMware->does_image_exist()
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:38|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
> to determine relative datastore path: '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk', path
> argument does not begin with any of the following:
>
> |8437|2:3|reload| '[standard]'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path
> (line: 2584)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
>
> |8437|2:3|reload| (-3) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-4) VMware.pm, does_image_exist (line: 2935)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, reload_image (line: 640)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:38|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable
> to determine datastore path, failed to determine relative datastore
> path: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-3) VMware.pm, does_image_exist (line: 2935)
>
> |8437|2:3|reload| (-4) new.pm <http://new.pm/>, reload_image (line: 640)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-6) vcld, make_new_child (line: 595)
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:does_image_exist(2940)|image does
> not exist in the non-persistent directory on the VM host, checking the
> image repository
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
> path is not set for the VM profile, using management node install
> path: /install/vmware_images
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:run_command(9082)|executed command:
> find "/install/vmware_images/vmwarelinux-base9-v3" -iname
> "vmwarelinux-base9-v3.vmdk", pid: 8453, exit status: 0, output:
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:does_image_exist(2959)|image exists
> in the image repository:
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:reload_image(641)|vmwarelinux-base9-v3
> exists on this management node
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, doesimageexists, confirmed image exists
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:update_computer_state(2091)|computer
> 3 state updated to: reloading
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(674)|computer
> vmguest-2 state set to reloading
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, computer state updated to reloading
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(685)|calling
> VCL::Module::Provisioning::VMware::VMware->load() subroutine
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, calling
> VCL::Module::Provisioning::VMware::VMware->load() subroutine
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, doesimageexists, image exists vmwarelinux-base9-v3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, startload, vmguest-2 vmwarelinux-base9-v3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:get_vmx_file_paths(3332)|attempting
> to find existing vmx files on the VM host
>
> 2010-12-27 10:43:38|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:38
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|vSphere_SDK.pm:get_file_info(1937)|searching
> for matching file paths: base directory path: '[standard]', search
> pattern: '*.vmx'
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|vSphere_SDK.pm:find_files(1705)|matching file
> count: 1
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|vSphere_SDK.pm:get_registered_vms(103)|found
> 1 registered VMs:
>
> |8437|2:3|reload| /var/lib/vmware/Virtual
> Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|VMware.pm:get_vmx_file_paths(3343)|found 1
> unique vmx files on VM host:
>
> |8437|2:3|reload| /var/lib/vmware/Virtual
> Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:get_registered_vms(103)|found
> 1 registered VMs:
>
> |8437|2:3|reload| /var/lib/vmware/Virtual
> Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:remove_existing_vms(1129)|ignoring
> existing vmx directory: vmwarelinux-base8-v1
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
> path is not set for the VM profile, using management node install
> path: /install/vmware_images
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
> to determine relative datastore path: '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk', path
> argument does not begin with any of the following:
>
> |8437|2:3|reload| '[standard]'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path
> (line: 2584)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
>
> |8437|2:3|reload| (-3) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-4) VMware.pm, prepare_vmdk (line: 1451)
>
> |8437|2:3|reload| (-5) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable
> to determine datastore path, failed to determine relative datastore
> path: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-3) VMware.pm, prepare_vmdk (line: 1451)
>
> |8437|2:3|reload| (-4) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, process (line: 282)
>
> 2010-12-27 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1468)|vmdk
> file does NOT exist on VM host: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> 2010-12-27 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1554)|found
> 12 vmdk files in image repository directory:
> '/install/vmware_images/vmwarelinux-base9-v3':
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s002.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s003.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s004.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s005.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s006.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s007.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s008.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s009.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s010.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s011.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
> to determine relative datastore path: '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk', path
> argument does not begin with any of the following:
>
> |8437|2:3|reload| '[standard]'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path
> (line: 2584)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
>
> |8437|2:3|reload| (-3) vSphere_SDK.pm, copy_file_to (line: 1296)
>
> |8437|2:3|reload| (-4) VMware.pm, prepare_vmdk (line: 1560)
>
> |8437|2:3|reload| (-5) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable
> to determine datastore path, failed to determine relative datastore
> path: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, copy_file_to (line: 1296)
>
> |8437|2:3|reload| (-3) VMware.pm, prepare_vmdk (line: 1560)
>
> |8437|2:3|reload| (-4) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1561)|failed to copy
> vmdk file from the repository to the VM host:
> '/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk'
> --> '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) VMware.pm, prepare_vmdk (line: 1561)
>
> |8437|2:3|reload| (-2) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-3) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-4) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-5) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-6) vcld, main (line: 342)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:load(335)|failed to prepare vmdk
> file for vmguest-2 on VM host: localvmhost
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) VMware.pm, load (line: 335)
>
> |8437|2:3|reload| (-2) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-3) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-4) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-5) vcld, main (line: 342)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|new.pm:reload_image(692)|vmwarelinux-base9-v3
> failed to load on vmguest-2, returning
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) new.pm <http://new.pm/>, reload_image (line: 692)
>
> |8437|2:3|reload| (-2) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-3) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-4) vcld, main (line: 342)
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, loadimagefailed, vmwarelinux-base9-v3 failed to load on
> vmguest-2
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|new.pm:process(329)|failed to load vmguest-2
> with vmwarelinux-base9-v3
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) new.pm <http://new.pm/>, process (line: 329)
>
> |8437|2:3|reload| (-2) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-3) vcld, main (line: 342)
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reloading
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reloading
>
> 2010-12-27 10:43:40|8437|2:3|reload|utils.pm:mail(1247)|SUCCESS --
> Sending mail To: 0, PROBLEM -- State.pm
>
> |8437|2:3|reload| ---- CRITICAL ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(287)|reservation
> failed on vmguest-2: process failed after trying to load or make available
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) State.pm, reservation_failed (line: 287)
>
> |8437|2:3|reload| (-2) new.pm <http://new.pm/>, process (line: 332)
>
> |8437|2:3|reload| (-3) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-4) vcld, main (line: 342)
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, failed, process failed after trying to load or make available
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(290)|inserted
> computerloadlog entry
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:update_computer_state(2091)|computer
> 3 state updated to: failed
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(309)|computer
> vmguest-2 (3) state set to failed
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:update_request_state(2049)|request 2
> state updated to: failed, laststate to: image
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(322)|set request
> state to 'failed'/'image'
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:is_inblockrequest(6250)|zero rows
> were returned from database select
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(340)|vmguest-2 is
> NOT in blockcomputers table
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(343)|exiting 1
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(902)|destructor
> called, ref($self)=VCL::new
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:delete_computerloadlog_reservation(6829)|removing
> computerloadlog entries matching loadstate = begin
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:delete_computerloadlog_reservation(6876)|deleted
> rows from computerloadlog for reservation id=3
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(909)|removed
> computerloadlog rows with loadstate=begin for reservation
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(921)|number of
> database handles state process created: 1
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(930)|process has
> a database handle stored in $ENV{dbh}, attempting disconnect
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(932)|$ENV{dbh}:
> database disconnect successful
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(946)|VCL::new
> process 8437 exiting
>
> End Disconnect
>
--
Aaron Peeler
Program Manager
Virtual Computing Lab
NC State University
aaron_peeler@ncsu.edu
919-513-4571
Re: Reservation failed
Posted by Andy Kurth <an...@ncsu.edu>.
There is a bug in the VCL 2.2 code that is causing the "unable to
determine relative datastore path" problem. I have traced through the
2.2 code and the latest code and believe this has been fixed. I would
recommend downloading and trying the latest code in the repository:
-Install a Subversion client on your management node if not already
installed
-/sbin/service vcld stop
-Rename the directory where the management node components are
installed, usually /usr/local/vcl
-Checkout the management node code from Subversion with the command:
svn co
http://svn.apache.org/repos/asf/incubator/vcl/tags/release-2.2/managementnode
/usr/local/vcl
-/sbin/service vcld stop
Running 'svn co' to checkout the code will allow you to easily update it
later on by running 'svn update'.
SSH will need to be working from the management node to the VM host.
The latest code will use SSH/vim-cmd to control the VMware host rather
than the vSphere SDK because the ability to manage some features are
missing from the vSphere SDK under VMware Server 2.0, so SSH access is
required. It appears that you're using the same computer for the
management node and VM host. This is fine but the following command
must work (change the path to your private SSH identity key if not using
/etc/vcl/vcl.key):
ssh -i /etc/vcl/vcl.key localvmhost
Also, the other warnings that appear in your log file can be suppressed
by setting a sysadmin email address for the management node:
Management Nodes > Edit Management Node Information > Edit > SysAdmin
Email Address(es):
Hope this helps,
Andy
On 1/6/2011 7:26 AM, Hicham Gibet Tani wrote:
> Hello everybody,
>
> We did fix the problem of copying the VM images.
>
>
> The image capture return an output describing that the image capture was
> successfully using the provisioning engine but after that when the image
> is being reloaded the reservation failed.
>
>
> We tried to access the image from the web browser but it displays that
> there is no selection currently available.
>
>
> Please we need your help!!
>
>
> Cordially,
>
> Gibet Tani Hicham
>
> Eloutouate Lamiae
>
>
> Here is the output:
>
> 2010-12-27
> 10:41:04|7331|1:2|image|image.pm:process(165)|vmwarelinux-base9-v3 image
> was successfully captured by the provisioning module
>
> 2010-12-27
> 10:41:04|7331|1:2|image|image.pm:process(222)|vmwarelinux-base9-v3 image
> files successfully saved
>
> 2010-12-27
> 10:41:04|7331|1:2|image|utils.pm:update_request_state(2049)|request 1
> state updated to: completed, laststate to: image
>
> 2010-12-27 10:41:04|7331|1:2|image|image.pm:process(225)|request state
> updated to completed, laststate to image
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
> path is not set for the VM profile, using management node install path:
> /install/vmware_images
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2855)|checking
> size of image in image repository:
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3*.vmdk
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2870)|retrieved
> size of image in image repository: 3587376055
>
> 2010-12-27
> 10:41:04|7331|1:2|image|VMware.pm:get_image_size_bytes(2900)|size of
> vmwarelinux-base9-v3 image: 3,587,376,055 bytes (3,421 MB, 3.34 GB)
>
> 2010-12-27 10:41:04|7331|1:2|image|image.pm:process(234)|size of
> vmwarelinux-base9-v3: 3421
>
> 2010-12-27
> 10:41:04|7331|1:2|image|DataStructure.pm:_automethod(786)|data structure
> updated: $self->request_data->{reservation}{2}{image}{size}
>
> |7331|1:2|image| image_size = 3421
>
> 2010-12-27 10:41:04|7331|1:2|image|image.pm:process(263)|image and
> imagerevision tables updated for image=9, imagerevision=10,
> name=vmwarelinux-base9-v3, lastupdate=2010-12-27 10:24:54, deleted=0,
> size=3421
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:41:04|7331|1:2|image|DataStructure.pm:_automethod(764)|corresponding
> data has not been initialized for get_management_node_sysadmin_email:
> $ENV{management_node_info}{SYSADMIN_EMAIL}
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) DataStructure.pm, _automethod (line: 764)
>
> |7331|1:2|image| (-2) Autoload.pm, __ANON__ (line: 80)
>
> |7331|1:2|image| (-3) image.pm <http://image.pm/>,
> reservation_successful (line: 307)
>
> |7331|1:2|image| (-4) image.pm <http://image.pm/>, process (line: 273)
>
> |7331|1:2|image| (-5) vcld, make_new_child (line: 595)
>
> |7331|1:2|image| (-6) vcld, main (line: 342)
>
> 2010-12-27 10:41:04|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:04
>
> 2010-12-27 10:41:09|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:09
>
> 2010-12-27 10:41:14|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:14
>
> 2010-12-27 10:41:19|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:19
>
> 2010-12-27 10:41:25|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:24
>
> 2010-12-27 10:41:30|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:30
>
> 2010-12-27 10:41:35|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:35
>
> 2010-12-27 10:41:40|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:40
>
> 2010-12-27 10:41:45|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:45
>
> 2010-12-27 10:41:50|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:50
>
> 2010-12-27 10:41:55|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:41:55
>
> 2010-12-27 10:42:00|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:00
>
> 2010-12-27 10:42:05|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:05
>
> 2010-12-27 10:42:10|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:10
>
> 2010-12-27 10:42:15|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:15
>
> 2010-12-27 10:42:20|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:20
>
> 2010-12-27 10:42:25|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:25
>
> 2010-12-27 10:42:30|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:30
>
> 2010-12-27 10:42:35|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:35
>
> 2010-12-27 10:42:40|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:40
>
> 2010-12-27 10:42:45|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:45
>
> 2010-12-27 10:42:50|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:50
>
> 2010-12-27 10:42:55|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:42:55
>
> 2010-12-27 10:43:00|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:00
>
> 2010-12-27 10:43:05|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:05
>
> 2010-12-27 10:43:10|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:10
>
> 2010-12-27 10:43:15|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:15
>
> 2010-12-27 10:43:20|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:20
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:mail(1247)|SUCCESS --
> Sending mail To: root@localhost, VCL -- No Apps (Linux) Image Creation
> Succeeded
>
> Use of uninitialized value in substitution (s///) at
>
> /usr/lib/perl5/site_perl/5.8.8/Mail/Mailer/rfc822.pm <http://rfc822.pm/>
> line 22 (#1)
>
> (W uninitialized) An undefined value was used as if it were already
>
> defined.It was interpreted as a "" or a 0, but maybe it was a mistake.
>
> To suppress this warning assign a defined value to your variables.
>
> To help you figure out what was undefined, perl tells you what operation
>
> you used the undefined value in.Note, however, that perl optimizes your
>
> program and the operation displayed in the warning may not necessarily
>
> appear literally in your program.For example, "that $foo" is
>
> usually optimized into "that " . $foo, and the warning will refer to
>
> the concatenation (.) operator, even though there is no . in your
>
> program.
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:43:22|7331|1:2|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 <http://rfc822.pm/>
> line 22.
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) vcld, warning_handler (line: 637)
>
> |7331|1:2|image| (-2) rfc822.pm <http://rfc822.pm/>, set_headers (line: 22)
>
> |7331|1:2|image| (-3) Mailer.pm, open (line: 162)
>
> |7331|1:2|image| (-4) utils.pm <http://utils.pm/>, mail (line: 1241)
>
> |7331|1:2|image| (-5) image.pm <http://image.pm/>,
> reservation_successful (line: 347)
>
> |7331|1:2|image| (-6) image.pm <http://image.pm/>, process (line: 273)
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:43:22|7331|1:2|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 <http://rfc822.pm/>
> line 23.
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) vcld, warning_handler (line: 637)
>
> |7331|1:2|image| (-2) rfc822.pm <http://rfc822.pm/>, set_headers (line: 23)
>
> |7331|1:2|image| (-3) Mailer.pm, open (line: 162)
>
> |7331|1:2|image| (-4) utils.pm <http://utils.pm/>, mail (line: 1241)
>
> |7331|1:2|image| (-5) image.pm <http://image.pm/>,
> reservation_successful (line: 347)
>
> |7331|1:2|image| (-6) image.pm <http://image.pm/>, process (line: 273)
>
> No recipient addresses found in header
>
> |7331|1:2|image| ---- WARNING ----
>
> |7331|1:2|image| 2010-12-27
> 10:43:22|7331|1:2|image|vcld:warning_handler(637)|Use of uninitialized
> value in concatenation (.) or string at
> /usr/local/vcl/bin/../lib/VCL/utils.pm <http://utils.pm/> line 1247.
>
> |7331|1:2|image| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |7331|1:2|image| (-1) vcld, warning_handler (line: 637)
>
> |7331|1:2|image| (-2) utils.pm <http://utils.pm/>, mail (line: 1247)
>
> |7331|1:2|image| (-3) image.pm <http://image.pm/>,
> reservation_successful (line: 347)
>
> |7331|1:2|image| (-4) image.pm <http://image.pm/>, process (line: 273)
>
> |7331|1:2|image| (-5) vcld, make_new_child (line: 595)
>
> |7331|1:2|image| (-6) vcld, main (line: 342)
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:mail(1247)|SUCCESS --
> Sending mail To: , VCL IMAGE Creation Completed: vmwarelinux-base9-v3
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, loadimagevmware, VCL::utils::insert_reload_request:
> switching request state to reload
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:update_computer_state(2091)|computer 3
> state updated to: reload
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_reload_request(8540)|req=1:
> setting computerid 3 into reload state
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_request(8443)|inserted new
> reload request into request table, request id=2
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_request(8474)|inserted new
> reload request into reservation table, reservation id=3
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:insert_reload_request(8550)|req=1:
> inserted new reload request, id=3 nodeid=3, imageid=9, imagerevision_id=10
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::utils::insert_reload_request: created new reload
> request
>
> 2010-12-27
> 10:43:22|7331|1:2|image|image.pm:reservation_successful(351)|inserted
> reload request into database for computer id=3
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:switch_state(7338)|called
> from VCL::image::reservation_successful(354)
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:switch_state(7374)|parent:
> parent reservation ID for this request: 2
>
> 2010-12-27 10:43:22|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::image: switching request state to complete
>
> 2010-12-27
> 10:43:22|7331|1:2|image|utils.pm:update_request_state(2049)|request 1
> state updated to: complete, laststate to: image
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7398)|req=1:
> request state changed: image->complete, laststate: image->image
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::image: request state changed to complete,
> laststate to image
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7408)|req=1:
> computer state not specified, vmguest-2 state not changed
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7426)|req=1:
> log table id=0, ending set to EOR
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, VCL::image: process exiting
>
> 2010-12-27 10:43:23|7331|1:2|image|utils.pm:switch_state(7442)|req=1:
> process exiting
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(902)|destructor
> called, ref($self)=VCL::image
>
> 2010-12-27
> 10:43:23|7331|1:2|image|utils.pm:delete_computerloadlog_reservation(6829)|removing
> computerloadlog entries matching loadstate = begin
>
> 2010-12-27
> 10:43:23|7331|1:2|image|utils.pm:delete_computerloadlog_reservation(6876)|deleted
> rows from computerloadlog for reservation id=2
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(909)|removed
> computerloadlog rows with loadstate=begin for reservation
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(921)|number of
> database handles state process created: 1
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(930)|process has a
> database handle stored in $ENV{dbh}, attempting disconnect
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(932)|$ENV{dbh}:
> database disconnect successful
>
> 2010-12-27 10:43:23|7331|1:2|image|State.pm:DESTROY(946)|VCL::image
> process 7331 exiting
>
> End Disconnect
>
> 2010-12-27 10:43:23|4041|vcld:REAPER(745)|VCL process exited for
> reservation 2, PID: 7331, signal: CHLD
>
> 2010-12-27 10:43:23|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:23
>
> 2010-12-27 10:43:23|4041|1:2|complete|vcld:main(251)|request deleted
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:reservation_being_processed(9010)|computerloadlog
> 'begin' entry does NOT exist for reservation 3
>
> 2010-12-27 10:43:23|4041|2:3|reload|utils.pm:run_command(9082)|executed
> command: pgrep -fl 'vcld [0-9]+:3 ', pid: 8423, exit status: 1, output:
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:is_management_node_process_running(9259)|process
> is NOT running, identifier: 'vcld [0-9]+:3 '
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:reservation_being_processed(9031)|reservation
> is NOT currently being processed
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:main(277)|reservation 3 is NOT
> already being processed
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:get_request_info(4589)|standalone
> affiliation found: Local
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:get_request_info(4596)|found NULL uid
> setting standalone flag: vclreload, uid: NULL
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:main(282)|retrieved request
> information from database
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:update_request_state(2049)|request 2
> state updated to: pending, laststate to: reload
>
> 2010-12-27
> 10:43:23|4041|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, begin, beginning to process, state is reload
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(502)|request
> will be processed by new.pm <http://new.pm/>
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(510)|loaded
> VCL::new module
>
> 2010-12-27 10:43:23|8437|2:3|reload|vcld:make_new_child(583)|vcld
> environment variable set to 0 for this process
>
> 2010-12-27 10:43:23|4041|2:3|reload|vcld:make_new_child(567)|current
> number of forked kids: 1
>
> 2010-12-27 10:43:23|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::new
>
> 2010-12-27 10:43:23|8437|2:3|reload|Module.pm:new(156)|VCL::new object
> created
>
> 2010-12-27 10:43:23|8437|2:3|reload|State.pm:initialize(85)|obtained a
> database handle for this state process, stored as $ENV{dbh}
>
> 2010-12-27 10:43:23|8437|2:3|reload|State.pm:check_image_os(817)|no
> corrections need to be made, not an imaging request, returning 1
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7183)|reservation
> count: 1
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7202)|PARENTIMAGE: 1
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7203)|SUBIMAGE: 0
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|utils.pm:rename_vcld_process(7221)|renamed
> process to 'vcld 2:3 reload vmguest-2 vmwarelinux-base9-v3 vclreload'
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:23|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27 10:43:23|8437|2:3|reload|State.pm:initialize(118)|attempting
> to load provisioning module: VCL::Module::Provisioning::VMware::VMware
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|State.pm:initialize(124)|VCL::Module::Provisioning::VMware::VMware
> module loaded
>
> 2010-12-27 10:43:24|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::Module::Provisioning::VMware::VMware
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VMware
> object created
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|DataStructure.pm:_initialize(594)|computer ID
> argument was specified, retrieving data for computer ID: 1
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_datastructure(923)|created
> DataStructure object for VM host: localvmhost
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|DataStructure.pm:_initialize(594)|computer ID
> argument was specified, retrieving data for computer ID: 1
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_datastructure(923)|created
> DataStructure object for VM host: localvmhost
>
> 2010-12-27
> 10:43:24|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1027)|attempting to
> load VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1033)|loaded
> VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27 10:43:25|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|Module.pm:new(156)|VCL::Module::Provisioning::VMware::vSphere_SDK
> object created
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1816)|attempting to
> connect to VM host: https://localvmhost/sdk
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1822)|unable to
> connect to VM host: https://localvmhost/sdk, username: 'root', error:
>
> |8437|2:3|reload| Error: Server version unavailable at
> 'https://localvmhost/sdk/vimService.wsdl'
>
> 2010-12-27
> 10:43:25|8437|2:3|reload|vSphere_SDK.pm:initialize(1816)|attempting to
> connect to VM host: https://localvmhost:8333/sdk
>
> 2010-12-27 10:43:28|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:28
>
> 2010-12-27 10:43:33|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:33
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:initialize(1826)|connected to VM
> host: https://localvmhost:8333/sdk
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|VMware.pm:get_vmhost_api_object(1046)|created
> API object: VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:is_restricted(1079)|access to
> the VM host via the vSphere SDK is NOT restricted due to the license
>
> 2010-12-27 10:43:37|8437|2:3|reload|VMware.pm:initialize(229)|vSphere
> SDK object will be used to control the VM: vmguest-2, and to control the
> OS of the VM host: localvmhost
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:get_vmware_product_name(955)|VMware
> product being used on VM host localvmhost: 'VMware Server 2.0.2
> build-203138'
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|vSphere_SDK.pm:file_exists(1558)|file
> (datastore root) exists: [standard]
>
> 2010-12-27 10:43:37|8437|2:3|reload|VMware.pm:initialize(294)|VMware
> provisioning object initialized:
>
> |8437|2:3|reload| VM host OS object type:
> VCL::Module::Provisioning::VMware::vSphere_SDK
>
> |8437|2:3|reload| API object type:
> VCL::Module::Provisioning::VMware::vSphere_SDK
>
> 2010-12-27
> 10:43:37|8437|2:3|reload|State.pm:initialize(128)|VCL::Module::Provisioning::VMware::VMware
> provisioner object created
>
> 2010-12-27 10:43:37|8437|2:3|reload|State.pm:initialize(142)|attempting
> to load OS module: VCL::Module::OS::Linux
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|State.pm:initialize(148)|VCL::Module::OS::Linux
> module loaded
>
> 2010-12-27 10:43:38|8437|2:3|reload|Module.pm:new(134)|constructor
> called, class=VCL::Module::OS::Linux
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|Module.pm:new(156)|VCL::Module::OS::Linux
> object created
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|State.pm:initialize(151)|VCL::Module::OS::Linux
> OS object created
>
> 2010-12-27 10:43:38|8437|2:3|reload|State.pm:initialize(166)|returning 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|vcld:make_new_child(592)|VCL::new
> object created and initialized
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
> variable: 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(133)|reservation is
> parent = 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(134)|preload only = 0
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(135)|originating
> request state = reload
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(136)|originating
> request laststate = image
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(137)|originating
> computer state = reload
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(138)|originating
> computer type = virtualmachine
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:process(167)|request_state_name is not new
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:is_inblockrequest(6250)|zero rows were
> returned from database select
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
> variable: 1
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:computer_not_being_used(787)|vmguest-2
> state is reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:computer_not_being_used(797)|vmguest-2
> is available, its state is reload
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:process(186)|vmguest-2 is not
> being used
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reload
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:get_management_node_id(8740)|environment
> variable: 1
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(529)|calling
> VCL::Module::Provisioning::VMware::VMware->node_status()
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, statuscheck, checking status of node
>
> 2010-12-27 10:43:38|8437|2:3|reload|utils.pm:nmap_port(2707)|port 22 is
> closed on vmguest-2
>
> 2010-12-27 10:43:38|8437|2:3|reload|utils.pm:nmap_port(2707)|port 24 is
> closed on vmguest-2
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|OS.pm:is_ssh_responding(416)|vmguest-2 is NOT
> responding to SSH, ports 22 or 24 are both closed
>
> 2010-12-27 10:43:38|8437|2:3|reload|VMware.pm:node_status(738)|VM
> vmguest-2 is not responding to SSH, returning 'RELOAD'
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(544)|node_status
> returned a hash reference
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(549)|node_status
> hash reference contains key {status}=RELOAD
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(591)|request
> state is reload, node will be reloaded regardless of status
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(624)|node status
> is reload, vmguest-2 will be reloaded
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, loadimageblade, vmguest-2 must be reloaded with
> vmwarelinux-base9-v3
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(638)|calling
> VCL::Module::Provisioning::VMware::VMware->does_image_exist()
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:38|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
> to determine relative datastore path: '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk', path argument
> does not begin with any of the following:
>
> |8437|2:3|reload| '[standard]'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path
> (line: 2584)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
>
> |8437|2:3|reload| (-3) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-4) VMware.pm, does_image_exist (line: 2935)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, reload_image (line: 640)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:38|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable
> to determine datastore path, failed to determine relative datastore
> path: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-3) VMware.pm, does_image_exist (line: 2935)
>
> |8437|2:3|reload| (-4) new.pm <http://new.pm/>, reload_image (line: 640)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-6) vcld, make_new_child (line: 595)
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:does_image_exist(2940)|image does not
> exist in the non-persistent directory on the VM host, checking the image
> repository
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
> path is not set for the VM profile, using management node install path:
> /install/vmware_images
>
> 2010-12-27 10:43:38|8437|2:3|reload|utils.pm:run_command(9082)|executed
> command: find "/install/vmware_images/vmwarelinux-base9-v3" -iname
> "vmwarelinux-base9-v3.vmdk", pid: 8453, exit status: 0, output:
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:does_image_exist(2959)|image exists
> in the image repository:
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|new.pm:reload_image(641)|vmwarelinux-base9-v3
> exists on this management node
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, doesimageexists, confirmed image exists
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:update_computer_state(2091)|computer 3
> state updated to: reloading
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(674)|computer
> vmguest-2 state set to reloading
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, computer state updated to reloading
>
> 2010-12-27 10:43:38|8437|2:3|reload|new.pm:reload_image(685)|calling
> VCL::Module::Provisioning::VMware::VMware->load() subroutine
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, info, calling
> VCL::Module::Provisioning::VMware::VMware->load() subroutine
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, doesimageexists, image exists vmwarelinux-base9-v3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, startload, vmguest-2 vmwarelinux-base9-v3
>
> 2010-12-27
> 10:43:38|8437|2:3|reload|VMware.pm:get_vmx_file_paths(3332)|attempting
> to find existing vmx files on the VM host
>
> 2010-12-27 10:43:38|4041|vcld:main(166)|lastcheckin time updated for
> management node 1: 2010-12-27 10:43:38
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|vSphere_SDK.pm:get_file_info(1937)|searching
> for matching file paths: base directory path: '[standard]', search
> pattern: '*.vmx'
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|vSphere_SDK.pm:find_files(1705)|matching file
> count: 1
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|vSphere_SDK.pm:get_registered_vms(103)|found 1
> registered VMs:
>
> |8437|2:3|reload| /var/lib/vmware/Virtual
> Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
>
> 2010-12-27
> 10:43:39|8437|2:3|reload|VMware.pm:get_vmx_file_paths(3343)|found 1
> unique vmx files on VM host:
>
> |8437|2:3|reload| /var/lib/vmware/Virtual
> Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:get_registered_vms(103)|found 1
> registered VMs:
>
> |8437|2:3|reload| /var/lib/vmware/Virtual
> Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmx
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:remove_existing_vms(1129)|ignoring
> existing vmx directory: vmwarelinux-base8-v1
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:get_repository_vmdk_base_directory_path(2654)|repository
> path is not set for the VM profile, using management node install path:
> /install/vmware_images
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
> to determine relative datastore path: '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk', path argument
> does not begin with any of the following:
>
> |8437|2:3|reload| '[standard]'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path
> (line: 2584)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
>
> |8437|2:3|reload| (-3) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-4) VMware.pm, prepare_vmdk (line: 1451)
>
> |8437|2:3|reload| (-5) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable
> to determine datastore path, failed to determine relative datastore
> path: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, file_exists (line: 1550)
>
> |8437|2:3|reload| (-3) VMware.pm, prepare_vmdk (line: 1451)
>
> |8437|2:3|reload| (-4) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, process (line: 282)
>
> 2010-12-27 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1468)|vmdk
> file does NOT exist on VM host: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> 2010-12-27 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1554)|found
> 12 vmdk files in image repository directory:
> '/install/vmware_images/vmwarelinux-base9-v3':
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s002.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s003.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s004.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s005.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s006.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s007.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s008.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s009.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s010.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s011.vmdk
>
> |8437|2:3|reload|
> /install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3.vmdk
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_relative_datastore_path(2584)|unable
> to determine relative datastore path: '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk', path
> argument does not begin with any of the following:
>
> |8437|2:3|reload| '[standard]'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| '/var/lib/vmware/Virtual Machines'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_relative_datastore_path
> (line: 2584)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, _get_datastore_path (line: 2165)
>
> |8437|2:3|reload| (-3) vSphere_SDK.pm, copy_file_to (line: 1296)
>
> |8437|2:3|reload| (-4) VMware.pm, prepare_vmdk (line: 1560)
>
> |8437|2:3|reload| (-5) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|vSphere_SDK.pm:_get_datastore_path(2167)|unable
> to determine datastore path, failed to determine relative datastore
> path: /var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) vSphere_SDK.pm, _get_datastore_path (line: 2167)
>
> |8437|2:3|reload| (-2) vSphere_SDK.pm, copy_file_to (line: 1296)
>
> |8437|2:3|reload| (-3) VMware.pm, prepare_vmdk (line: 1560)
>
> |8437|2:3|reload| (-4) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-5) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-6) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:prepare_vmdk(1561)|failed to copy
> vmdk file from the repository to the VM host:
> '/install/vmware_images/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk'
> --> '/var/lib/vmware/Virtual\
> Machines/vmwarelinux-base9-v3/vmwarelinux-base9-v3-s001.vmdk'
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) VMware.pm, prepare_vmdk (line: 1561)
>
> |8437|2:3|reload| (-2) VMware.pm, load (line: 334)
>
> |8437|2:3|reload| (-3) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-4) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-5) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-6) vcld, main (line: 342)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|VMware.pm:load(335)|failed to prepare vmdk file
> for vmguest-2 on VM host: localvmhost
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) VMware.pm, load (line: 335)
>
> |8437|2:3|reload| (-2) new.pm <http://new.pm/>, reload_image (line: 687)
>
> |8437|2:3|reload| (-3) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-4) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-5) vcld, main (line: 342)
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|new.pm:reload_image(692)|vmwarelinux-base9-v3
> failed to load on vmguest-2, returning
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) new.pm <http://new.pm/>, reload_image (line: 692)
>
> |8437|2:3|reload| (-2) new.pm <http://new.pm/>, process (line: 282)
>
> |8437|2:3|reload| (-3) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-4) vcld, main (line: 342)
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, loadimagefailed, vmwarelinux-base9-v3 failed to load on
> vmguest-2
>
> |8437|2:3|reload| ---- WARNING ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|new.pm:process(329)|failed to load vmguest-2
> with vmwarelinux-base9-v3
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) new.pm <http://new.pm/>, process (line: 329)
>
> |8437|2:3|reload| (-2) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-3) vcld, main (line: 342)
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vmguest-2 from the database
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vmguest-2 from the database: reloading
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|DataStructure.pm:_automethod(786)|data
> structure updated:
> $self->request_data->{reservation}{3}{computer}{state}{name}
>
> |8437|2:3|reload| computer_state_name = reloading
>
> 2010-12-27 10:43:40|8437|2:3|reload|utils.pm:mail(1247)|SUCCESS --
> Sending mail To: 0, PROBLEM -- State.pm
>
> |8437|2:3|reload| ---- CRITICAL ----
>
> |8437|2:3|reload| 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(287)|reservation
> failed on vmguest-2: process failed after trying to load or make available
>
> |8437|2:3|reload| ( 0) utils.pm <http://utils.pm/>, notify (line: 630)
>
> |8437|2:3|reload| (-1) State.pm, reservation_failed (line: 287)
>
> |8437|2:3|reload| (-2) new.pm <http://new.pm/>, process (line: 332)
>
> |8437|2:3|reload| (-3) vcld, make_new_child (line: 595)
>
> |8437|2:3|reload| (-4) vcld, main (line: 342)
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:insertloadlog(3933)|inserted
> computer=3, failed, process failed after trying to load or make available
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(290)|inserted
> computerloadlog entry
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:update_computer_state(2091)|computer 3
> state updated to: failed
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(309)|computer
> vmguest-2 (3) state set to failed
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:update_request_state(2049)|request 2
> state updated to: failed, laststate to: image
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:reservation_failed(322)|set
> request state to 'failed'/'image'
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:is_inblockrequest(6250)|zero rows were
> returned from database select
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(340)|vmguest-2 is
> NOT in blockcomputers table
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|State.pm:reservation_failed(343)|exiting 1
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(902)|destructor
> called, ref($self)=VCL::new
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:delete_computerloadlog_reservation(6829)|removing
> computerloadlog entries matching loadstate = begin
>
> 2010-12-27
> 10:43:40|8437|2:3|reload|utils.pm:delete_computerloadlog_reservation(6876)|deleted
> rows from computerloadlog for reservation id=3
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(909)|removed
> computerloadlog rows with loadstate=begin for reservation
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(921)|number of
> database handles state process created: 1
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(930)|process has a
> database handle stored in $ENV{dbh}, attempting disconnect
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(932)|$ENV{dbh}:
> database disconnect successful
>
> 2010-12-27 10:43:40|8437|2:3|reload|State.pm:DESTROY(946)|VCL::new
> process 8437 exiting
>
> End Disconnect
>