Fwd: PROBLEM -- localhost|20:20|image|vcld|VM7Cent6VCL7>VM7|vmwarelinux-vm7vcl7222-v0|admin

[Elwin Litchfield <le...@mail.usf.edu>]

Do I have something configured incorrectly?  Is there more information
needed? I am totally lost.


---------- Forwarded message ----------
From: <ro...@localhost.localdomain>
Date: Fri, May 8, 2015 at 10:09 AM
Subject: PROBLEM --
localhost|20:20|image|vcld|VM7Cent6VCL7>VM7|vmwarelinux-vm7vcl7222-v0|admin
To: lewis15@mail.usf.edu


VCL::image object could not be created and initialized
------------------------------------------------------------------------
time: 2015-05-08 10:09:56
caller: vcld:make_new_child(574)
( 0) vcld, make_new_child (line: 574)
(-1) vcld, main (line: 350)
------------------------------------------------------------------------
management node: localhost
reservation PID: 12247
parent vcld PID: 26123

request ID: 20
reservation ID: 20
request state/laststate: image/image
request start time: 2015-05-08 10:07:06
request end time: 2015-05-08 11:07:06
for imaging: no
log ID: none

computer: VM7Cent6VCL7
computer id: 10
computer type: virtualmachine
computer eth0 MAC address: 00:50:56:1D:8B:C6
computer eth1 MAC address: 00:50:56:1D:8B:D0
computer private IP address: 192.168.10.70
computer public IP address: 131.247.29.235
computer in block allocation: no
provisioning module: VCL::Module::Provisioning::VMware::VMware

vm host: VM7
vm host ID: 2
vm host computer ID: 5
vm profile: VMware ESXi - local storage
vm profile VM path: datastore1
vm profile repository path: 'VMware ESXi - local storage'
vm profile datastore path: datastore1
vm profile disk type: shared

image: vmwarelinux-vm7vcl7222-v0
image display name: vm7vcl7-2
image ID: 22
image revision ID: 22
image size: 1450 MB
use Sysprep: yes
root access: yes
image owner ID: 1
image owner affiliation: Local
image revision date created: 2015-05-08 10:07:06
image revision production: yes
OS module: VCL::Module::OS::Linux

