You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@vcl.apache.org by Melba Lopez <mi...@gmail.com> on 2009/03/19 04:55:13 UTC

Reservation Problem

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:"
>

Re: Reservation Problem

Posted by Melba Lopez <mi...@gmail.com>.
Sorry I meant the virtual network adapters within the VM; not the vSwitch
created on the Host.

On Tue, Mar 24, 2009 at 3:24 PM, Melba Lopez <mi...@gmail.com> wrote:

>
>
> ---------- Forwarded message ----------
> From: Melba Lopez <mi...@gmail.com>
> Date: Tue, Mar 24, 2009 at 2:24 PM
> Subject: Re: Reservation Problem
> To: vcl-dev@incubator.apache.org
>
>
> After ensuring the computer hostnames in the DB matches the VI Client
> hostname, with some changes to the hostname at the ESXi host gui, the
> reservation seemed to go a lot farther.
>
> I actually saw the VM deployed and turned on at it's designated blade,
> however the reservation ultimately failed.  As I mentioned in a previous
> email, the vSwitch settings in the golden VM does not stay once it's copied
> over to inuse.  Perhaps this is causing this failure?
>
>
>
>>
> 2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(321)|Registered:
>>
> |7840|148:15|new| Register of VM 'esx3-lamp-v0-bl1' successfully completed
>> under host esxibl1.preloads.private
>>
> 2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(330)|Power on command:
>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server
>> 'esxibl1.preloads.private' --vmname esx3-lamp-v0-bl1 --operation poweron
>> --username vcl --password 'd834jfhd734jgfhf7'
>>
> 2009-03-24 22:46:02|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-24 22:46:02
>>
> 2009-03-24 22:46:05|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-24 22:46:05|7840|148:15|new|esx.pm:load(333)|Powered on:
>>
> |7840|148:15|new| virtual machine 'esx3-lamp-v0-bl1' under host
>> esxibl1.preloads.private powered on
>>
> 2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(349)|deviceinfo->summary:
>> VirtualPCNet32=HASH(0xbaaf304)->deviceinfo->summary
>>
> 2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0: VM
>> Network
>>
>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(349)|deviceinfo->summary:
>> VirtualPCNet32=HASH(0xa9860fc)->deviceinfo->summary
>>
> 2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0: VM
>> Network
>>
>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(360)|Queried MAC address
>> is 00:0c:29:17:db:6a
>>
>  2009-03-24 22:46:06|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>> exit status: 0
>>
>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 1
>>
> 2009-03-24 22:46:11|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-24 22:46:11|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 2
>>
> 2009-03-24 22:46:14|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-24 22:46:14
>>
> ...
>>
> ....
>>
> .....keeps trying until 25 below
>
>
>
> 2009-03-24 22:48:07|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 25
>
>  2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>> exit status: 0
>>
>  2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>> exit status: 0
>>
>  2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>> exit status: 0
>>
>  2009-03-24 22:50:48|7840|148:15|new|utils.pm:mail(1281)|SUCCESS --
>> Sending mail To: root@localhost, PROBLEM -- esx.pm
>>
>
>> |7840|148:15|new| ---- CRITICAL ----
>>
> |7840|148:15|new| 2009-03-24 22:48:12|7840|148:15|new|esx.pm:load(376)|waited
>> acceptable amount of time for dhcp, please check esx3-lamp-v0-bl1 on
>> esxibl1.preloads.private
>>
> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>
>  |7840|148:15|new| (-1) esx.pm, load (line: 376)
>>
>  |7840|148:15|new| (-2) new.pm, reload_image (line: 664)
>>
>  |7840|148:15|new| (-3) new.pm, process (line: 266)
>>
>  |7840|148:15|new| (-4) vcld, make_new_child (line: 606)
>>
> |7840|148:15|new| (-5) vcld, main (line: 353)
>>
>
>>
>> |7840|148:15|new| ---- WARNING ----
>>
> |7840|148:15|new| 2009-03-24 22:50:48|7840|148:15|new|new.pm:reload_image(669)|esx3-lamp-v0
>> failed to load on esx3-lamp-v0-bl1, returning
>>
> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>
>  |7840|148:15|new| (-1) new.pm, reload_image (line: 669)
>>
>  |7840|148:15|new| (-2) new.pm, process (line: 266)
>>
>  |7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>>
> |7840|148:15|new| (-4) vcld, main (line: 353)
>>
>
>> 2009-03-24 22:50:48|7840|148:15|new|utils.pm:insertloadlog(5300)|inserted
>> computer=11, loadimagefailed, esx3-lamp-v0 failed to load on
>> esx3-lamp-v0-bl1
>>
>
>> |7840|148:15|new| ---- WARNING ----
>>
> |7840|148:15|new| 2009-03-24 22:50:48|7840|148:15|new|new.pm:process(313)|failed
>> to load esx3-lamp-v0-bl1 with esx3-lamp-v0
>>
> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>
>  |7840|148:15|new| (-1) new.pm, process (line: 313)
>>
>  |7840|148:15|new| (-2) vcld, make_new_child (line: 606)
>>
> |7840|148:15|new| (-3) vcld, main (line: 353)
>>
>
>> 2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:mail(1281)|SUCCESS -- Sending
> mail To: root@localhost, PROBLEM -- State.pm
>
>
> |7840|148:15|new| ---- CRITICAL ----
>
> |7840|148:15|new| 2009-03-24
> 22:50:48|7840|148:15|new|State.pm:reservation_failed(285)|reservation failed
> on esx3-lamp-v0-bl1: process failed after trying to load or make available
>
> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>
> |7840|148:15|new| (-1) State.pm, reservation_failed (line: 285)
>
> |7840|148:15|new| (-2) new.pm, process (line: 316)
>
> |7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>
> |7840|148:15|new| (-4) vcld, main (line: 353)
>
>
> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:insertloadlog(5300)|inserted
> computer=11, failed, process failed after trying to load or make available
>
> 2009-03-24
> 22:53:24|7840|148:15|new|State.pm:reservation_failed(288)|inserted
> computerloadlog entry
>
> 2009-03-24
> 22:53:24|7840|148:15|new|State.pm:reservation_failed(296)|updated log ending
> value to 'failed', logid=82
>
> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:update_computer_state(2305)|computer
> 11 state updated to: failed
>
> 2009-03-24
> 22:53:24|7840|148:15|new|State.pm:reservation_failed(304)|computer
> esx3-lamp-v0-bl1 (11) state set to failed
>
> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:update_request_state(2263)|request
> 148 state updated to: failed, laststate to: new
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:reservation_failed(312)|set
> request state to 'failed'/'new'
>
> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:is_inblockrequest(7356)|zero
> rows were returned from database select
>
> 2009-03-24
> 22:53:24|7840|148:15|new|State.pm:reservation_failed(330)|esx3-lamp-v0-bl1
> is NOT in blockcomputers table
>
> 2009-03-24
> 22:53:24|7840|148:15|new|State.pm:reservation_failed(333)|exiting 1
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(435)|destructor
> called, ref($self)=VCL::new
>
> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:delete_computerloadlog_reservation(8013)|removing
> computerloadlog entries matching loadstate = begin
>
> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:delete_computerloadlog_reservation(8060)|deleted
> rows from computerloadlog for reservation id=15
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(438)|removed
> computerloadlog rows with loadstate=begin for reservation
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(446)|number of
> database handles state process created: 1
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(455)|process has a
> database handle stored in $ENV{dbh}, attempting disconnect
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(457)|$ENV{dbh}:
> database disconnect successful
>
> On Tue, Mar 24, 2009 at 12:14 PM, Brian Bouterse <bm...@ncsu.edu>wrote:
>
>> As it turns out, the vcl-dev list strips out embedded URLs.  I've pasted
>> it below.
>>
>>
>> http://wiki.oscr.ncsu.edu/wiki/index.php/Updating_the_VCL_VM_to_the_latest_code_version
>>
>> Best,
>> Brian
>>
>> Brian Bouterse
>> Secure Open Systems Initiative
>> 919.698.8796
>>
>>
>>
>>
>> On Mar 24, 2009, at 12:44 PM, Brian Bouterse wrote:
>>
>>  I forgot to include the link with the upgrade how-to:  It is located
>>> here.
>>>
>>> Best,
>>> Brian
>>>
>>>
>>> Brian Bouterse
>>> Secure Open Systems Initiative
>>> 919.698.8796
>>>
>>>
>>>
>>>
>>> On Mar 24, 2009, at 12:20 PM, Brian Bouterse wrote:
>>>
>>>  I've put in some more debugging into the esx.pm module.  This should
>>>> print the registration command to the screen so that it can be tried to run
>>>> manually.  Can you update to the latest code version and try it?  I've
>>>> written a how-to located here.
>>>>
>>>> Best,
>>>> Brian
>>>>
>>>>
>>>> Brian Bouterse
>>>> Secure Open Systems Initiative
>>>> 919.698.8796
>>>>
>>>>
>>>>
>>>>
>>>> On Mar 24, 2009, at 10:20 AM, Melba Lopez wrote:
>>>>
>>>>  Actually everything you've mentioned has been put into place.
>>>>> The nameserver entry is in /etc/resolv.conf and all the esxibl1-3
>>>>> hostnames
>>>>> are in the /etc/hosts.
>>>>> I can connect to the blades by putting esxibl1-3 into VIClient without
>>>>> a
>>>>> problem.
>>>>>
>>>>> Note:  /etc/resolv.conf is generated by /sbin/dhclient-script; once
>>>>> network/vm is rebooted it restores original.
>>>>>
>>>>> I also restarted the networking and went as far as to reboot the VCL VM
>>>>> and
>>>>> still it gives me the same error.
>>>>>
>>>>>
>>>>> --Melba
>>>>>
>>>>>
>>>>> On Tue, Mar 24, 2009 at 9:34 AM, Brian Bouterse <bm...@ncsu.edu>
>>>>> wrote:
>>>>>
>>>>>  I'm still suspicious of your DNS resolution and configuration.  In
>>>>>> addition
>>>>>> to creating the DNS entries in your lab's DNS server, did you connect
>>>>>> VCL to
>>>>>> that DNS by creating an entry similar to the one below in the
>>>>>> /etc/resolv.conf on your VCL management node?
>>>>>>
>>>>>> nameserver <ip_of_your_DNS_here>
>>>>>>
>>>>>> Can you connect with virtual center to the blade you're trying to
>>>>>> provision
>>>>>> to when referencing it strictly by it's hostname?
>>>>>>
>>>>>> If you want to remove DNS resolution from the list of possible
>>>>>> culprits,
>>>>>> you can create an entry in /etc/hosts of your VCL management node
>>>>>> similar to
>>>>>> the line below.  I think that should work.
>>>>>>
>>>>>> <IP Address of esxib1>  esxibl1.
>>>>>>
>>>>>> Remember to restart networking (or the whole VCL management node) when
>>>>>> testing these configuration changes.
>>>>>>
>>>>>> Best,
>>>>>> Brian
>>>>>>
>>>>>>
>>>>>> Brian Bouterse
>>>>>> Secure Open Systems Initiative
>>>>>> 919.698.8796
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:
>>>>>>
>>>>>> Ok, our lab already had DNS capabilities, so I've set esxibl1-3* *to
>>>>>> be
>>>>>>
>>>>>>> valid hostnames*.
>>>>>>>
>>>>>>> *However, it is still saying it can't find "esxibl1".  I've pinged
>>>>>>> that
>>>>>>> hostname from another machine on the same network and it works just
>>>>>>> fine.
>>>>>>>
>>>>>>>
>>>>>>> Also because it kept saying it couldn't load the VM, I've found
>>>>>>> another
>>>>>>> problem.  The vmdk file successfully copies over into the "inuse"
>>>>>>> folder.
>>>>>>> When I manually add that VM to a blade, I'm noticing that the VM does
>>>>>>> not
>>>>>>> keep the network setings.  I watched someone actually create this VM
>>>>>>> and I
>>>>>>> redid it myself, and the settings do not stay when its copied over.
>>>>>>>  Not
>>>>>>> sure if it's related, but thought I might mention it.
>>>>>>> *
>>>>>>>
>>>>>>>
>>>>>>> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote vmxarray
>>>>>>> to
>>>>>>> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>> 0,
>>>>>>> exit
>>>>>>> status: 0
>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
>>>>>>> |24815|143:10|new| No host found with name esxibl1.
>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on
>>>>>>> command:
>>>>>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1'
>>>>>>> --vmname
>>>>>>> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
>>>>>>> 'd834jfhd734jgfhf7'
>>>>>>> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>> 0,
>>>>>>> exit
>>>>>>> status: 0
>>>>>>> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered on:
>>>>>>> Virtual
>>>>>>> Machine esx3-lamp-v0-bl1 not found.
>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>> 0,
>>>>>>> exit
>>>>>>> status: 0
>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>> 0,
>>>>>>> exit
>>>>>>> status: 0
>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS --
>>>>>>> Sending
>>>>>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>>>>>
>>>>>>> |24815|143:10|new| ---- CRITICAL ----
>>>>>>> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:
>>>>>>> load(341)|Could
>>>>>>> not query for VM in VI PERL API
>>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
>>>>>>> |24815|143:10|new| (-1) esx.pm, load (line: 341)
>>>>>>> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
>>>>>>> |24815|143:10|new| (-3) new.pm, process (line: 266)
>>>>>>> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
>>>>>>> |24815|143:10|new| (-5) vcld, main (line: 353)
>>>>>>>
>>>>>>>
>>>>>>> |24815|143:10|new| ---- WARNING ----
>>>>>>> |24815|143:10|new| 2009-03-24
>>>>>>> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
>>>>>>> failed to load on esx3-lamp-v0-bl1, returning
>>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>>>>>>>
>>>>>>>
>>>>>>> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <
>>>>>>> josh_thompson@ncsu.edu
>>>>>>>
>>>>>>>> wrote:
>>>>>>>>
>>>>>>>
>>>>>>> -----BEGIN PGP SIGNED MESSAGE-----
>>>>>>>
>>>>>>>> Hash: SHA1
>>>>>>>>
>>>>>>>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>>>>>>>
>>>>>>>>  always fake the DNS resolution by placing an entry /etc/resolv.conf
>>>>>>>>>
>>>>>>>>>
>>>>>>>> That would be /etc/hosts  :)
>>>>>>>>
>>>>>>>> Josh
>>>>>>>> - --
>>>>>>>> - -------------------------------
>>>>>>>> Josh Thompson
>>>>>>>> Systems Programmer
>>>>>>>> Virtual Computing Lab (VCL)
>>>>>>>> North Carolina State University
>>>>>>>>
>>>>>>>> Josh_Thompson@ncsu.edu
>>>>>>>> 919-515-5323
>>>>>>>>
>>>>>>>> my GPG/PGP key can be found at www.keyserver.net
>>>>>>>> -----BEGIN PGP SIGNATURE-----
>>>>>>>> Version: GnuPG v2.0.9 (GNU/Linux)
>>>>>>>>
>>>>>>>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
>>>>>>>> nKgBCGnhdhToNQ0EtzLhRC8=
>>>>>>>> =Yjph
>>>>>>>> -----END PGP SIGNATURE-----
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>
>>>>
>>>
>>
>
>
> --
> Melba Lopez
> (305) 807-6260
> milopez@gmail.com
>
>
>
> --
> Melba Lopez
> (305) 807-6260
> milopez@gmail.com
>



-- 
Melba Lopez
(305) 807-6260
milopez@gmail.com

Re: Reservation Problem

Posted by Melba Lopez <mi...@gmail.com>.
 After being able to deploy the VM successfully, I tried to connect to the
VM via ssh and it would not allow me to login with the credentials given to
me at the "Connect" screen in the VCL web interface.

Poking through the logs (see below), I noticed it failed to create the admin
user because it couldn't find the group ncsu. (Online documentation does not
state to add this group)  I went back to the VM, added the group, and
created a new reservation.  This time, I was able to have a completely
successful reservation.

Is it possible for VCL to add the user admin without the requirement of
there being a ncsu group?

Thanks for all your help.  I really appreciate it :o)

31755|150:17|reserved| ---- CRITICAL ----
>
|31755|150:17|reserved| 2009-03-25
23:18:15|31755|150:17|reserved|utils.pm:add_user(3098)|PROBLEM
> added user admin to esx3-lamp-v0-bl2 useradd: unknown group ncsu
>
|31755|150:17|reserved| ( 0) utils.pm, notify (line: 683)
>
|31755|150:17|reserved| (-1) utils.pm, add_user (line: 3098)
>
|31755|150:17|reserved| (-2) reserved.pm, process (line: 289)
>
|31755|150:17|reserved| (-3) vcld, make_new_child (line: 606)
>
|31755|150:17|reserved| (-4) vcld, main (line: 353)
>

>
> |31755|150:17|reserved| ---- WARNING ----
>
|31755|150:17|reserved| 2009-03-25
> 23:20:51|31755|150:17|reserved|reserved.pm:process(294)|could not add user
> admin to esx3-lamp-v0-bl2
>
|31755|150:17|reserved| ( 0) utils.pm, notify (line: 683)
>
|31755|150:17|reserved| (-1) reserved.pm, process (line: 294)
>
|31755|150:17|reserved| (-2) vcld, make_new_child (line: 606)
>
|31755|150:17|reserved| (-3) vcld, main (line: 353)
>

> 2009-03-25 23:20:51|31755|150:17|reserved|utils.pm:insertloadlog(5300)|inserted
> computer=12, failed, reserved: could not add user to node
>
2009-03-25 23:20:51|31755|150:17|reserved|reserved.pm:process(430)|retval_conn
> = failed
>
2009-03-25 23:20:51|31755|150:17|reserved|reserved.pm:process(577)|failed to
> reserve machine
>
2009-03-25 23:20:51|31755|150:17|reserved|utils.pm:update_request_state(2263)|request
> 150 state updated to: failed, laststate to: reserved
>
2009-03-25 23:20:51|31755|150:17|reserved|reserved.pm:process(579)|setting
> request into failed state
>
2009-03-25 23:20:51|31755|150:17|reserved|utils.pm:update_computer_state(2305)|computer
> 12 state updated to: failed
>
2009-03-25 23:20:51|31755|150:17|reserved|reserved.pm:process(587)|setting
> computerid 12 into failed state
>
2009-03-25 23:20:51|31755|150:17|reserved|reserved.pm:process(595)|log id 84
> was updated and ending set to failed
>
2009-03-25 23:20:51|31755|150:17|reserved|reserved.pm:process(602)|exiting
>


--Melba





On Wed, Mar 25, 2009 at 5:32 PM, Melba Lopez <mi...@gmail.com> wrote:

