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 2010/12/10 20:44:14 UTC
vsphere SDK (image reservation failed)
Good evening everybody,
We are installing and configuring a standalone VCL environment using VCL
2.0, we started the reservation a few hours ago and we are stopped because
of the reservation failed.
The problem seem to be related to the vsphere SDK (login and password), but
I don’t know how to resolve it.
Please advice.
Cordially,
Gibet Tani Hicham
Here is the VCL log:
2010-12-10 15:10:20|6913|1:3|image|utils.pm:reservation_being_processed(9010)|computerloadlog
'begin' entry does NOT exist for reservation 3
2010-12-10 15:10:21|6913|1:3|image|utils.pm:run_command(9082)|executed
command: pgrep -fl 'vcld [0-9]+:3 ', pid: 10067, exit status: 1, output:
2010-12-10 15:10:21|6913|1:3|image|utils.pm:is_management_node_process_running(9259)|process
is NOT running, identifier: 'vcld [0-9]+:3 '
2010-12-10 15:10:21|6913|1:3|image|utils.pm:reservation_being_processed(9031)|reservation
is NOT currently being processed
2010-12-10 15:10:21|6913|1:3|image|vcld:main(277)|reservation 3 is NOT
already being processed
2010-12-10 15:10:21|6913|1:3|image|utils.pm:get_request_info(4589)|standalone
affiliation found: Local
2010-12-10 15:10:21|6913|1:3|image|vcld:main(282)|retrieved request
information from database
2010-12-10
15:10:21|6913|1:3|image|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-10 15:10:21|6913|1:3|image|utils.pm:update_request_state(2049)|request
1 state updated to: pending, laststate to: image
2010-12-10 15:10:21|6913|1:3|image|utils.pm:insertloadlog(3933)|inserted
computer=2, begin, beginning to process, state is image
2010-12-10 15:10:21|6913|1:3|image|vcld:make_new_child(510)|loaded
VCL::image module
2010-12-10 15:10:21|6913|1:3|image|vcld:make_new_child(567)|current number
of forked kids: 1
2010-12-10 15:10:21|10081|1:3|image|vcld:make_new_child(583)|vcld
environment variable set to 0 for this process
2010-12-10 15:10:21|10081|1:3|image|Module.pm:new(134)|constructor called,
class=VCL::image
2010-12-10 15:10:21|10081|1:3|image|Module.pm:new(156)|VCL::image object
created
2010-12-10 15:10:21|10081|1:3|image|State.pm:initialize(85)|obtained a
database handle for this state process, stored as $ENV{dbh}
2010-12-10 15:10:21|10081|1:3|image|State.pm:check_image_os(836)|no
corrections need to be made to image OS: vmwarelinux
2010-12-10
15:10:21|10081|1:3|image|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-10 15:10:21|10081|1:3|image|utils.pm:rename_vcld_process(7183)|reservation
count: 1
2010-12-10 15:10:21|10081|1:3|image|utils.pm:rename_vcld_process(7202)|PARENTIMAGE:
1
2010-12-10 15:10:21|10081|1:3|image|utils.pm:rename_vcld_process(7203)|SUBIMAGE:
0
2010-12-10 15:10:21|10081|1:3|image|utils.pm:rename_vcld_process(7221)|renamed
process to 'vcld 1:3 image vmguest-1 vmwarelinux-base8-v1 admin (imaging)'
2010-12-10
15:10:21|10081|1:3|image|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-10
15:10:21|10081|1:3|image|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 3
2010-12-10 15:10:21|10081|1:3|image|State.pm:initialize(118)|attempting to
load provisioning module: VCL::Module::Provisioning::VMware::VMware
2010-12-10
15:10:21|10081|1:3|image|State.pm:initialize(124)|VCL::Module::Provisioning::VMware::VMware
module loaded
2010-12-10 15:10:21|10081|1:3|image|Module.pm:new(134)|constructor called,
class=VCL::Module::Provisioning::VMware::VMware
2010-12-10
15:10:21|10081|1:3|image|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VMware
object created
2010-12-10
15:10:21|10081|1:3|image|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 1
2010-12-10
15:10:21|10081|1:3|image|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: localvmhost
2010-12-10
15:10:21|10081|1:3|image|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 1
2010-12-10
15:10:21|10081|1:3|image|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: localvmhost
2010-12-10
15:10:21|10081|1:3|image|VMware.pm:get_vmhost_api_object(1027)|attempting to
load VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
2010-12-10
15:10:21|10081|1:3|image|VMware.pm:get_vmhost_api_object(1033)|loaded VMware
control module: VCL::Module::Provisioning::VMware::vSphere_SDK
2010-12-10 15:10:21|10081|1:3|image|Module.pm:new(134)|constructor called,
class=VCL::Module::Provisioning::VMware::vSphere_SDK
2010-12-10
15:10:21|10081|1:3|image|Module.pm:new(156)|VCL::Module::Provisioning::VMware::vSphere_SDK
object created
2010-12-10 *15:10:21|10081|1:3|image|vSphere_SDK.pm:initialize(1816)|attempting
to connect to VM host: https://localvmhost/sdk*
*2010-12-10 15:10:21|10081|1:3|image|vSphere_SDK.pm:initialize(1822)|unable
to connect to VM host: https://localvmhost/sdk, username: '0', error:*
*|10081|1:3|image| Server version unavailable at '
https://localvmhost:443/sdk/vimService.wsdl' at
/usr/lib/perl5/5.8.8/VMware/VICommon.pm line 545.*
*2010-12-10
15:10:21|10081|1:3|image|vSphere_SDK.pm:initialize(1816)|attempting to
connect to VM host: https://localvmhost:8333/sdk*
*2010-12-10 15:10:23|10081|1:3|image|vSphere_SDK.pm:initialize(1822)|unable
to connect to VM host: https://localvmhost:8333/sdk, username: '0', error:*
*|10081|1:3|image| Error connecting to server at '
https://localvmhost:8333/sdk': Login failed due to a bad username or
password*
* *
*|10081|1:3|image| ---- WARNING ---- *
*|10081|1:3|image| 2010-12-10
15:10:23|10081|1:3|image|vSphere_SDK.pm:initialize(1831)|failed to connect
to VM host: localvmhost*
|10081|1:3|image| ( 0) utils.pm, notify (line: 630)
|10081|1:3|image| (-1) vSphere_SDK.pm, initialize (line: 1831)
|10081|1:3|image| (-2) Module.pm, new (line: 159)
|10081|1:3|image| (-3) VMware.pm, (eval) (line: 1037)
|10081|1:3|image| (-4) VMware.pm, get_vmhost_api_object (line: 1037)
|10081|1:3|image| (-5) VMware.pm, initialize (line: 224)
|10081|1:3|image| (-6) Module.pm, new (line: 159)
|10081|1:3|image| ---- WARNING ----
|10081|1:3|image| 2010-12-10
15:10:23|10081|1:3|image|VMware.pm:get_vmhost_api_object(1040)|API object
could not be created: VCL::Module::Provisioning::VMware::vSphere_SDK, no
eval error
|10081|1:3|image| ( 0) utils.pm, notify (line: 630)
|10081|1:3|image| (-1) VMware.pm, get_vmhost_api_object (line: 1040)
|10081|1:3|image| (-2) VMware.pm, initialize (line: 224)
|10081|1:3|image| (-3) Module.pm, new (line: 159)
|10081|1:3|image| (-4) State.pm, initialize (line: 127)
|10081|1:3|image| (-5) Module.pm, new (line: 159)
|10081|1:3|image| (-6) vcld, make_new_child (line: 591)
2010-12-10 15:10:23|10081|1:3|image|VMware.pm:initialize(240)|attempting to
create OS object for the image currently loaded on the VM host: localvmhost
|10081|1:3|image| image name: noimage
|10081|1:3|image| OS module: VCL::Module::OS::Linux::UnixLab
2010-12-10
15:10:23|10081|1:3|image|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 1
2010-12-10
15:10:23|10081|1:3|image|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: localvmhost
2010-12-10
15:10:23|10081|1:3|image|VMware.pm:get_vmhost_os_object(965)|attempting to
load VM host OS module: VCL::Module::OS::Linux::UnixLab
2010-12-10 15:10:24|10081|1:3|image|VMware.pm:get_vmhost_os_object(971)|VM
host OS module loaded: VCL::Module::OS::Linux::UnixLab
2010-12-10 15:10:24|10081|1:3|image|Module.pm:new(134)|constructor called,
class=VCL::Module::OS::Linux::UnixLab
2010-12-10
15:10:24|10081|1:3|image|Module.pm:new(156)|VCL::Module::OS::Linux::UnixLab
object created
2010-12-10 15:10:24|10081|1:3|image|VMware.pm:get_vmhost_os_object(977)|VM
host OS object created: VCL::Module::OS::Linux::UnixLab
2010-12-10 15:10:24|10081|1:3|image|VMware.pm:initialize(241)|created OS
object to control the OS of VM host: localvmhost
2010-12-10 15:10:24|10081|1:3|image|utils.pm:nmap_port(2699)|port 22 is open
on localvmhost
2010-12-10 15:10:24|10081|1:3|image|utils.pm:nmap_port(2707)|port 24 is
closed on localvmhost
2010-12-10 15:10:26|6913|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-10 15:10:26
2010-12-10 15:10:28|10081|1:3|image|OS.pm:is_ssh_responding(430)|localvmhost
is responding to SSH, port 22: open, port 24: closed
2010-12-10 15:10:28|10081|1:3|image|VMware.pm:initialize(250)|OS of VM host
localvmhost will be controlled via SSH using OS object:
VCL::Module::OS::Linux::UnixLab
2010-12-10
15:10:28|10081|1:3|image|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 1
2010-12-10
15:10:28|10081|1:3|image|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: localvmhost
2010-12-10
15:10:28|10081|1:3|image|VMware.pm:get_vmhost_api_object(1027)|attempting to
load VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
2010-12-10
15:10:28|10081|1:3|image|VMware.pm:get_vmhost_api_object(1033)|loaded VMware
control module: VCL::Module::Provisioning::VMware::VIM_SSH
2010-12-10 15:10:28|10081|1:3|image|Module.pm:new(134)|constructor called,
class=VCL::Module::Provisioning::VMware::VIM_SSH
2010-12-10
15:10:28|10081|1:3|image|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VIM_SSH
object created
2010-12-10 15:10:31|6913|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-10 15:10:31
2010-12-10 15:10:34|10081|1:3|image|VIM_SSH.pm:initialize(141)|VIM
executable available on VM host: vmware-vim-cmd
2010-12-10
15:10:34|10081|1:3|image|VIM_SSH.pm:initialize(143)|VCL::Module::Provisioning::VMware::VIM_SSH
object initialized
2010-12-10
15:10:34|10081|1:3|image|VMware.pm:get_vmhost_api_object(1046)|created API
object: VCL::Module::Provisioning::VMware::VIM_SSH
2010-12-10 15:10:34|10081|1:3|image|VMware.pm:initialize(264)|VIM SSH
command object will be used to control the VM: vmguest-1
2010-12-10 15:10:36|6913|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-10 15:10:36
2010-12-10
15:10:38|10081|1:3|image|VMware.pm:get_vmhost_product_name(4089)|VMware
product being used on VM host localvmhost: 'VMware Server 2.0.2
build-203138'
2010-12-10 15:10:41|6913|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-10 15:10:41
2010-12-10 15:10:44|10081|1:3|image|VMware.pm:initialize(294)|VMware
provisioning object initialized:
|10081|1:3|image| VM host OS object type: VCL::Module::OS::Linux::UnixLab
|10081|1:3|image| API object type:
VCL::Module::Provisioning::VMware::VIM_SSH
2010-12-10
15:10:44|10081|1:3|image|State.pm:initialize(128)|VCL::Module::Provisioning::VMware::VMware
provisioner object created
2010-12-10 15:10:44|10081|1:3|image|State.pm:initialize(142)|attempting to
load OS module: VCL::Module::OS::Linux
2010-12-10
15:10:44|10081|1:3|image|State.pm:initialize(148)|VCL::Module::OS::Linux
module loaded
2010-12-10 15:10:44|10081|1:3|image|Module.pm:new(134)|constructor called,
class=VCL::Module::OS::Linux
2010-12-10
15:10:44|10081|1:3|image|Module.pm:new(156)|VCL::Module::OS::Linux object
created
2010-12-10
15:10:44|10081|1:3|image|State.pm:initialize(151)|VCL::Module::OS::Linux OS
object created
2010-12-10 15:10:44|10081|1:3|image|State.pm:initialize(166)|returning 1
2010-12-10 15:10:44|10081|1:3|image|vcld:make_new_child(592)|VCL::image
object created and initialized
|10081|1:3|image| ---- WARNING ----
|10081|1:3|image| 2010-12-10
15:10:44|10081|1:3|image|DataStructure.pm:_automethod(764)|corresponding
data has not been initialized for get_management_node_sysadmin_email:
$ENV{management_node_info}{SYSADMIN_EMAIL}
|10081|1:3|image| ( 0) utils.pm, notify (line: 630)
|10081|1:3|image| (-1) DataStructure.pm, _automethod (line: 764)
|10081|1:3|image| (-2) Autoload.pm, __ANON__ (line: 80)
|10081|1:3|image| (-3) image.pm, process (line: 108)
|10081|1:3|image| (-4) vcld, make_new_child (line: 595)
|10081|1:3|image| (-5) vcld, main (line: 342)
*2010-12-10 15:10:46|6913|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-12-10 15:10:46*
*2010-12-10 15:10:50|10081|1:3|image|VMware.pm:does_image_exist(2936)|image
exists in the non-persistent directory on the VM host:
/var/lib/vmware/Virtual\
Machines/vmwarelinux-base8-v1/vmwarelinux-base8-v1.vmdk*
2010-12-10 15:10:50|10081|1:3|image|utils.pm:mail(1247)|SUCCESS -- Sending
mail To: 0, PROBLEM -- image.pm
|10081|1:3|image| ---- CRITICAL ----
|10081|1:3|image| 2010-12-10
15:10:50|10081|1:3|image|image.pm:process(140)|image
vmwarelinux-base8-v1 already exists in the repository
|10081|1:3|image| ( 0) utils.pm, notify (line: 630)
|10081|1:3|image| (-1) image.pm, process (line: 140)
|10081|1:3|image| (-2) vcld, make_new_child (line: 595)
|10081|1:3|image| (-3) vcld, main (line: 342)
|10081|1:3|image| ---- WARNING ----
|10081|1:3|image| 2010-12-10
15:10:50|10081|1:3|image|DataStructure.pm:_automethod(764)|corresponding
data has not been initialized for get_management_node_sysadmin_email:
$ENV{management_node_info}{SYSADMIN_EMAIL}
|10081|1:3|image| ( 0) utils.pm, notify (line: 630)
|10081|1:3|image| (-1) DataStructure.pm, _automethod (line: 764)
|10081|1:3|image| (-2) Autoload.pm, __ANON__ (line: 80)
|10081|1:3|image| (-3) image.pm, reservation_failed (line: 390)
|10081|1:3|image| (-4) image.pm, process (line: 141)
|10081|1:3|image| (-5) vcld, make_new_child (line: 595)
|10081|1:3|image| (-6) vcld, main (line: 342)
2010-12-10 15:10:50|10081|1:3|image|utils.pm:mail(1247)|SUCCESS -- Sending
mail To: 0, PROBLEM -- image.pm
|10081|1:3|image| ---- CRITICAL ----
|10081|1:3|image| 2010-12-10
15:10:50|10081|1:3|image|image.pm:reservation_failed(393)|vmwarelinux-base8-v1
image creation failed
|10081|1:3|image| ( 0) utils.pm, notify (line: 630)
|10081|1:3|image| (-1) image.pm, reservation_failed (line: 393)
|10081|1:3|image| (-2) image.pm, process (line: 141)
|10081|1:3|image| (-3) vcld, make_new_child (line: 595)
|10081|1:3|image| (-4) vcld, main (line: 342)
2010-12-10 15:10:50|10081|1:3|image|utils.pm:mail(1247)|SUCCESS -- Sending
mail To: root@localhost, VCL -- NOTICE DELAY Image Creation No Apps (Ubuntu)
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.
|10081|1:3|image| ---- WARNING ----
|10081|1:3|image| 2010-12-10
15:10:50|10081|1:3|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.
|10081|1:3|image| ( 0) utils.pm, notify (line: 630)
|10081|1:3|image| (-1) vcld, warning_handler (line: 637)
|10081|1:3|image| (-2) rfc822.pm, set_headers (line: 22)
|10081|1:3|image| (-3) Mailer.pm, open (line: 162)
|10081|1:3|image| (-4) utils.pm, mail (line: 1241)
|10081|1:3|image| (-5) image.pm, reservation_failed (line: 442)
|10081|1:3|image| (-6) image.pm, process (line: 141)
|10081|1:3|image| ---- WARNING ----
|10081|1:3|image| 2010-12-10
15:10:50|10081|1:3|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.
|10081|1:3|image| ( 0) utils.pm, notify (line: 630)
|10081|1:3|image| (-1) vcld, warning_handler (line: 637)
|10081|1:3|image| (-2) rfc822.pm, set_headers (line: 23)
|10081|1:3|image| (-3) Mailer.pm, open (line: 162)
|10081|1:3|image| (-4) utils.pm, mail (line: 1241)
|10081|1:3|image| (-5) image.pm, reservation_failed (line: 442)
|10081|1:3|image| (-6) image.pm, process (line: 141)
No recipient addresses found in header
|10081|1:3|image| ---- WARNING ----
|10081|1:3|image| 2010-12-10
15:10:51|10081|1:3|image|vcld:warning_handler(637)|Use of uninitialized
value in concatenation (.) or string at /usr/local/vcl/bin/../lib/VCL/
utils.pm line 1247.
|10081|1:3|image| ( 0) utils.pm, notify (line: 630)
|10081|1:3|image| (-1) vcld, warning_handler (line: 637)
|10081|1:3|image| (-2) utils.pm, mail (line: 1247)
|10081|1:3|image| (-3) image.pm, reservation_failed (line: 442)
|10081|1:3|image| (-4) image.pm, process (line: 141)
|10081|1:3|image| (-5) vcld, make_new_child (line: 595)
|10081|1:3|image| (-6) vcld, main (line: 342)
2010-12-10 15:10:51|10081|1:3|image|utils.pm:mail(1247)|SUCCESS -- Sending
mail To: , VCL -- NOTICE FAILED Image Creation No Apps (Ubuntu)
2010-12-10 15:10:51|10081|1:3|image|utils.pm:update_request_state(2049)|request
1 state updated to: maintenance, laststate to: image
2010-12-10 15:10:51|10081|1:3|image|image.pm:reservation_failed(445)|request
state set to maintenance, laststate to image
2010-12-10 15:10:51|10081|1:3|image|utils.pm:update_computer_state(2091)|computer
2 state updated to: maintenance
2010-12-10 15:10:51|10081|1:3|image|image.pm:reservation_failed(453)|vmguest-1
state set to maintenance
2010-12-10 15:10:51|10081|1:3|image|image.pm:reservation_failed(460)|exiting
2010-12-10 15:10:51|10081|1:3|image|State.pm:DESTROY(902)|destructor called,
ref($self)=VCL::image
2010-12-10 15:10:51|10081|1:3|image|utils.pm:delete_computerloadlog_reservation(6829)|removing
computerloadlog entries matching loadstate = begin
2010-12-10 15:10:51|10081|1:3|image|utils.pm:delete_computerloadlog_reservation(6876)|deleted
rows from computerloadlog for reservation id=3
2010-12-10 15:10:51|10081|1:3|image|State.pm:DESTROY(909)|removed
computerloadlog rows with loadstate=begin for reservation
2010-12-10 15:10:51|10081|1:3|image|State.pm:DESTROY(921)|number of database
handles state process created: 1
2010-12-10 15:10:51|10081|1:3|image|State.pm:DESTROY(930)|process has a
database handle stored in $ENV{dbh}, attempting disconnect
2010-12-10 15:10:51|10081|1:3|image|State.pm:DESTROY(932)|$ENV{dbh}:
database disconnect successful
2010-12-10 15:10:51|10081|1:3|image|State.pm:DESTROY(946)|VCL::image process
10081 exiting