user: admin
user name: vcl admin
user ID: 1
user affiliation: Local
------------------------------------------------------------------------
RECENT LOG ENTRIES FOR THIS PROCESS:
2015-05-08 10:07:11|12247|20:20|image|utils.pm:run_ssh_command(4902)|executing
SSH command on VM7:
|12247|20:20|image| /usr/bin/ssh -i /etc/vcl/vcl.key  -o
StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o
ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'vim-cmd ;
vmware-vim-cmd' 2>&1
2015-05-08 10:07:12|12247|20:20|image|utils.pm:run_ssh_command(5020)|run_ssh_command
output:
|12247|20:20|image| Commands available under /:
|12247|20:20|image| hbrsvc/ internalsvc/ solo/ vmsvc/
|12247|20:20|image| hostsvc/ proxysvc/ vimsvc/ help
|12247|20:20|image| sh: vmware-vim-cmd: not found
2015-05-08 10:07:12|12247|20:20|image|utils.pm:run_ssh_command(5030)|SSH
command executed on VM7, command:
|12247|20:20|image| /usr/bin/ssh -i /etc/vcl/vcl.key  -o
StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o
ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'vim-cmd ;
vmware-vim-cmd' 2>&1
|12247|20:20|image| returning (127, "Commands available under /: hb...")
2015-05-08 10:07:12|12247|20:20|image|VIM_SSH.pm:initialize(138)|VIM
executable available on VM host: vim-cmd
2015-05-08
10:07:12|12247|20:20|image|VIM_SSH.pm:initialize(140)|VCL::Module::Provisioning::VMware::VIM_SSH
object initialized
2015-05-08
10:07:12|12247|20:20|image|VMware.pm:get_vmhost_api_object(1527)|created
API object: VCL::Module::Provisioning::VMware::VIM_SSH
2015-05-08 10:07:12|12247|20:20|image|VMware.pm:initialize(312)|VM host VM7
will be controlled using vim-cmd via SSH
2015-05-08 10:07:12|12247|20:20|image|VMware.pm:initialize(327)|VMware OS
and API objects created for VM host VM7:
|12247|20:20|image| VM host OS object type: VCL::Module::OS::Linux::UnixLab
|12247|20:20|image| VMware API object type:
VCL::Module::Provisioning::VMware::VIM_SSH
2015-05-08 10:07:12|12247|20:20|image|utils.pm:run_ssh_command(4902)|executing
SSH command on VM7:
|12247|20:20|image| /usr/bin/ssh -i /etc/vcl/vcl.key  -o
StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o
ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'vmware -v'
2>&1
2015-05-08 10:07:12|12247|20:20|image|utils.pm:run_ssh_command(5020)|run_ssh_command
output:
|12247|20:20|image| VMware ESXi 5.5.0 build-1331820
2015-05-08 10:07:12|12247|20:20|image|utils.pm:run_ssh_command(5034)|SSH
command executed on VM7, returning (0, "VMware ESXi 5.5.0 build-133182...")
2015-05-08
10:07:12|12247|20:20|image|VMware.pm:get_vmhost_product_name(6634)|VMware
product being used on VM host VM7: 'VMware ESXi 5.5.0 build-1331820'
2015-05-08 10:09:56|12247|20:20|image|VIM_SSH.pm:_run_vim_cmd(210)|executed
command on VM host VM7: vim-cmd hostsvc/datastore/listsummary
|12247|20:20|image| ---- WARNING ----
|12247|20:20|image| 2015-05-08
10:09:56|12247|20:20|image|VIM_SSH.pm:_get_datastore_info(492)|unable to
determine datastore names, unexpected output returned, VIM command
arguments: 'hostsvc/datastore/listsummary', output:
|12247|20:20|image| Failed to login: vim.fault.InvalidLogin
|12247|20:20|image| ( 0) VIM_SSH.pm, _get_datastore_info (line: 492)
|12247|20:20|image| (-1) VMware.pm, get_datastore_info (line: 6753)
|12247|20:20|image| (-2) VMware.pm, _get_datastore_name (line: 7056)
|12247|20:20|image| (-3) VMware.pm, _get_datastore_root_normal_path (line:
6914)
|12247|20:20|image| (-4) VMware.pm, _get_normal_path (line: 7006)
|12247|20:20|image| (-5) VMware.pm, get_vmx_base_directory_path (line: 3092)
|12247|20:20|image| ---- WARNING ----
|12247|20:20|image| 2015-05-08
10:09:56|12247|20:20|image|VMware.pm:get_datastore_info(6756)|failed to
retrieve datastore info from VCL::Module::Provisioning::VMware::VIM_SSH API
object
|12247|20:20|image| ( 0) VMware.pm, get_datastore_info (line: 6756)
|12247|20:20|image| (-1) VMware.pm, _get_datastore_name (line: 7056)
|12247|20:20|image| (-2) VMware.pm, _get_datastore_root_normal_path (line:
6914)
|12247|20:20|image| (-3) VMware.pm, _get_normal_path (line: 7006)
|12247|20:20|image| (-4) VMware.pm, get_vmx_base_directory_path (line: 3092)
|12247|20:20|image| (-5) VMware.pm, initialize (line: 340)
|12247|20:20|image| ---- WARNING ----
|12247|20:20|image| 2015-05-08
10:09:56|12247|20:20|image|VMware.pm:_get_datastore_root_normal_path(6916)|failed
to determine datastore root normal path, unable to determine datastore
name: datastore1
|12247|20:20|image| ( 0) VMware.pm, _get_datastore_root_normal_path (line:
6916)
|12247|20:20|image| (-1) VMware.pm, _get_normal_path (line: 7006)
|12247|20:20|image| (-2) VMware.pm, get_vmx_base_directory_path (line: 3092)
|12247|20:20|image| (-3) VMware.pm, initialize (line: 340)
|12247|20:20|image| (-4) Module.pm, new (line: 207)
|12247|20:20|image| (-5) Module.pm, create_provisioning_object (line: 522)
|12247|20:20|image| ---- WARNING ----
|12247|20:20|image| 2015-05-08
10:09:56|12247|20:20|image|VMware.pm:_get_normal_path(7008)|unable to
determine normal path, failed to determine datastore root normal path:
datastore1
|12247|20:20|image| ( 0) VMware.pm, _get_normal_path (line: 7008)
|12247|20:20|image| (-1) VMware.pm, get_vmx_base_directory_path (line: 3092)
|12247|20:20|image| (-2) VMware.pm, initialize (line: 340)
|12247|20:20|image| (-3) Module.pm, new (line: 207)
|12247|20:20|image| (-4) Module.pm, create_provisioning_object (line: 522)
|12247|20:20|image| (-5) State.pm, initialize (line: 136)
|12247|20:20|image| ---- WARNING ----
|12247|20:20|image| 2015-05-08
10:09:56|12247|20:20|image|VMware.pm:get_vmx_base_directory_path(3098)|unable
to determine the vmx base directory path, failed to convert path configured
in the VM profile to a normal path: datastore1
|12247|20:20|image| ( 0) VMware.pm, get_vmx_base_directory_path (line: 3098)
|12247|20:20|image| (-1) VMware.pm, initialize (line: 340)
|12247|20:20|image| (-2) Module.pm, new (line: 207)
|12247|20:20|image| (-3) Module.pm, create_provisioning_object (line: 522)
|12247|20:20|image| (-4) State.pm, initialize (line: 136)
|12247|20:20|image| (-5) Module.pm, new (line: 207)
|12247|20:20|image| ---- WARNING ----
|12247|20:20|image| 2015-05-08
10:09:56|12247|20:20|image|VMware.pm:initialize(342)|unable to determine
vmx base directory path on VM host VM7
|12247|20:20|image| ( 0) VMware.pm, initialize (line: 342)
|12247|20:20|image| (-1) Module.pm, new (line: 207)
|12247|20:20|image| (-2) Module.pm, create_provisioning_object (line: 522)
|12247|20:20|image| (-3) State.pm, initialize (line: 136)
|12247|20:20|image| (-4) Module.pm, new (line: 207)
|12247|20:20|image| (-5) vcld, make_new_child (line: 567)
|12247|20:20|image| ---- WARNING ----
|12247|20:20|image| 2015-05-08
10:09:56|12247|20:20|image|Module.pm:create_provisioning_object(530)|provisioning
object could not be created, returning 0
|12247|20:20|image| ( 0) Module.pm, create_provisioning_object (line: 530)
|12247|20:20|image| (-1) State.pm, initialize (line: 136)
|12247|20:20|image| (-2) Module.pm, new (line: 207)
|12247|20:20|image| (-3) vcld, make_new_child (line: 567)
|12247|20:20|image| (-4) vcld, main (line: 350)
|12247|20:20|image| ---- WARNING ----
|12247|20:20|image| 2015-05-08
10:09:56|12247|20:20|image|State.pm:initialize(145)|failed to create
provisioning object
|12247|20:20|image| ( 0) State.pm, initialize (line: 145)
|12247|20:20|image| (-1) Module.pm, new (line: 207)
|12247|20:20|image| (-2) vcld, make_new_child (line: 567)
|12247|20:20|image| (-3) vcld, main (line: 350)
2015-05-08 10:09:56|12247|20:20|image|utils.pm:delete_computerloadlog_reservation(6396)|removing
computerloadlog entries matching loadstate = begin
2015-05-08 10:09:56|12247|20:20|image|utils.pm:delete_computerloadlog_reservation(6443)|deleted
rows from computerloadlog for reservation id=20
2015-05-08 10:09:56|12247|20:20|image|State.pm:DESTROY(929)|VCL::image
process duration: 166 seconds
2015-05-08 10:09:56|12247|20:20|image|utils.pm:get_management_node_info(5456)|retrieving
current management node info for 'localhost' from database, cached data is
stale: 166 seconds old
2015-05-08 10:09:56|12247|20:20|image|utils.pm:getnewdbh(2474)|unable to
use database handle stored in $ENV{dbh}
2015-05-08 10:09:56|12247|20:20|image|utils.pm:getnewdbh(2531)|database
handle stored in $ENV{dbh}
2015-05-08 10:09:56|12247|20:20|image|utils.pm:get_management_node_info(5603)|retrieved
management node info: 'localhost' (localhost)
2015-05-08
10:09:56|12247|20:20|image|DataStructure.pm:get_computer_private_ip_address(1641)|attempting
to retrieve private IP address for computer: VM7Cent6VCL7
2015-05-08
10:09:56|12247|20:20|image|OS.pm:get_file_contents(1897)|retrieved 14 lines
from file on localhost: '/etc/hosts'
2015-05-08
10:09:56|12247|20:20|image|DataStructure.pm:get_computer_private_ip_address(1697)|returning
IP address from /etc/hosts file: 192.168.10.70
2015-05-08 10:09:56|12247|20:20|image|utils.pm:is_inblockrequest(5760)|zero
rows were returned from database select
2015-05-08
10:09:56|12247|20:20|image|DataStructure.pm:get_image_affiliation_name(2121)|image
owner id: 1
2015-05-08
10:09:56|12247|20:20|image|DataStructure.pm:retrieve_user_data(1412)|attempting
to retrieve and store data for user: user.id = '1'
2015-05-08
10:09:56|12247|20:20|image|DataStructure.pm:retrieve_user_data(1475)|data
has been retrieved for user: admin (id: 1)