> The failed reservation problem that we were experiencing was related to our
> configuration.
>
> We are currently running our VCL installation in an isolated lab, so we
> have the "public" network on a 10.138.x.x subnet and the "private"
> management network on 10.0.x.x  utils.pm in looking for the dynamic
> address finds the private IP address, but skips our public IP address on the
> 10.138 subnet.
>
> From the utils.pm linux path:
>
> elsif ($image_os_type =~ /linux/) {
>   $identity = $IDENTITY_bladerhel;
>   undef @sshcmd;
>   @sshcmd = run_ssh_command($node, $identity, "/sbin/ifconfig \|grep inet",
> "root");
>   for my $l (@{$sshcmd[1]}) {
>    # skip class a,b,c private addresses
>    next if ($l =~ /inet addr:$privateIP/);
>    next if ($l =~ /inet addr:10.([.0-9]*)/);       <------- removing this
> line made our configuration work.
>    next if ($l =~ /inet addr:127([.0-9]*)/);
>    next if ($l =~ /inet addr:172([.0-9]*)/);
>    next if ($l =~ /inet addr:192.168([.0-9]*)/);
>    if ($l =~ /inet addr:([.0-9]*)/) {
>     if ($l !~ /inet addr:$privateIP/) {
>      #to cover sites using eth0 as public
>      $dynaIPaddress = $1;
>     }
>    }
>   } ## end for my $l (@{$sshcmd[1]})
>
>
> --Melba
>
> On Wed, Mar 25, 2009 at 2:37 PM, Melba Lopez <mi...@gmail.com> wrote:
>
>> Thanks for that vmprofile tip. That fixed the network naming issue I was
>> seeing.
>> Good news is that it got farther in the process, but still failed.  Here's
>> the new logs:
>>
>>
>>  2009-03-25 19:29:33|28031|149:16|new|esx.pm:load(235)|SSHing to copy
>>> vmdk-flat file
>>>
>>  2009-03-25 19:29:43|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:29:43
>>>
>> 2009-03-25 19:29:55|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:29:55
>>>
>> 2009-03-25 19:29:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:29:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:29:57|28031|149:16|new|esx.pm:load(258)|adapter= lsilogic
>>>
>>  2009-03-25 19:29:57|28031|149:16|new|esx.pm:load(300)|wrote vmxarray to
>>> /mnt/vcl/inuse/esx3-lamp-v0-bl3/esx3-lamp-v0.vmx
>>>
>> 2009-03-25 19:30:00|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:00|28031|149:16|new|esx.pm:load(321)|Registered:
>>>
>> |28031|149:16|new| Register of VM 'esx3-lamp-v0-bl3' successfully
>>> completed under host esxibl3.preloads.private
>>>
>> 2009-03-25 19:30:00|28031|149:16|new|esx.pm:load(330)|Power on command:
>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server
>>> 'esxibl3.preloads.private' --vmname esx3-lamp-v0-bl3 --operation poweron
>>> --username vcl --password 'd834jfhd734jgfhf7'
>>>
>> 2009-03-25 19:30:04|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:04|28031|149:16|new|esx.pm:load(333)|Powered on:
>>>
>> |28031|149:16|new| virtual machine 'esx3-lamp-v0-bl3' under host
>>> esxibl3.preloads.private powered on
>>>
>> 2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(349)|deviceinfo->summary:
>>> VirtualPCNet32=HASH(0xbdd3d64)->deviceinfo->summary
>>>
>> 2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(350)|virtualswitch0:
>>> Management
>>>
>>  2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(349)|deviceinfo->summary:
>>> VirtualPCNet32=HASH(0xacbce1c)->deviceinfo->summary
>>>
>> 2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(350)|virtualswitch0:
>>> Management
>>>
>>  2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(360)|Queried MAC
>>> address is 00:0c:29:46:1d:c7
>>>
>>  2009-03-25 19:30:05|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(381)|going to sleep 5
>>> seconds, waiting for computer to DHCP. Try 1
>>>
>> 2009-03-25 19:30:07|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:30:07
>>>
>> 2009-03-25 19:30:10|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:10|28031|149:16|new|esx.pm:load(381)|going to sleep 5
>>> seconds, waiting for computer to DHCP. Try 2
>>>
>> 2009-03-25 19:30:15|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:15|28031|149:16|new|esx.pm:load(381)|going to sleep 5
>>> seconds, waiting for computer to DHCP. Try 3
>>>
>> 2009-03-25 19:30:19|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:30:19
>>>
>> 2009-03-25 19:30:20|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:20|28031|149:16|new|esx.pm:load(381)|going to sleep 5
>>> seconds, waiting for computer to DHCP. Try 4
>>>
>> 2009-03-25 19:30:25|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:25|28031|149:16|new|esx.pm:load(381)|going to sleep 5
>>> seconds, waiting for computer to DHCP. Try 5
>>>
>> 2009-03-25 19:30:30|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(372)|esx3-lamp-v0-bl3
>>> now has ip 10.0.4.101
>>>
>>  2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(388)|Found IP address
>>> 10.0.4.101
>>>
>>  2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(391)|Removing old hosts
>>> entry
>>>
>>  2009-03-25 19:30:30|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(393)|
>>>
>> 2009-03-25 19:30:30|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(402)|Waiting for ssh to
>>> come up on esx3-lamp-v0-bl3
>>>
>> 2009-03-25 19:30:31|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:31|28031|149:16|new|esx.pm:load(419)|going to sleep 5
>>> seconds, waiting for computer to start SSH. Try 1
>>>
>> 2009-03-25 19:30:31|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:30:31
>>>
>> 2009-03-25 19:30:36|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:36|28031|149:16|new|utils.pm:run_ssh_command(6672)|executing
>>> SSH command on esx3-lamp-v0-bl3: uname -s
>>>
>> 2009-03-25 19:30:43|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:30:43
>>>
>> 2009-03-25 19:30:47|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:47|28031|149:16|new|utils.pm:run_ssh_command(6753)|run_ssh_command
>>> output: Linux
>>>
>> 2009-03-25 19:30:47|28031|149:16|new|utils.pm:run_ssh_command(6756)|SSH
>>> command executed on esx3-lamp-v0-bl3: uname -s, returning (0, output)
>>>
>> 2009-03-25 19:30:47|28031|149:16|new|esx.pm:load(407)|esx3-lamp-v0-bl3
>>> now has active sshd running
>>>
>> 2009-03-25 19:30:47|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
>>> computer=13, dynamicDHCPaddress, collecting dynamic IP address for node
>>>
>> 2009-03-25 19:30:47|28031|149:16|new|esx.pm:load(430)|Attempting to query
>>> vmclient for its public IP...
>>>
>> 2009-03-25 19:30:47|28031|149:16|new|utils.pm:getdynamicaddress(1640)|PrivateIP
>>> address for esx3-lamp-v0-bl3 collected 10.0.4.101
>>>
>> 2009-03-25 19:30:47|28031|149:16|new|utils.pm:run_ssh_command(6672)|executing
>>> SSH command on esx3-lamp-v0-bl3: /sbin/ifconfig |grep inet
>>>
>> 2009-03-25 19:30:55|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:30:55
>>>
>> 2009-03-25 19:30:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:30:57|28031|149:16|new|utils.pm:run_ssh_command(6753)|run_ssh_command
>>> output: inet addr:10.0.4.101 Bcast:10.0.255.255 Mask:255.255.0.0
>>>
>> |28031|149:16|new|  inet6 addr: fe80::20c:29ff:fe46:1dc7/64 Scope:Link
>>>
>>  |28031|149:16|new|  inet addr:10.138.1.185 Bcast:10.138.1.255
>>> Mask:255.255.255.0
>>>
>>  |28031|149:16|new|  inet6 addr: fe80::20c:29ff:fe46:1dd1/64 Scope:Link
>>>
>>  |28031|149:16|new|  inet addr:127.0.0.1 Mask:255.0.0.0
>>>
>> |28031|149:16|new|  inet6 addr: ::1/128 Scope:Host
>>>
>> 2009-03-25 19:30:57|28031|149:16|new|utils.pm:run_ssh_command(6756)|SSH
>>> command executed on esx3-lamp-v0-bl3: /sbin/ifconfig |grep inet, returning
>>> (0, output)
>>>
>> 2009-03-25 19:30:57|28031|149:16|new|utils.pm:getdynamicaddress(1697)|dynamic
>>> IP address for esx3-lamp-v0-bl3 collected: 0
>>>
>> 2009-03-25 19:30:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:31:07|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:31:07
>>>
>> 2009-03-25 19:33:31|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:33:31
>>>
>> 2009-03-25 19:33:39|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:33:39|28031|149:16|new|utils.pm:mail(1281)|SUCCESS --
>>> Sending mail To: root@localhost, PROBLEM -- esx.pm
>>>
>>
>>> |28031|149:16|new| ---- CRITICAL ----
>>>
>> |28031|149:16|new| 2009-03-25 19:30:57|28031|149:16|new|esx.pm:load(444)|could
>>> not fetch dynamic address from esx3-lamp-v0-bl3 esx3-lamp-v0
>>>
>> |28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>>>
>>  |28031|149:16|new| (-1) esx.pm, load (line: 444)
>>>
>>  |28031|149:16|new| (-2) new.pm, reload_image (line: 664)
>>>
>>  |28031|149:16|new| (-3) new.pm, process (line: 266)
>>>
>>  |28031|149:16|new| (-4) vcld, make_new_child (line: 606)
>>>
>> |28031|149:16|new| (-5) vcld, main (line: 353)
>>>
>>
>>> 2009-03-25 19:33:39|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
>>> computer=13, failed, could not collect dynamic IP address for node
>>>
>>
>>> |28031|149:16|new| ---- WARNING ----
>>>
>> |28031|149:16|new| 2009-03-25 19:33:39|28031|149:16|new|new.pm:reload_image(669)|esx3-lamp-v0
>>> failed to load on esx3-lamp-v0-bl3, returning
>>>
>> |28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>>>
>>  |28031|149:16|new| (-1) new.pm, reload_image (line: 669)
>>>
>>  |28031|149:16|new| (-2) new.pm, process (line: 266)
>>>
>>  |28031|149:16|new| (-3) vcld, make_new_child (line: 606)
>>>
>> |28031|149:16|new| (-4) vcld, main (line: 353)
>>>
>>
>>> 2009-03-25 19:33:39|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
>>> computer=13, loadimagefailed, esx3-lamp-v0 failed to load on
>>> esx3-lamp-v0-bl3
>>>
>>
>>> |28031|149:16|new| ---- WARNING ----
>>>
>> |28031|149:16|new| 2009-03-25 19:33:39|28031|149:16|new|new.pm:process(313)|failed
>>> to load esx3-lamp-v0-bl3 with esx3-lamp-v0
>>>
>> |28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>>>
>>  |28031|149:16|new| (-1) new.pm, process (line: 313)
>>>
>>  |28031|149:16|new| (-2) vcld, make_new_child (line: 606)
>>>
>> |28031|149:16|new| (-3) vcld, main (line: 353)
>>>
>>
>>> 2009-03-25 19:33:39|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:33:43|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:33:43
>>>
>> 2009-03-25 19:33:55|2421|vcld:main(166)|lastcheckin time updated for
>>> management node 1: 2009-03-25 19:33:55
>>>
>>
>>> 2009-03-25 19:36:21|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>>> exit status: 0
>>>
>>  2009-03-25 19:36:21|28031|149:16|new|utils.pm:mail(1281)|SUCCESS --
>>> Sending mail To: root@localhost, PROBLEM -- State.pm
>>>
>>
>>> |28031|149:16|new| ---- CRITICAL ----
>>>
>> |28031|149:16|new| 2009-03-25
>>> 19:33:39|28031|149:16|new|State.pm:reservation_failed(285)|reservation
>>> failed on esx3-lamp-v0-bl3: process failed after trying to load or make
>>> available
>>>
>> |28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>>>
>>  |28031|149:16|new| (-1) State.pm, reservation_failed (line: 285)
>>>
>> |28031|149:16|new| (-2) new.pm, process (line: 316)
>>>
>>  |28031|149:16|new| (-3) vcld, make_new_child (line: 606)
>>>
>> |28031|149:16|new| (-4) vcld, main (line: 353)
>>>
>>
>>> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
>>> computer=13, failed, process failed after trying to load or make available
>>>
>> 2009-03-25
>>> 19:36:21|28031|149:16|new|State.pm:reservation_failed(288)|inserted
>>> computerloadlog entry
>>>
>> 2009-03-25
>>> 19:36:21|28031|149:16|new|State.pm:reservation_failed(296)|updated log
>>> ending value to 'failed', logid=83
>>>
>> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:update_computer_state(2305)|computer
>>> 13 state updated to: failed
>>>
>> 2009-03-25
>>> 19:36:21|28031|149:16|new|State.pm:reservation_failed(304)|computer
>>> esx3-lamp-v0-bl3 (13) state set to failed
>>>
>> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:update_request_state(2263)|request
>>> 149 state updated to: failed, laststate to: new
>>>
>> 2009-03-25 19:36:21|28031|149:16|new|State.pm:reservation_failed(312)|set
>>> request state to 'failed'/'new'
>>>
>> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:is_inblockrequest(7356)|zero
>>> rows were returned from database select
>>>
>> 2009-03-25
>>> 19:36:21|28031|149:16|new|State.pm:reservation_failed(330)|esx3-lamp-v0-bl3
>>> is NOT in blockcomputers table
>>>
>> 2009-03-25
>>> 19:36:21|28031|149:16|new|State.pm:reservation_failed(333)|exiting 1
>>>
>>  2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(435)|destructor
>>> called, ref($self)=VCL::new
>>>
>> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:delete_computerloadlog_reservation(8013)|removing
>>> computerloadlog entries matching loadstate = begin
>>>
>> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:delete_computerloadlog_reservation(8060)|deleted
>>> rows from computerloadlog for reservation id=16
>>>
>> 2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(438)|removed
>>> computerloadlog rows with loadstate=begin for reservation
>>>
>> 2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(446)|number of
>>> database handles state process created: 1
>>>
>> 2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(455)|process has a
>>> database handle stored in $ENV{dbh}, attempting disconnect
>>>
>> 2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(457)|$ENV{dbh}:
>>> database disconnect successful
>>>
>> 2009-03-25 19:36:21|2421|vcld:REAPER(751)|process reaped: pid: 28031, $?:
>>> 256, exit status: 1
>>>
>>  2009-03-25 19:36:21|2421|vcld:REAPER(756)|VCL process exited for
>>> reservation 16
>>>
>>  2009-03-25 19:36:21|2421|vcld:REAPER(770)|setting $? to 256, exit
>>> status: 1
>>>
>>
>>
>>
>>
>> --
>> Melba
>>
>>
>> On Wed, Mar 25, 2009 at 10:54 AM, Brian Bouterse <bm...@ncsu.edu>wrote:
>>
>>> Here are a few things to look into around the virtual switch assignments
>>> of deployed ESX compatible virtual machines.  When the esx.pm writes out
>>> the .vmx file, on-the-fly, it indicates the network names each interface
>>> should connect to with the following tags.
>>>
>>> Ethernet0.networkName = "VM Port Group Network Name (Management)"
>>> Ethernet1.networkName = "VM Port Group Network Name (Public)"
>>>
>>> These are pulled from the virtualswitch0 and virtualswitch1 fields of the
>>> VMware ESX entry in the vmprofile table.
>>>
>>> To make this correct, the two virtual switch names (VCL assumes the
>>> virtual switches are already existing) need to be entered into the vmprofile
>>> table.  Is this that case for your installation?
>>>
>>> Best,
>>> Brian
>>>
>>> Brian Bouterse
>>> Secure Open Systems Initiative
>>> 919.698.8796
>>>
>>>
>>>
>>>
>>> On Mar 24, 2009, at 3:24 PM, Melba Lopez wrote:
>>>
>>>  After ensuring the computer hostnames in the DB matches the VI Client
>>>> hostname, with some changes to the hostname at the ESXi host gui, the
>>>> reservation seemed to go a lot farther.
>>>>
>>>> I actually saw the VM deployed and turned on at it's designated blade,
>>>> however the reservation ultimately failed.  As I mentioned in a previous
>>>> email, the vSwitch settings in the golden VM does not stay once it's
>>>> copied
>>>> over to inuse.  Perhaps this is causing this failure?
>>>>
>>>>
>>>>
>>>>
>>>>>  2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(321)|Registered:
>>>>
>>>>>
>>>>>  |7840|148:15|new| Register of VM 'esx3-lamp-v0-bl1' successfully
>>>> completed
>>>>
>>>>> under host esxibl1.preloads.private
>>>>>
>>>>>  2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(330)|Power on
>>>> command:
>>>>
>>>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server
>>>>> 'esxibl1.preloads.private' --vmname esx3-lamp-v0-bl1 --operation
>>>>> poweron
>>>>> --username vcl --password 'd834jfhd734jgfhf7'
>>>>>
>>>>>  2009-03-24 22:46:02|2421|vcld:main(166)|lastcheckin time updated for
>>>>
>>>>> management node 1: 2009-03-24 22:46:02
>>>>>
>>>>>  2009-03-24 22:46:05|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>>> exit
>>>>
>>>>> status: 0
>>>>>
>>>>>  2009-03-24 22:46:05|7840|148:15|new|esx.pm:load(333)|Powered on:
>>>>
>>>>>
>>>>>  |7840|148:15|new| virtual machine 'esx3-lamp-v0-bl1' under host
>>>>
>>>>> esxibl1.preloads.private powered on
>>>>>
>>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:
>>>> load(349)|deviceinfo->summary:
>>>>
>>>>> VirtualPCNet32=HASH(0xbaaf304)->deviceinfo->summary
>>>>>
>>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0:
>>>> VM
>>>>
>>>>> Network
>>>>>
>>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:
>>>> load(349)|deviceinfo->summary:
>>>>
>>>>> VirtualPCNet32=HASH(0xa9860fc)->deviceinfo->summary
>>>>>
>>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0:
>>>> VM
>>>>
>>>>> Network
>>>>>
>>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(360)|Queried MAC
>>>> address is
>>>>
>>>>> 00:0c:29:17:db:6a
>>>>>
>>>>>  2009-03-24 22:46:06|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>>> exit
>>>>
>>>>> status: 0
>>>>>
>>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>>>>
>>>>> seconds, waiting for computer to DHCP. Try 1
>>>>>
>>>>>  2009-03-24 22:46:11|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>>> exit
>>>>
>>>>> status: 0
>>>>>
>>>>>  2009-03-24 22:46:11|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>>>>
>>>>> seconds, waiting for computer to DHCP. Try 2
>>>>>
>>>>>  2009-03-24 22:46:14|2421|vcld:main(166)|lastcheckin time updated for
>>>>
>>>>> management node 1: 2009-03-24 22:46:14
>>>>>
>>>>>  ...
>>>>
>>>>>
>>>>>  ....
>>>>
>>>>>
>>>>>  .....keeps trying until 25 below
>>>>
>>>>
>>>>
>>>> 2009-03-24 22:48:07|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>>>>
>>>>> seconds, waiting for computer to DHCP. Try 25
>>>>>
>>>>
>>>> 2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>>> exit
>>>>
>>>>> status: 0
>>>>>
>>>>>  2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>>> exit
>>>>
>>>>> status: 0
>>>>>
>>>>>  2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>>> exit
>>>>
>>>>> status: 0
>>>>>
>>>>>  2009-03-24 22:50:48|7840|148:15|new|utils.pm:mail(1281)|SUCCESS --
>>>> Sending
>>>>
>>>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>>>
>>>>>
>>>>  |7840|148:15|new| ---- CRITICAL ----
>>>>>
>>>>>  |7840|148:15|new| 2009-03-24 22:48:12|7840|148:15|new|esx.pm:
>>>> load(376)|waited
>>>>
>>>>> acceptable amount of time for dhcp, please check esx3-lamp-v0-bl1 on
>>>>> esxibl1.preloads.private
>>>>>
>>>>>  |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-1) esx.pm, load (line: 376)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-2) new.pm, reload_image (line: 664)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-3) new.pm, process (line: 266)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-4) vcld, make_new_child (line: 606)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-5) vcld, main (line: 353)
>>>>
>>>>>
>>>>>
>>>>
>>>>> |7840|148:15|new| ---- WARNING ----
>>>>>
>>>>>  |7840|148:15|new| 2009-03-24
>>>> 22:50:48|7840|148:15|new|new.pm:reload_image(669)|esx3-lamp-v0
>>>>
>>>>> failed to load on esx3-lamp-v0-bl1, returning
>>>>>
>>>>>  |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-1) new.pm, reload_image (line: 669)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-2) new.pm, process (line: 266)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-4) vcld, main (line: 353)
>>>>
>>>>>
>>>>>
>>>>  2009-03-24 22:50:48|7840|148:15|new|utils.pm:
>>>>> insertloadlog(5300)|inserted
>>>>> computer=11, loadimagefailed, esx3-lamp-v0 failed to load on
>>>>> esx3-lamp-v0-bl1
>>>>>
>>>>>
>>>>  |7840|148:15|new| ---- WARNING ----
>>>>>
>>>>>  |7840|148:15|new| 2009-03-24
>>>> 22:50:48|7840|148:15|new|new.pm:process(313)|failed
>>>>
>>>>> to load esx3-lamp-v0-bl1 with esx3-lamp-v0
>>>>>
>>>>>  |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-1) new.pm, process (line: 313)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-2) vcld, make_new_child (line: 606)
>>>>
>>>>>
>>>>>  |7840|148:15|new| (-3) vcld, main (line: 353)
>>>>
>>>>>
>>>>>
>>>>  2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>>>> exit
>>>>> status: 0
>>>>>
>>>>>  2009-03-24 22:53:24|7840|148:15|new|utils.pm:mail(1281)|SUCCESS --
>>>> Sending
>>>> mail To: root@localhost, PROBLEM -- State.pm
>>>>
>>>>
>>>> |7840|148:15|new| ---- CRITICAL ----
>>>>
>>>> |7840|148:15|new| 2009-03-24
>>>> 22:50:48|7840|148:15|new|State.pm:reservation_failed(285)|reservation
>>>> failed
>>>> on esx3-lamp-v0-bl1: process failed after trying to load or make
>>>> available
>>>>
>>>> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>>>
>>>> |7840|148:15|new| (-1) State.pm, reservation_failed (line: 285)
>>>>
>>>> |7840|148:15|new| (-2) new.pm, process (line: 316)
>>>>
>>>> |7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>>>>
>>>> |7840|148:15|new| (-4) vcld, main (line: 353)
>>>>
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>>> insertloadlog(5300)|inserted
>>>> computer=11, failed, process failed after trying to load or make
>>>> available
>>>>
>>>> 2009-03-24
>>>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(288)|inserted
>>>> computerloadlog entry
>>>>
>>>> 2009-03-24
>>>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(296)|updated
>>>> log ending value to 'failed', logid=82
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>>> update_computer_state(2305)|computer
>>>> 11 state updated to: failed
>>>>
>>>> 2009-03-24
>>>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(304)|computer
>>>> esx3-lamp-v0-bl1 (11) state set to failed
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>>> update_request_state(2263)|request
>>>> 148 state updated to: failed, laststate to: new
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:reservation_failed(312)|set
>>>> request state to 'failed'/'new'
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>>> is_inblockrequest(7356)|zero
>>>> rows were returned from database select
>>>>
>>>> 2009-03-24
>>>>
>>>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(330)|esx3-lamp-v0-bl1
>>>> is NOT in blockcomputers table
>>>>
>>>> 2009-03-24
>>>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(333)|exiting
>>>> 1
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(435)|destructor
>>>> called,
>>>> ref($self)=VCL::new
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>>> delete_computerloadlog_reservation(8013)|removing
>>>> computerloadlog entries matching loadstate = begin
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>>> delete_computerloadlog_reservation(8060)|deleted
>>>> rows from computerloadlog for reservation id=15
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(438)|removed
>>>> computerloadlog rows with loadstate=begin for reservation
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(446)|number of
>>>> database
>>>> handles state process created: 1
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(455)|process has a
>>>> database handle stored in $ENV{dbh}, attempting disconnect
>>>>
>>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(457)|$ENV{dbh}:
>>>> database disconnect successful
>>>>
>>>> On Tue, Mar 24, 2009 at 12:14 PM, Brian Bouterse <bm...@ncsu.edu>
>>>> wrote:
>>>>
>>>>  As it turns out, the vcl-dev list strips out embedded URLs.  I've
>>>>> pasted it
>>>>> below.
>>>>>
>>>>>
>>>>>
>>>>> http://wiki.oscr.ncsu.edu/wiki/index.php/Updating_the_VCL_VM_to_the_latest_code_version
>>>>>
>>>>> Best,
>>>>> Brian
>>>>>
>>>>> Brian Bouterse
>>>>> Secure Open Systems Initiative
>>>>> 919.698.8796
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> On Mar 24, 2009, at 12:44 PM, Brian Bouterse wrote:
>>>>>
>>>>> I forgot to include the link with the upgrade how-to:  It is located
>>>>> here.
>>>>>
>>>>>>
>>>>>> Best,
>>>>>> Brian
>>>>>>
>>>>>>
>>>>>> Brian Bouterse
>>>>>> Secure Open Systems Initiative
>>>>>> 919.698.8796
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> On Mar 24, 2009, at 12:20 PM, Brian Bouterse wrote:
>>>>>>
>>>>>> I've put in some more debugging into the esx.pm module.  This should
>>>>>>
>>>>>>> print the registration command to the screen so that it can be tried
>>>>>>> to run
>>>>>>> manually.  Can you update to the latest code version and try it?
>>>>>>>  I've
>>>>>>> written a how-to located here.
>>>>>>>
>>>>>>> Best,
>>>>>>> Brian
>>>>>>>
>>>>>>>
>>>>>>> Brian Bouterse
>>>>>>> Secure Open Systems Initiative
>>>>>>> 919.698.8796
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> On Mar 24, 2009, at 10:20 AM, Melba Lopez wrote:
>>>>>>>
>>>>>>> Actually everything you've mentioned has been put into place.
>>>>>>>
>>>>>>>> The nameserver entry is in /etc/resolv.conf and all the esxibl1-3
>>>>>>>> hostnames
>>>>>>>> are in the /etc/hosts.
>>>>>>>> I can connect to the blades by putting esxibl1-3 into VIClient
>>>>>>>> without a
>>>>>>>> problem.
>>>>>>>>
>>>>>>>> Note:  /etc/resolv.conf is generated by /sbin/dhclient-script; once
>>>>>>>> network/vm is rebooted it restores original.
>>>>>>>>
>>>>>>>> I also restarted the networking and went as far as to reboot the VCL
>>>>>>>> VM
>>>>>>>> and
>>>>>>>> still it gives me the same error.
>>>>>>>>
>>>>>>>>
>>>>>>>> --Melba
>>>>>>>>
>>>>>>>>
>>>>>>>> On Tue, Mar 24, 2009 at 9:34 AM, Brian Bouterse <bm...@ncsu.edu>
>>>>>>>> wrote:
>>>>>>>>
>>>>>>>> I'm still suspicious of your DNS resolution and configuration.  In
>>>>>>>>
>>>>>>>>> addition
>>>>>>>>> to creating the DNS entries in your lab's DNS server, did you
>>>>>>>>> connect
>>>>>>>>> VCL to
>>>>>>>>> that DNS by creating an entry similar to the one below in the
>>>>>>>>> /etc/resolv.conf on your VCL management node?
>>>>>>>>>
>>>>>>>>> nameserver <ip_of_your_DNS_here>
>>>>>>>>>
>>>>>>>>> Can you connect with virtual center to the blade you're trying to
>>>>>>>>> provision
>>>>>>>>> to when referencing it strictly by it's hostname?
>>>>>>>>>
>>>>>>>>> If you want to remove DNS resolution from the list of possible
>>>>>>>>> culprits,
>>>>>>>>> you can create an entry in /etc/hosts of your VCL management node
>>>>>>>>> similar to
>>>>>>>>> the line below.  I think that should work.
>>>>>>>>>
>>>>>>>>> <IP Address of esxib1>  esxibl1.
>>>>>>>>>
>>>>>>>>> Remember to restart networking (or the whole VCL management node)
>>>>>>>>> when
>>>>>>>>> testing these configuration changes.
>>>>>>>>>
>>>>>>>>> Best,
>>>>>>>>> Brian
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Brian Bouterse
>>>>>>>>> Secure Open Systems Initiative
>>>>>>>>> 919.698.8796
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:
>>>>>>>>>
>>>>>>>>> Ok, our lab already had DNS capabilities, so I've set esxibl1-3*
>>>>>>>>> *to be
>>>>>>>>>
>>>>>>>>>  valid hostnames*.
>>>>>>>>>>
>>>>>>>>>> *However, it is still saying it can't find "esxibl1".  I've pinged
>>>>>>>>>> that
>>>>>>>>>> hostname from another machine on the same network and it works
>>>>>>>>>> just
>>>>>>>>>> fine.
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> Also because it kept saying it couldn't load the VM, I've found
>>>>>>>>>> another
>>>>>>>>>> problem.  The vmdk file successfully copies over into the "inuse"
>>>>>>>>>> folder.
>>>>>>>>>> When I manually add that VM to a blade, I'm noticing that the VM
>>>>>>>>>> does
>>>>>>>>>> not
>>>>>>>>>> keep the network setings.  I watched someone actually create this
>>>>>>>>>> VM
>>>>>>>>>> and I
>>>>>>>>>> redid it myself, and the settings do not stay when its copied
>>>>>>>>>> over.
>>>>>>>>>> Not
>>>>>>>>>> sure if it's related, but thought I might mention it.
>>>>>>>>>> *
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote
>>>>>>>>>> vmxarray
>>>>>>>>>> to
>>>>>>>>>> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
>>>>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $?
>>>>>>>>>> to 0,
>>>>>>>>>> exit
>>>>>>>>>> status: 0
>>>>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
>>>>>>>>>> |24815|143:10|new| No host found with name esxibl1.
>>>>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on
>>>>>>>>>> command:
>>>>>>>>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1'
>>>>>>>>>> --vmname
>>>>>>>>>> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
>>>>>>>>>> 'd834jfhd734jgfhf7'
>>>>>>>>>> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $?
>>>>>>>>>> to 0,
>>>>>>>>>> exit
>>>>>>>>>> status: 0
>>>>>>>>>> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered on:
>>>>>>>>>> Virtual
>>>>>>>>>> Machine esx3-lamp-v0-bl1 not found.
>>>>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $?
>>>>>>>>>> to 0,
>>>>>>>>>> exit
>>>>>>>>>> status: 0
>>>>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $?
>>>>>>>>>> to 0,
>>>>>>>>>> exit
>>>>>>>>>> status: 0
>>>>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS
>>>>>>>>>> --
>>>>>>>>>> Sending
>>>>>>>>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>>>>>>>>
>>>>>>>>>> |24815|143:10|new| ---- CRITICAL ----
>>>>>>>>>> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:
>>>>>>>>>> load(341)|Could
>>>>>>>>>> not query for VM in VI PERL API
>>>>>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
>>>>>>>>>> |24815|143:10|new| (-1) esx.pm, load (line: 341)
>>>>>>>>>> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
>>>>>>>>>> |24815|143:10|new| (-3) new.pm, process (line: 266)
>>>>>>>>>> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
>>>>>>>>>> |24815|143:10|new| (-5) vcld, main (line: 353)
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> |24815|143:10|new| ---- WARNING ----
>>>>>>>>>> |24815|143:10|new| 2009-03-24
>>>>>>>>>> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
>>>>>>>>>> failed to load on esx3-lamp-v0-bl1, returning
>>>>>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <
>>>>>>>>>> josh_thompson@ncsu.edu
>>>>>>>>>>
>>>>>>>>>>  wrote:
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>> -----BEGIN PGP SIGNED MESSAGE-----
>>>>>>>>>>
>>>>>>>>>>  Hash: SHA1
>>>>>>>>>>>
>>>>>>>>>>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>>>>>>>>>>
>>>>>>>>>>> always fake the DNS resolution by placing an entry
>>>>>>>>>>> /etc/resolv.conf
>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>>  That would be /etc/hosts  :)
>>>>>>>>>>>
>>>>>>>>>>> Josh
>>>>>>>>>>> - --
>>>>>>>>>>> - -------------------------------
>>>>>>>>>>> Josh Thompson
>>>>>>>>>>> Systems Programmer
>>>>>>>>>>> Virtual Computing Lab (VCL)
>>>>>>>>>>> North Carolina State University
>>>>>>>>>>>
>>>>>>>>>>> Josh_Thompson@ncsu.edu
>>>>>>>>>>> 919-515-5323
>>>>>>>>>>>
>>>>>>>>>>> my GPG/PGP key can be found at www.keyserver.net
>>>>>>>>>>> -----BEGIN PGP SIGNATURE-----
>>>>>>>>>>> Version: GnuPG v2.0.9 (GNU/Linux)
>>>>>>>>>>>
>>>>>>>>>>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
>>>>>>>>>>> nKgBCGnhdhToNQ0EtzLhRC8=
>>>>>>>>>>> =Yjph
>>>>>>>>>>> -----END PGP SIGNATURE-----
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>>
>>
>
>

