Good afternoon everybody,
We started testing VCL 2.2 and we did all the configuration steps for a
standalone VMware VCL environment but we are experiencing some problems with
the API object.
2010-10-12
11:55:53|7432|1:5|image|utils.pm:reservation_being_processed(9010)|computerloadlog
'begin' entry does NOT exist for reservation 5
2010-10-12 11:55:53|7432|1:5|image|utils.pm:run_command(9082)|executed
command: pgrep -fl 'vcld [0-9]+:5 ', pid: 8924, exit status: 1, output:
2010-10-12
11:55:53|7432|1:5|image|utils.pm:is_management_node_process_running(9259)|process
is NOT running, identifier: 'vcld [0-9]+:5 '
2010-10-12
11:55:53|7432|1:5|image|utils.pm:reservation_being_processed(9031)|reservation
is NOT currently being processed
2010-10-12 11:55:53|7432|1:5|image|vcld:main(277)|reservation 5 is NOT
already being processed
2010-10-12 11:55:53|7432|1:5|image|utils.pm:get_request_info(4589)|standalone
affiliation found: Local
2010-10-12 11:55:53|7432|1:5|image|vcld:main(282)|retrieved request
information from database
2010-10-12
11:55:53|7432|1:5|image|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 5
2010-10-12 11:55:53|7432|1:5|image|utils.pm:update_request_state(2049)|request
1 state updated to: pending, laststate to: image
2010-10-12 11:55:53|7432|1:5|image|utils.pm:insertloadlog(3933)|inserted
computer=4, begin, beginning to process, state is image
2010-10-12 11:55:53|7432|1:5|image|vcld:make_new_child(510)|loaded
VCL::image module
2010-10-12 11:55:53|8938|1:5|image|vcld:make_new_child(583)|vcld environment
variable set to 0 for this process
2010-10-12 11:55:53|7432|1:5|image|vcld:make_new_child(567)|current number
of forked kids: 1
2010-10-12 11:55:53|8938|1:5|image|Module.pm:new(134)|constructor called,
class=VCL::image
2010-10-12 11:55:53|8938|1:5|image|Module.pm:new(156)|VCL::image object
created
2010-10-12 11:55:53|8938|1:5|image|State.pm:initialize(85)|obtained a
database handle for this state process, stored as $ENV{dbh}
2010-10-12 11:55:53|8938|1:5|image|State.pm:check_image_os(836)|no
corrections need to be made to image OS: vmwarelinux
2010-10-12
11:55:53|8938|1:5|image|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 5
2010-10-12
11:55:53|8938|1:5|image|utils.pm:rename_vcld_process(7183)|reservation
count: 1
2010-10-12
11:55:53|8938|1:5|image|utils.pm:rename_vcld_process(7202)|PARENTIMAGE:
1
2010-10-12 11:55:53|8938|1:5|image|utils.pm:rename_vcld_process(7203)|SUBIMAGE:
0
2010-10-12 11:55:53|8938|1:5|image|utils.pm:rename_vcld_process(7221)|renamed
process to 'vcld 1:5 image vmguest-1 vmwarelinux-base8-v1 admin'
2010-10-12
11:55:53|8938|1:5|image|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 5
2010-10-12
11:55:53|8938|1:5|image|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 5
2010-10-12 11:55:53|8938|1:5|image|State.pm:initialize(118)|attempting to
load provisioning module: VCL::Module::Provisioning::VMware::VMware
2010-10-12
11:55:53|8938|1:5|image|State.pm:initialize(124)|VCL::Module::Provisioning::VMware::VMware
module loaded
2010-10-12 11:55:53|8938|1:5|image|Module.pm:new(134)|constructor called,
class=VCL::Module::Provisioning::VMware::VMware
2010-10-12
11:55:53|8938|1:5|image|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VMware
object created
2010-10-12
11:55:53|8938|1:5|image|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 3
2010-10-12
11:55:53|8938|1:5|image|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: localvmhost
2010-10-12
11:55:53|8938|1:5|image|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 3
2010-10-12
11:55:53|8938|1:5|image|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: localvmhost
2010-10-12
11:55:53|8938|1:5|image|VMware.pm:get_vmhost_api_object(1027)|attempting to
load VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
2010-10-12
11:55:53|8938|1:5|image|VMware.pm:get_vmhost_api_object(1033)|loaded VMware
control module: VCL::Module::Provisioning::VMware::vSphere_SDK
2010-10-12 11:55:53|8938|1:5|image|Module.pm:new(134)|constructor called,
class=VCL::Module::Provisioning::VMware::vSphere_SDK
2010-10-12
11:55:53|8938|1:5|image|Module.pm:new(156)|VCL::Module::Provisioning::VMware::vSphere_SDK
object created
|8938|1:5|image| ---- WARNING ----
|8938|1:5|image| 2010-10-12
11:55:53|8938|1:5|image|vSphere_SDK.pm:initialize(1789)|VM host password is
not configured in the database for the VM profile
|8938|1:5|image| ( 0) utils.pm, notify (line: 630)
|8938|1:5|image| (-1) vSphere_SDK.pm, initialize (line: 1789)
|8938|1:5|image| (-2) Module.pm, new (line: 159)
|8938|1:5|image| (-3) VMware.pm, (eval) (line: 1037)
|8938|1:5|image| (-4) VMware.pm, get_vmhost_api_object (line: 1037)
|8938|1:5|image| (-5) VMware.pm, initialize (line: 224)
|8938|1:5|image| (-6) Module.pm, new (line: 159)
|8938|1:5|image| ---- WARNING ----
|8938|1:5|image| 2010-10-12
11:55:53|8938|1:5|image|VMware.pm:get_vmhost_api_object(1040)|API object
could not be created: VCL::Module::Provisioning::VMware::vSphere_SDK, no
eval error
|8938|1:5|image| ( 0) utils.pm, notify (line: 630)
|8938|1:5|image| (-1) VMware.pm, get_vmhost_api_object (line: 1040)
|8938|1:5|image| (-2) VMware.pm, initialize (line: 224)
|8938|1:5|image| (-3) Module.pm, new (line: 159)
|8938|1:5|image| (-4) State.pm, initialize (line: 127)
|8938|1:5|image| (-5) Module.pm, new (line: 159)
|8938|1:5|image| (-6) vcld, make_new_child (line: 591)
2010-10-12 11:55:53|8938|1:5|image|VMware.pm:initialize(240)|attempting to
create OS object for the image currently loaded on the VM host: localvmhost
|8938|1:5|image| image name: noimage
|8938|1:5|image| OS module: VCL::Module::OS::Linux::UnixLab
2010-10-12
11:55:53|8938|1:5|image|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 3
2010-10-12
11:55:53|8938|1:5|image|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: localvmhost
2010-10-12
11:55:53|8938|1:5|image|VMware.pm:get_vmhost_os_object(965)|attempting to
load VM host OS module: VCL::Module::OS::Linux::UnixLab
2010-10-12 11:55:53|8938|1:5|image|VMware.pm:get_vmhost_os_object(971)|VM
host OS module loaded: VCL::Module::OS::Linux::UnixLab
2010-10-12 11:55:53|8938|1:5|image|Module.pm:new(134)|constructor called,
class=VCL::Module::OS::Linux::UnixLab
2010-10-12
11:55:53|8938|1:5|image|Module.pm:new(156)|VCL::Module::OS::Linux::UnixLab
object created
2010-10-12 11:55:53|8938|1:5|image|VMware.pm:get_vmhost_os_object(977)|VM
host OS object created: VCL::Module::OS::Linux::UnixLab
2010-10-12 11:55:53|8938|1:5|image|VMware.pm:initialize(241)|created OS
object to control the OS of VM host: localvmhost
2010-10-12 11:55:53|8938|1:5|image|utils.pm:nmap_port(2699)|port 22 is open
on localvmhost
2010-10-12 11:55:53|8938|1:5|image|utils.pm:nmap_port(2707)|port 24 is
closed on localvmhost
2010-10-12 11:55:54|8938|1:5|image|OS.pm:is_ssh_responding(430)|localvmhost
is responding to SSH, port 22: open, port 24: closed
2010-10-12 11:55:54|8938|1:5|image|VMware.pm:initialize(250)|OS of VM host
localvmhost will be controlled via SSH using OS object:
VCL::Module::OS::Linux::UnixLab
2010-10-12
11:55:54|8938|1:5|image|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 3
2010-10-12
11:55:54|8938|1:5|image|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: localvmhost
2010-10-12
11:55:54|8938|1:5|image|VMware.pm:get_vmhost_api_object(1027)|attempting to
load VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
2010-10-12
11:55:54|8938|1:5|image|VMware.pm:get_vmhost_api_object(1033)|loaded VMware
control module: VCL::Module::Provisioning::VMware::VIM_SSH
2010-10-12 11:55:54|8938|1:5|image|Module.pm:new(134)|constructor called,
class=VCL::Module::Provisioning::VMware::VIM_SSH
2010-10-12
11:55:54|8938|1:5|image|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VIM_SSH
object created
2010-10-12 11:55:54|8938|1:5|image|VIM_SSH.pm:initialize(126)|failed to
determine which VIM executable is available on the VM host, output:
|8938|1:5|image| bash: vim-cmd: command not found
|8938|1:5|image| bash: vmware-vim-cmd: command not found
|8938|1:5|image| ---- WARNING ----
|8938|1:5|image| 2010-10-12
11:55:54|8938|1:5|image|VMware.pm:get_vmhost_api_object(1040)|API object
could not be created: VCL::Module::Provisioning::VMware::VIM_SSH, no eval
error
|8938|1:5|image| ( 0) utils.pm, notify (line: 630)
|8938|1:5|image| (-1) VMware.pm, get_vmhost_api_object (line: 1040)
|8938|1:5|image| (-2) VMware.pm, initialize (line: 264)
|8938|1:5|image| (-3) Module.pm, new (line: 159)
|8938|1:5|image| (-4) State.pm, initialize (line: 127)
|8938|1:5|image| (-5) Module.pm, new (line: 159)
|8938|1:5|image| (-6) vcld, make_new_child (line: 591)
|8938|1:5|image| ---- WARNING ----
|8938|1:5|image| 2010-10-12
11:55:54|8938|1:5|image|VMware.pm:initialize(271)|failed to create an API
object to control the VM: vmguest-1
|8938|1:5|image| ( 0) utils.pm, notify (line: 630)
|8938|1:5|image| (-1) VMware.pm, initialize (line: 271)
|8938|1:5|image| (-2) Module.pm, new (line: 159)
|8938|1:5|image| (-3) State.pm, initialize (line: 127)
|8938|1:5|image| (-4) Module.pm, new (line: 159)
|8938|1:5|image| (-5) vcld, make_new_child (line: 591)
|8938|1:5|image| (-6) vcld, main (line: 342)
|8938|1:5|image| ---- WARNING ----
|8938|1:5|image| 2010-10-12
11:55:54|8938|1:5|image|State.pm:initialize(132)|provisioning object could
not be created, returning 0
|8938|1:5|image| ( 0) utils.pm, notify (line: 630)
|8938|1:5|image| (-1) State.pm, initialize (line: 132)
|8938|1:5|image| (-2) Module.pm, new (line: 159)
|8938|1:5|image| (-3) vcld, make_new_child (line: 591)
|8938|1:5|image| (-4) vcld, main (line: 342)
2010-10-12 11:55:54|8938|1:5|image|State.pm:DESTROY(902)|destructor called,
ref($self)=VCL::image
2010-10-12
11:55:54|8938|1:5|image|utils.pm:delete_computerloadlog_reservation(6829)|removing
computerloadlog entries matching loadstate = begin
2010-10-12
11:55:54|8938|1:5|image|utils.pm:delete_computerloadlog_reservation(6876)|deleted
rows from computerloadlog for reservation id=5
2010-10-12 11:55:54|8938|1:5|image|State.pm:DESTROY(909)|removed
computerloadlog rows with loadstate=begin for reservation
2010-10-12 11:55:54|8938|1:5|image|State.pm:DESTROY(921)|number of database
handles state process created: 1
2010-10-12 11:55:54|8938|1:5|image|State.pm:DESTROY(930)|process has a
database handle stored in $ENV{dbh}, attempting disconnect
2010-10-12 11:55:54|8938|1:5|image|State.pm:DESTROY(932)|$ENV{dbh}: database
disconnect successful
2010-10-12 11:55:54|8938|1:5|image|State.pm:DESTROY(946)|VCL::image process
8938 exiting
2010-10-12 11:55:55|8938|1:5|image|utils.pm:mail(1234)|SUCCESS -- Sending
mail To: [email protected], PROBLEM -- vcld
|8938|1:5|image| ---- CRITICAL ----
|8938|1:5|image| 2010-10-12
11:55:54|8938|1:5|image|vcld:make_new_child(598)|VCL::image object could not
be created and initialized
|8938|1:5|image| ( 0) utils.pm, notify (line: 630)
|8938|1:5|image| (-1) vcld, make_new_child (line: 598)
|8938|1:5|image| (-2) vcld, main (line: 342)
2010-10-12 11:55:55|8938|1:5|image|utils.pm:switch_state(7338)|called from
VCL::vcld::make_new_child(599)
2010-10-12 11:55:55|8938|1:5|image|utils.pm:switch_state(7374)|parent:
parent reservation ID for this request: 5
2010-10-12 11:55:55|8938|1:5|image|utils.pm:getnewdbh(2761)|unable to use
database handle stored in $ENV{dbh}
2010-10-12 11:55:55|8938|1:5|image|utils.pm:getnewdbh(2818)|database handle
stored in $ENV{dbh}
2010-10-12 11:55:55|8938|1:5|image|utils.pm:insertloadlog(3933)|inserted
computer=4, info, VCL::vcld: switching request state to failed
2010-10-12 11:55:55|8938|1:5|image|utils.pm:update_request_state(2049)|request
1 state updated to: failed, laststate to: image
2010-10-12 11:55:55|8938|1:5|image|utils.pm:switch_state(7398)|req=1:
request state changed: image->failed, laststate: image->image
2010-10-12 11:55:55|8938|1:5|image|utils.pm:insertloadlog(3933)|inserted
computer=4, info, VCL::vcld: request state changed to failed, laststate to
image
2010-10-12 11:55:55|8938|1:5|image|utils.pm:switch_state(7408)|req=1:
computer state not specified, vmguest-1 state not changed
2010-10-12 11:55:55|8938|1:5|image|utils.pm:switch_state(7426)|req=1: log
table id=0, ending set to failed
2010-10-12 11:55:55|8938|1:5|image|utils.pm:insertloadlog(3933)|inserted
computer=4, info, VCL::vcld: process exiting
2010-10-12 11:55:55|8938|1:5|image|utils.pm:switch_state(7442)|req=1:
process exiting
2010-10-12 11:55:55|7432|vcld:REAPER(745)|VCL process exited for reservation
5, PID: 8938, signal: CHLD
2010-10-12 11:55:55|7432|vcld:main(166)|lastcheckin time updated for
management node 1: 2010-10-12 11:55:55
2010-10-12 11:55:55|7432|1:5|failed|vcld:main(251)|request deleted
Please we need your advice.
Cordially,
Gibet Tani Hicham
Eloutouate Lamiae.
