You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@vcl.apache.org by Jeffrey Wisman <je...@csueastbay.edu> on 2010/02/22 06:50:54 UTC
Errors creating reservation with new bulk-added computers
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.pm line
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.pm line
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.pm line
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: jwisman@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: jwisman@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