Re: Reservation Problem

Posted by Melba Lopez <mi...@gmail.com>.
The failed reservation problem that we were experiencing was related to our
configuration.

We are currently running our VCL installation in an isolated lab, so we have
the "public" network on a 10.138.x.x subnet and the "private" management
network on 10.0.x.x  utils.pm in looking for the dynamic address finds the
private IP address, but skips our public IP address on the 10.138 subnet.

>From the utils.pm linux path:

elsif ($image_os_type =~ /linux/) {
  $identity = $IDENTITY_bladerhel;
  undef @sshcmd;
  @sshcmd = run_ssh_command($node, $identity, "/sbin/ifconfig \|grep inet",
"root");
  for my $l (@{$sshcmd[1]}) {
   # skip class a,b,c private addresses
   next if ($l =~ /inet addr:$privateIP/);
   next if ($l =~ /inet addr:10.([.0-9]*)/);       <------- removing this
line made our configuration work.
   next if ($l =~ /inet addr:127([.0-9]*)/);
   next if ($l =~ /inet addr:172([.0-9]*)/);
   next if ($l =~ /inet addr:192.168([.0-9]*)/);
   if ($l =~ /inet addr:([.0-9]*)/) {
    if ($l !~ /inet addr:$privateIP/) {
     #to cover sites using eth0 as public
     $dynaIPaddress = $1;
    }
   }
  } ## end for my $l (@{$sshcmd[1]})


--Melba

On Wed, Mar 25, 2009 at 2:37 PM, Melba Lopez <mi...@gmail.com> wrote:

> Thanks for that vmprofile tip. That fixed the network naming issue I was
> seeing.
> Good news is that it got farther in the process, but still failed.  Here's
> the new logs:
>
>
>  2009-03-25 19:29:33|28031|149:16|new|esx.pm:load(235)|SSHing to copy
>> vmdk-flat file
>>
>  2009-03-25 19:29:43|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:29:43
>>
> 2009-03-25 19:29:55|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:29:55
>>
> 2009-03-25 19:29:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:29:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>> exit status: 0
>>
>  2009-03-25 19:29:57|28031|149:16|new|esx.pm:load(258)|adapter= lsilogic
>>
>  2009-03-25 19:29:57|28031|149:16|new|esx.pm:load(300)|wrote vmxarray to
>> /mnt/vcl/inuse/esx3-lamp-v0-bl3/esx3-lamp-v0.vmx
>>
> 2009-03-25 19:30:00|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:00|28031|149:16|new|esx.pm:load(321)|Registered:
>>
> |28031|149:16|new| Register of VM 'esx3-lamp-v0-bl3' successfully completed
>> under host esxibl3.preloads.private
>>
> 2009-03-25 19:30:00|28031|149:16|new|esx.pm:load(330)|Power on command:
>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server
>> 'esxibl3.preloads.private' --vmname esx3-lamp-v0-bl3 --operation poweron
>> --username vcl --password 'd834jfhd734jgfhf7'
>>
> 2009-03-25 19:30:04|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:04|28031|149:16|new|esx.pm:load(333)|Powered on:
>>
> |28031|149:16|new| virtual machine 'esx3-lamp-v0-bl3' under host
>> esxibl3.preloads.private powered on
>>
> 2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(349)|deviceinfo->summary:
>> VirtualPCNet32=HASH(0xbdd3d64)->deviceinfo->summary
>>
> 2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(350)|virtualswitch0:
>> Management
>>
>  2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(349)|deviceinfo->summary:
>> VirtualPCNet32=HASH(0xacbce1c)->deviceinfo->summary
>>
> 2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(350)|virtualswitch0:
>> Management
>>
>  2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(360)|Queried MAC address
>> is 00:0c:29:46:1d:c7
>>
>  2009-03-25 19:30:05|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>> exit status: 0
>>
>  2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 1
>>
> 2009-03-25 19:30:07|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:30:07
>>
> 2009-03-25 19:30:10|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:10|28031|149:16|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 2
>>
> 2009-03-25 19:30:15|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:15|28031|149:16|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 3
>>
> 2009-03-25 19:30:19|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:30:19
>>
> 2009-03-25 19:30:20|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:20|28031|149:16|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 4
>>
> 2009-03-25 19:30:25|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:25|28031|149:16|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 5
>>
> 2009-03-25 19:30:30|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(372)|esx3-lamp-v0-bl3
>> now has ip 10.0.4.101
>>
>  2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(388)|Found IP address
>> 10.0.4.101
>>
>  2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(391)|Removing old hosts
>> entry
>>
>  2009-03-25 19:30:30|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>> exit status: 0
>>
>  2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(393)|
>>
> 2009-03-25 19:30:30|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(402)|Waiting for ssh to
>> come up on esx3-lamp-v0-bl3
>>
> 2009-03-25 19:30:31|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:31|28031|149:16|new|esx.pm:load(419)|going to sleep 5
>> seconds, waiting for computer to start SSH. Try 1
>>
> 2009-03-25 19:30:31|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:30:31
>>
> 2009-03-25 19:30:36|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:36|28031|149:16|new|utils.pm:run_ssh_command(6672)|executing
>> SSH command on esx3-lamp-v0-bl3: uname -s
>>
> 2009-03-25 19:30:43|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:30:43
>>
> 2009-03-25 19:30:47|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:47|28031|149:16|new|utils.pm:run_ssh_command(6753)|run_ssh_command
>> output: Linux
>>
> 2009-03-25 19:30:47|28031|149:16|new|utils.pm:run_ssh_command(6756)|SSH
>> command executed on esx3-lamp-v0-bl3: uname -s, returning (0, output)
>>
> 2009-03-25 19:30:47|28031|149:16|new|esx.pm:load(407)|esx3-lamp-v0-bl3 now
>> has active sshd running
>>
> 2009-03-25 19:30:47|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
>> computer=13, dynamicDHCPaddress, collecting dynamic IP address for node
>>
> 2009-03-25 19:30:47|28031|149:16|new|esx.pm:load(430)|Attempting to query
>> vmclient for its public IP...
>>
> 2009-03-25 19:30:47|28031|149:16|new|utils.pm:getdynamicaddress(1640)|PrivateIP
>> address for esx3-lamp-v0-bl3 collected 10.0.4.101
>>
> 2009-03-25 19:30:47|28031|149:16|new|utils.pm:run_ssh_command(6672)|executing
>> SSH command on esx3-lamp-v0-bl3: /sbin/ifconfig |grep inet
>>
> 2009-03-25 19:30:55|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:30:55
>>
> 2009-03-25 19:30:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:30:57|28031|149:16|new|utils.pm:run_ssh_command(6753)|run_ssh_command
>> output: inet addr:10.0.4.101 Bcast:10.0.255.255 Mask:255.255.0.0
>>
> |28031|149:16|new|  inet6 addr: fe80::20c:29ff:fe46:1dc7/64 Scope:Link
>>
>  |28031|149:16|new|  inet addr:10.138.1.185 Bcast:10.138.1.255
>> Mask:255.255.255.0
>>
>  |28031|149:16|new|  inet6 addr: fe80::20c:29ff:fe46:1dd1/64 Scope:Link
>>
>  |28031|149:16|new|  inet addr:127.0.0.1 Mask:255.0.0.0
>>
> |28031|149:16|new|  inet6 addr: ::1/128 Scope:Host
>>
> 2009-03-25 19:30:57|28031|149:16|new|utils.pm:run_ssh_command(6756)|SSH
>> command executed on esx3-lamp-v0-bl3: /sbin/ifconfig |grep inet, returning
>> (0, output)
>>
> 2009-03-25 19:30:57|28031|149:16|new|utils.pm:getdynamicaddress(1697)|dynamic
>> IP address for esx3-lamp-v0-bl3 collected: 0
>>
> 2009-03-25 19:30:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:31:07|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:31:07
>>
> 2009-03-25 19:33:31|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:33:31
>>
> 2009-03-25 19:33:39|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
>> status: 0
>>
>  2009-03-25 19:33:39|28031|149:16|new|utils.pm:mail(1281)|SUCCESS --
>> Sending mail To: root@localhost, PROBLEM -- esx.pm
>>
>
>> |28031|149:16|new| ---- CRITICAL ----
>>
> |28031|149:16|new| 2009-03-25 19:30:57|28031|149:16|new|esx.pm:load(444)|could
>> not fetch dynamic address from esx3-lamp-v0-bl3 esx3-lamp-v0
>>
> |28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>>
>  |28031|149:16|new| (-1) esx.pm, load (line: 444)
>>
>  |28031|149:16|new| (-2) new.pm, reload_image (line: 664)
>>
>  |28031|149:16|new| (-3) new.pm, process (line: 266)
>>
>  |28031|149:16|new| (-4) vcld, make_new_child (line: 606)
>>
> |28031|149:16|new| (-5) vcld, main (line: 353)
>>
>
>> 2009-03-25 19:33:39|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
>> computer=13, failed, could not collect dynamic IP address for node
>>
>
>> |28031|149:16|new| ---- WARNING ----
>>
> |28031|149:16|new| 2009-03-25 19:33:39|28031|149:16|new|new.pm:reload_image(669)|esx3-lamp-v0
>> failed to load on esx3-lamp-v0-bl3, returning
>>
> |28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>>
>  |28031|149:16|new| (-1) new.pm, reload_image (line: 669)
>>
>  |28031|149:16|new| (-2) new.pm, process (line: 266)
>>
>  |28031|149:16|new| (-3) vcld, make_new_child (line: 606)
>>
> |28031|149:16|new| (-4) vcld, main (line: 353)
>>
>
>> 2009-03-25 19:33:39|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
>> computer=13, loadimagefailed, esx3-lamp-v0 failed to load on
>> esx3-lamp-v0-bl3
>>
>
>> |28031|149:16|new| ---- WARNING ----
>>
> |28031|149:16|new| 2009-03-25 19:33:39|28031|149:16|new|new.pm:process(313)|failed
>> to load esx3-lamp-v0-bl3 with esx3-lamp-v0
>>
> |28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>>
>  |28031|149:16|new| (-1) new.pm, process (line: 313)
>>
>  |28031|149:16|new| (-2) vcld, make_new_child (line: 606)
>>
> |28031|149:16|new| (-3) vcld, main (line: 353)
>>
>
>> 2009-03-25 19:33:39|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>> exit status: 0
>>
>  2009-03-25 19:33:43|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:33:43
>>
> 2009-03-25 19:33:55|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-25 19:33:55
>>
>
>> 2009-03-25 19:36:21|28031|149:16|new|vcld:REAPER(770)|setting $? to 0,
>> exit status: 0
>>
>  2009-03-25 19:36:21|28031|149:16|new|utils.pm:mail(1281)|SUCCESS --
>> Sending mail To: root@localhost, PROBLEM -- State.pm
>>
>
>> |28031|149:16|new| ---- CRITICAL ----
>>
> |28031|149:16|new| 2009-03-25
>> 19:33:39|28031|149:16|new|State.pm:reservation_failed(285)|reservation
>> failed on esx3-lamp-v0-bl3: process failed after trying to load or make
>> available
>>
> |28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>>
>  |28031|149:16|new| (-1) State.pm, reservation_failed (line: 285)
>>
> |28031|149:16|new| (-2) new.pm, process (line: 316)
>>
>  |28031|149:16|new| (-3) vcld, make_new_child (line: 606)
>>
> |28031|149:16|new| (-4) vcld, main (line: 353)
>>
>
>> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
>> computer=13, failed, process failed after trying to load or make available
>>
> 2009-03-25
>> 19:36:21|28031|149:16|new|State.pm:reservation_failed(288)|inserted
>> computerloadlog entry
>>
> 2009-03-25
>> 19:36:21|28031|149:16|new|State.pm:reservation_failed(296)|updated log
>> ending value to 'failed', logid=83
>>
> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:update_computer_state(2305)|computer
>> 13 state updated to: failed
>>
> 2009-03-25
>> 19:36:21|28031|149:16|new|State.pm:reservation_failed(304)|computer
>> esx3-lamp-v0-bl3 (13) state set to failed
>>
> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:update_request_state(2263)|request
>> 149 state updated to: failed, laststate to: new
>>
> 2009-03-25 19:36:21|28031|149:16|new|State.pm:reservation_failed(312)|set
>> request state to 'failed'/'new'
>>
> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:is_inblockrequest(7356)|zero
>> rows were returned from database select
>>
> 2009-03-25
>> 19:36:21|28031|149:16|new|State.pm:reservation_failed(330)|esx3-lamp-v0-bl3
>> is NOT in blockcomputers table
>>
> 2009-03-25
>> 19:36:21|28031|149:16|new|State.pm:reservation_failed(333)|exiting 1
>>
>  2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(435)|destructor
>> called, ref($self)=VCL::new
>>
> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:delete_computerloadlog_reservation(8013)|removing
>> computerloadlog entries matching loadstate = begin
>>
> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:delete_computerloadlog_reservation(8060)|deleted
>> rows from computerloadlog for reservation id=16
>>
> 2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(438)|removed
>> computerloadlog rows with loadstate=begin for reservation
>>
> 2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(446)|number of
>> database handles state process created: 1
>>
> 2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(455)|process has a
>> database handle stored in $ENV{dbh}, attempting disconnect
>>
> 2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(457)|$ENV{dbh}:
>> database disconnect successful
>>
> 2009-03-25 19:36:21|2421|vcld:REAPER(751)|process reaped: pid: 28031, $?:
>> 256, exit status: 1
>>
>  2009-03-25 19:36:21|2421|vcld:REAPER(756)|VCL process exited for
>> reservation 16
>>
>  2009-03-25 19:36:21|2421|vcld:REAPER(770)|setting $? to 256, exit status:
>> 1
>>
>
>
>
>
> --
> Melba
>
>
> On Wed, Mar 25, 2009 at 10:54 AM, Brian Bouterse <bm...@ncsu.edu>wrote:
>
>> Here are a few things to look into around the virtual switch assignments
>> of deployed ESX compatible virtual machines.  When the esx.pm writes out
>> the .vmx file, on-the-fly, it indicates the network names each interface
>> should connect to with the following tags.
>>
>> Ethernet0.networkName = "VM Port Group Network Name (Management)"
>> Ethernet1.networkName = "VM Port Group Network Name (Public)"
>>
>> These are pulled from the virtualswitch0 and virtualswitch1 fields of the
>> VMware ESX entry in the vmprofile table.
>>
>> To make this correct, the two virtual switch names (VCL assumes the
>> virtual switches are already existing) need to be entered into the vmprofile
>> table.  Is this that case for your installation?
>>
>> Best,
>> Brian
>>
>> Brian Bouterse
>> Secure Open Systems Initiative
>> 919.698.8796
>>
>>
>>
>>
>> On Mar 24, 2009, at 3:24 PM, Melba Lopez wrote:
>>
>>  After ensuring the computer hostnames in the DB matches the VI Client
>>> hostname, with some changes to the hostname at the ESXi host gui, the
>>> reservation seemed to go a lot farther.
>>>
>>> I actually saw the VM deployed and turned on at it's designated blade,
>>> however the reservation ultimately failed.  As I mentioned in a previous
>>> email, the vSwitch settings in the golden VM does not stay once it's
>>> copied
>>> over to inuse.  Perhaps this is causing this failure?
>>>
>>>
>>>
>>>
>>>>  2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(321)|Registered:
>>>
>>>>
>>>>  |7840|148:15|new| Register of VM 'esx3-lamp-v0-bl1' successfully
>>> completed
>>>
>>>> under host esxibl1.preloads.private
>>>>
>>>>  2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(330)|Power on command:
>>>
>>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server
>>>> 'esxibl1.preloads.private' --vmname esx3-lamp-v0-bl1 --operation poweron
>>>> --username vcl --password 'd834jfhd734jgfhf7'
>>>>
>>>>  2009-03-24 22:46:02|2421|vcld:main(166)|lastcheckin time updated for
>>>
>>>> management node 1: 2009-03-24 22:46:02
>>>>
>>>>  2009-03-24 22:46:05|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>> exit
>>>
>>>> status: 0
>>>>
>>>>  2009-03-24 22:46:05|7840|148:15|new|esx.pm:load(333)|Powered on:
>>>
>>>>
>>>>  |7840|148:15|new| virtual machine 'esx3-lamp-v0-bl1' under host
>>>
>>>> esxibl1.preloads.private powered on
>>>>
>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:
>>> load(349)|deviceinfo->summary:
>>>
>>>> VirtualPCNet32=HASH(0xbaaf304)->deviceinfo->summary
>>>>
>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0:
>>> VM
>>>
>>>> Network
>>>>
>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:
>>> load(349)|deviceinfo->summary:
>>>
>>>> VirtualPCNet32=HASH(0xa9860fc)->deviceinfo->summary
>>>>
>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0:
>>> VM
>>>
>>>> Network
>>>>
>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(360)|Queried MAC
>>> address is
>>>
>>>> 00:0c:29:17:db:6a
>>>>
>>>>  2009-03-24 22:46:06|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>> exit
>>>
>>>> status: 0
>>>>
>>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>>>
>>>> seconds, waiting for computer to DHCP. Try 1
>>>>
>>>>  2009-03-24 22:46:11|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>> exit
>>>
>>>> status: 0
>>>>
>>>>  2009-03-24 22:46:11|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>>>
>>>> seconds, waiting for computer to DHCP. Try 2
>>>>
>>>>  2009-03-24 22:46:14|2421|vcld:main(166)|lastcheckin time updated for
>>>
>>>> management node 1: 2009-03-24 22:46:14
>>>>
>>>>  ...
>>>
>>>>
>>>>  ....
>>>
>>>>
>>>>  .....keeps trying until 25 below
>>>
>>>
>>>
>>> 2009-03-24 22:48:07|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>>>
>>>> seconds, waiting for computer to DHCP. Try 25
>>>>
>>>
>>> 2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>> exit
>>>
>>>> status: 0
>>>>
>>>>  2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>> exit
>>>
>>>> status: 0
>>>>
>>>>  2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>> exit
>>>
>>>> status: 0
>>>>
>>>>  2009-03-24 22:50:48|7840|148:15|new|utils.pm:mail(1281)|SUCCESS --
>>> Sending
>>>
>>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>>
>>>>
>>>  |7840|148:15|new| ---- CRITICAL ----
>>>>
>>>>  |7840|148:15|new| 2009-03-24 22:48:12|7840|148:15|new|esx.pm:
>>> load(376)|waited
>>>
>>>> acceptable amount of time for dhcp, please check esx3-lamp-v0-bl1 on
>>>> esxibl1.preloads.private
>>>>
>>>>  |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>>
>>>>
>>>>  |7840|148:15|new| (-1) esx.pm, load (line: 376)
>>>
>>>>
>>>>  |7840|148:15|new| (-2) new.pm, reload_image (line: 664)
>>>
>>>>
>>>>  |7840|148:15|new| (-3) new.pm, process (line: 266)
>>>
>>>>
>>>>  |7840|148:15|new| (-4) vcld, make_new_child (line: 606)
>>>
>>>>
>>>>  |7840|148:15|new| (-5) vcld, main (line: 353)
>>>
>>>>
>>>>
>>>
>>>> |7840|148:15|new| ---- WARNING ----
>>>>
>>>>  |7840|148:15|new| 2009-03-24
>>> 22:50:48|7840|148:15|new|new.pm:reload_image(669)|esx3-lamp-v0
>>>
>>>> failed to load on esx3-lamp-v0-bl1, returning
>>>>
>>>>  |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>>
>>>>
>>>>  |7840|148:15|new| (-1) new.pm, reload_image (line: 669)
>>>
>>>>
>>>>  |7840|148:15|new| (-2) new.pm, process (line: 266)
>>>
>>>>
>>>>  |7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>>>
>>>>
>>>>  |7840|148:15|new| (-4) vcld, main (line: 353)
>>>
>>>>
>>>>
>>>  2009-03-24 22:50:48|7840|148:15|new|utils.pm:
>>>> insertloadlog(5300)|inserted
>>>> computer=11, loadimagefailed, esx3-lamp-v0 failed to load on
>>>> esx3-lamp-v0-bl1
>>>>
>>>>
>>>  |7840|148:15|new| ---- WARNING ----
>>>>
>>>>  |7840|148:15|new| 2009-03-24
>>> 22:50:48|7840|148:15|new|new.pm:process(313)|failed
>>>
>>>> to load esx3-lamp-v0-bl1 with esx3-lamp-v0
>>>>
>>>>  |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>>
>>>>
>>>>  |7840|148:15|new| (-1) new.pm, process (line: 313)
>>>
>>>>
>>>>  |7840|148:15|new| (-2) vcld, make_new_child (line: 606)
>>>
>>>>
>>>>  |7840|148:15|new| (-3) vcld, main (line: 353)
>>>
>>>>
>>>>
>>>  2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>>> exit
>>>> status: 0
>>>>
>>>>  2009-03-24 22:53:24|7840|148:15|new|utils.pm:mail(1281)|SUCCESS --
>>> Sending
>>> mail To: root@localhost, PROBLEM -- State.pm
>>>
>>>
>>> |7840|148:15|new| ---- CRITICAL ----
>>>
>>> |7840|148:15|new| 2009-03-24
>>> 22:50:48|7840|148:15|new|State.pm:reservation_failed(285)|reservation
>>> failed
>>> on esx3-lamp-v0-bl1: process failed after trying to load or make
>>> available
>>>
>>> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>>
>>> |7840|148:15|new| (-1) State.pm, reservation_failed (line: 285)
>>>
>>> |7840|148:15|new| (-2) new.pm, process (line: 316)
>>>
>>> |7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>>>
>>> |7840|148:15|new| (-4) vcld, main (line: 353)
>>>
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>> insertloadlog(5300)|inserted
>>> computer=11, failed, process failed after trying to load or make
>>> available
>>>
>>> 2009-03-24
>>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(288)|inserted
>>> computerloadlog entry
>>>
>>> 2009-03-24
>>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(296)|updated
>>> log ending value to 'failed', logid=82
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>> update_computer_state(2305)|computer
>>> 11 state updated to: failed
>>>
>>> 2009-03-24
>>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(304)|computer
>>> esx3-lamp-v0-bl1 (11) state set to failed
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>> update_request_state(2263)|request
>>> 148 state updated to: failed, laststate to: new
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:reservation_failed(312)|set
>>> request state to 'failed'/'new'
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>> is_inblockrequest(7356)|zero
>>> rows were returned from database select
>>>
>>> 2009-03-24
>>>
>>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(330)|esx3-lamp-v0-bl1
>>> is NOT in blockcomputers table
>>>
>>> 2009-03-24
>>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(333)|exiting
>>> 1
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(435)|destructor
>>> called,
>>> ref($self)=VCL::new
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>> delete_computerloadlog_reservation(8013)|removing
>>> computerloadlog entries matching loadstate = begin
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>>> delete_computerloadlog_reservation(8060)|deleted
>>> rows from computerloadlog for reservation id=15
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(438)|removed
>>> computerloadlog rows with loadstate=begin for reservation
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(446)|number of
>>> database
>>> handles state process created: 1
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(455)|process has a
>>> database handle stored in $ENV{dbh}, attempting disconnect
>>>
>>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(457)|$ENV{dbh}:
>>> database disconnect successful
>>>
>>> On Tue, Mar 24, 2009 at 12:14 PM, Brian Bouterse <bm...@ncsu.edu>
>>> wrote:
>>>
>>>  As it turns out, the vcl-dev list strips out embedded URLs.  I've pasted
>>>> it
>>>> below.
>>>>
>>>>
>>>>
>>>> http://wiki.oscr.ncsu.edu/wiki/index.php/Updating_the_VCL_VM_to_the_latest_code_version
>>>>
>>>> Best,
>>>> Brian
>>>>
>>>> Brian Bouterse
>>>> Secure Open Systems Initiative
>>>> 919.698.8796
>>>>
>>>>
>>>>
>>>>
>>>> On Mar 24, 2009, at 12:44 PM, Brian Bouterse wrote:
>>>>
>>>> I forgot to include the link with the upgrade how-to:  It is located
>>>> here.
>>>>
>>>>>
>>>>> Best,
>>>>> Brian
>>>>>
>>>>>
>>>>> Brian Bouterse
>>>>> Secure Open Systems Initiative
>>>>> 919.698.8796
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> On Mar 24, 2009, at 12:20 PM, Brian Bouterse wrote:
>>>>>
>>>>> I've put in some more debugging into the esx.pm module.  This should
>>>>>
>>>>>> print the registration command to the screen so that it can be tried
>>>>>> to run
>>>>>> manually.  Can you update to the latest code version and try it?  I've
>>>>>> written a how-to located here.
>>>>>>
>>>>>> Best,
>>>>>> Brian
>>>>>>
>>>>>>
>>>>>> Brian Bouterse
>>>>>> Secure Open Systems Initiative
>>>>>> 919.698.8796
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> On Mar 24, 2009, at 10:20 AM, Melba Lopez wrote:
>>>>>>
>>>>>> Actually everything you've mentioned has been put into place.
>>>>>>
>>>>>>> The nameserver entry is in /etc/resolv.conf and all the esxibl1-3
>>>>>>> hostnames
>>>>>>> are in the /etc/hosts.
>>>>>>> I can connect to the blades by putting esxibl1-3 into VIClient
>>>>>>> without a
>>>>>>> problem.
>>>>>>>
>>>>>>> Note:  /etc/resolv.conf is generated by /sbin/dhclient-script; once
>>>>>>> network/vm is rebooted it restores original.
>>>>>>>
>>>>>>> I also restarted the networking and went as far as to reboot the VCL
>>>>>>> VM
>>>>>>> and
>>>>>>> still it gives me the same error.
>>>>>>>
>>>>>>>
>>>>>>> --Melba
>>>>>>>
>>>>>>>
>>>>>>> On Tue, Mar 24, 2009 at 9:34 AM, Brian Bouterse <bm...@ncsu.edu>
>>>>>>> wrote:
>>>>>>>
>>>>>>> I'm still suspicious of your DNS resolution and configuration.  In
>>>>>>>
>>>>>>>> addition
>>>>>>>> to creating the DNS entries in your lab's DNS server, did you
>>>>>>>> connect
>>>>>>>> VCL to
>>>>>>>> that DNS by creating an entry similar to the one below in the
>>>>>>>> /etc/resolv.conf on your VCL management node?
>>>>>>>>
>>>>>>>> nameserver <ip_of_your_DNS_here>
>>>>>>>>
>>>>>>>> Can you connect with virtual center to the blade you're trying to
>>>>>>>> provision
>>>>>>>> to when referencing it strictly by it's hostname?
>>>>>>>>
>>>>>>>> If you want to remove DNS resolution from the list of possible
>>>>>>>> culprits,
>>>>>>>> you can create an entry in /etc/hosts of your VCL management node
>>>>>>>> similar to
>>>>>>>> the line below.  I think that should work.
>>>>>>>>
>>>>>>>> <IP Address of esxib1>  esxibl1.
>>>>>>>>
>>>>>>>> Remember to restart networking (or the whole VCL management node)
>>>>>>>> when
>>>>>>>> testing these configuration changes.
>>>>>>>>
>>>>>>>> Best,
>>>>>>>> Brian
>>>>>>>>
>>>>>>>>
>>>>>>>> Brian Bouterse
>>>>>>>> Secure Open Systems Initiative
>>>>>>>> 919.698.8796
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:
>>>>>>>>
>>>>>>>> Ok, our lab already had DNS capabilities, so I've set esxibl1-3* *to
>>>>>>>> be
>>>>>>>>
>>>>>>>>  valid hostnames*.
>>>>>>>>>
>>>>>>>>> *However, it is still saying it can't find "esxibl1".  I've pinged
>>>>>>>>> that
>>>>>>>>> hostname from another machine on the same network and it works just
>>>>>>>>> fine.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Also because it kept saying it couldn't load the VM, I've found
>>>>>>>>> another
>>>>>>>>> problem.  The vmdk file successfully copies over into the "inuse"
>>>>>>>>> folder.
>>>>>>>>> When I manually add that VM to a blade, I'm noticing that the VM
>>>>>>>>> does
>>>>>>>>> not
>>>>>>>>> keep the network setings.  I watched someone actually create this
>>>>>>>>> VM
>>>>>>>>> and I
>>>>>>>>> redid it myself, and the settings do not stay when its copied over.
>>>>>>>>> Not
>>>>>>>>> sure if it's related, but thought I might mention it.
>>>>>>>>> *
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote
>>>>>>>>> vmxarray
>>>>>>>>> to
>>>>>>>>> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
>>>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>>>> 0,
>>>>>>>>> exit
>>>>>>>>> status: 0
>>>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
>>>>>>>>> |24815|143:10|new| No host found with name esxibl1.
>>>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on
>>>>>>>>> command:
>>>>>>>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1'
>>>>>>>>> --vmname
>>>>>>>>> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
>>>>>>>>> 'd834jfhd734jgfhf7'
>>>>>>>>> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>>>> 0,
>>>>>>>>> exit
>>>>>>>>> status: 0
>>>>>>>>> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered on:
>>>>>>>>> Virtual
>>>>>>>>> Machine esx3-lamp-v0-bl1 not found.
>>>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>>>> 0,
>>>>>>>>> exit
>>>>>>>>> status: 0
>>>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>>>> 0,
>>>>>>>>> exit
>>>>>>>>> status: 0
>>>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS
>>>>>>>>> --
>>>>>>>>> Sending
>>>>>>>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>>>>>>>
>>>>>>>>> |24815|143:10|new| ---- CRITICAL ----
>>>>>>>>> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:
>>>>>>>>> load(341)|Could
>>>>>>>>> not query for VM in VI PERL API
>>>>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
>>>>>>>>> |24815|143:10|new| (-1) esx.pm, load (line: 341)
>>>>>>>>> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
>>>>>>>>> |24815|143:10|new| (-3) new.pm, process (line: 266)
>>>>>>>>> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
>>>>>>>>> |24815|143:10|new| (-5) vcld, main (line: 353)
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> |24815|143:10|new| ---- WARNING ----
>>>>>>>>> |24815|143:10|new| 2009-03-24
>>>>>>>>> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
>>>>>>>>> failed to load on esx3-lamp-v0-bl1, returning
>>>>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <
>>>>>>>>> josh_thompson@ncsu.edu
>>>>>>>>>
>>>>>>>>>  wrote:
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>> -----BEGIN PGP SIGNED MESSAGE-----
>>>>>>>>>
>>>>>>>>>  Hash: SHA1
>>>>>>>>>>
>>>>>>>>>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>>>>>>>>>
>>>>>>>>>> always fake the DNS resolution by placing an entry
>>>>>>>>>> /etc/resolv.conf
>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>  That would be /etc/hosts  :)
>>>>>>>>>>
>>>>>>>>>> Josh
>>>>>>>>>> - --
>>>>>>>>>> - -------------------------------
>>>>>>>>>> Josh Thompson
>>>>>>>>>> Systems Programmer
>>>>>>>>>> Virtual Computing Lab (VCL)
>>>>>>>>>> North Carolina State University
>>>>>>>>>>
>>>>>>>>>> Josh_Thompson@ncsu.edu
>>>>>>>>>> 919-515-5323
>>>>>>>>>>
>>>>>>>>>> my GPG/PGP key can be found at www.keyserver.net
>>>>>>>>>> -----BEGIN PGP SIGNATURE-----
>>>>>>>>>> Version: GnuPG v2.0.9 (GNU/Linux)
>>>>>>>>>>
>>>>>>>>>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
>>>>>>>>>> nKgBCGnhdhToNQ0EtzLhRC8=
>>>>>>>>>> =Yjph
>>>>>>>>>> -----END PGP SIGNATURE-----
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>
>
>

