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 <milo...@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 <milo...@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: r...@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: r...@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 <bmbou...@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: r...@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: r...@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 <bmbou...@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 <bmbou...@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: r...@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_thomp...@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_thomp...@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-----
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>>
>>
>
>
