Thanks for the feedback. I was unaware that DNS was a requirement. I'll
have to see if this can be done in our environment
On Thu, Mar 19, 2009 at 3:47 PM, Brian Bouterse <bmbou...@ncsu.edu> wrote:
> Let's analyze this log ...
>
> 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'
>>
>
> Here the esx.pm module is trying to use the vminfo.pl file (part of the
> VMware VI perl toolkit) to ask the hypervisor (vclblade1) about the VM
> 'esx3-lamp-v0_blade1' Clearly this isn't working because the next line in
> the log is:
>
> 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.
>>
>
>
> So why is the command failing? The log says it's because
> esx3-lamp_v0_blade1 does not exist. Is there a DNS entry for that blade
> that would allow esx3-lamp_v0_blade1 to resolve to IP address of the
> hypervisor?
>
> Also, we output the commands the esx.pm module runs to the log so that
> they can be run manually. Which means you can test this command without
> needing to test all of VCL by running the following on the command line:
>
> /usr/lib/vmware-viperl/apps/vm/vminfo.pl --server 'vclblade1' --vmname
> esx3-lamp-v0_blade1 --username vcl --password 'd834jfhd734jgfhf7'
>
> Best,
> Brian
>
> Brian Bouterse
> Secure Open Systems Initiative
> 919.698.8796
>
>
>
>
> On Mar 19, 2009, at 3:20 PM, Melba Lopez wrote:
>
> I've verified and tried everything you have mentioned. I also followed
>> the
>> steps in "esx.README" to make sure I configured everything ok, but I still
>> get a failure. Good news is that the reservation doesn't stay stuck in
>> "Pending" and actually returns as "Failed". I also do not see it
>> complaining about the host name, but rather that it cannot "load" the VM.
>>
>> Do you have any other suggestions on what other configurations I'm
>> missing?
>>
>> *Log of Reservation:*
>>
>>
>> *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
>>> *
>>>
>>
>>
>>
>>
>> On Thu, Mar 19, 2009 at 9:22 AM, Brian Bouterse <bmbou...@ncsu.edu>
>> wrote:
>>
>> 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:"
>>>>>
>>>>
>>>>
>>>>>
>>>>>
>>>
>
