After digging into this more, I've narrowed down the issues to the
vmregister.pl, part of the Vsphere perl toolkit. I get the same error when
running the command manually. We're running VMWare ESXi 4.0.0 and VCL 2.0.
Are there any known issues or incompatibilities between ESXi 4.0.0 and VCL
2.0? Anyone have any insight into this registration issue? Please see
below for the command run manually, and also the version command.
>>>>>>>>>>>>>>
[r...@vclmgmt vm]# /usr/lib/vmware-viperl/apps/vm/vmregister.pl --server
'vclvm1' --username root --password '***********' --vmxpath
'[VCL]/inuse/csuvm10/vmwarewinxp-base7-v0.vmx' --operation register --vmname
csuvm10 --pool Resources --hostname 'vclvm1.csueastbay.edu' --datacenter
'ha-datacenter'
SOAP Fault:
-----------
Fault string: fault.RestrictedVersion.summary
Fault detail: RestrictedVersionFault
>>>>>>>>>>>>>>
>>>>>>>>>>>>>>
[r...@vclmgmt vm]# /usr/lib/vmware-viperl/apps/general/viversion.pl --server
'vclvm1' --username root --password '**********'
This is HostAgent 4.0
This is VMware ESXi 4.0.0 build-208167 running on x86 ESX Server microkernel
The product Line ID is a unique identifier for a product line. product line
id is embeddedEsx
Short form of the product name is VMware ESXi having version 4.0.0
System is running on x86 ESX Server microkernel
>>>>>>>>>>>>>>
Thanks,
Jeff
On Sun, Feb 21, 2010 at 9:50 PM, Jeffrey Wisman
<jeff.wis...@csueastbay.edu>wrote:
> I was troubleshooting this error before as an issue with creating more than
> one reservation at a time. As it turns out, its really just an issue with
> the new computers I added using the "add multiple" function. In the last
> thread, it was suggested that I configure dhcpd.conf and the database with
> the appropriate MAC addresses, which I did. Unfortunately, I'm still not
> getting any further.
>
> I disabled the first computer (the one that works) and then tried to create
> a reservation, and ended up with the following logs. There are so many
> warnings that I'm not sure what ones to care about. Even when it works with
> the original VM, I get a ton of warnings.
>
> It seems like the issue is the "SOAP fault" that gets returned when trying
> to register the virtual machine. Please note that we're running ESX 4.0.0.
>
> Can somebody take a look and let me know if its obvious what's wrong? I'm
> not really sure where to go from here.
>
> Thanks,
> Jeff
>
>
>
>
>
> 2010-02-21 21:32:37|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:32:37
> 2010-02-21
> 21:32:37|7225|13:13|new|utils.pm:reservation_being_processed(9616)|computerloadlog
> 'begin' entry does NOT exist for reservation 13
> 2010-02-21
> 21:32:37|7225|13:13|new|utils.pm:reservation_being_processed(9668)|reservation
> is NOT currently being processed
> 2010-02-21 21:32:37|7225|13:13|new|vcld:main(276)|reservation 13 is NOT
> already being processed
>
> |7225|13:13|new| ---- WARNING ----
> |7225|13:13|new| 2010-02-21
> 21:32:37|7225|13:13|new|utils.pm:get_request_info(5209)|preferredimageid
> is not set for computer id=19
> |7225|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7225|13:13|new| (-1) utils.pm, get_request_info (line: 5209)
> |7225|13:13|new| (-2) vcld, main (line: 280)
>
> 2010-02-21 21:32:37|7225|13:13|new|utils.pm:get_request_info(5349)|non-NCSU
> user affiliation found: Local
> 2010-02-21
> 21:32:37|7225|13:13|new|utils.pm:get_management_node_info(6797)|management
> node info retrieved from database for vclmgmt
> 2010-02-21 21:32:37|7225|13:13|new|vcld:main(281)|retrieved request
> information from database
> 2010-02-21
> 21:32:37|7225|13:13|new|DataStructure.pm:is_parent_reservation(854)|returning
> true: parent reservation ID for this request: 13
> 2010-02-21 21:32:37|7225|13:13|new|utils.pm:update_request_state(2177)|request
> 13 state updated to: pending, laststate to: new
> 2010-02-21 21:32:37|7225|13:13|new|utils.pm:insertloadlog(4701)|inserted
> computer=19, begin, beginning to process, state is new
> 2010-02-21 21:32:37|7225|13:13|new|vcld:make_new_child(509)|loaded VCL::new
> module
> 2010-02-21 21:32:37|7958|13:13|new|vcld:make_new_child(582)|vcld
> environment variable set to 0 for this process
> 2010-02-21 21:32:37|7225|13:13|new|vcld:make_new_child(566)|current number
> of forked kids: 1
> 2010-02-21 21:32:37|7958|13:13|new|Module.pm:new(132)|constructor called,
> class=VCL::new
> 2010-02-21 21:32:37|7958|13:13|new|Module.pm:new(154)|VCL::new object
> created
> 2010-02-21 21:32:37|7958|13:13|new|State.pm:initialize(85)|obtained a
> database handle for this state process, stored as $ENV{dbh}
> 2010-02-21 21:32:37|7958|13:13|new|State.pm:check_image_os(820)|no
> corrections need to be made, not an imaging request, returning 1
> 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:is_parent_reservation(854)|returning
> true: parent reservation ID for this request: 13
> 2010-02-21
> 21:32:37|7958|13:13|new|utils.pm:rename_vcld_process(7845)|reservation
> count: 1
> 2010-02-21
> 21:32:37|7958|13:13|new|utils.pm:rename_vcld_process(7864)|PARENTIMAGE:
> 1
> 2010-02-21
> 21:32:37|7958|13:13|new|utils.pm:rename_vcld_process(7865)|SUBIMAGE:
> 0
> 2010-02-21 21:32:37|7958|13:13|new|utils.pm:rename_vcld_process(7883)|renamed
> process to 'vcld VCL::new 13:13 new'
> 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:is_parent_reservation(854)|returning
> true: parent reservation ID for this request: 13
> 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:is_parent_reservation(854)|returning
> true: parent reservation ID for this request: 13
> 2010-02-21 21:32:37|7958|13:13|new|State.pm:initialize(121)|attempting to
> load provisioning module: VCL::Module::Provisioning::esx
> 2010-02-21 21:32:37|7958|13:13|new|esx.pm:initialize(138)|esx vmware
> toolkit root path found: /usr/lib/vmware-viperl/apps
> 2010-02-21 21:32:37|7958|13:13|new|esx.pm:initialize(140)|vmware ESX
> module initialized
> 2010-02-21
> 21:32:37|7958|13:13|new|State.pm:initialize(127)|VCL::Module::Provisioning::esx
> module loaded
> 2010-02-21 21:32:37|7958|13:13|new|Module.pm:new(132)|constructor called,
> class=VCL::Module::Provisioning::esx
> 2010-02-21
> 21:32:37|7958|13:13|new|Module.pm:new(154)|VCL::Module::Provisioning::esx
> object created
> 2010-02-21 21:32:37|7958|13:13|new|esx.pm:initialize(138)|esx vmware
> toolkit root path found: /usr/lib/vmware-viperl/apps
> 2010-02-21 21:32:37|7958|13:13|new|esx.pm:initialize(140)|vmware ESX
> module initialized
> 2010-02-21
> 21:32:37|7958|13:13|new|State.pm:initialize(131)|VCL::Module::Provisioning::esx
> provisioner object created
> 2010-02-21 21:32:37|7958|13:13|new|State.pm:initialize(145)|attempting to
> load OS module: VCL::Module::OS::Windows::Version_5::XP
> 2010-02-21
> 21:32:37|7958|13:13|new|State.pm:initialize(151)|VCL::Module::OS::Windows::Version_5::XP
> module loaded
> 2010-02-21 21:32:37|7958|13:13|new|Module.pm:new(132)|constructor called,
> class=VCL::Module::OS::Windows::Version_5::XP
> 2010-02-21
> 21:32:37|7958|13:13|new|Module.pm:new(154)|VCL::Module::OS::Windows::Version_5::XP
> object created
> 2010-02-21
> 21:32:37|7958|13:13|new|State.pm:initialize(154)|VCL::Module::OS::Windows::Version_5::XP
> OS object created
> 2010-02-21 21:32:37|7958|13:13|new|State.pm:initialize(169)|returning 1
> 2010-02-21 21:32:37|7958|13:13|new|vcld:make_new_child(591)|VCL::new object
> created and initialized
> 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:is_parent_reservation(854)|returning
> true: parent reservation ID for this request: 13
> 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:get_computer_state_name(1893)|attempting
> to retrieve current state of computer csuvm10 from the database
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:get_computer_state_name(1913)|zero
> rows were returned from database select
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, get_computer_state_name (line:
> 1913)
> |7958|13:13|new| (-2) new.pm, process (line: 105)
> |7958|13:13|new| (-3) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-4) vcld, main (line: 341)
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:_automethod(675)|corresponding data
> has not been initialized for get_computer_preferredimage_id:
> $self->request_data->{reservation}{13}{computer}{preferredimage}{id}
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, _automethod (line: 675)
> |7958|13:13|new| (-2) Autoload.pm, __ANON__ (line: 80)
> |7958|13:13|new| (-3) new.pm, process (line: 106)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:_automethod(675)|corresponding data
> has not been initialized for get_computer_preferredimage_name:
> $self->request_data->{reservation}{13}{computer}{preferredimage}{name}
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, _automethod (line: 675)
> |7958|13:13|new| (-2) Autoload.pm, __ANON__ (line: 80)
> |7958|13:13|new| (-3) new.pm, process (line: 107)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
> 2010-02-21
> 21:32:37|7958|13:13|new|utils.pm:get_management_node_id(9346)|environment
> variable: 1
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:process(134)|reservation is
> parent = 1
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:process(135)|preload only = 0
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:process(136)|originating request
> state = new
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:process(137)|originating request
> laststate = new
> Use of uninitialized value in concatenation (.) or string at
> /usr/local/vcl/bin/../lib/VCL/new.pm line 138 (#1)
> (W uninitialized) An undefined value was used as if it were already
> defined. It was interpreted as a "" or a 0, but maybe it was a
> mistake.
> To suppress this warning assign a defined value to your variables.
>
> To help you figure out what was undefined, perl tells you what
> operation
> you used the undefined value in. Note, however, that perl optimizes
> your
> program and the operation displayed in the warning may not necessarily
> appear literally in your program. For example, "that $foo" is
> usually optimized into "that " . $foo, and the warning will refer to
> the concatenation (.) operator, even though there is no . in your
> program.
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|vcld:warning_handler(636)|Use of uninitialized value
> in concatenation (.) or string at /usr/local/vcl/bin/../lib/VCL/new.pmline
> 138.
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) vcld, warning_handler (line: 636)
> |7958|13:13|new| (-2) new.pm, process (line: 138)
> |7958|13:13|new| (-3) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-4) vcld, main (line: 341)
>
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:process(138)|originating
> computer state =
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:process(139)|originating
> computer type = virtualmachine
> 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:is_parent_reservation(854)|returning
> true: parent reservation ID for this request: 13
> 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:get_computer_state_name(1893)|attempting
> to retrieve current state of computer csuvm10 from the database
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:get_computer_state_name(1913)|zero
> rows were returned from database select
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, get_computer_state_name (line:
> 1913)
> |7958|13:13|new| (-2) new.pm, computer_not_being_used (line: 749)
> |7958|13:13|new| (-3) new.pm, process (line: 170)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:_automethod(675)|corresponding data
> has not been initialized for get_computer_preferredimage_id:
> $self->request_data->{reservation}{13}{computer}{preferredimage}{id}
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, _automethod (line: 675)
> |7958|13:13|new| (-2) Autoload.pm, __ANON__ (line: 80)
> |7958|13:13|new| (-3) new.pm, computer_not_being_used (line: 750)
> |7958|13:13|new| (-4) new.pm, process (line: 170)
> |7958|13:13|new| (-5) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-6) vcld, main (line: 341)
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:_automethod(675)|corresponding data
> has not been initialized for get_computer_preferredimage_name:
> $self->request_data->{reservation}{13}{computer}{preferredimage}{name}
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, _automethod (line: 675)
> |7958|13:13|new| (-2) Autoload.pm, __ANON__ (line: 80)
> |7958|13:13|new| (-3) new.pm, computer_not_being_used (line: 751)
> |7958|13:13|new| (-4) new.pm, process (line: 170)
> |7958|13:13|new| (-5) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-6) vcld, main (line: 341)
>
> 2010-02-21
> 21:32:37|7958|13:13|new|utils.pm:get_management_node_id(9346)|environment
> variable: 1
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|vcld:warning_handler(636)|Use of uninitialized value
> in concatenation (.) or string at /usr/local/vcl/bin/../lib/VCL/new.pmline
> 788.
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) vcld, warning_handler (line: 636)
> |7958|13:13|new| (-2) new.pm, computer_not_being_used (line: 788)
> |7958|13:13|new| (-3) new.pm, process (line: 170)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:computer_not_being_used(788)|csuvm10
> state is
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|vcld:warning_handler(636)|Use of uninitialized value
> in pattern match (m//) at /usr/local/vcl/bin/../lib/VCL/new.pm line 791.
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) vcld, warning_handler (line: 636)
> |7958|13:13|new| (-2) new.pm, computer_not_being_used (line: 791)
> |7958|13:13|new| (-3) new.pm, process (line: 170)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|vcld:warning_handler(636)|Use of uninitialized value
> in pattern match (m//) at /usr/local/vcl/bin/../lib/VCL/new.pm line 797.
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) vcld, warning_handler (line: 636)
> |7958|13:13|new| (-2) new.pm, computer_not_being_used (line: 797)
> |7958|13:13|new| (-3) new.pm, process (line: 170)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|vcld:warning_handler(636)|Use of uninitialized value
> in concatenation (.) or string at /usr/local/vcl/bin/../lib/VCL/new.pmline
> 803.
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) vcld, warning_handler (line: 636)
> |7958|13:13|new| (-2) new.pm, computer_not_being_used (line: 803)
> |7958|13:13|new| (-3) new.pm, process (line: 170)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|new.pm:computer_not_being_used(803)|csuvm10
> state is , checking if any conflicting requests are active
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) new.pm, computer_not_being_used (line: 803)
> |7958|13:13|new| (-2) new.pm, process (line: 170)
> |7958|13:13|new| (-3) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-4) vcld, main (line: 341)
>
> 2010-02-21
> 21:32:37|7958|13:13|new|new.pm:computer_not_being_used(820)|checking
> neighbor reservations for csuvm10
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:computer_not_being_used(829)|found
> 2 total reservations for csuvm10
> 2010-02-21
> 21:32:37|7958|13:13|new|new.pm:computer_not_being_used(848)|checking
> neighbor request=11, reservation=11, state=new, laststate=new
> 2010-02-21
> 21:32:37|7958|13:13|new|new.pm:computer_not_being_used(849)|neighbor
> start time: 2010-02-22 13:00:00 (55643)
> 2010-02-21
> 21:32:37|7958|13:13|new|new.pm:computer_not_being_used(943)|neighbor
> request state is OK: new/new
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:computer_not_being_used(949)|checked
> neighbor requests and didn't find any conflicting reservations for csuvm10
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:process(170)|csuvm10 is not
> being used
> 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:is_parent_reservation(854)|returning
> true: parent reservation ID for this request: 13
> 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:get_computer_state_name(1893)|attempting
> to retrieve current state of computer csuvm10 from the database
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:get_computer_state_name(1913)|zero
> rows were returned from database select
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, get_computer_state_name (line:
> 1913)
> |7958|13:13|new| (-2) new.pm, reload_image (line: 479)
> |7958|13:13|new| (-3) new.pm, process (line: 266)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:_automethod(675)|corresponding data
> has not been initialized for get_computer_preferredimage_id:
> $self->request_data->{reservation}{13}{computer}{preferredimage}{id}
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, _automethod (line: 675)
> |7958|13:13|new| (-2) Autoload.pm, __ANON__ (line: 80)
> |7958|13:13|new| (-3) new.pm, reload_image (line: 480)
> |7958|13:13|new| (-4) new.pm, process (line: 266)
> |7958|13:13|new| (-5) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-6) vcld, main (line: 341)
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:37|7958|13:13|new|DataStructure.pm:_automethod(675)|corresponding data
> has not been initialized for get_computer_preferredimage_name:
> $self->request_data->{reservation}{13}{computer}{preferredimage}{name}
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, _automethod (line: 675)
> |7958|13:13|new| (-2) Autoload.pm, __ANON__ (line: 80)
> |7958|13:13|new| (-3) new.pm, reload_image (line: 481)
> |7958|13:13|new| (-4) new.pm, process (line: 266)
> |7958|13:13|new| (-5) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-6) vcld, main (line: 341)
>
> 2010-02-21
> 21:32:37|7958|13:13|new|utils.pm:get_management_node_id(9346)|environment
> variable: 1
> 2010-02-21 21:32:37|7958|13:13|new|new.pm:reload_image(514)|calling
> VCL::Module::Provisioning::esx->node_status()
> 2010-02-21 21:32:37|7958|13:13|new|utils.pm:insertloadlog(4701)|inserted
> computer=19, statuscheck, checking status of node
> 2010-02-21 21:32:37|7958|13:13|new|esx.pm:node_status(787)|Entering
> node_status, checking status of csuvm10
> 2010-02-21
> 21:32:37|7958|13:13|new|esx.pm:node_status(788)|request_for_imaging:
> 0
> 2010-02-21 21:32:37|7958|13:13|new|esx.pm:node_status(789)|requeseted
> image name: vmwarewinxp-base7-v0
> 2010-02-21 21:32:37|7958|13:13|new|esx.pm:node_status(819)|checking if
> csuvm10 is pingable
> 2010-02-21 21:32:38|7958|13:13|new|esx.pm:node_status(825)|csuvm10 is not
> pingable (0)
> 2010-02-21 21:32:38|7958|13:13|new|new.pm:reload_image(560)|node_status
> returned a scalar: RELOAD
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:38|7958|13:13|new|vcld:warning_handler(636)|Use of uninitialized value
> in string eq at /usr/local/vcl/bin/../lib/VCL/new.pm line 573.
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) vcld, warning_handler (line: 636)
> |7958|13:13|new| (-2) new.pm, reload_image (line: 573)
> |7958|13:13|new| (-3) new.pm, process (line: 266)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
> 2010-02-21 21:32:38|7958|13:13|new|new.pm:reload_image(602)|node status is
> RELOAD, csuvm10 will be reloaded
> 2010-02-21 21:32:38|7958|13:13|new|utils.pm:insertloadlog(4701)|inserted
> computer=19, loadimageblade, csuvm10 must be reloaded with
> vmwarewinxp-base7-v0
> 2010-02-21 21:32:38|7958|13:13|new|new.pm:reload_image(616)|calling
> VCL::Module::Provisioning::esx->does_image_exist()
> 2010-02-21 21:32:38|7958|13:13|new|utils.pm:run_ssh_command(6168)|executing
> SSH command on vclvm1.csueastbay.edu:
> |7958|13:13|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x
> vclvm1.csueastbay.edu 'ls -1 /vmfs/volumes/VOL_GEN_1/golden 2>&1' 2>&1
> 2010-02-21 21:32:42|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:32:42
> 2010-02-21 21:32:47|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:32:47
> 2010-02-21 21:32:52|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:32:52
> 2010-02-21 21:32:57|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:32:57
> 2010-02-21
> 21:32:58|7958|13:13|new|utils.pm:run_ssh_command(6250)|run_ssh_command
> output:
> |7958|13:13|new| vmwarewinxp-base7-v0
> 2010-02-21 21:32:58|7958|13:13|new|utils.pm:run_ssh_command(6264)|SSH
> command executed on vclvm1.csueastbay.edu, returning (0,
> "vmwarewinxp-base7-v0")
> 2010-02-21 21:32:58|7958|13:13|new|esx.pm:does_image_exist(916)|image
> vmwarewinxp-base7-v0 exists
> 2010-02-21
> 21:32:58|7958|13:13|new|new.pm:reload_image(619)|vmwarewinxp-base7-v0
> exists on this management node
> 2010-02-21 21:32:58|7958|13:13|new|utils.pm:insertloadlog(4701)|inserted
> computer=19, doesimageexists, confirmed image exists
> 2010-02-21
> 21:32:58|7958|13:13|new|utils.pm:update_computer_state(2219)|computer
> 19 state updated to: reloading
> 2010-02-21 21:32:58|7958|13:13|new|new.pm:reload_image(652)|computer
> csuvm10 state set to reloading
> 2010-02-21 21:32:58|7958|13:13|new|utils.pm:insertloadlog(4701)|inserted
> computer=19, info, computer state updated to reloading
> 2010-02-21 21:32:58|7958|13:13|new|new.pm:reload_image(663)|calling
> VCL::Module::Provisioning::esx->load() subroutine
> 2010-02-21 21:32:58|7958|13:13|new|utils.pm:insertloadlog(4701)|inserted
> computer=19, info, calling VCL::Module::Provisioning::esx->load() subroutine
> 2010-02-21 21:32:58|7958|13:13|new|esx.pm:
> load(165)|****************************************************
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:32:58|7958|13:13|new|DataStructure.pm:_automethod(675)|corresponding data
> has not been initialized for get_computer_eth1_mac_address:
> $self->request_data->{reservation}{13}{computer}{eth1macaddress}
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, _automethod (line: 675)
> |7958|13:13|new| (-2) Autoload.pm, __ANON__ (line: 80)
> |7958|13:13|new| (-3) esx.pm, load (line: 182)
> |7958|13:13|new| (-4) new.pm, reload_image (line: 665)
> |7958|13:13|new| (-5) new.pm, process (line: 266)
> |7958|13:13|new| (-6) vcld, make_new_child (line: 594)
>
> 2010-02-21 21:32:58|7958|13:13|new|esx.pm:load(193)|Calling
> get_vmware_host_info
> 2010-02-21 21:33:02|7958|13:13|new|esx.pm:get_vmware_host_info(1014)|host
> info output for vclvm1
> |7958|13:13|new| Host Information
> |7958|13:13|new| Host Name: vclvm1.csueastbay.edu
> 2010-02-21 21:33:02|7958|13:13|new|esx.pm:get_vmware_host_info(1020)|found
> hostname_value= vclvm1.csueastbay.edu
> 2010-02-21 21:33:02|7958|13:13|new|esx.pm:load(197)|Collected
> vclvm1.csueastbay.edu for vmware host name
> 2010-02-21 21:33:02|7958|13:13|new|esx.pm:load(210)|DATASTORE IP is
> vclvm1.csueastbay.edu and DATASTORE_SHARE_PATH is /vmfs/volumes/VOL_GEN_1
> 2010-02-21 21:33:02|7958|13:13|new|esx.pm:load(211)|Entered ESX module,
> loading vmwarewinxp-base7-v0 on csuvm10 (on vclvm1.csueastbay.edu) for
> reservation 13
> 2010-02-21 21:33:02|7958|13:13|new|esx.pm:load(212)|Datastore:
> vclvm1.csueastbay.edu:/vmfs/volumes/VOL_GEN_1
> 2010-02-21 21:33:02|7958|13:13|new|esx.pm:load(223)|VM info command:
> /usr/lib/vmware-viperl/apps/vm/vminfo.pl --server 'vclvm1' --vmname
> csuvm10 --username root --password '*******'
> 2010-02-21 21:33:02|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:02
> 2010-02-21 21:33:03|7958|13:13|new|esx.pm:load(226)|VM info output:
> Virtual Machine csuvm10 not found.
> 2010-02-21 21:33:03|7958|13:13|new|utils.pm:run_ssh_command(6168)|executing
> SSH command on vclvm1.csueastbay.edu:
> |7958|13:13|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x
> vclvm1.csueastbay.edu 'rm -rf /vmfs/volumes/VOL_GEN_1/inuse/csuvm10' 2>&1
> 2010-02-21 21:33:07|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:07
> 2010-02-21 21:33:12|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:12
> 2010-02-21 21:33:17|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:17
> 2010-02-21 21:33:22|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:22
> 2010-02-21
> 21:33:24|7958|13:13|new|utils.pm:run_ssh_command(6250)|run_ssh_command
> output:
> |7958|13:13|new| none
> 2010-02-21 21:33:24|7958|13:13|new|utils.pm:run_ssh_command(6264)|SSH
> command executed on vclvm1.csueastbay.edu, returning (0, "none")
> 2010-02-21 21:33:24|7958|13:13|new|esx.pm:load(262)|Removed old vm folder
> 2010-02-21 21:33:24|7958|13:13|new|utils.pm:run_ssh_command(6168)|executing
> SSH command on vclvm1.csueastbay.edu:
> |7958|13:13|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x
> vclvm1.csueastbay.edu 'mkdir /vmfs/volumes/VOL_GEN_1/inuse/csuvm10' 2>&1
> 2010-02-21 21:33:27|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:27
> 2010-02-21 21:33:32|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:32
> 2010-02-21 21:33:37|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:37
> 2010-02-21 21:33:42|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:42
> 2010-02-21
> 21:33:44|7958|13:13|new|utils.pm:run_ssh_command(6250)|run_ssh_command
> output:
> |7958|13:13|new| none
> 2010-02-21 21:33:44|7958|13:13|new|utils.pm:run_ssh_command(6264)|SSH
> command executed on vclvm1.csueastbay.edu, returning (0, "none")
> 2010-02-21 21:33:44|7958|13:13|new|utils.pm:run_ssh_command(6168)|executing
> SSH command on vclvm1.csueastbay.edu:
> |7958|13:13|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x
> vclvm1.csueastbay.edu 'cp
> /vmfs/volumes/VOL_GEN_1/golden/vmwarewinxp-base7-v0/vmwarewinxp-base7-v0.vmdk
> /vmfs/volumes/VOL_GEN_1/inuse/csuvm10/vmwarewinxp-base7-v0.vmdk' 2>&1
> 2010-02-21 21:33:47|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:47
> 2010-02-21 21:33:52|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:52
> 2010-02-21 21:33:57|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:33:57
> 2010-02-21 21:34:02|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:02
> 2010-02-21
> 21:34:04|7958|13:13|new|utils.pm:run_ssh_command(6250)|run_ssh_command
> output:
> |7958|13:13|new| cp: cannot stat
> '/vmfs/volumes/VOL_GEN_1/golden/vmwarewinxp-base7-v0/vmwarewinxp-base7-v0.vmdk':
> No such file or directory
> 2010-02-21 21:34:04|7958|13:13|new|utils.pm:run_ssh_command(6260)|SSH
> command executed on vclvm1.csueastbay.edu, command:
> |7958|13:13|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x
> vclvm1.csueastbay.edu 'cp
> /vmfs/volumes/VOL_GEN_1/golden/vmwarewinxp-base7-v0/vmwarewinxp-base7-v0.vmdk
> /vmfs/volumes/VOL_GEN_1/inuse/csuvm10/vmwarewinxp-base7-v0.vmdk' 2>&1
> |7958|13:13|new| returning (1, "cp: cannot stat '/vmfs/volumes...")
> 2010-02-21 21:34:04|7958|13:13|new|esx.pm:load(278)|COPIED VMDK
> SUCCESSFULLY
> 2010-02-21 21:34:04|7958|13:13|new|utils.pm:run_ssh_command(6168)|executing
> SSH command on vclvm1.csueastbay.edu:
> |7958|13:13|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x
> vclvm1.csueastbay.edu 'cp
> /vmfs/volumes/VOL_GEN_1/golden/vmwarewinxp-base7-v0/vmwarewinxp-base7-v0-flat.vmdk
> /vmfs/volumes/VOL_GEN_1/inuse/csuvm10/vmwarewinxp-base7-v0-flat.vmdk' 2>&1
> 2010-02-21 21:34:07|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:07
> 2010-02-21 21:34:12|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:12
> 2010-02-21 21:34:17|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:17
> 2010-02-21 21:34:22|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:22
> 2010-02-21
> 21:34:24|7958|13:13|new|utils.pm:run_ssh_command(6250)|run_ssh_command
> output:
> |7958|13:13|new| cp: cannot stat
> '/vmfs/volumes/VOL_GEN_1/golden/vmwarewinxp-base7-v0/vmwarewinxp-base7-v0-flat.vmdk':
> No such file or directory
> 2010-02-21 21:34:24|7958|13:13|new|utils.pm:run_ssh_command(6260)|SSH
> command executed on vclvm1.csueastbay.edu, command:
> |7958|13:13|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x
> vclvm1.csueastbay.edu 'cp
> /vmfs/volumes/VOL_GEN_1/golden/vmwarewinxp-base7-v0/vmwarewinxp-base7-v0-flat.vmdk
> /vmfs/volumes/VOL_GEN_1/inuse/csuvm10/vmwarewinxp-base7-v0-flat.vmdk' 2>&1
> |7958|13:13|new| returning (1, "cp: cannot stat '/vmfs/volumes...")
> 2010-02-21 21:34:24|7958|13:13|new|utils.pm:run_ssh_command(6168)|executing
> SSH command on vclvm1.csueastbay.edu:
> |7958|13:13|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x
> vclvm1.csueastbay.edu 'grep adapterType
> /vmfs/volumes/VOL_GEN_1/inuse/csuvm10/vmwarewinxp-base7-v0.vmdk 2>&1' 2>&1
> 2010-02-21 21:34:27|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:27
> 2010-02-21 21:34:32|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:32
> 2010-02-21 21:34:37|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:37
> 2010-02-21 21:34:42|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:42
> 2010-02-21
> 21:34:45|7958|13:13|new|utils.pm:run_ssh_command(6250)|run_ssh_command
> output:
> |7958|13:13|new| grep:
> /vmfs/volumes/VOL_GEN_1/inuse/csuvm10/vmwarewinxp-base7-v0.vmdk: No such
> file or directory
> 2010-02-21 21:34:45|7958|13:13|new|utils.pm:run_ssh_command(6260)|SSH
> command executed on vclvm1.csueastbay.edu, command:
> |7958|13:13|new| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p 22 -x
> vclvm1.csueastbay.edu 'grep adapterType
> /vmfs/volumes/VOL_GEN_1/inuse/csuvm10/vmwarewinxp-base7-v0.vmdk 2>&1' 2>&1
> |7958|13:13|new| returning (2, "grep: /vmfs/volumes/VOL_GEN_1/...")
> 2010-02-21 21:34:45|7958|13:13|new|esx.pm:load(342)|eth0 MAC address set
> for vcl assigned
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:34:45|7958|13:13|new|vcld:warning_handler(636)|Use of uninitialized value
> in concatenation (.) or string at
> /usr/local/vcl/bin/../lib/VCL/Module/Provisioning/esx.pm line 353.
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) vcld, warning_handler (line: 636)
> |7958|13:13|new| (-2) esx.pm, load (line: 353)
> |7958|13:13|new| (-3) new.pm, reload_image (line: 665)
> |7958|13:13|new| (-4) new.pm, process (line: 266)
> |7958|13:13|new| (-5) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-6) vcld, main (line: 341)
>
> 2010-02-21 21:34:45|7958|13:13|new|esx.pm:load(353)|eth1 MAC address set
> for vcl assigned
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:34:45|7958|13:13|new|vcld:warning_handler(636)|Use of uninitialized value
> in concatenation (.) or string at
> /usr/local/vcl/bin/../lib/VCL/Module/Provisioning/esx.pm line 354.
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) vcld, warning_handler (line: 636)
> |7958|13:13|new| (-2) esx.pm, load (line: 354)
> |7958|13:13|new| (-3) new.pm, reload_image (line: 665)
> |7958|13:13|new| (-4) new.pm, process (line: 266)
> |7958|13:13|new| (-5) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-6) vcld, main (line: 341)
>
> 2010-02-21 21:34:45|7958|13:13|new|esx.pm:load(376)|wrote vmxarray to
> /tmp/csuvm10.vmx
> 2010-02-21 21:34:45|7958|13:13|new|utils.pm:run_scp_command(6391)|attempt
> 1/3: executing SCP command: /usr/bin/scp -B -i /etc/vcl/vcl.key -P 22 -p -r
> /tmp/csuvm10.vmx
> vclvm1.csueastbay.edu:/vmfs/volumes/VOL_GEN_1/inuse/csuvm10/vmwarewinxp-base7-v0.vmx
> 2>&1
> 2010-02-21 21:34:47|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:47
> 2010-02-21 21:34:52|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:52
> 2010-02-21 21:34:57|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:34:57
> 2010-02-21 21:35:02|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:02
> 2010-02-21 21:35:05|7958|13:13|new|utils.pm:run_scp_command(6441)|scp
> successful: attempt 1/3, exit status: 0, output: none
> 2010-02-21 21:35:05|7958|13:13|new|esx.pm:load(401)|Register Command:
> /usr/lib/vmware-viperl/apps/vm/vmregister.pl --server 'vclvm1' --username
> root --password '******' --vmxpath
> '[VCL]/inuse/csuvm10/vmwarewinxp-base7-v0.vmx' --operation register --vmname
> csuvm10 --pool Resources --hostname 'vclvm1.csueastbay.edu' --datacenter
> 'ha-datacenter'
> 2010-02-21 21:35:07|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:07
> 2010-02-21 21:35:09|7958|13:13|new|esx.pm:load(404)|Registered:
> |7958|13:13|new| SOAP Fault:
> |7958|13:13|new| -----------
> |7958|13:13|new| Fault string: fault.RestrictedVersion.summary
> |7958|13:13|new| Fault detail: RestrictedVersionFault
> 2010-02-21 21:35:09|7958|13:13|new|esx.pm:load(413)|Power on command:
> /usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'vclvm1' --vmname
> csuvm10 --operation poweron --username root --password '*****'
> 2010-02-21 21:35:10|7958|13:13|new|esx.pm:load(416)|Powered on: Virtual
> Machine csuvm10 not found.
> 2010-02-21 21:35:10|7958|13:13|new|esx.pm:load(505)|IP is known for
> csuvm10
> 2010-02-21 21:35:10|7958|13:13|new|esx.pm:load(511)|Waiting for ssh to
> come up on csuvm10
> 2010-02-21 21:35:10|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 1
> 2010-02-21 21:35:13|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:13
> 2010-02-21 21:35:16|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 2
> 2010-02-21 21:35:18|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:18
> 2010-02-21 21:35:21|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 3
> 2010-02-21 21:35:23|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:23
> 2010-02-21 21:35:26|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 4
> 2010-02-21 21:35:28|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:28
> 2010-02-21 21:35:31|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 5
> 2010-02-21 21:35:33|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:33
> 2010-02-21 21:35:37|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 6
> 2010-02-21 21:35:38|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:38
> 2010-02-21 21:35:42|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 7
> 2010-02-21 21:35:43|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:43
> 2010-02-21 21:35:47|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 8
> 2010-02-21 21:35:48|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:48
> 2010-02-21 21:35:52|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 9
> 2010-02-21 21:35:53|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:53
> 2010-02-21 21:35:58|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 10
> 2010-02-21 21:35:58|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:35:58
> 2010-02-21 21:36:03|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:03
> 2010-02-21 21:36:03|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 11
> 2010-02-21 21:36:08|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:08
> 2010-02-21 21:36:08|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 12
> 2010-02-21 21:36:13|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:13
> 2010-02-21 21:36:13|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 13
> 2010-02-21 21:36:18|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:18
> 2010-02-21 21:36:18|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 14
> 2010-02-21 21:36:23|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:23
> 2010-02-21 21:36:24|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 15
> 2010-02-21 21:36:28|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:28
> 2010-02-21 21:36:29|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 16
> 2010-02-21 21:36:33|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:33
> 2010-02-21 21:36:34|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 17
> 2010-02-21 21:36:38|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:38
> 2010-02-21 21:36:39|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 18
> 2010-02-21 21:36:43|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:43
> 2010-02-21 21:36:45|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 19
> 2010-02-21 21:36:48|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:48
> 2010-02-21 21:36:50|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 20
> 2010-02-21 21:36:53|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:53
> 2010-02-21 21:36:55|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 21
> 2010-02-21 21:36:58|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:36:58
> 2010-02-21 21:37:00|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 22
> 2010-02-21 21:37:03|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:03
> 2010-02-21 21:37:05|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 23
> 2010-02-21 21:37:08|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:08
> 2010-02-21 21:37:11|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 24
> 2010-02-21 21:37:13|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:13
> 2010-02-21 21:37:16|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 25
> 2010-02-21 21:37:18|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:18
> 2010-02-21 21:37:21|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 26
> 2010-02-21 21:37:23|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:23
> 2010-02-21 21:37:26|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 27
> 2010-02-21 21:37:28|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:28
> 2010-02-21 21:37:32|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 28
> 2010-02-21 21:37:33|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:33
> 2010-02-21 21:37:37|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 29
> 2010-02-21 21:37:38|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:38
> 2010-02-21 21:37:42|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 30
> 2010-02-21 21:37:43|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:43
> 2010-02-21 21:37:47|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 31
> 2010-02-21 21:37:48|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:48
> 2010-02-21 21:37:53|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 32
> 2010-02-21 21:37:53|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:53
> 2010-02-21 21:37:58|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 33
> 2010-02-21 21:37:58|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:37:58
> 2010-02-21 21:38:03|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 34
> 2010-02-21 21:38:03|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:03
> 2010-02-21 21:38:08|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:08
> 2010-02-21 21:38:08|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 35
> 2010-02-21 21:38:13|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:13
> 2010-02-21 21:38:13|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 36
> 2010-02-21 21:38:18|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:18
> 2010-02-21 21:38:19|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 37
> 2010-02-21 21:38:23|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:23
> 2010-02-21 21:38:24|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 38
> 2010-02-21 21:38:28|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:28
> 2010-02-21 21:38:29|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 39
> 2010-02-21 21:38:33|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:33
> 2010-02-21 21:38:34|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 40
> 2010-02-21 21:38:38|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:38
> 2010-02-21 21:38:40|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 41
> 2010-02-21 21:38:43|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:43
> 2010-02-21 21:38:45|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 42
> 2010-02-21 21:38:48|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:48
> 2010-02-21 21:38:50|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 43
> 2010-02-21 21:38:53|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:53
> 2010-02-21 21:38:55|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 44
> 2010-02-21 21:38:58|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:38:58
> 2010-02-21 21:39:01|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 45
> 2010-02-21 21:39:03|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:39:03
> 2010-02-21 21:39:06|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 46
> 2010-02-21 21:39:08|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:39:08
> 2010-02-21 21:39:11|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 47
> 2010-02-21 21:39:13|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:39:13
> 2010-02-21 21:39:16|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 48
> 2010-02-21 21:39:18|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:39:18
> 2010-02-21 21:39:21|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 49
> 2010-02-21 21:39:23|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:39:23
> 2010-02-21 21:39:27|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 50
> 2010-02-21 21:39:28|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:39:28
> 2010-02-21 21:39:32|7958|13:13|new|esx.pm:load(528)|going to sleep 5
> seconds, waiting for computer to start SSH. Try 51
> 2010-02-21 21:39:33|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:39:33
> 2010-02-21 21:39:37|7958|13:13|new|utils.pm:mail(1339)|SUCCESS -- Sending
> mail To: jwis...@csueastbay.edu,, PROBLEM -- esx.pm
>
> |7958|13:13|new| ---- CRITICAL ----
> |7958|13:13|new| 2010-02-21 21:39:37|7958|13:13|new|esx.pm:load(521)|waited
> acceptable amount of time for sshd to become active, please check csuvm10 on
> vclvm1
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) esx.pm, load (line: 521)
> |7958|13:13|new| (-2) new.pm, reload_image (line: 665)
> |7958|13:13|new| (-3) new.pm, process (line: 266)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:39:37|7958|13:13|new|new.pm:reload_image(670)|vmwarewinxp-base7-v0
> failed to load on csuvm10, returning
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) new.pm, reload_image (line: 670)
> |7958|13:13|new| (-2) new.pm, process (line: 266)
> |7958|13:13|new| (-3) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-4) vcld, main (line: 341)
>
> 2010-02-21 21:39:37|7958|13:13|new|utils.pm:insertloadlog(4701)|inserted
> computer=19, loadimagefailed, vmwarewinxp-base7-v0 failed to load on csuvm10
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21 21:39:37|7958|13:13|new|new.pm:process(313)|failed
> to load csuvm10 with vmwarewinxp-base7-v0
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) new.pm, process (line: 313)
> |7958|13:13|new| (-2) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-3) vcld, main (line: 341)
>
> 2010-02-21
> 21:39:37|7958|13:13|new|DataStructure.pm:get_computer_state_name(1893)|attempting
> to retrieve current state of computer csuvm10 from the database
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:39:37|7958|13:13|new|DataStructure.pm:get_computer_state_name(1913)|zero
> rows were returned from database select
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) DataStructure.pm, get_computer_state_name (line:
> 1913)
> |7958|13:13|new| (-2) State.pm, reservation_failed (line: 266)
> |7958|13:13|new| (-3) new.pm, process (line: 316)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
> 2010-02-21 21:39:37|7958|13:13|new|utils.pm:mail(1339)|SUCCESS -- Sending
> mail To: jwis...@csueastbay.edu,, PROBLEM -- State.pm
>
> |7958|13:13|new| ---- CRITICAL ----
> |7958|13:13|new| 2010-02-21
> 21:39:37|7958|13:13|new|State.pm:reservation_failed(290)|reservation failed
> on csuvm10: process failed after trying to load or make available
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) State.pm, reservation_failed (line: 290)
> |7958|13:13|new| (-2) new.pm, process (line: 316)
> |7958|13:13|new| (-3) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-4) vcld, main (line: 341)
>
> 2010-02-21 21:39:37|7958|13:13|new|utils.pm:insertloadlog(4701)|inserted
> computer=19, failed, process failed after trying to load or make available
> 2010-02-21
> 21:39:37|7958|13:13|new|State.pm:reservation_failed(293)|inserted
> computerloadlog entry
> 2010-02-21 21:39:37|7958|13:13|new|State.pm:reservation_failed(301)|updated
> log ending value to 'failed', logid=35
>
> |7958|13:13|new| ---- WARNING ----
> |7958|13:13|new| 2010-02-21
> 21:39:37|7958|13:13|new|vcld:warning_handler(636)|Use of uninitialized value
> in pattern match (m//) at /usr/local/vcl/bin/../lib/VCL/Module/State.pm line
> 312.
> |7958|13:13|new| ( 0) utils.pm, notify (line: 728)
> |7958|13:13|new| (-1) vcld, warning_handler (line: 636)
> |7958|13:13|new| (-2) State.pm, reservation_failed (line: 312)
> |7958|13:13|new| (-3) new.pm, process (line: 316)
> |7958|13:13|new| (-4) vcld, make_new_child (line: 594)
> |7958|13:13|new| (-5) vcld, main (line: 341)
>
> 2010-02-21
> 21:39:37|7958|13:13|new|utils.pm:update_computer_state(2219)|computer
> 19 state updated to: failed
> 2010-02-21
> 21:39:37|7958|13:13|new|State.pm:reservation_failed(312)|computer csuvm10
> (19) state set to failed
> 2010-02-21 21:39:37|7958|13:13|new|utils.pm:update_request_state(2177)|request
> 13 state updated to: failed, laststate to: new
> 2010-02-21 21:39:37|7958|13:13|new|State.pm:reservation_failed(325)|set
> request state to 'failed'/'new'
> 2010-02-21 21:39:37|7958|13:13|new|utils.pm:is_inblockrequest(6954)|zero
> rows were returned from database select
> 2010-02-21 21:39:37|7958|13:13|new|State.pm:reservation_failed(343)|csuvm10
> is NOT in blockcomputers table
> 2010-02-21 21:39:37|7958|13:13|new|State.pm:reservation_failed(346)|exiting
> 1
> 2010-02-21 21:39:37|7958|13:13|new|State.pm:DESTROY(905)|destructor called,
> ref($self)=VCL::new
> 2010-02-21
> 21:39:37|7958|13:13|new|utils.pm:delete_computerloadlog_reservation(7533)|removing
> computerloadlog entries matching loadstate = begin
> 2010-02-21
> 21:39:37|7958|13:13|new|utils.pm:delete_computerloadlog_reservation(7580)|deleted
> rows from computerloadlog for reservation id=13
> 2010-02-21 21:39:37|7958|13:13|new|State.pm:DESTROY(912)|removed
> computerloadlog rows with loadstate=begin for reservation
> 2010-02-21 21:39:37|7958|13:13|new|State.pm:DESTROY(924)|number of database
> handles state process created: 1
> 2010-02-21 21:39:37|7958|13:13|new|State.pm:DESTROY(933)|process has a
> database handle stored in $ENV{dbh}, attempting disconnect
> 2010-02-21 21:39:37|7958|13:13|new|State.pm:DESTROY(935)|$ENV{dbh}:
> database disconnect successful
> 2010-02-21 21:39:37|7958|13:13|new|State.pm:DESTROY(949)|VCL::new process
> 7958 exiting
> 2010-02-21 21:39:38|7225|vcld:REAPER(744)|VCL process exited for
> reservation 13
> 2010-02-21 21:39:38|7225|vcld:main(165)|lastcheckin time updated for
> management node 1: 2010-02-21 21:39:38
>
>
