*2009-03-19 23:04:02|4359|137:4|new|esx.pm:load(166)|Entered ESX
module,
loading esx3-lamp-v0 on esx3-lamp-v0_blade1 (on vclblade1) for
reservation 4
2009-03-19 23:04:02|4359|137:4|new|esx.pm:load(176)|VM info command:
/usr/lib/vmware-viperl/apps/vm/vminfo.pl --server 'vclblade1' --
vmname
esx3-lamp-v0_blade1 --username vcl --password 'd834jfhd734jgfhf7'
2009-03-19 23:04:04|4359|137:4|new|vcld:REAPER(770)|setting $? to
0, exit
status: 0
2009-03-19 23:04:04|4359|137:4|new|esx.pm:load(179)|VM info output:
Virtual Machine esx3-lamp-v0_blade1 not found.
2009-03-19 23:04:04|4359|137:4|new|vcld:REAPER(770)|setting $? to
0, exit
status: 0
2009-03-19 23:04:04|4359|137:4|new|esx.pm:load(212)|Output from
remove
command is:
2009-03-19 23:04:04|4359|137:4|new|esx.pm:load(227)|COPIED VMDK
SUCCESSFULLY
2009-03-19 23:04:04|4359|137:4|new|esx.pm:load(235)|SSHing to copy
vmdk-flat file
2009-03-19 23:04:14|2420|vcld:main(166)|lastcheckin time updated for
management node 1: 2009-03-19 23:04:14
2009-03-19 23:04:26|2420|vcld:main(166)|lastcheckin time updated for
management node 1: 2009-03-19 23:04:26
2009-03-19 23:04:28|4359|137:4|new|vcld:REAPER(770)|setting $? to
0, exit
status: 0
2009-03-19 23:04:28|4359|137:4|new|vcld:REAPER(751)|process reaped:
pid:
4374, $?: 0, exit status: 0
2009-03-19 23:04:28|4359|137:4|new|vcld:REAPER(770)|setting $? to
0, exit
status: 0
2009-03-19 23:04:28|4359|137:4|new|esx.pm:load(258)|adapter= lsilogic
2009-03-19 23:04:28|4359|137:4|new|esx.pm:load(300)|wrote vmxarray to
/mnt/vcl/inuse/esx3-lamp-v0_blade1/esx3-lamp-v0.vmx
2009-03-19 23:04:29|4359|137:4|new|vcld:REAPER(770)|setting $? to
0, exit
status: 0
2009-03-19 23:04:29|4359|137:4|new|esx.pm:load(321)|Registered:
|4359|137:4|new| No host found with name vclblade1.
2009-03-19 23:04:29|4359|137:4|new|esx.pm:load(330)|Power on command:
/usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'vclblade1' --
vmname
esx3-lamp-v0_blade1 --operation poweron --username vcl --password
'd834jfhd734jgfhf7'
2009-03-19 23:04:31|4359|137:4|new|vcld:REAPER(770)|setting $? to
0, exit
status: 0
2009-03-19 23:04:31|4359|137:4|new|esx.pm:load(333)|Powered on:
Virtual
Machine esx3-lamp-v0_blade1 not found.
2009-03-19 23:04:32|4359|137:4|new|vcld:REAPER(770)|setting $? to
0, exit
status: 0
2009-03-19 23:04:32|4359|137:4|new|vcld:REAPER(770)|setting $? to
0, exit
status: 0
2009-03-19 23:04:32|4359|137:4|new|utils.pm:mail(1281)|SUCCESS --
Sending
mail To: r...@localhost, PROBLEM -- esx.pm
|4359|137:4|new| ---- CRITICAL ----
|4359|137:4|new| 2009-03-19 23:04:32|4359|137:4|new|
esx.pm:load(341)|Could
not query for VM in VI PERL API
|4359|137:4|new| ( 0) utils.pm, notify (line: 683)
|4359|137:4|new| (-1) esx.pm, load (line: 341)
|4359|137:4|new| (-2) new.pm, reload_image (line: 664)
|4359|137:4|new| (-3) new.pm, process (line: 266)
|4359|137:4|new| (-4) vcld, make_new_child (line: 606)
|4359|137:4|new| (-5) vcld, main (line: 353)
|4359|137:4|new| ---- WARNING ----
|4359|137:4|new| 2009-03-19 23:04:32|4359|137:4|new|
new.pm:reload_image(669)|esx3-lamp-v0
failed to load on esx3-lamp-v0_blade1, returning
|4359|137:4|new| ( 0) utils.pm, notify (line: 683)
|4359|137:4|new| (-1) new.pm, reload_image (line: 669)
|4359|137:4|new| (-2) new.pm, process (line: 266)
|4359|137:4|new| (-3) vcld, make_new_child (line: 606)
|4359|137:4|new| (-4) vcld, main (line: 353)
2009-03-19 23:04:32|4359|137:4|new|utils.pm:insertloadlog(5300)|
inserted
computer=11, loadimagefailed, esx3-lamp-v0 failed to load on
esx3-lamp-v0_blade1
|4359|137:4|new| ---- WARNING ----
|4359|137:4|new| 2009-03-19 23:04:32|4359|137:4|new|
new.pm:process(313)|failed
to load esx3-lamp-v0_blade1 with esx3-lamp-v0
|4359|137:4|new| ( 0) utils.pm, notify (line: 683)
|4359|137:4|new| (-1) new.pm, process (line: 313)
|4359|137:4|new| (-2) vcld, make_new_child (line: 606)
|4359|137:4|new| (-3) vcld, main (line: 353)
2009-03-19 23:04:32|4359|137:4|new|vcld:REAPER(770)|setting $? to
0, exit
status: 0
2009-03-19 23:04:32|4359|137:4|new|vcld:REAPER(770)|setting $? to
0, exit
status: 0
2009-03-19 23:04:32|4359|137:4|new|utils.pm:mail(1281)|SUCCESS --
Sending
mail To: r...@localhost, PROBLEM -- State.pm
|4359|137:4|new| ---- CRITICAL ----
|4359|137:4|new| 2009-03-19
23:04:32|4359|137:4|new|State.pm:reservation_failed(285)|
reservation failed
on esx3-lamp-v0_blade1: process failed after trying to load or make
available
|4359|137:4|new| ( 0) utils.pm, notify (line: 683)
|4359|137:4|new| (-1) State.pm, reservation_failed (line: 285)
|4359|137:4|new| (-2) new.pm, process (line: 316)
|4359|137:4|new| (-3) vcld, make_new_child (line: 606)
|4359|137:4|new| (-4) vcld, main (line: 353)
2009-03-19 23:04:32|4359|137:4|new|utils.pm:insertloadlog(5300)|
inserted
computer=11, failed, process failed after trying to load or make
available
2009-03-19
23:04:32|4359|137:4|new|State.pm:reservation_failed(288)|inserted
computerloadlog entry
2009-03-19 23:04:32|4359|137:4|new|State.pm:reservation_failed(296)|
updated
log ending value to 'failed', logid=71
2009-03-19 23:04:32|4359|137:4|new|
utils.pm:update_computer_state(2305)|computer
11 state updated to: failed
2009-03-19
23:04:32|4359|137:4|new|State.pm:reservation_failed(304)|computer
esx3-lamp-v0_blade1 (11) state set to failed
2009-03-19 23:04:32|4359|137:4|new|
utils.pm:update_request_state(2263)|request
137 state updated to: failed, laststate to: new
2009-03-19 23:04:32|4359|137:4|new|State.pm:reservation_failed(312)|
set
request state to 'failed'/'new'
2009-03-19 23:04:32|4359|137:4|new|utils.pm:is_inblockrequest(7356)|
zero
rows were returned from database select
2009-03-19
23:04:32|4359|137:4|new|State.pm:reservation_failed(330)|esx3-lamp-
v0_blade1
is NOT in blockcomputers table
2009-03-19 23:04:32|4359|137:4|new|State.pm:reservation_failed(333)|
exiting
1
2009-03-19 23:04:32|4359|137:4|new|State.pm:DESTROY(435)|destructor
called,
ref($self)=VCL::new
2009-03-19 23:04:32|4359|137:4|new|
utils.pm:delete_computerloadlog_reservation(8013)|removing
computerloadlog entries matching loadstate = begin
2009-03-19 23:04:32|4359|137:4|new|
utils.pm:delete_computerloadlog_reservation(8060)|deleted
rows from computerloadlog for reservation id=4
2009-03-19 23:04:32|4359|137:4|new|State.pm:DESTROY(438)|removed
computerloadlog rows with loadstate=begin for reservation
2009-03-19 23:04:32|4359|137:4|new|State.pm:DESTROY(446)|number of
database
handles state process created: 1
2009-03-19 23:04:32|4359|137:4|new|State.pm:DESTROY(455)|process
has a
database handle stored in $ENV{dbh}, attempting disconnect
2009-03-19 23:04:32|4359|137:4|new|State.pm:DESTROY(457)|$ENV{dbh}:
database disconnect successful
2009-03-19 23:04:32|2420|vcld:REAPER(751)|process reaped: pid:
4359, $?:
256, exit status: 1
2009-03-19 23:04:32|2420|vcld:REAPER(756)|VCL process exited for
reservation 4
2009-03-19 23:04:32|2420|vcld:REAPER(770)|setting $? to 256, exit
status: 1
*
Your installation does correctly call the esx.pm module because I
can see
the code inside of it executing through your log post. The problem
seems to
be that the vmhost_ variables are not being passed into the module.
This could be because the associations are not all correct in the
database.
I'll give an example of a correct association below where I only
include
the important information:
In the vmtype table ensure you have an entry:
<id,name=vmwareESX3>
In the vmprofile table have an entry for your hypervisor:
<id,vmtype=the entry from the vmtype table,datastorepath=NFS mount
point(ip:/path/to/
NFS),virtualswitch0=Management,virtualswitch1=Public,username=user
on hypervisor,password=password of hypervisor user>
In the computer table you should have:
an entry for a hypervisor:
<id,hostname,IPaddress,type=blade,vmhostid=NULL,vmtypeid=NULL>
an entry for a virtual machine slot:
<id,hostname,type=virtualmachine,vmhost=id of
hypervisor,vmtype=entry from
vmtype table>
The vmhost table associates the hypervisor's entry in the computer
table
with the hypervisor type declared in vmprofile. In the vmhost
table you
will require:
<computerid=id of hypervisor,vmprofileid=id of hypervisor in
vmprofile>
Here is a dump example from a working database:
INSERT INTO `vmtype` (`id`, `name`) VALUES (5, 'vmwareESX3');
INSERT INTO `vmprofile` (`id`, `profilename`, `vmtypeid`, `imageid`,
`nasshare`, `datastorepath`, `vmpath`, `virtualswitch0`,
`virtualswitch1`,
`vmdisk`, `username`, `password`) VALUES (4, 'VMware ESX SAN ', 2,
4, NULL,
'152.14.17.112:/mnt/export', '/vmfs/volumes/storage1', 'Management',
'Public', 'networkdisk', 'vcl', 'j45789fgdkhj542j');
INSERT INTO `computer` (`id`, `stateid`, `ownerid`, `deptid`,
`platformid`,
`scheduleid`, `currentimageid`, `preferredimageid`, `nextimageid`,
`imagerevisionid`, `RAM`, `procnumber`, `procspeed`, `network`,
`hostname`,
`IPaddress`, `privateIPaddress`, `eth0macaddress`,
`eth1macaddress`, `type`,
`provisioningid`, `drivetype`, `deleted`, `notes`, `lastcheck`,
`location`,
`dsa`, `dsapub`, `rsa`, `rsapub`, `host`, `hostpub`, `vmhostid`,
`vmtypeid`)
VALUES (2, 2, 1, 1, 1, 1, 10, 10, 10, 10, 1024, 1, 1000, 1000,
'test_vm',
'152.14.17.18', '10.0.5.1', '00:50:56:01:4d:9b', '00:50:56:01:4d:9c',
'virtualmachine', 4, 'hda', 0, '', NULL, NULL, NULL, NULL, NULL,
NULL, NULL,
NULL, 1, 5), (3, 2, 1, 1, 1, 1, 4, 4, 0, 0, 512, 1, 500, 10, '
blade2-1.cnl.ncsu.edu', '152.14.17.235', NULL, NULL, NULL, 'blade',
1,
'hda', 0, '', NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL,
NULL);
INSERT INTO `vmhost` (`id`, `computerid`, `vmlimit`, `vmprofileid`,
`vmkernalnic`, `vmwaredisk`) VALUES (1, 3, 3, 4, NULL, 'localdisk');
Best,
Brian
Brian Bouterse
Secure Open Systems Initiative
919.698.8796
On Mar 18, 2009, at 11:55 PM, Melba Lopez wrote:
I'm trying to setup VCL to work in our environment, but we can't
seem to
get
it quite working.
When we schedule a reservation, it goes through and shows that it's
"Pending". However, it stays in that mode and won't ever come
out. We
don't get any notification of accepting or rejecting etc.
Looking through the log file, the following message seems to be
repeating.
What configuration am I missing?
"|30189|116:16|new| ---- WARNING ----
|30189|116:16|new| 2009-03-18
22:28:17|30189|116:16|new|vcld:warning_handler(648)|Use of
uninitialized
value $vmhost_hostname in concatenation (.) or string at
/opt/vcl/bin/../lib/VCL/Module/Provisioning/esx.pm line 325.
|30189|116:16|new| ( 0) utils.pm, notify (line: 683)
|30189|116:16|new| (-1) vcld, warning_handler (line: 648)
|30189|116:16|new| (-2) esx.pm, load (line: 325)
|30189|116:16|new| (-3) new.pm, reload_image (line: 664)
|30189|116:16|new| (-4) new.pm, process (line: 266)
|30189|116:16|new| (-5) vcld, make_new_child (line: 606)
|30189|116:16|new| (-6) vcld, main (line: 353)
2009-03-18 22:28:17|30189|116:16|new|esx.pm:load(330)|Power on
command:
/usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server '' --vmname
vclblade1
--operation poweron --username vcl --password 'd834jfhd734jgfhf7'
Error: Server version unavailable at 'https:///sdk/
vimService.wsdl' :1:
parser error : Start tag expected, '<' not found
500 No Host option provided
^ at /usr/local/lib/perl5/site_perl/5.10.0/VMware/VICommon.pm
line 323
2009-03-18 22:28:17|30189|116:16|new|vcld:REAPER(770)|setting $?
to 512,
exit status: 2
2009-03-18 22:28:17|30189|116:16|new|esx.pm:load(333)|Powered on:"