Re: Reservation Problem

Posted by Melba Lopez <mi...@gmail.com>.
Thanks for that vmprofile tip. That fixed the network naming issue I was
seeing.
Good news is that it got farther in the process, but still failed.  Here's
the new logs:


2009-03-25 19:29:33|28031|149:16|new|esx.pm:load(235)|SSHing to copy
> vmdk-flat file
>
2009-03-25 19:29:43|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:29:43
>
2009-03-25 19:29:55|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:29:55
>
2009-03-25 19:29:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:29:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:29:57|28031|149:16|new|esx.pm:load(258)|adapter= lsilogic
>
2009-03-25 19:29:57|28031|149:16|new|esx.pm:load(300)|wrote vmxarray to
> /mnt/vcl/inuse/esx3-lamp-v0-bl3/esx3-lamp-v0.vmx
>
2009-03-25 19:30:00|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:00|28031|149:16|new|esx.pm:load(321)|Registered:
>
|28031|149:16|new| Register of VM 'esx3-lamp-v0-bl3' successfully completed
> under host esxibl3.preloads.private
>
2009-03-25 19:30:00|28031|149:16|new|esx.pm:load(330)|Power on command:
> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server
> 'esxibl3.preloads.private' --vmname esx3-lamp-v0-bl3 --operation poweron
> --username vcl --password 'd834jfhd734jgfhf7'
>
2009-03-25 19:30:04|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:04|28031|149:16|new|esx.pm:load(333)|Powered on:
>
|28031|149:16|new| virtual machine 'esx3-lamp-v0-bl3' under host
> esxibl3.preloads.private powered on
>
2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(349)|deviceinfo->summary:
> VirtualPCNet32=HASH(0xbdd3d64)->deviceinfo->summary
>
2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(350)|virtualswitch0:
> Management
>
2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(349)|deviceinfo->summary:
> VirtualPCNet32=HASH(0xacbce1c)->deviceinfo->summary
>
2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(350)|virtualswitch0:
> Management
>
2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(360)|Queried MAC address is
> 00:0c:29:46:1d:c7
>
2009-03-25 19:30:05|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:05|28031|149:16|new|esx.pm:load(381)|going to sleep 5
> seconds, waiting for computer to DHCP. Try 1
>
2009-03-25 19:30:07|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:30:07
>
2009-03-25 19:30:10|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:10|28031|149:16|new|esx.pm:load(381)|going to sleep 5
> seconds, waiting for computer to DHCP. Try 2
>
2009-03-25 19:30:15|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:15|28031|149:16|new|esx.pm:load(381)|going to sleep 5
> seconds, waiting for computer to DHCP. Try 3
>
2009-03-25 19:30:19|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:30:19
>
2009-03-25 19:30:20|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:20|28031|149:16|new|esx.pm:load(381)|going to sleep 5
> seconds, waiting for computer to DHCP. Try 4
>
2009-03-25 19:30:25|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:25|28031|149:16|new|esx.pm:load(381)|going to sleep 5
> seconds, waiting for computer to DHCP. Try 5
>
2009-03-25 19:30:30|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(372)|esx3-lamp-v0-bl3 now
> has ip 10.0.4.101
>
2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(388)|Found IP address
> 10.0.4.101
>
2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(391)|Removing old hosts
> entry
>
2009-03-25 19:30:30|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(393)|
>
2009-03-25 19:30:30|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:30|28031|149:16|new|esx.pm:load(402)|Waiting for ssh to
> come up on esx3-lamp-v0-bl3
>
2009-03-25 19:30:31|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:31|28031|149:16|new|esx.pm:load(419)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 1
>
2009-03-25 19:30:31|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:30:31
>
2009-03-25 19:30:36|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:36|28031|149:16|new|utils.pm:run_ssh_command(6672)|executing
> SSH command on esx3-lamp-v0-bl3: uname -s
>
2009-03-25 19:30:43|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:30:43
>
2009-03-25 19:30:47|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:47|28031|149:16|new|utils.pm:run_ssh_command(6753)|run_ssh_command
> output: Linux
>
2009-03-25 19:30:47|28031|149:16|new|utils.pm:run_ssh_command(6756)|SSH
> command executed on esx3-lamp-v0-bl3: uname -s, returning (0, output)
>
2009-03-25 19:30:47|28031|149:16|new|esx.pm:load(407)|esx3-lamp-v0-bl3 now
> has active sshd running
>
2009-03-25 19:30:47|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
> computer=13, dynamicDHCPaddress, collecting dynamic IP address for node
>
2009-03-25 19:30:47|28031|149:16|new|esx.pm:load(430)|Attempting to query
> vmclient for its public IP...
>
2009-03-25 19:30:47|28031|149:16|new|utils.pm:getdynamicaddress(1640)|PrivateIP
> address for esx3-lamp-v0-bl3 collected 10.0.4.101
>
2009-03-25 19:30:47|28031|149:16|new|utils.pm:run_ssh_command(6672)|executing
> SSH command on esx3-lamp-v0-bl3: /sbin/ifconfig |grep inet
>
2009-03-25 19:30:55|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:30:55
>
2009-03-25 19:30:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:30:57|28031|149:16|new|utils.pm:run_ssh_command(6753)|run_ssh_command
> output: inet addr:10.0.4.101 Bcast:10.0.255.255 Mask:255.255.0.0
>
|28031|149:16|new|  inet6 addr: fe80::20c:29ff:fe46:1dc7/64 Scope:Link
>
|28031|149:16|new|  inet addr:10.138.1.185 Bcast:10.138.1.255
> Mask:255.255.255.0
>
|28031|149:16|new|  inet6 addr: fe80::20c:29ff:fe46:1dd1/64 Scope:Link
>
|28031|149:16|new|  inet addr:127.0.0.1 Mask:255.0.0.0
>
|28031|149:16|new|  inet6 addr: ::1/128 Scope:Host
>
2009-03-25 19:30:57|28031|149:16|new|utils.pm:run_ssh_command(6756)|SSH
> command executed on esx3-lamp-v0-bl3: /sbin/ifconfig |grep inet, returning
> (0, output)
>
2009-03-25 19:30:57|28031|149:16|new|utils.pm:getdynamicaddress(1697)|dynamic
> IP address for esx3-lamp-v0-bl3 collected: 0
>
2009-03-25 19:30:57|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:31:07|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:31:07
>
2009-03-25 19:33:31|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:33:31
>
2009-03-25 19:33:39|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:33:39|28031|149:16|new|utils.pm:mail(1281)|SUCCESS -- Sending
> mail To: root@localhost, PROBLEM -- esx.pm
>

