---------- Forwarded message ---------- From: Hicham Gibet Tani <hgtsweethone...@gmail.com> Date: 2010/10/12 Subject: Abdelmalek Essaadi university, Computer engineering department, MOROCCO To: vcl-user@incubator.apache.org
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: hgtsweethone...@gmail.com, 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.