> |28031|149:16|new| ---- CRITICAL ----
>
|28031|149:16|new| 2009-03-25 19:30:57|28031|149:16|new|esx.pm:load(444)|could
> not fetch dynamic address from esx3-lamp-v0-bl3 esx3-lamp-v0
>
|28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>
|28031|149:16|new| (-1) esx.pm, load (line: 444)
>
|28031|149:16|new| (-2) new.pm, reload_image (line: 664)
>
|28031|149:16|new| (-3) new.pm, process (line: 266)
>
|28031|149:16|new| (-4) vcld, make_new_child (line: 606)
>
|28031|149:16|new| (-5) vcld, main (line: 353)
>

> 2009-03-25 19:33:39|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
> computer=13, failed, could not collect dynamic IP address for node
>

> |28031|149:16|new| ---- WARNING ----
>
|28031|149:16|new| 2009-03-25
19:33:39|28031|149:16|new|new.pm:reload_image(669)|esx3-lamp-v0
> failed to load on esx3-lamp-v0-bl3, returning
>
|28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>
|28031|149:16|new| (-1) new.pm, reload_image (line: 669)
>
|28031|149:16|new| (-2) new.pm, process (line: 266)
>
|28031|149:16|new| (-3) vcld, make_new_child (line: 606)
>
|28031|149:16|new| (-4) vcld, main (line: 353)
>

> 2009-03-25 19:33:39|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
> computer=13, loadimagefailed, esx3-lamp-v0 failed to load on
> esx3-lamp-v0-bl3
>

> |28031|149:16|new| ---- WARNING ----
>
|28031|149:16|new| 2009-03-25
19:33:39|28031|149:16|new|new.pm:process(313)|failed
> to load esx3-lamp-v0-bl3 with esx3-lamp-v0
>
|28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>
|28031|149:16|new| (-1) new.pm, process (line: 313)
>
|28031|149:16|new| (-2) vcld, make_new_child (line: 606)
>
|28031|149:16|new| (-3) vcld, main (line: 353)
>

> 2009-03-25 19:33:39|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:33:43|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:33:43
>
2009-03-25 19:33:55|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-25 19:33:55
>

> 2009-03-25 19:36:21|28031|149:16|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-25 19:36:21|28031|149:16|new|utils.pm:mail(1281)|SUCCESS -- Sending
> mail To: root@localhost, PROBLEM -- State.pm
>

> |28031|149:16|new| ---- CRITICAL ----
>
|28031|149:16|new| 2009-03-25
> 19:33:39|28031|149:16|new|State.pm:reservation_failed(285)|reservation
> failed on esx3-lamp-v0-bl3: process failed after trying to load or make
> available
>
|28031|149:16|new| ( 0) utils.pm, notify (line: 683)
>
|28031|149:16|new| (-1) State.pm, reservation_failed (line: 285)
>
|28031|149:16|new| (-2) new.pm, process (line: 316)
>
|28031|149:16|new| (-3) vcld, make_new_child (line: 606)
>
|28031|149:16|new| (-4) vcld, main (line: 353)
>

> 2009-03-25 19:36:21|28031|149:16|new|utils.pm:insertloadlog(5300)|inserted
> computer=13, failed, process failed after trying to load or make available
>
2009-03-25
> 19:36:21|28031|149:16|new|State.pm:reservation_failed(288)|inserted
> computerloadlog entry
>
2009-03-25
> 19:36:21|28031|149:16|new|State.pm:reservation_failed(296)|updated log
> ending value to 'failed', logid=83
>
2009-03-25 19:36:21|28031|149:16|new|utils.pm:update_computer_state(2305)|computer
> 13 state updated to: failed
>
2009-03-25
> 19:36:21|28031|149:16|new|State.pm:reservation_failed(304)|computer
> esx3-lamp-v0-bl3 (13) state set to failed
>
2009-03-25 19:36:21|28031|149:16|new|utils.pm:update_request_state(2263)|request
> 149 state updated to: failed, laststate to: new
>
2009-03-25 19:36:21|28031|149:16|new|State.pm:reservation_failed(312)|set
> request state to 'failed'/'new'
>
2009-03-25 19:36:21|28031|149:16|new|utils.pm:is_inblockrequest(7356)|zero
> rows were returned from database select
>
2009-03-25
> 19:36:21|28031|149:16|new|State.pm:reservation_failed(330)|esx3-lamp-v0-bl3
> is NOT in blockcomputers table
>
2009-03-25
> 19:36:21|28031|149:16|new|State.pm:reservation_failed(333)|exiting 1
>
2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(435)|destructor
> called, ref($self)=VCL::new
>
2009-03-25 19:36:21|28031|149:16|new|utils.pm:delete_computerloadlog_reservation(8013)|removing
> computerloadlog entries matching loadstate = begin
>
2009-03-25 19:36:21|28031|149:16|new|utils.pm:delete_computerloadlog_reservation(8060)|deleted
> rows from computerloadlog for reservation id=16
>
2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(438)|removed
> computerloadlog rows with loadstate=begin for reservation
>
2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(446)|number of
> database handles state process created: 1
>
2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(455)|process has a
> database handle stored in $ENV{dbh}, attempting disconnect
>
2009-03-25 19:36:21|28031|149:16|new|State.pm:DESTROY(457)|$ENV{dbh}:
> database disconnect successful
>
2009-03-25 19:36:21|2421|vcld:REAPER(751)|process reaped: pid: 28031, $?:
> 256, exit status: 1
>
2009-03-25 19:36:21|2421|vcld:REAPER(756)|VCL process exited for reservation
> 16
>
2009-03-25 19:36:21|2421|vcld:REAPER(770)|setting $? to 256, exit status: 1
>




-- 
Melba


On Wed, Mar 25, 2009 at 10:54 AM, Brian Bouterse <bm...@ncsu.edu> wrote:

> Here are a few things to look into around the virtual switch assignments of
> deployed ESX compatible virtual machines.  When the esx.pm writes out the
> .vmx file, on-the-fly, it indicates the network names each interface should
> connect to with the following tags.
>
> Ethernet0.networkName = "VM Port Group Network Name (Management)"
> Ethernet1.networkName = "VM Port Group Network Name (Public)"
>
> These are pulled from the virtualswitch0 and virtualswitch1 fields of the
> VMware ESX entry in the vmprofile table.
>
> To make this correct, the two virtual switch names (VCL assumes the virtual
> switches are already existing) need to be entered into the vmprofile table.
>  Is this that case for your installation?
>
> Best,
> Brian
>
> Brian Bouterse
> Secure Open Systems Initiative
> 919.698.8796
>
>
>
>
> On Mar 24, 2009, at 3:24 PM, Melba Lopez wrote:
>
>  After ensuring the computer hostnames in the DB matches the VI Client
>> hostname, with some changes to the hostname at the ESXi host gui, the
>> reservation seemed to go a lot farther.
>>
>> I actually saw the VM deployed and turned on at it's designated blade,
>> however the reservation ultimately failed.  As I mentioned in a previous
>> email, the vSwitch settings in the golden VM does not stay once it's
>> copied
>> over to inuse.  Perhaps this is causing this failure?
>>
>>
>>
>>
>>>  2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(321)|Registered:
>>
>>>
>>>  |7840|148:15|new| Register of VM 'esx3-lamp-v0-bl1' successfully
>> completed
>>
>>> under host esxibl1.preloads.private
>>>
>>>  2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(330)|Power on command:
>>
>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server
>>> 'esxibl1.preloads.private' --vmname esx3-lamp-v0-bl1 --operation poweron
>>> --username vcl --password 'd834jfhd734jgfhf7'
>>>
>>>  2009-03-24 22:46:02|2421|vcld:main(166)|lastcheckin time updated for
>>
>>> management node 1: 2009-03-24 22:46:02
>>>
>>>  2009-03-24 22:46:05|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>> exit
>>
>>> status: 0
>>>
>>>  2009-03-24 22:46:05|7840|148:15|new|esx.pm:load(333)|Powered on:
>>
>>>
>>>  |7840|148:15|new| virtual machine 'esx3-lamp-v0-bl1' under host
>>
>>> esxibl1.preloads.private powered on
>>>
>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:
>> load(349)|deviceinfo->summary:
>>
>>> VirtualPCNet32=HASH(0xbaaf304)->deviceinfo->summary
>>>
>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0: VM
>>
>>> Network
>>>
>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:
>> load(349)|deviceinfo->summary:
>>
>>> VirtualPCNet32=HASH(0xa9860fc)->deviceinfo->summary
>>>
>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0: VM
>>
>>> Network
>>>
>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(360)|Queried MAC
>> address is
>>
>>> 00:0c:29:17:db:6a
>>>
>>>  2009-03-24 22:46:06|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>> exit
>>
>>> status: 0
>>>
>>>  2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>>
>>> seconds, waiting for computer to DHCP. Try 1
>>>
>>>  2009-03-24 22:46:11|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>> exit
>>
>>> status: 0
>>>
>>>  2009-03-24 22:46:11|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>>
>>> seconds, waiting for computer to DHCP. Try 2
>>>
>>>  2009-03-24 22:46:14|2421|vcld:main(166)|lastcheckin time updated for
>>
>>> management node 1: 2009-03-24 22:46:14
>>>
>>>  ...
>>
>>>
>>>  ....
>>
>>>
>>>  .....keeps trying until 25 below
>>
>>
>>
>> 2009-03-24 22:48:07|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>>
>>> seconds, waiting for computer to DHCP. Try 25
>>>
>>
>> 2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
>>
>>> status: 0
>>>
>>>  2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>> exit
>>
>>> status: 0
>>>
>>>  2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>> exit
>>
>>> status: 0
>>>
>>>  2009-03-24 22:50:48|7840|148:15|new|utils.pm:mail(1281)|SUCCESS --
>> Sending
>>
>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>
>>>
>>  |7840|148:15|new| ---- CRITICAL ----
>>>
>>>  |7840|148:15|new| 2009-03-24 22:48:12|7840|148:15|new|esx.pm:
>> load(376)|waited
>>
>>> acceptable amount of time for dhcp, please check esx3-lamp-v0-bl1 on
>>> esxibl1.preloads.private
>>>
>>>  |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>
>>>
>>>  |7840|148:15|new| (-1) esx.pm, load (line: 376)
>>
>>>
>>>  |7840|148:15|new| (-2) new.pm, reload_image (line: 664)
>>
>>>
>>>  |7840|148:15|new| (-3) new.pm, process (line: 266)
>>
>>>
>>>  |7840|148:15|new| (-4) vcld, make_new_child (line: 606)
>>
>>>
>>>  |7840|148:15|new| (-5) vcld, main (line: 353)
>>
>>>
>>>
>>
>>> |7840|148:15|new| ---- WARNING ----
>>>
>>>  |7840|148:15|new| 2009-03-24
>> 22:50:48|7840|148:15|new|new.pm:reload_image(669)|esx3-lamp-v0
>>
>>> failed to load on esx3-lamp-v0-bl1, returning
>>>
>>>  |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>
>>>
>>>  |7840|148:15|new| (-1) new.pm, reload_image (line: 669)
>>
>>>
>>>  |7840|148:15|new| (-2) new.pm, process (line: 266)
>>
>>>
>>>  |7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>>
>>>
>>>  |7840|148:15|new| (-4) vcld, main (line: 353)
>>
>>>
>>>
>>  2009-03-24 22:50:48|7840|148:15|new|utils.pm:
>>> insertloadlog(5300)|inserted
>>> computer=11, loadimagefailed, esx3-lamp-v0 failed to load on
>>> esx3-lamp-v0-bl1
>>>
>>>
>>  |7840|148:15|new| ---- WARNING ----
>>>
>>>  |7840|148:15|new| 2009-03-24
>> 22:50:48|7840|148:15|new|new.pm:process(313)|failed
>>
>>> to load esx3-lamp-v0-bl1 with esx3-lamp-v0
>>>
>>>  |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>
>>>
>>>  |7840|148:15|new| (-1) new.pm, process (line: 313)
>>
>>>
>>>  |7840|148:15|new| (-2) vcld, make_new_child (line: 606)
>>
>>>
>>>  |7840|148:15|new| (-3) vcld, main (line: 353)
>>
>>>
>>>
>>  2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to 0,
>>> exit
>>> status: 0
>>>
>>>  2009-03-24 22:53:24|7840|148:15|new|utils.pm:mail(1281)|SUCCESS --
>> Sending
>> mail To: root@localhost, PROBLEM -- State.pm
>>
>>
>> |7840|148:15|new| ---- CRITICAL ----
>>
>> |7840|148:15|new| 2009-03-24
>> 22:50:48|7840|148:15|new|State.pm:reservation_failed(285)|reservation
>> failed
>> on esx3-lamp-v0-bl1: process failed after trying to load or make available
>>
>> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>
>> |7840|148:15|new| (-1) State.pm, reservation_failed (line: 285)
>>
>> |7840|148:15|new| (-2) new.pm, process (line: 316)
>>
>> |7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>>
>> |7840|148:15|new| (-4) vcld, main (line: 353)
>>
>>
>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:insertloadlog(5300)|inserted
>> computer=11, failed, process failed after trying to load or make available
>>
>> 2009-03-24
>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(288)|inserted
>> computerloadlog entry
>>
>> 2009-03-24
>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(296)|updated
>> log ending value to 'failed', logid=82
>>
>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>> update_computer_state(2305)|computer
>> 11 state updated to: failed
>>
>> 2009-03-24
>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(304)|computer
>> esx3-lamp-v0-bl1 (11) state set to failed
>>
>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>> update_request_state(2263)|request
>> 148 state updated to: failed, laststate to: new
>>
>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:reservation_failed(312)|set
>> request state to 'failed'/'new'
>>
>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:is_inblockrequest(7356)|zero
>> rows were returned from database select
>>
>> 2009-03-24
>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(330)|esx3-lamp-v0-bl1
>> is NOT in blockcomputers table
>>
>> 2009-03-24
>> 22:53:24|7840|148:15|new|State.pm:reservation_failed(333)|exiting
>> 1
>>
>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(435)|destructor
>> called,
>> ref($self)=VCL::new
>>
>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>> delete_computerloadlog_reservation(8013)|removing
>> computerloadlog entries matching loadstate = begin
>>
>> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:
>> delete_computerloadlog_reservation(8060)|deleted
>> rows from computerloadlog for reservation id=15
>>
>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(438)|removed
>> computerloadlog rows with loadstate=begin for reservation
>>
>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(446)|number of
>> database
>> handles state process created: 1
>>
>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(455)|process has a
>> database handle stored in $ENV{dbh}, attempting disconnect
>>
>> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(457)|$ENV{dbh}:
>> database disconnect successful
>>
>> On Tue, Mar 24, 2009 at 12:14 PM, Brian Bouterse <bm...@ncsu.edu>
>> wrote:
>>
>>  As it turns out, the vcl-dev list strips out embedded URLs.  I've pasted
>>> it
>>> below.
>>>
>>>
>>>
>>> http://wiki.oscr.ncsu.edu/wiki/index.php/Updating_the_VCL_VM_to_the_latest_code_version
>>>
>>> Best,
>>> Brian
>>>
>>> Brian Bouterse
>>> Secure Open Systems Initiative
>>> 919.698.8796
>>>
>>>
>>>
>>>
>>> On Mar 24, 2009, at 12:44 PM, Brian Bouterse wrote:
>>>
>>> I forgot to include the link with the upgrade how-to:  It is located
>>> here.
>>>
>>>>
>>>> Best,
>>>> Brian
>>>>
>>>>
>>>> Brian Bouterse
>>>> Secure Open Systems Initiative
>>>> 919.698.8796
>>>>
>>>>
>>>>
>>>>
>>>> On Mar 24, 2009, at 12:20 PM, Brian Bouterse wrote:
>>>>
>>>> I've put in some more debugging into the esx.pm module.  This should
>>>>
>>>>> print the registration command to the screen so that it can be tried to
>>>>> run
>>>>> manually.  Can you update to the latest code version and try it?  I've
>>>>> written a how-to located here.
>>>>>
>>>>> Best,
>>>>> Brian
>>>>>
>>>>>
>>>>> Brian Bouterse
>>>>> Secure Open Systems Initiative
>>>>> 919.698.8796
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> On Mar 24, 2009, at 10:20 AM, Melba Lopez wrote:
>>>>>
>>>>> Actually everything you've mentioned has been put into place.
>>>>>
>>>>>> The nameserver entry is in /etc/resolv.conf and all the esxibl1-3
>>>>>> hostnames
>>>>>> are in the /etc/hosts.
>>>>>> I can connect to the blades by putting esxibl1-3 into VIClient without
>>>>>> a
>>>>>> problem.
>>>>>>
>>>>>> Note:  /etc/resolv.conf is generated by /sbin/dhclient-script; once
>>>>>> network/vm is rebooted it restores original.
>>>>>>
>>>>>> I also restarted the networking and went as far as to reboot the VCL
>>>>>> VM
>>>>>> and
>>>>>> still it gives me the same error.
>>>>>>
>>>>>>
>>>>>> --Melba
>>>>>>
>>>>>>
>>>>>> On Tue, Mar 24, 2009 at 9:34 AM, Brian Bouterse <bm...@ncsu.edu>
>>>>>> wrote:
>>>>>>
>>>>>> I'm still suspicious of your DNS resolution and configuration.  In
>>>>>>
>>>>>>> addition
>>>>>>> to creating the DNS entries in your lab's DNS server, did you connect
>>>>>>> VCL to
>>>>>>> that DNS by creating an entry similar to the one below in the
>>>>>>> /etc/resolv.conf on your VCL management node?
>>>>>>>
>>>>>>> nameserver <ip_of_your_DNS_here>
>>>>>>>
>>>>>>> Can you connect with virtual center to the blade you're trying to
>>>>>>> provision
>>>>>>> to when referencing it strictly by it's hostname?
>>>>>>>
>>>>>>> If you want to remove DNS resolution from the list of possible
>>>>>>> culprits,
>>>>>>> you can create an entry in /etc/hosts of your VCL management node
>>>>>>> similar to
>>>>>>> the line below.  I think that should work.
>>>>>>>
>>>>>>> <IP Address of esxib1>  esxibl1.
>>>>>>>
>>>>>>> Remember to restart networking (or the whole VCL management node)
>>>>>>> when
>>>>>>> testing these configuration changes.
>>>>>>>
>>>>>>> Best,
>>>>>>> Brian
>>>>>>>
>>>>>>>
>>>>>>> Brian Bouterse
>>>>>>> Secure Open Systems Initiative
>>>>>>> 919.698.8796
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:
>>>>>>>
>>>>>>> Ok, our lab already had DNS capabilities, so I've set esxibl1-3* *to
>>>>>>> be
>>>>>>>
>>>>>>>  valid hostnames*.
>>>>>>>>
>>>>>>>> *However, it is still saying it can't find "esxibl1".  I've pinged
>>>>>>>> that
>>>>>>>> hostname from another machine on the same network and it works just
>>>>>>>> fine.
>>>>>>>>
>>>>>>>>
>>>>>>>> Also because it kept saying it couldn't load the VM, I've found
>>>>>>>> another
>>>>>>>> problem.  The vmdk file successfully copies over into the "inuse"
>>>>>>>> folder.
>>>>>>>> When I manually add that VM to a blade, I'm noticing that the VM
>>>>>>>> does
>>>>>>>> not
>>>>>>>> keep the network setings.  I watched someone actually create this VM
>>>>>>>> and I
>>>>>>>> redid it myself, and the settings do not stay when its copied over.
>>>>>>>> Not
>>>>>>>> sure if it's related, but thought I might mention it.
>>>>>>>> *
>>>>>>>>
>>>>>>>>
>>>>>>>> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote
>>>>>>>> vmxarray
>>>>>>>> to
>>>>>>>> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
>>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>>> 0,
>>>>>>>> exit
>>>>>>>> status: 0
>>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
>>>>>>>> |24815|143:10|new| No host found with name esxibl1.
>>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on
>>>>>>>> command:
>>>>>>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1'
>>>>>>>> --vmname
>>>>>>>> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
>>>>>>>> 'd834jfhd734jgfhf7'
>>>>>>>> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>>> 0,
>>>>>>>> exit
>>>>>>>> status: 0
>>>>>>>> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered on:
>>>>>>>> Virtual
>>>>>>>> Machine esx3-lamp-v0-bl1 not found.
>>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>>> 0,
>>>>>>>> exit
>>>>>>>> status: 0
>>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to
>>>>>>>> 0,
>>>>>>>> exit
>>>>>>>> status: 0
>>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS --
>>>>>>>> Sending
>>>>>>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>>>>>>
>>>>>>>> |24815|143:10|new| ---- CRITICAL ----
>>>>>>>> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:
>>>>>>>> load(341)|Could
>>>>>>>> not query for VM in VI PERL API
>>>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
>>>>>>>> |24815|143:10|new| (-1) esx.pm, load (line: 341)
>>>>>>>> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
>>>>>>>> |24815|143:10|new| (-3) new.pm, process (line: 266)
>>>>>>>> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
>>>>>>>> |24815|143:10|new| (-5) vcld, main (line: 353)
>>>>>>>>
>>>>>>>>
>>>>>>>> |24815|143:10|new| ---- WARNING ----
>>>>>>>> |24815|143:10|new| 2009-03-24
>>>>>>>> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
>>>>>>>> failed to load on esx3-lamp-v0-bl1, returning
>>>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>>>>>>>>
>>>>>>>>
>>>>>>>> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <
>>>>>>>> josh_thompson@ncsu.edu
>>>>>>>>
>>>>>>>>  wrote:
>>>>>>>>>
>>>>>>>>>
>>>>>>>> -----BEGIN PGP SIGNED MESSAGE-----
>>>>>>>>
>>>>>>>>  Hash: SHA1
>>>>>>>>>
>>>>>>>>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>>>>>>>>
>>>>>>>>> always fake the DNS resolution by placing an entry /etc/resolv.conf
>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>  That would be /etc/hosts  :)
>>>>>>>>>
>>>>>>>>> Josh
>>>>>>>>> - --
>>>>>>>>> - -------------------------------
>>>>>>>>> Josh Thompson
>>>>>>>>> Systems Programmer
>>>>>>>>> Virtual Computing Lab (VCL)
>>>>>>>>> North Carolina State University
>>>>>>>>>
>>>>>>>>> Josh_Thompson@ncsu.edu
>>>>>>>>> 919-515-5323
>>>>>>>>>
>>>>>>>>> my GPG/PGP key can be found at www.keyserver.net
>>>>>>>>> -----BEGIN PGP SIGNATURE-----
>>>>>>>>> Version: GnuPG v2.0.9 (GNU/Linux)
>>>>>>>>>
>>>>>>>>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
>>>>>>>>> nKgBCGnhdhToNQ0EtzLhRC8=
>>>>>>>>> =Yjph
>>>>>>>>> -----END PGP SIGNATURE-----
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>
>>>>>
>>>>
>>>
>>
>

Re: Reservation Problem

Posted by Brian Bouterse <bm...@ncsu.edu>.
Here are a few things to look into around the virtual switch  
assignments of deployed ESX compatible virtual machines.  When the  
esx.pm writes out the .vmx file, on-the-fly, it indicates the network  
names each interface should connect to with the following tags.

Ethernet0.networkName = "VM Port Group Network Name (Management)"
Ethernet1.networkName = "VM Port Group Network Name (Public)"

These are pulled from the virtualswitch0 and virtualswitch1 fields of  
the VMware ESX entry in the vmprofile table.

To make this correct, the two virtual switch names (VCL assumes the  
virtual switches are already existing) need to be entered into the  
vmprofile table.  Is this that case for your installation?

Best,
Brian

Brian Bouterse
Secure Open Systems Initiative
919.698.8796




On Mar 24, 2009, at 3:24 PM, Melba Lopez wrote:

> After ensuring the computer hostnames in the DB matches the VI Client
> hostname, with some changes to the hostname at the ESXi host gui, the
> reservation seemed to go a lot farther.
>
> I actually saw the VM deployed and turned on at it's designated blade,
> however the reservation ultimately failed.  As I mentioned in a  
> previous
> email, the vSwitch settings in the golden VM does not stay once it's  
> copied
> over to inuse.  Perhaps this is causing this failure?
>
>
>
>>
> 2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(321)|Registered:
>>
> |7840|148:15|new| Register of VM 'esx3-lamp-v0-bl1' successfully  
> completed
>> under host esxibl1.preloads.private
>>
> 2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(330)|Power on command:
>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server
>> 'esxibl1.preloads.private' --vmname esx3-lamp-v0-bl1 --operation  
>> poweron
>> --username vcl --password 'd834jfhd734jgfhf7'
>>
> 2009-03-24 22:46:02|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-24 22:46:02
>>
> 2009-03-24 22:46:05|7840|148:15|new|vcld:REAPER(770)|setting $? to  
> 0, exit
>> status: 0
>>
> 2009-03-24 22:46:05|7840|148:15|new|esx.pm:load(333)|Powered on:
>>
> |7840|148:15|new| virtual machine 'esx3-lamp-v0-bl1' under host
>> esxibl1.preloads.private powered on
>>
> 2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(349)|deviceinfo- 
> >summary:
>> VirtualPCNet32=HASH(0xbaaf304)->deviceinfo->summary
>>
> 2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0:  
> VM
>> Network
>>
> 2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(349)|deviceinfo- 
> >summary:
>> VirtualPCNet32=HASH(0xa9860fc)->deviceinfo->summary
>>
> 2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0:  
> VM
>> Network
>>
> 2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(360)|Queried MAC  
> address is
>> 00:0c:29:17:db:6a
>>
> 2009-03-24 22:46:06|7840|148:15|new|vcld:REAPER(770)|setting $? to  
> 0, exit
>> status: 0
>>
> 2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 1
>>
> 2009-03-24 22:46:11|7840|148:15|new|vcld:REAPER(770)|setting $? to  
> 0, exit
>> status: 0
>>
> 2009-03-24 22:46:11|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 2
>>
> 2009-03-24 22:46:14|2421|vcld:main(166)|lastcheckin time updated for
>> management node 1: 2009-03-24 22:46:14
>>
> ...
>>
> ....
>>
> .....keeps trying until 25 below
>
>
>
> 2009-03-24 22:48:07|7840|148:15|new|esx.pm:load(381)|going to sleep 5
>> seconds, waiting for computer to DHCP. Try 25
>
> 2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to  
> 0, exit
>> status: 0
>>
> 2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to  
> 0, exit
>> status: 0
>>
> 2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to  
> 0, exit
>> status: 0
>>
> 2009-03-24 22:50:48|7840|148:15|new|utils.pm:mail(1281)|SUCCESS --  
> Sending
>> mail To: root@localhost, PROBLEM -- esx.pm
>>
>
>> |7840|148:15|new| ---- CRITICAL ----
>>
> |7840|148:15|new| 2009-03-24 22:48:12|7840|148:15|new| 
> esx.pm:load(376)|waited
>> acceptable amount of time for dhcp, please check esx3-lamp-v0-bl1 on
>> esxibl1.preloads.private
>>
> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>
> |7840|148:15|new| (-1) esx.pm, load (line: 376)
>>
> |7840|148:15|new| (-2) new.pm, reload_image (line: 664)
>>
> |7840|148:15|new| (-3) new.pm, process (line: 266)
>>
> |7840|148:15|new| (-4) vcld, make_new_child (line: 606)
>>
> |7840|148:15|new| (-5) vcld, main (line: 353)
>>
>
>>
>> |7840|148:15|new| ---- WARNING ----
>>
> |7840|148:15|new| 2009-03-24
> 22:50:48|7840|148:15|new|new.pm:reload_image(669)|esx3-lamp-v0
>> failed to load on esx3-lamp-v0-bl1, returning
>>
> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>
> |7840|148:15|new| (-1) new.pm, reload_image (line: 669)
>>
> |7840|148:15|new| (-2) new.pm, process (line: 266)
>>
> |7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>>
> |7840|148:15|new| (-4) vcld, main (line: 353)
>>
>
>> 2009-03-24 22:50:48|7840|148:15|new|utils.pm:insertloadlog(5300)| 
>> inserted
>> computer=11, loadimagefailed, esx3-lamp-v0 failed to load on
>> esx3-lamp-v0-bl1
>>
>
>> |7840|148:15|new| ---- WARNING ----
>>
> |7840|148:15|new| 2009-03-24
> 22:50:48|7840|148:15|new|new.pm:process(313)|failed
>> to load esx3-lamp-v0-bl1 with esx3-lamp-v0
>>
> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>>
> |7840|148:15|new| (-1) new.pm, process (line: 313)
>>
> |7840|148:15|new| (-2) vcld, make_new_child (line: 606)
>>
> |7840|148:15|new| (-3) vcld, main (line: 353)
>>
>
>> 2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to  
>> 0, exit
>> status: 0
>>
> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:mail(1281)|SUCCESS --  
> Sending
> mail To: root@localhost, PROBLEM -- State.pm
>
>
> |7840|148:15|new| ---- CRITICAL ----
>
> |7840|148:15|new| 2009-03-24
> 22:50:48|7840|148:15|new|State.pm:reservation_failed(285)| 
> reservation failed
> on esx3-lamp-v0-bl1: process failed after trying to load or make  
> available
>
> |7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>
> |7840|148:15|new| (-1) State.pm, reservation_failed (line: 285)
>
> |7840|148:15|new| (-2) new.pm, process (line: 316)
>
> |7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>
> |7840|148:15|new| (-4) vcld, main (line: 353)
>
>
> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:insertloadlog(5300)| 
> inserted
> computer=11, failed, process failed after trying to load or make  
> available
>
> 2009-03-24
> 22:53:24|7840|148:15|new|State.pm:reservation_failed(288)|inserted
> computerloadlog entry
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:reservation_failed(296)| 
> updated
> log ending value to 'failed', logid=82
>
> 2009-03-24 22:53:24|7840|148:15|new| 
> utils.pm:update_computer_state(2305)|computer
> 11 state updated to: failed
>
> 2009-03-24
> 22:53:24|7840|148:15|new|State.pm:reservation_failed(304)|computer
> esx3-lamp-v0-bl1 (11) state set to failed
>
> 2009-03-24 22:53:24|7840|148:15|new| 
> utils.pm:update_request_state(2263)|request
> 148 state updated to: failed, laststate to: new
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:reservation_failed(312)| 
> set
> request state to 'failed'/'new'
>
> 2009-03-24 22:53:24|7840|148:15|new|utils.pm:is_inblockrequest(7356)| 
> zero
> rows were returned from database select
>
> 2009-03-24
> 22:53:24|7840|148:15|new|State.pm:reservation_failed(330)|esx3-lamp- 
> v0-bl1
> is NOT in blockcomputers table
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:reservation_failed(333)| 
> exiting
> 1
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(435)|destructor  
> called,
> ref($self)=VCL::new
>
> 2009-03-24 22:53:24|7840|148:15|new| 
> utils.pm:delete_computerloadlog_reservation(8013)|removing
> computerloadlog entries matching loadstate = begin
>
> 2009-03-24 22:53:24|7840|148:15|new| 
> utils.pm:delete_computerloadlog_reservation(8060)|deleted
> rows from computerloadlog for reservation id=15
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(438)|removed
> computerloadlog rows with loadstate=begin for reservation
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(446)|number of  
> database
> handles state process created: 1
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(455)|process  
> has a
> database handle stored in $ENV{dbh}, attempting disconnect
>
> 2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(457)|$ENV{dbh}:
> database disconnect successful
>
> On Tue, Mar 24, 2009 at 12:14 PM, Brian Bouterse <bm...@ncsu.edu>  
> wrote:
>
>> As it turns out, the vcl-dev list strips out embedded URLs.  I've  
>> pasted it
>> below.
>>
>>
>> http://wiki.oscr.ncsu.edu/wiki/index.php/Updating_the_VCL_VM_to_the_latest_code_version
>>
>> Best,
>> Brian
>>
>> Brian Bouterse
>> Secure Open Systems Initiative
>> 919.698.8796
>>
>>
>>
>>
>> On Mar 24, 2009, at 12:44 PM, Brian Bouterse wrote:
>>
>> I forgot to include the link with the upgrade how-to:  It is  
>> located here.
>>>
>>> Best,
>>> Brian
>>>
>>>
>>> Brian Bouterse
>>> Secure Open Systems Initiative
>>> 919.698.8796
>>>
>>>
>>>
>>>
>>> On Mar 24, 2009, at 12:20 PM, Brian Bouterse wrote:
>>>
>>> I've put in some more debugging into the esx.pm module.  This should
>>>> print the registration command to the screen so that it can be  
>>>> tried to run
>>>> manually.  Can you update to the latest code version and try it?   
>>>> I've
>>>> written a how-to located here.
>>>>
>>>> Best,
>>>> Brian
>>>>
>>>>
>>>> Brian Bouterse
>>>> Secure Open Systems Initiative
>>>> 919.698.8796
>>>>
>>>>
>>>>
>>>>
>>>> On Mar 24, 2009, at 10:20 AM, Melba Lopez wrote:
>>>>
>>>> Actually everything you've mentioned has been put into place.
>>>>> The nameserver entry is in /etc/resolv.conf and all the esxibl1-3
>>>>> hostnames
>>>>> are in the /etc/hosts.
>>>>> I can connect to the blades by putting esxibl1-3 into VIClient  
>>>>> without a
>>>>> problem.
>>>>>
>>>>> Note:  /etc/resolv.conf is generated by /sbin/dhclient-script;  
>>>>> once
>>>>> network/vm is rebooted it restores original.
>>>>>
>>>>> I also restarted the networking and went as far as to reboot the  
>>>>> VCL VM
>>>>> and
>>>>> still it gives me the same error.
>>>>>
>>>>>
>>>>> --Melba
>>>>>
>>>>>
>>>>> On Tue, Mar 24, 2009 at 9:34 AM, Brian Bouterse  
>>>>> <bm...@ncsu.edu>
>>>>> wrote:
>>>>>
>>>>> I'm still suspicious of your DNS resolution and configuration.  In
>>>>>> addition
>>>>>> to creating the DNS entries in your lab's DNS server, did you  
>>>>>> connect
>>>>>> VCL to
>>>>>> that DNS by creating an entry similar to the one below in the
>>>>>> /etc/resolv.conf on your VCL management node?
>>>>>>
>>>>>> nameserver <ip_of_your_DNS_here>
>>>>>>
>>>>>> Can you connect with virtual center to the blade you're trying to
>>>>>> provision
>>>>>> to when referencing it strictly by it's hostname?
>>>>>>
>>>>>> If you want to remove DNS resolution from the list of possible
>>>>>> culprits,
>>>>>> you can create an entry in /etc/hosts of your VCL management node
>>>>>> similar to
>>>>>> the line below.  I think that should work.
>>>>>>
>>>>>> <IP Address of esxib1>  esxibl1.
>>>>>>
>>>>>> Remember to restart networking (or the whole VCL management  
>>>>>> node) when
>>>>>> testing these configuration changes.
>>>>>>
>>>>>> Best,
>>>>>> Brian
>>>>>>
>>>>>>
>>>>>> Brian Bouterse
>>>>>> Secure Open Systems Initiative
>>>>>> 919.698.8796
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:
>>>>>>
>>>>>> Ok, our lab already had DNS capabilities, so I've set  
>>>>>> esxibl1-3* *to be
>>>>>>
>>>>>>> valid hostnames*.
>>>>>>>
>>>>>>> *However, it is still saying it can't find "esxibl1".  I've  
>>>>>>> pinged
>>>>>>> that
>>>>>>> hostname from another machine on the same network and it works  
>>>>>>> just
>>>>>>> fine.
>>>>>>>
>>>>>>>
>>>>>>> Also because it kept saying it couldn't load the VM, I've found
>>>>>>> another
>>>>>>> problem.  The vmdk file successfully copies over into the  
>>>>>>> "inuse"
>>>>>>> folder.
>>>>>>> When I manually add that VM to a blade, I'm noticing that the  
>>>>>>> VM does
>>>>>>> not
>>>>>>> keep the network setings.  I watched someone actually create  
>>>>>>> this VM
>>>>>>> and I
>>>>>>> redid it myself, and the settings do not stay when its copied  
>>>>>>> over.
>>>>>>> Not
>>>>>>> sure if it's related, but thought I might mention it.
>>>>>>> *
>>>>>>>
>>>>>>>
>>>>>>> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote  
>>>>>>> vmxarray
>>>>>>> to
>>>>>>> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting  
>>>>>>> $? to 0,
>>>>>>> exit
>>>>>>> status: 0
>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)| 
>>>>>>> Registered:
>>>>>>> |24815|143:10|new| No host found with name esxibl1.
>>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on
>>>>>>> command:
>>>>>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1'
>>>>>>> --vmname
>>>>>>> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
>>>>>>> 'd834jfhd734jgfhf7'
>>>>>>> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting  
>>>>>>> $? to 0,
>>>>>>> exit
>>>>>>> status: 0
>>>>>>> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered  
>>>>>>> on:
>>>>>>> Virtual
>>>>>>> Machine esx3-lamp-v0-bl1 not found.
>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting  
>>>>>>> $? to 0,
>>>>>>> exit
>>>>>>> status: 0
>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting  
>>>>>>> $? to 0,
>>>>>>> exit
>>>>>>> status: 0
>>>>>>> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)| 
>>>>>>> SUCCESS --
>>>>>>> Sending
>>>>>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>>>>>
>>>>>>> |24815|143:10|new| ---- CRITICAL ----
>>>>>>> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:
>>>>>>> load(341)|Could
>>>>>>> not query for VM in VI PERL API
>>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
>>>>>>> |24815|143:10|new| (-1) esx.pm, load (line: 341)
>>>>>>> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
>>>>>>> |24815|143:10|new| (-3) new.pm, process (line: 266)
>>>>>>> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
>>>>>>> |24815|143:10|new| (-5) vcld, main (line: 353)
>>>>>>>
>>>>>>>
>>>>>>> |24815|143:10|new| ---- WARNING ----
>>>>>>> |24815|143:10|new| 2009-03-24
>>>>>>> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
>>>>>>> failed to load on esx3-lamp-v0-bl1, returning
>>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>>>>>>>
>>>>>>>
>>>>>>> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <
>>>>>>> josh_thompson@ncsu.edu
>>>>>>>
>>>>>>>> wrote:
>>>>>>>>
>>>>>>>
>>>>>>> -----BEGIN PGP SIGNED MESSAGE-----
>>>>>>>
>>>>>>>> Hash: SHA1
>>>>>>>>
>>>>>>>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>>>>>>>
>>>>>>>> always fake the DNS resolution by placing an entry /etc/ 
>>>>>>>> resolv.conf
>>>>>>>>>
>>>>>>>>>
>>>>>>>> That would be /etc/hosts  :)
>>>>>>>>
>>>>>>>> Josh
>>>>>>>> - --
>>>>>>>> - -------------------------------
>>>>>>>> Josh Thompson
>>>>>>>> Systems Programmer
>>>>>>>> Virtual Computing Lab (VCL)
>>>>>>>> North Carolina State University
>>>>>>>>
>>>>>>>> Josh_Thompson@ncsu.edu
>>>>>>>> 919-515-5323
>>>>>>>>
>>>>>>>> my GPG/PGP key can be found at www.keyserver.net
>>>>>>>> -----BEGIN PGP SIGNATURE-----
>>>>>>>> Version: GnuPG v2.0.9 (GNU/Linux)
>>>>>>>>
>>>>>>>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/ 
>>>>>>>> 1wKWFw9W3zIQCffxLj
>>>>>>>> nKgBCGnhdhToNQ0EtzLhRC8=
>>>>>>>> =Yjph
>>>>>>>> -----END PGP SIGNATURE-----
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>
>>>>
>>>
>>
>
>
> -- 
> Melba Lopez
> (305) 807-6260
> milopez@gmail.com


Re: Reservation Problem

Posted by Melba Lopez <mi...@gmail.com>.
After ensuring the computer hostnames in the DB matches the VI Client
hostname, with some changes to the hostname at the ESXi host gui, the
reservation seemed to go a lot farther.

I actually saw the VM deployed and turned on at it's designated blade,
however the reservation ultimately failed.  As I mentioned in a previous
email, the vSwitch settings in the golden VM does not stay once it's copied
over to inuse.  Perhaps this is causing this failure?



>
2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(321)|Registered:
>
|7840|148:15|new| Register of VM 'esx3-lamp-v0-bl1' successfully completed
> under host esxibl1.preloads.private
>
2009-03-24 22:46:01|7840|148:15|new|esx.pm:load(330)|Power on command:
> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server
> 'esxibl1.preloads.private' --vmname esx3-lamp-v0-bl1 --operation poweron
> --username vcl --password 'd834jfhd734jgfhf7'
>
2009-03-24 22:46:02|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-24 22:46:02
>
2009-03-24 22:46:05|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-24 22:46:05|7840|148:15|new|esx.pm:load(333)|Powered on:
>
|7840|148:15|new| virtual machine 'esx3-lamp-v0-bl1' under host
> esxibl1.preloads.private powered on
>
2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(349)|deviceinfo->summary:
> VirtualPCNet32=HASH(0xbaaf304)->deviceinfo->summary
>
2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0: VM
> Network
>
2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(349)|deviceinfo->summary:
> VirtualPCNet32=HASH(0xa9860fc)->deviceinfo->summary
>
2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(350)|virtualswitch0: VM
> Network
>
2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(360)|Queried MAC address is
> 00:0c:29:17:db:6a
>
2009-03-24 22:46:06|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-24 22:46:06|7840|148:15|new|esx.pm:load(381)|going to sleep 5
> seconds, waiting for computer to DHCP. Try 1
>
2009-03-24 22:46:11|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-24 22:46:11|7840|148:15|new|esx.pm:load(381)|going to sleep 5
> seconds, waiting for computer to DHCP. Try 2
>
2009-03-24 22:46:14|2421|vcld:main(166)|lastcheckin time updated for
> management node 1: 2009-03-24 22:46:14
>
...
>
....
>
.....keeps trying until 25 below



2009-03-24 22:48:07|7840|148:15|new|esx.pm:load(381)|going to sleep 5
> seconds, waiting for computer to DHCP. Try 25

2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-24 22:48:12|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-24 22:50:48|7840|148:15|new|utils.pm:mail(1281)|SUCCESS -- Sending
> mail To: root@localhost, PROBLEM -- esx.pm
>

> |7840|148:15|new| ---- CRITICAL ----
>
|7840|148:15|new| 2009-03-24 22:48:12|7840|148:15|new|esx.pm:load(376)|waited
> acceptable amount of time for dhcp, please check esx3-lamp-v0-bl1 on
> esxibl1.preloads.private
>
|7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>
|7840|148:15|new| (-1) esx.pm, load (line: 376)
>
|7840|148:15|new| (-2) new.pm, reload_image (line: 664)
>
|7840|148:15|new| (-3) new.pm, process (line: 266)
>
|7840|148:15|new| (-4) vcld, make_new_child (line: 606)
>
|7840|148:15|new| (-5) vcld, main (line: 353)
>

>
> |7840|148:15|new| ---- WARNING ----
>
|7840|148:15|new| 2009-03-24
22:50:48|7840|148:15|new|new.pm:reload_image(669)|esx3-lamp-v0
> failed to load on esx3-lamp-v0-bl1, returning
>
|7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>
|7840|148:15|new| (-1) new.pm, reload_image (line: 669)
>
|7840|148:15|new| (-2) new.pm, process (line: 266)
>
|7840|148:15|new| (-3) vcld, make_new_child (line: 606)
>
|7840|148:15|new| (-4) vcld, main (line: 353)
>

> 2009-03-24 22:50:48|7840|148:15|new|utils.pm:insertloadlog(5300)|inserted
> computer=11, loadimagefailed, esx3-lamp-v0 failed to load on
> esx3-lamp-v0-bl1
>

> |7840|148:15|new| ---- WARNING ----
>
|7840|148:15|new| 2009-03-24
22:50:48|7840|148:15|new|new.pm:process(313)|failed
> to load esx3-lamp-v0-bl1 with esx3-lamp-v0
>
|7840|148:15|new| ( 0) utils.pm, notify (line: 683)
>
|7840|148:15|new| (-1) new.pm, process (line: 313)
>
|7840|148:15|new| (-2) vcld, make_new_child (line: 606)
>
|7840|148:15|new| (-3) vcld, main (line: 353)
>

> 2009-03-24 22:50:48|7840|148:15|new|vcld:REAPER(770)|setting $? to 0, exit
> status: 0
>
2009-03-24 22:53:24|7840|148:15|new|utils.pm:mail(1281)|SUCCESS -- Sending
mail To: root@localhost, PROBLEM -- State.pm


|7840|148:15|new| ---- CRITICAL ----

|7840|148:15|new| 2009-03-24
22:50:48|7840|148:15|new|State.pm:reservation_failed(285)|reservation failed
on esx3-lamp-v0-bl1: process failed after trying to load or make available

|7840|148:15|new| ( 0) utils.pm, notify (line: 683)

|7840|148:15|new| (-1) State.pm, reservation_failed (line: 285)

|7840|148:15|new| (-2) new.pm, process (line: 316)

|7840|148:15|new| (-3) vcld, make_new_child (line: 606)

|7840|148:15|new| (-4) vcld, main (line: 353)


2009-03-24 22:53:24|7840|148:15|new|utils.pm:insertloadlog(5300)|inserted
computer=11, failed, process failed after trying to load or make available

2009-03-24
22:53:24|7840|148:15|new|State.pm:reservation_failed(288)|inserted
computerloadlog entry

2009-03-24 22:53:24|7840|148:15|new|State.pm:reservation_failed(296)|updated
log ending value to 'failed', logid=82

2009-03-24 22:53:24|7840|148:15|new|utils.pm:update_computer_state(2305)|computer
11 state updated to: failed

2009-03-24
22:53:24|7840|148:15|new|State.pm:reservation_failed(304)|computer
esx3-lamp-v0-bl1 (11) state set to failed

2009-03-24 22:53:24|7840|148:15|new|utils.pm:update_request_state(2263)|request
148 state updated to: failed, laststate to: new

2009-03-24 22:53:24|7840|148:15|new|State.pm:reservation_failed(312)|set
request state to 'failed'/'new'

2009-03-24 22:53:24|7840|148:15|new|utils.pm:is_inblockrequest(7356)|zero
rows were returned from database select

2009-03-24
22:53:24|7840|148:15|new|State.pm:reservation_failed(330)|esx3-lamp-v0-bl1
is NOT in blockcomputers table

2009-03-24 22:53:24|7840|148:15|new|State.pm:reservation_failed(333)|exiting
1

2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(435)|destructor called,
ref($self)=VCL::new

2009-03-24 22:53:24|7840|148:15|new|utils.pm:delete_computerloadlog_reservation(8013)|removing
computerloadlog entries matching loadstate = begin

2009-03-24 22:53:24|7840|148:15|new|utils.pm:delete_computerloadlog_reservation(8060)|deleted
rows from computerloadlog for reservation id=15

2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(438)|removed
computerloadlog rows with loadstate=begin for reservation

2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(446)|number of database
handles state process created: 1

2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(455)|process has a
database handle stored in $ENV{dbh}, attempting disconnect

2009-03-24 22:53:24|7840|148:15|new|State.pm:DESTROY(457)|$ENV{dbh}:
database disconnect successful

On Tue, Mar 24, 2009 at 12:14 PM, Brian Bouterse <bm...@ncsu.edu> wrote:

> As it turns out, the vcl-dev list strips out embedded URLs.  I've pasted it
> below.
>
>
> http://wiki.oscr.ncsu.edu/wiki/index.php/Updating_the_VCL_VM_to_the_latest_code_version
>
> Best,
> Brian
>
> Brian Bouterse
> Secure Open Systems Initiative
> 919.698.8796
>
>
>
>
> On Mar 24, 2009, at 12:44 PM, Brian Bouterse wrote:
>
>  I forgot to include the link with the upgrade how-to:  It is located here.
>>
>> Best,
>> Brian
>>
>>
>> Brian Bouterse
>> Secure Open Systems Initiative
>> 919.698.8796
>>
>>
>>
>>
>> On Mar 24, 2009, at 12:20 PM, Brian Bouterse wrote:
>>
>>  I've put in some more debugging into the esx.pm module.  This should
>>> print the registration command to the screen so that it can be tried to run
>>> manually.  Can you update to the latest code version and try it?  I've
>>> written a how-to located here.
>>>
>>> Best,
>>> Brian
>>>
>>>
>>> Brian Bouterse
>>> Secure Open Systems Initiative
>>> 919.698.8796
>>>
>>>
>>>
>>>
>>> On Mar 24, 2009, at 10:20 AM, Melba Lopez wrote:
>>>
>>>  Actually everything you've mentioned has been put into place.
>>>> The nameserver entry is in /etc/resolv.conf and all the esxibl1-3
>>>> hostnames
>>>> are in the /etc/hosts.
>>>> I can connect to the blades by putting esxibl1-3 into VIClient without a
>>>> problem.
>>>>
>>>> Note:  /etc/resolv.conf is generated by /sbin/dhclient-script; once
>>>> network/vm is rebooted it restores original.
>>>>
>>>> I also restarted the networking and went as far as to reboot the VCL VM
>>>> and
>>>> still it gives me the same error.
>>>>
>>>>
>>>> --Melba
>>>>
>>>>
>>>> On Tue, Mar 24, 2009 at 9:34 AM, Brian Bouterse <bm...@ncsu.edu>
>>>> wrote:
>>>>
>>>>  I'm still suspicious of your DNS resolution and configuration.  In
>>>>> addition
>>>>> to creating the DNS entries in your lab's DNS server, did you connect
>>>>> VCL to
>>>>> that DNS by creating an entry similar to the one below in the
>>>>> /etc/resolv.conf on your VCL management node?
>>>>>
>>>>> nameserver <ip_of_your_DNS_here>
>>>>>
>>>>> Can you connect with virtual center to the blade you're trying to
>>>>> provision
>>>>> to when referencing it strictly by it's hostname?
>>>>>
>>>>> If you want to remove DNS resolution from the list of possible
>>>>> culprits,
>>>>> you can create an entry in /etc/hosts of your VCL management node
>>>>> similar to
>>>>> the line below.  I think that should work.
>>>>>
>>>>> <IP Address of esxib1>  esxibl1.
>>>>>
>>>>> Remember to restart networking (or the whole VCL management node) when
>>>>> testing these configuration changes.
>>>>>
>>>>> Best,
>>>>> Brian
>>>>>
>>>>>
>>>>> Brian Bouterse
>>>>> Secure Open Systems Initiative
>>>>> 919.698.8796
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:
>>>>>
>>>>> Ok, our lab already had DNS capabilities, so I've set esxibl1-3* *to be
>>>>>
>>>>>> valid hostnames*.
>>>>>>
>>>>>> *However, it is still saying it can't find "esxibl1".  I've pinged
>>>>>> that
>>>>>> hostname from another machine on the same network and it works just
>>>>>> fine.
>>>>>>
>>>>>>
>>>>>> Also because it kept saying it couldn't load the VM, I've found
>>>>>> another
>>>>>> problem.  The vmdk file successfully copies over into the "inuse"
>>>>>> folder.
>>>>>> When I manually add that VM to a blade, I'm noticing that the VM does
>>>>>> not
>>>>>> keep the network setings.  I watched someone actually create this VM
>>>>>> and I
>>>>>> redid it myself, and the settings do not stay when its copied over.
>>>>>>  Not
>>>>>> sure if it's related, but thought I might mention it.
>>>>>> *
>>>>>>
>>>>>>
>>>>>> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote vmxarray
>>>>>> to
>>>>>> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
>>>>>> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $? to 0,
>>>>>> exit
>>>>>> status: 0
>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
>>>>>> |24815|143:10|new| No host found with name esxibl1.
>>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on
>>>>>> command:
>>>>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1'
>>>>>> --vmname
>>>>>> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
>>>>>> 'd834jfhd734jgfhf7'
>>>>>> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $? to 0,
>>>>>> exit
>>>>>> status: 0
>>>>>> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered on:
>>>>>> Virtual
>>>>>> Machine esx3-lamp-v0-bl1 not found.
>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to 0,
>>>>>> exit
>>>>>> status: 0
>>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to 0,
>>>>>> exit
>>>>>> status: 0
>>>>>> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS --
>>>>>> Sending
>>>>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>>>>
>>>>>> |24815|143:10|new| ---- CRITICAL ----
>>>>>> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:
>>>>>> load(341)|Could
>>>>>> not query for VM in VI PERL API
>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
>>>>>> |24815|143:10|new| (-1) esx.pm, load (line: 341)
>>>>>> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
>>>>>> |24815|143:10|new| (-3) new.pm, process (line: 266)
>>>>>> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
>>>>>> |24815|143:10|new| (-5) vcld, main (line: 353)
>>>>>>
>>>>>>
>>>>>> |24815|143:10|new| ---- WARNING ----
>>>>>> |24815|143:10|new| 2009-03-24
>>>>>> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
>>>>>> failed to load on esx3-lamp-v0-bl1, returning
>>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>>>>>>
>>>>>>
>>>>>> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <
>>>>>> josh_thompson@ncsu.edu
>>>>>>
>>>>>>> wrote:
>>>>>>>
>>>>>>
>>>>>> -----BEGIN PGP SIGNED MESSAGE-----
>>>>>>
>>>>>>> Hash: SHA1
>>>>>>>
>>>>>>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>>>>>>
>>>>>>>  always fake the DNS resolution by placing an entry /etc/resolv.conf
>>>>>>>>
>>>>>>>>
>>>>>>> That would be /etc/hosts  :)
>>>>>>>
>>>>>>> Josh
>>>>>>> - --
>>>>>>> - -------------------------------
>>>>>>> Josh Thompson
>>>>>>> Systems Programmer
>>>>>>> Virtual Computing Lab (VCL)
>>>>>>> North Carolina State University
>>>>>>>
>>>>>>> Josh_Thompson@ncsu.edu
>>>>>>> 919-515-5323
>>>>>>>
>>>>>>> my GPG/PGP key can be found at www.keyserver.net
>>>>>>> -----BEGIN PGP SIGNATURE-----
>>>>>>> Version: GnuPG v2.0.9 (GNU/Linux)
>>>>>>>
>>>>>>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
>>>>>>> nKgBCGnhdhToNQ0EtzLhRC8=
>>>>>>> =Yjph
>>>>>>> -----END PGP SIGNATURE-----
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>
>>>
>>
>


-- 
Melba Lopez
(305) 807-6260
milopez@gmail.com

Re: Reservation Problem

Posted by Brian Bouterse <bm...@ncsu.edu>.
As it turns out, the vcl-dev list strips out embedded URLs.  I've  
pasted it below.

http://wiki.oscr.ncsu.edu/wiki/index.php/Updating_the_VCL_VM_to_the_latest_code_version

Best,
Brian

Brian Bouterse
Secure Open Systems Initiative
919.698.8796




On Mar 24, 2009, at 12:44 PM, Brian Bouterse wrote:

> I forgot to include the link with the upgrade how-to:  It is located  
> here.
>
> Best,
> Brian
>
>
> Brian Bouterse
> Secure Open Systems Initiative
> 919.698.8796
>
>
>
>
> On Mar 24, 2009, at 12:20 PM, Brian Bouterse wrote:
>
>> I've put in some more debugging into the esx.pm module.  This  
>> should print the registration command to the screen so that it can  
>> be tried to run manually.  Can you update to the latest code  
>> version and try it?  I've written a how-to located here.
>>
>> Best,
>> Brian
>>
>>
>> Brian Bouterse
>> Secure Open Systems Initiative
>> 919.698.8796
>>
>>
>>
>>
>> On Mar 24, 2009, at 10:20 AM, Melba Lopez wrote:
>>
>>> Actually everything you've mentioned has been put into place.
>>> The nameserver entry is in /etc/resolv.conf and all the esxibl1-3  
>>> hostnames
>>> are in the /etc/hosts.
>>> I can connect to the blades by putting esxibl1-3 into VIClient  
>>> without a
>>> problem.
>>>
>>> Note:  /etc/resolv.conf is generated by /sbin/dhclient-script; once
>>> network/vm is rebooted it restores original.
>>>
>>> I also restarted the networking and went as far as to reboot the  
>>> VCL VM and
>>> still it gives me the same error.
>>>
>>>
>>> --Melba
>>>
>>>
>>> On Tue, Mar 24, 2009 at 9:34 AM, Brian Bouterse  
>>> <bm...@ncsu.edu> wrote:
>>>
>>>> I'm still suspicious of your DNS resolution and configuration.   
>>>> In addition
>>>> to creating the DNS entries in your lab's DNS server, did you  
>>>> connect VCL to
>>>> that DNS by creating an entry similar to the one below in the
>>>> /etc/resolv.conf on your VCL management node?
>>>>
>>>> nameserver <ip_of_your_DNS_here>
>>>>
>>>> Can you connect with virtual center to the blade you're trying to  
>>>> provision
>>>> to when referencing it strictly by it's hostname?
>>>>
>>>> If you want to remove DNS resolution from the list of possible  
>>>> culprits,
>>>> you can create an entry in /etc/hosts of your VCL management node  
>>>> similar to
>>>> the line below.  I think that should work.
>>>>
>>>> <IP Address of esxib1>  esxibl1.
>>>>
>>>> Remember to restart networking (or the whole VCL management node)  
>>>> when
>>>> testing these configuration changes.
>>>>
>>>> Best,
>>>> Brian
>>>>
>>>>
>>>> Brian Bouterse
>>>> Secure Open Systems Initiative
>>>> 919.698.8796
>>>>
>>>>
>>>>
>>>>
>>>> On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:
>>>>
>>>> Ok, our lab already had DNS capabilities, so I've set esxibl1-3*  
>>>> *to be
>>>>> valid hostnames*.
>>>>>
>>>>> *However, it is still saying it can't find "esxibl1".  I've  
>>>>> pinged that
>>>>> hostname from another machine on the same network and it works  
>>>>> just fine.
>>>>>
>>>>>
>>>>> Also because it kept saying it couldn't load the VM, I've found  
>>>>> another
>>>>> problem.  The vmdk file successfully copies over into the  
>>>>> "inuse" folder.
>>>>> When I manually add that VM to a blade, I'm noticing that the VM  
>>>>> does not
>>>>> keep the network setings.  I watched someone actually create  
>>>>> this VM and I
>>>>> redid it myself, and the settings do not stay when its copied  
>>>>> over.  Not
>>>>> sure if it's related, but thought I might mention it.
>>>>> *
>>>>>
>>>>>
>>>>> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote  
>>>>> vmxarray to
>>>>> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
>>>>> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>>>> to 0,
>>>>> exit
>>>>> status: 0
>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
>>>>> |24815|143:10|new| No host found with name esxibl1.
>>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on  
>>>>> command:
>>>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1' -- 
>>>>> vmname
>>>>> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
>>>>> 'd834jfhd734jgfhf7'
>>>>> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>>>> to 0,
>>>>> exit
>>>>> status: 0
>>>>> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered  
>>>>> on: Virtual
>>>>> Machine esx3-lamp-v0-bl1 not found.
>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>>>> to 0,
>>>>> exit
>>>>> status: 0
>>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>>>> to 0,
>>>>> exit
>>>>> status: 0
>>>>> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS  
>>>>> --
>>>>> Sending
>>>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>>>
>>>>> |24815|143:10|new| ---- CRITICAL ----
>>>>> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:
>>>>> load(341)|Could
>>>>> not query for VM in VI PERL API
>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
>>>>> |24815|143:10|new| (-1) esx.pm, load (line: 341)
>>>>> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
>>>>> |24815|143:10|new| (-3) new.pm, process (line: 266)
>>>>> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
>>>>> |24815|143:10|new| (-5) vcld, main (line: 353)
>>>>>
>>>>>
>>>>> |24815|143:10|new| ---- WARNING ----
>>>>> |24815|143:10|new| 2009-03-24
>>>>> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
>>>>> failed to load on esx3-lamp-v0-bl1, returning
>>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>>>>>
>>>>>
>>>>> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <josh_thompson@ncsu.edu
>>>>>> wrote:
>>>>>
>>>>> -----BEGIN PGP SIGNED MESSAGE-----
>>>>>> Hash: SHA1
>>>>>>
>>>>>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>>>>>
>>>>>>> always fake the DNS resolution by placing an entry /etc/ 
>>>>>>> resolv.conf
>>>>>>>
>>>>>>
>>>>>> That would be /etc/hosts  :)
>>>>>>
>>>>>> Josh
>>>>>> - --
>>>>>> - -------------------------------
>>>>>> Josh Thompson
>>>>>> Systems Programmer
>>>>>> Virtual Computing Lab (VCL)
>>>>>> North Carolina State University
>>>>>>
>>>>>> Josh_Thompson@ncsu.edu
>>>>>> 919-515-5323
>>>>>>
>>>>>> my GPG/PGP key can be found at www.keyserver.net
>>>>>> -----BEGIN PGP SIGNATURE-----
>>>>>> Version: GnuPG v2.0.9 (GNU/Linux)
>>>>>>
>>>>>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
>>>>>> nKgBCGnhdhToNQ0EtzLhRC8=
>>>>>> =Yjph
>>>>>> -----END PGP SIGNATURE-----
>>>>>>
>>>>>>
>>>>
>>
>


Re: Reservation Problem

Posted by Brian Bouterse <bm...@ncsu.edu>.
I forgot to include the link with the upgrade how-to:  It is located  
here.

Best,
Brian


Brian Bouterse
Secure Open Systems Initiative
919.698.8796




On Mar 24, 2009, at 12:20 PM, Brian Bouterse wrote:

> I've put in some more debugging into the esx.pm module.  This should  
> print the registration command to the screen so that it can be tried  
> to run manually.  Can you update to the latest code version and try  
> it?  I've written a how-to located here.
>
> Best,
> Brian
>
>
> Brian Bouterse
> Secure Open Systems Initiative
> 919.698.8796
>
>
>
>
> On Mar 24, 2009, at 10:20 AM, Melba Lopez wrote:
>
>> Actually everything you've mentioned has been put into place.
>> The nameserver entry is in /etc/resolv.conf and all the esxibl1-3  
>> hostnames
>> are in the /etc/hosts.
>> I can connect to the blades by putting esxibl1-3 into VIClient  
>> without a
>> problem.
>>
>> Note:  /etc/resolv.conf is generated by /sbin/dhclient-script; once
>> network/vm is rebooted it restores original.
>>
>> I also restarted the networking and went as far as to reboot the  
>> VCL VM and
>> still it gives me the same error.
>>
>>
>> --Melba
>>
>>
>> On Tue, Mar 24, 2009 at 9:34 AM, Brian Bouterse <bm...@ncsu.edu>  
>> wrote:
>>
>>> I'm still suspicious of your DNS resolution and configuration.  In  
>>> addition
>>> to creating the DNS entries in your lab's DNS server, did you  
>>> connect VCL to
>>> that DNS by creating an entry similar to the one below in the
>>> /etc/resolv.conf on your VCL management node?
>>>
>>> nameserver <ip_of_your_DNS_here>
>>>
>>> Can you connect with virtual center to the blade you're trying to  
>>> provision
>>> to when referencing it strictly by it's hostname?
>>>
>>> If you want to remove DNS resolution from the list of possible  
>>> culprits,
>>> you can create an entry in /etc/hosts of your VCL management node  
>>> similar to
>>> the line below.  I think that should work.
>>>
>>> <IP Address of esxib1>  esxibl1.
>>>
>>> Remember to restart networking (or the whole VCL management node)  
>>> when
>>> testing these configuration changes.
>>>
>>> Best,
>>> Brian
>>>
>>>
>>> Brian Bouterse
>>> Secure Open Systems Initiative
>>> 919.698.8796
>>>
>>>
>>>
>>>
>>> On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:
>>>
>>> Ok, our lab already had DNS capabilities, so I've set esxibl1-3*  
>>> *to be
>>>> valid hostnames*.
>>>>
>>>> *However, it is still saying it can't find "esxibl1".  I've  
>>>> pinged that
>>>> hostname from another machine on the same network and it works  
>>>> just fine.
>>>>
>>>>
>>>> Also because it kept saying it couldn't load the VM, I've found  
>>>> another
>>>> problem.  The vmdk file successfully copies over into the "inuse"  
>>>> folder.
>>>> When I manually add that VM to a blade, I'm noticing that the VM  
>>>> does not
>>>> keep the network setings.  I watched someone actually create this  
>>>> VM and I
>>>> redid it myself, and the settings do not stay when its copied  
>>>> over.  Not
>>>> sure if it's related, but thought I might mention it.
>>>> *
>>>>
>>>>
>>>> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote  
>>>> vmxarray to
>>>> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
>>>> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>>> to 0,
>>>> exit
>>>> status: 0
>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
>>>> |24815|143:10|new| No host found with name esxibl1.
>>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on  
>>>> command:
>>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1' -- 
>>>> vmname
>>>> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
>>>> 'd834jfhd734jgfhf7'
>>>> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>>> to 0,
>>>> exit
>>>> status: 0
>>>> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered on:  
>>>> Virtual
>>>> Machine esx3-lamp-v0-bl1 not found.
>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>>> to 0,
>>>> exit
>>>> status: 0
>>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>>> to 0,
>>>> exit
>>>> status: 0
>>>> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS --
>>>> Sending
>>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>>
>>>> |24815|143:10|new| ---- CRITICAL ----
>>>> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:
>>>> load(341)|Could
>>>> not query for VM in VI PERL API
>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
>>>> |24815|143:10|new| (-1) esx.pm, load (line: 341)
>>>> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
>>>> |24815|143:10|new| (-3) new.pm, process (line: 266)
>>>> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
>>>> |24815|143:10|new| (-5) vcld, main (line: 353)
>>>>
>>>>
>>>> |24815|143:10|new| ---- WARNING ----
>>>> |24815|143:10|new| 2009-03-24
>>>> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
>>>> failed to load on esx3-lamp-v0-bl1, returning
>>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>>>>
>>>>
>>>> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <josh_thompson@ncsu.edu
>>>>> wrote:
>>>>
>>>> -----BEGIN PGP SIGNED MESSAGE-----
>>>>> Hash: SHA1
>>>>>
>>>>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>>>>
>>>>>> always fake the DNS resolution by placing an entry /etc/ 
>>>>>> resolv.conf
>>>>>>
>>>>>
>>>>> That would be /etc/hosts  :)
>>>>>
>>>>> Josh
>>>>> - --
>>>>> - -------------------------------
>>>>> Josh Thompson
>>>>> Systems Programmer
>>>>> Virtual Computing Lab (VCL)
>>>>> North Carolina State University
>>>>>
>>>>> Josh_Thompson@ncsu.edu
>>>>> 919-515-5323
>>>>>
>>>>> my GPG/PGP key can be found at www.keyserver.net
>>>>> -----BEGIN PGP SIGNATURE-----
>>>>> Version: GnuPG v2.0.9 (GNU/Linux)
>>>>>
>>>>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
>>>>> nKgBCGnhdhToNQ0EtzLhRC8=
>>>>> =Yjph
>>>>> -----END PGP SIGNATURE-----
>>>>>
>>>>>
>>>
>


Re: Reservation Problem

Posted by Brian Bouterse <bm...@ncsu.edu>.
I've put in some more debugging into the esx.pm module.  This should  
print the registration command to the screen so that it can be tried  
to run manually.  Can you update to the latest code version and try  
it?  I've written a how-to located here.

Best,
Brian


Brian Bouterse
Secure Open Systems Initiative
919.698.8796




On Mar 24, 2009, at 10:20 AM, Melba Lopez wrote:

> Actually everything you've mentioned has been put into place.
> The nameserver entry is in /etc/resolv.conf and all the esxibl1-3  
> hostnames
> are in the /etc/hosts.
> I can connect to the blades by putting esxibl1-3 into VIClient  
> without a
> problem.
>
> Note:  /etc/resolv.conf is generated by /sbin/dhclient-script; once
> network/vm is rebooted it restores original.
>
> I also restarted the networking and went as far as to reboot the VCL  
> VM and
> still it gives me the same error.
>
>
> --Melba
>
>
> On Tue, Mar 24, 2009 at 9:34 AM, Brian Bouterse <bm...@ncsu.edu>  
> wrote:
>
>> I'm still suspicious of your DNS resolution and configuration.  In  
>> addition
>> to creating the DNS entries in your lab's DNS server, did you  
>> connect VCL to
>> that DNS by creating an entry similar to the one below in the
>> /etc/resolv.conf on your VCL management node?
>>
>> nameserver <ip_of_your_DNS_here>
>>
>> Can you connect with virtual center to the blade you're trying to  
>> provision
>> to when referencing it strictly by it's hostname?
>>
>> If you want to remove DNS resolution from the list of possible  
>> culprits,
>> you can create an entry in /etc/hosts of your VCL management node  
>> similar to
>> the line below.  I think that should work.
>>
>> <IP Address of esxib1>  esxibl1.
>>
>> Remember to restart networking (or the whole VCL management node)  
>> when
>> testing these configuration changes.
>>
>> Best,
>> Brian
>>
>>
>> Brian Bouterse
>> Secure Open Systems Initiative
>> 919.698.8796
>>
>>
>>
>>
>> On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:
>>
>> Ok, our lab already had DNS capabilities, so I've set esxibl1-3*  
>> *to be
>>> valid hostnames*.
>>>
>>> *However, it is still saying it can't find "esxibl1".  I've pinged  
>>> that
>>> hostname from another machine on the same network and it works  
>>> just fine.
>>>
>>>
>>> Also because it kept saying it couldn't load the VM, I've found  
>>> another
>>> problem.  The vmdk file successfully copies over into the "inuse"  
>>> folder.
>>> When I manually add that VM to a blade, I'm noticing that the VM  
>>> does not
>>> keep the network setings.  I watched someone actually create this  
>>> VM and I
>>> redid it myself, and the settings do not stay when its copied  
>>> over.  Not
>>> sure if it's related, but thought I might mention it.
>>> *
>>>
>>>
>>> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote  
>>> vmxarray to
>>> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
>>> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>> to 0,
>>> exit
>>> status: 0
>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
>>> |24815|143:10|new| No host found with name esxibl1.
>>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on  
>>> command:
>>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1' -- 
>>> vmname
>>> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
>>> 'd834jfhd734jgfhf7'
>>> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>> to 0,
>>> exit
>>> status: 0
>>> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered on:  
>>> Virtual
>>> Machine esx3-lamp-v0-bl1 not found.
>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>> to 0,
>>> exit
>>> status: 0
>>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $?  
>>> to 0,
>>> exit
>>> status: 0
>>> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS --
>>> Sending
>>> mail To: root@localhost, PROBLEM -- esx.pm
>>>
>>> |24815|143:10|new| ---- CRITICAL ----
>>> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:
>>> load(341)|Could
>>> not query for VM in VI PERL API
>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
>>> |24815|143:10|new| (-1) esx.pm, load (line: 341)
>>> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
>>> |24815|143:10|new| (-3) new.pm, process (line: 266)
>>> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
>>> |24815|143:10|new| (-5) vcld, main (line: 353)
>>>
>>>
>>> |24815|143:10|new| ---- WARNING ----
>>> |24815|143:10|new| 2009-03-24
>>> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
>>> failed to load on esx3-lamp-v0-bl1, returning
>>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>>>
>>>
>>> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <josh_thompson@ncsu.edu
>>>> wrote:
>>>
>>> -----BEGIN PGP SIGNED MESSAGE-----
>>>> Hash: SHA1
>>>>
>>>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>>>
>>>>> always fake the DNS resolution by placing an entry /etc/ 
>>>>> resolv.conf
>>>>>
>>>>
>>>> That would be /etc/hosts  :)
>>>>
>>>> Josh
>>>> - --
>>>> - -------------------------------
>>>> Josh Thompson
>>>> Systems Programmer
>>>> Virtual Computing Lab (VCL)
>>>> North Carolina State University
>>>>
>>>> Josh_Thompson@ncsu.edu
>>>> 919-515-5323
>>>>
>>>> my GPG/PGP key can be found at www.keyserver.net
>>>> -----BEGIN PGP SIGNATURE-----
>>>> Version: GnuPG v2.0.9 (GNU/Linux)
>>>>
>>>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
>>>> nKgBCGnhdhToNQ0EtzLhRC8=
>>>> =Yjph
>>>> -----END PGP SIGNATURE-----
>>>>
>>>>
>>


Re: Reservation Problem

Posted by Melba Lopez <mi...@gmail.com>.
Actually everything you've mentioned has been put into place.
The nameserver entry is in /etc/resolv.conf and all the esxibl1-3 hostnames
are in the /etc/hosts.
I can connect to the blades by putting esxibl1-3 into VIClient without a
problem.

Note:  /etc/resolv.conf is generated by /sbin/dhclient-script; once
network/vm is rebooted it restores original.

I also restarted the networking and went as far as to reboot the VCL VM and
still it gives me the same error.


--Melba


On Tue, Mar 24, 2009 at 9:34 AM, Brian Bouterse <bm...@ncsu.edu> wrote:

> I'm still suspicious of your DNS resolution and configuration.  In addition
> to creating the DNS entries in your lab's DNS server, did you connect VCL to
> that DNS by creating an entry similar to the one below in the
> /etc/resolv.conf on your VCL management node?
>
> nameserver <ip_of_your_DNS_here>
>
> Can you connect with virtual center to the blade you're trying to provision
> to when referencing it strictly by it's hostname?
>
> If you want to remove DNS resolution from the list of possible culprits,
> you can create an entry in /etc/hosts of your VCL management node similar to
> the line below.  I think that should work.
>
> <IP Address of esxib1>  esxibl1.
>
> Remember to restart networking (or the whole VCL management node) when
> testing these configuration changes.
>
> Best,
> Brian
>
>
> Brian Bouterse
> Secure Open Systems Initiative
> 919.698.8796
>
>
>
>
> On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:
>
>  Ok, our lab already had DNS capabilities, so I've set esxibl1-3* *to be
>> valid hostnames*.
>>
>> *However, it is still saying it can't find "esxibl1".  I've pinged that
>> hostname from another machine on the same network and it works just fine.
>>
>>
>> Also because it kept saying it couldn't load the VM, I've found another
>> problem.  The vmdk file successfully copies over into the "inuse" folder.
>> When I manually add that VM to a blade, I'm noticing that the VM does not
>> keep the network setings.  I watched someone actually create this VM and I
>> redid it myself, and the settings do not stay when its copied over.  Not
>> sure if it's related, but thought I might mention it.
>> *
>>
>>
>> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote vmxarray to
>> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
>> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $? to 0,
>> exit
>> status: 0
>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
>> |24815|143:10|new| No host found with name esxibl1.
>> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on command:
>> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1' --vmname
>> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
>> 'd834jfhd734jgfhf7'
>> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $? to 0,
>> exit
>> status: 0
>> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered on: Virtual
>> Machine esx3-lamp-v0-bl1 not found.
>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to 0,
>> exit
>> status: 0
>> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to 0,
>> exit
>> status: 0
>> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS --
>> Sending
>> mail To: root@localhost, PROBLEM -- esx.pm
>>
>> |24815|143:10|new| ---- CRITICAL ----
>> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:
>> load(341)|Could
>> not query for VM in VI PERL API
>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
>> |24815|143:10|new| (-1) esx.pm, load (line: 341)
>> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
>> |24815|143:10|new| (-3) new.pm, process (line: 266)
>> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
>> |24815|143:10|new| (-5) vcld, main (line: 353)
>>
>>
>> |24815|143:10|new| ---- WARNING ----
>> |24815|143:10|new| 2009-03-24
>> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
>> failed to load on esx3-lamp-v0-bl1, returning
>> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>>
>>
>> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <josh_thompson@ncsu.edu
>> >wrote:
>>
>>  -----BEGIN PGP SIGNED MESSAGE-----
>>> Hash: SHA1
>>>
>>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>>
>>>> always fake the DNS resolution by placing an entry /etc/resolv.conf
>>>>
>>>
>>> That would be /etc/hosts  :)
>>>
>>> Josh
>>> - --
>>> - -------------------------------
>>> Josh Thompson
>>> Systems Programmer
>>> Virtual Computing Lab (VCL)
>>> North Carolina State University
>>>
>>> Josh_Thompson@ncsu.edu
>>> 919-515-5323
>>>
>>> my GPG/PGP key can be found at www.keyserver.net
>>> -----BEGIN PGP SIGNATURE-----
>>> Version: GnuPG v2.0.9 (GNU/Linux)
>>>
>>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
>>> nKgBCGnhdhToNQ0EtzLhRC8=
>>> =Yjph
>>> -----END PGP SIGNATURE-----
>>>
>>>
>

Re: Reservation Problem

Posted by Brian Bouterse <bm...@ncsu.edu>.
I'm still suspicious of your DNS resolution and configuration.  In  
addition to creating the DNS entries in your lab's DNS server, did you  
connect VCL to that DNS by creating an entry similar to the one below  
in the /etc/resolv.conf on your VCL management node?

nameserver <ip_of_your_DNS_here>

Can you connect with virtual center to the blade you're trying to  
provision to when referencing it strictly by it's hostname?

If you want to remove DNS resolution from the list of possible  
culprits, you can create an entry in /etc/hosts of your VCL management  
node similar to the line below.  I think that should work.

<IP Address of esxib1>	esxibl1.

Remember to restart networking (or the whole VCL management node) when  
testing these configuration changes.

Best,
Brian


Brian Bouterse
Secure Open Systems Initiative
919.698.8796




On Mar 23, 2009, at 9:13 PM, Melba Lopez wrote:

> Ok, our lab already had DNS capabilities, so I've set esxibl1-3* *to  
> be
> valid hostnames*.
>
> *However, it is still saying it can't find "esxibl1".  I've pinged  
> that
> hostname from another machine on the same network and it works just  
> fine.
>
>
> Also because it kept saying it couldn't load the VM, I've found  
> another
> problem.  The vmdk file successfully copies over into the "inuse"  
> folder.
> When I manually add that VM to a blade, I'm noticing that the VM  
> does not
> keep the network setings.  I watched someone actually create this VM  
> and I
> redid it myself, and the settings do not stay when its copied over.   
> Not
> sure if it's related, but thought I might mention it.
> *
>
>
> 2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote vmxarray  
> to
> /mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
> 2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $? to  
> 0, exit
> status: 0
> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
> |24815|143:10|new| No host found with name esxibl1.
> 2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on  
> command:
> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1' -- 
> vmname
> esx3-lamp-v0-bl1 --operation poweron --username vcl --password
> 'd834jfhd734jgfhf7'
> 2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $? to  
> 0, exit
> status: 0
> 2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered on:  
> Virtual
> Machine esx3-lamp-v0-bl1 not found.
> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to  
> 0, exit
> status: 0
> 2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to  
> 0, exit
> status: 0
> 2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS --  
> Sending
> mail To: root@localhost, PROBLEM -- esx.pm
>
> |24815|143:10|new| ---- CRITICAL ----
> |24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new| 
> esx.pm:load(341)|Could
> not query for VM in VI PERL API
> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)
> |24815|143:10|new| (-1) esx.pm, load (line: 341)
> |24815|143:10|new| (-2) new.pm, reload_image (line: 664)
> |24815|143:10|new| (-3) new.pm, process (line: 266)
> |24815|143:10|new| (-4) vcld, make_new_child (line: 606)
> |24815|143:10|new| (-5) vcld, main (line: 353)
>
>
> |24815|143:10|new| ---- WARNING ----
> |24815|143:10|new| 2009-03-24
> 04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
> failed to load on esx3-lamp-v0-bl1, returning
> |24815|143:10|new| ( 0) utils.pm, notify (line: 683)*
>
>
> On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson  
> <jo...@ncsu.edu>wrote:
>
>> -----BEGIN PGP SIGNED MESSAGE-----
>> Hash: SHA1
>>
>> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
>>> always fake the DNS resolution by placing an entry /etc/resolv.conf
>>
>> That would be /etc/hosts  :)
>>
>> Josh
>> - --
>> - -------------------------------
>> Josh Thompson
>> Systems Programmer
>> Virtual Computing Lab (VCL)
>> North Carolina State University
>>
>> Josh_Thompson@ncsu.edu
>> 919-515-5323
>>
>> my GPG/PGP key can be found at www.keyserver.net
>> -----BEGIN PGP SIGNATURE-----
>> Version: GnuPG v2.0.9 (GNU/Linux)
>>
>> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
>> nKgBCGnhdhToNQ0EtzLhRC8=
>> =Yjph
>> -----END PGP SIGNATURE-----
>>


Re: Reservation Problem

Posted by Melba Lopez <mi...@gmail.com>.
Ok, our lab already had DNS capabilities, so I've set esxibl1-3* *to be
valid hostnames*.

*However, it is still saying it can't find "esxibl1".  I've pinged that
hostname from another machine on the same network and it works just fine.


Also because it kept saying it couldn't load the VM, I've found another
problem.  The vmdk file successfully copies over into the "inuse" folder.
When I manually add that VM to a blade, I'm noticing that the VM does not
keep the network setings.  I watched someone actually create this VM and I
redid it myself, and the settings do not stay when its copied over.  Not
sure if it's related, but thought I might mention it.
*


2009-03-24 04:28:57|24815|143:10|new|esx.pm:load(300)|wrote vmxarray to
/mnt/vcl/inuse/esx3-lamp-v0-bl1/esx3-lamp-v0.vmx
2009-03-24 04:28:59|24815|143:10|new|vcld:REAPER(770)|setting $? to 0, exit
status: 0
2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(321)|Registered:
|24815|143:10|new| No host found with name esxibl1.
2009-03-24 04:28:59|24815|143:10|new|esx.pm:load(330)|Power on command:
/usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'esxibl1' --vmname
esx3-lamp-v0-bl1 --operation poweron --username vcl --password
'd834jfhd734jgfhf7'
2009-03-24 04:29:00|24815|143:10|new|vcld:REAPER(770)|setting $? to 0, exit
status: 0
2009-03-24 04:29:00|24815|143:10|new|esx.pm:load(333)|Powered on: Virtual
Machine esx3-lamp-v0-bl1 not found.
2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to 0, exit
status: 0
2009-03-24 04:29:01|24815|143:10|new|vcld:REAPER(770)|setting $? to 0, exit
status: 0
2009-03-24 04:29:01|24815|143:10|new|utils.pm:mail(1281)|SUCCESS -- Sending
mail To: root@localhost, PROBLEM -- esx.pm

|24815|143:10|new| ---- CRITICAL ----
|24815|143:10|new| 2009-03-24 04:29:01|24815|143:10|new|esx.pm:load(341)|Could
not query for VM in VI PERL API
|24815|143:10|new| ( 0) utils.pm, notify (line: 683)
|24815|143:10|new| (-1) esx.pm, load (line: 341)
|24815|143:10|new| (-2) new.pm, reload_image (line: 664)
|24815|143:10|new| (-3) new.pm, process (line: 266)
|24815|143:10|new| (-4) vcld, make_new_child (line: 606)
|24815|143:10|new| (-5) vcld, main (line: 353)


|24815|143:10|new| ---- WARNING ----
|24815|143:10|new| 2009-03-24
04:29:01|24815|143:10|new|new.pm:reload_image(669)|esx3-lamp-v0
failed to load on esx3-lamp-v0-bl1, returning
|24815|143:10|new| ( 0) utils.pm, notify (line: 683)*


On Thu, Mar 19, 2009 at 7:12 PM, Josh Thompson <jo...@ncsu.edu>wrote:

> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
> On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
> > always fake the DNS resolution by placing an entry /etc/resolv.conf
>
> That would be /etc/hosts  :)
>
> Josh
> - --
> - -------------------------------
> Josh Thompson
> Systems Programmer
> Virtual Computing Lab (VCL)
> North Carolina State University
>
> Josh_Thompson@ncsu.edu
> 919-515-5323
>
> my GPG/PGP key can be found at www.keyserver.net
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v2.0.9 (GNU/Linux)
>
> iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
> nKgBCGnhdhToNQ0EtzLhRC8=
> =Yjph
> -----END PGP SIGNATURE-----
>

Re: Reservation Problem

Posted by Josh Thompson <jo...@ncsu.edu>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On Thu March 19 2009 5:45:40 pm Brian Bouterse wrote:
> always fake the DNS resolution by placing an entry /etc/resolv.conf

That would be /etc/hosts  :)

Josh
- -- 
- -------------------------------
Josh Thompson
Systems Programmer
Virtual Computing Lab (VCL)
North Carolina State University

Josh_Thompson@ncsu.edu
919-515-5323

my GPG/PGP key can be found at www.keyserver.net
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.9 (GNU/Linux)

iD8DBQFJwt9xV/LQcNdtPQMRAiekAJ9Sna6on6gIZC8fO/1wKWFw9W3zIQCffxLj
nKgBCGnhdhToNQ0EtzLhRC8=
=Yjph
-----END PGP SIGNATURE-----

Re: Reservation Problem

Posted by Brian Bouterse <bm...@ncsu.edu>.
You could try it by IP also.  That could be tested by changing the  
hypervisor's entry in the computer table.  Alternativly, you could  
always fake the DNS resolution by placing an entry /etc/resolv.conf

Also, you could try to run that command from the command line using an  
IP instead of the blade's current name 'vclblade1'.

Best,
Brian


Brian Bouterse
Secure Open Systems Initiative
919.698.8796




On Mar 19, 2009, at 4:01 PM, Melba Lopez wrote:

> 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 <bm...@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: root@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: root@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 <bm...@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:"
>>>>>>
>>>>>
>>>>>
>>>>>>
>>>>>>
>>>>
>>


Re: Reservation Problem

Posted by Melba Lopez <mi...@gmail.com>.
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 <bm...@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: root@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: root@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 <bm...@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:"
>>>>>
>>>>
>>>>
>>>>>
>>>>>
>>>
>

Re: Reservation Problem

Posted by Brian Bouterse <bm...@ncsu.edu>.
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: root@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: root@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 <bm...@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:"
>>>
>>>>
>>>>
>>


Re: Reservation Problem

Posted by Melba Lopez <mi...@gmail.com>.
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: root@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: root@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 <bm...@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:"
>>
>>>
>>>
>

Re: Reservation Problem

Posted by Brian Bouterse <bm...@ncsu.edu>.
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:"
>>