VCL SSH time out errors

[Alexander Patterson <al...@csueastbay.edu>]

VCL 2.2.1

I'm still getting about 5 to 10 of these same errors daily. I have the
machine it boost up but the machine take to long to SSH in and end up
failing?

Here is the error log Any way to fix this?
reservation failed on vmguest-171: process failed after trying to load
or make available
------------------------------------------------------------------------
time: 2012-12-06 11:46:56
caller: State.pm:reservation_failed(213)
( 0) State.pm, reservation_failed (line: 213)
(-1) new.pm, process (line: 298)
(-2) vcld, make_new_child (line: 568)
(-3) vcld, main (line: 346)
------------------------------------------------------------------------
management node: vclnfs01.calstate.edu
reservation PID: 2548
parent vcld PID: 5613

request ID: 101346
reservation ID: 101082
request state/laststate: new/new
request start time: 2012-12-06 11:30:00
request end time: 2012-12-06 12:45:00
for imaging: no
log ID: 41936

computer: vmguest-171
computer id: 179
computer type: virtualmachine
computer eth0 MAC address: 00:50:56:2a:3c:52
computer eth1 MAC address: 00:50:56:2a:3c:53
computer private IP address: 10.10.10.79
computer public IP address: 137.145.56.192
computer in block allocation: no
provisioning module: VCL::Module::Provisioning::VMware::VMware

vm host: vclesxi20
vm host ID: 1
vm host computer ID: 1
vm profile: VMware ESXI Network Storage
vm profile VM path: /vmfs/volumes/netappfiler02-sata1
vm profile repository path:
vm profile datastore path: /vmfs/volumes/netappfiler02-sata1
vm profile disk type: networkdisk

image: vmwarewincw7vista-ITSTrain150-v6
image display name: ITS Train
image ID: 150
image revision ID: 367
image size: 33792 MB
use Sysprep: no
root access: yes
image owner ID: 10
image owner affiliation: CSUEB
image revision date created: 2012-05-04 14:04:30
image revision production: yes
OS module: VCL::Module::OS::Windows::Version_6::Vista
image revision comments: Updated

user: kj3557
user name: Dylan McClintock
user ID: 279
user affiliation: CSUEB
------------------------------------------------------------------------
RECENT LOG ENTRIES FOR THIS PROCESS:
2012-12-06 11:42:29|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
18: waiting for vmguest-171 to respond to SSH
2012-12-06 11:42:30|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:42:30|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
18: code returned false, seconds elapsed/remaining: 349/251, sleeping
for 20 seconds
2012-12-06 11:42:50|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
19: waiting for vmguest-171 to respond to SSH
2012-12-06 11:42:50|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:42:50|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
19: code returned false, seconds elapsed/remaining: 369/231, sleeping
for 20 seconds
2012-12-06 11:43:10|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
20: waiting for vmguest-171 to respond to SSH
2012-12-06 11:43:11|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:43:11|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
20: code returned false, seconds elapsed/remaining: 390/210, sleeping
for 20 seconds
2012-12-06 11:43:31|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
21: waiting for vmguest-171 to respond to SSH
2012-12-06 11:43:31|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:43:31|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
21: code returned false, seconds elapsed/remaining: 410/190, sleeping
for 20 seconds
2012-12-06 11:43:51|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
22: waiting for vmguest-171 to respond to SSH
2012-12-06 11:43:51|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:43:51|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
22: code returned false, seconds elapsed/remaining: 430/170, sleeping
for 20 seconds
2012-12-06 11:44:11|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
23: waiting for vmguest-171 to respond to SSH
2012-12-06 11:44:12|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:44:12|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
23: code returned false, seconds elapsed/remaining: 451/149, sleeping
for 20 seconds
2012-12-06 11:44:32|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
24: waiting for vmguest-171 to respond to SSH
2012-12-06 11:44:32|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:44:32|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
24: code returned false, seconds elapsed/remaining: 471/129, sleeping
for 20 seconds
2012-12-06 11:44:52|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
25: waiting for vmguest-171 to respond to SSH
2012-12-06 11:44:53|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:44:53|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
25: code returned false, seconds elapsed/remaining: 492/108, sleeping
for 20 seconds
2012-12-06 11:45:13|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
26: waiting for vmguest-171 to respond to SSH
2012-12-06 11:45:13|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:45:13|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
26: code returned false, seconds elapsed/remaining: 512/88, sleeping
for 20 seconds
2012-12-06 11:45:33|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
27: waiting for vmguest-171 to respond to SSH
2012-12-06 11:45:34|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:45:34|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
27: code returned false, seconds elapsed/remaining: 533/67, sleeping
for 20 seconds
2012-12-06 11:45:54|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
28: waiting for vmguest-171 to respond to SSH
2012-12-06 11:45:54|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:45:54|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
28: code returned false, seconds elapsed/remaining: 553/47, sleeping
for 20 seconds
2012-12-06 11:46:14|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
29: waiting for vmguest-171 to respond to SSH
2012-12-06 11:46:15|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:46:15|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
29: code returned false, seconds elapsed/remaining: 574/26, sleeping
for 20 seconds
2012-12-06 11:46:35|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
30: waiting for vmguest-171 to respond to SSH
2012-12-06 11:46:35|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:46:35|2548|101346:101082|new|Module.pm:code_loop_timeout(755)|attempt
30: code returned false, seconds elapsed/remaining: 594/6, sleeping
for 20 seconds
2012-12-06 11:46:55|2548|101346:101082|new|Module.pm:code_loop_timeout(759)|attempt
31: waiting for vmguest-171 to respond to SSH
2012-12-06 11:46:56|2548|101346:101082|new|OS.pm:is_ssh_responding(386)|vmguest-171
is NOT responding to SSH, ports 22 or 24 are both closed
2012-12-06 11:46:56|2548|101346:101082|new|Module.pm:code_loop_timeout(767)|waiting
for vmguest-171 to respond to SSH, code did not return true after
waiting 600 seconds
|2548|101346:101082|new| ---- WARNING ----
|2548|101346:101082|new| 2012-12-06
11:46:56|2548|101346:101082|new|OS.pm:wait_for_response(465)|failed to
connect to vmguest-171 via SSH after 600 seconds
|2548|101346:101082|new| ( 0) OS.pm, wait_for_response (line: 465)
|2548|101346:101082|new| (-1) Version_6.pm, wait_for_response (line: 1767)
|2548|101346:101082|new| (-2) Windows.pm, post_load (line: 591)
|2548|101346:101082|new| (-3) Version_6.pm, post_load (line: 194)
|2548|101346:101082|new| (-4) VMware.pm, load (line: 415)
|2548|101346:101082|new| (-5) new.pm, reload_image (line: 618)
|2548|101346:101082|new| ---- WARNING ----
|2548|101346:101082|new| 2012-12-06
11:46:56|2548|101346:101082|new|Windows.pm:post_load(592)|vmguest-171
never responded to SSH
|2548|101346:101082|new| ( 0) Windows.pm, post_load (line: 592)
|2548|101346:101082|new| (-1) Version_6.pm, post_load (line: 194)
|2548|101346:101082|new| (-2) VMware.pm, load (line: 415)
|2548|101346:101082|new| (-3) new.pm, reload_image (line: 618)
|2548|101346:101082|new| (-4) new.pm, process (line: 248)
|2548|101346:101082|new| (-5) vcld, make_new_child (line: 568)
|2548|101346:101082|new| ---- WARNING ----
|2548|101346:101082|new| 2012-12-06
11:46:56|2548|101346:101082|new|Version_6.pm:post_load(198)|failed to
execute parent class post_load() subroutine
|2548|101346:101082|new| ( 0) Version_6.pm, post_load (line: 198)
|2548|101346:101082|new| (-1) VMware.pm, load (line: 415)
|2548|101346:101082|new| (-2) new.pm, reload_image (line: 618)
|2548|101346:101082|new| (-3) new.pm, process (line: 248)
|2548|101346:101082|new| (-4) vcld, make_new_child (line: 568)
|2548|101346:101082|new| (-5) vcld, main (line: 346)
|2548|101346:101082|new| ---- WARNING ----
|2548|101346:101082|new| 2012-12-06
11:46:56|2548|101346:101082|new|VMware.pm:load(419)|failed to perform
OS post-load tasks on VM vmguest-171 on VM host: vclesxi20
|2548|101346:101082|new| ( 0) VMware.pm, load (line: 419)
|2548|101346:101082|new| (-1) new.pm, reload_image (line: 618)
|2548|101346:101082|new| (-2) new.pm, process (line: 248)
|2548|101346:101082|new| (-3) vcld, make_new_child (line: 568)
|2548|101346:101082|new| (-4) vcld, main (line: 346)
|2548|101346:101082|new| ---- WARNING ----
|2548|101346:101082|new| 2012-12-06
11:46:56|2548|101346:101082|new|new.pm:reload_image(623)|vmwarewincw7vista-ITSTrain150-v6
failed to load on vmguest-171, returning
|2548|101346:101082|new| ( 0) new.pm, reload_image (line: 623)
|2548|101346:101082|new| (-1) new.pm, process (line: 248)
|2548|101346:101082|new| (-2) vcld, make_new_child (line: 568)
|2548|101346:101082|new| (-3) vcld, main (line: 346)
2012-12-06 11:46:56|2548|101346:101082|new|utils.pm:insertloadlog(3875)|inserted
computer=179, loadimagefailed, vmwarewincw7vista-ITSTrain150-v6 failed
to load on vmguest-171
|2548|101346:101082|new| ---- WARNING ----
|2548|101346:101082|new| 2012-12-06
11:46:56|2548|101346:101082|new|new.pm:process(295)|failed to load
vmguest-171 with vmwarewincw7vista-ITSTrain150-v6
|2548|101346:101082|new| ( 0) new.pm, process (line: 295)
|2548|101346:101082|new| (-1) vcld, make_new_child (line: 568)
|2548|101346:101082|new| (-2) vcld, main (line: 346)
2012-12-06 11:46:56|2548|101346:101082|new|DataStructure.pm:get_computer_state_name(2305)|attempting
to retrieve current state of computer vmguest-171 from the database
2012-12-06 11:46:56|2548|101346:101082|new|DataStructure.pm:get_computer_state_name(2336)|retrieved
current state of computer vmguest-171 from the database: reloading
2012-12-06 11:46:56|2548|101346:101082|new|DataStructure.pm:_automethod(834)|data
structure updated:
$self->request_data->{reservation}{101082}{computer}{state}{name}
|2548|101346:101082|new| computer_state_name = reloading
2012-12-06 11:46:56|2548|101346:101082|new|DataStructure.pm:get_computer_private_ip_address(1581)|attempting
to retrieve private IP address for computer: vmguest-171
2012-12-06 11:46:56|2548|101346:101082|new|DataStructure.pm:get_computer_private_ip_address(1585)|retrieved
contents of /etc/hosts on this management node, contains 531 lines
2012-12-06 11:46:56|2548|101346:101082|new|DataStructure.pm:get_computer_private_ip_address(1645)|returning
IP address from /etc/hosts file: 10.10.10.79
2012-12-06 11:46:56|2548|101346:101082|new|utils.pm:is_inblockrequest(6163)|zero
rows were returned from database select
2012-12-06 11:46:56|2548|101346:101082|new|DataStructure.pm:get_image_affiliation_name(2035)|image
owner id: 10
2012-12-06 11:46:56|2548|101346:101082|new|utils.pm:getnewdbh(2709)|database
requested (information_schema) does not match handle stored in
$ENV{dbh} (vcl:localhost)
2012-12-06 11:46:56|2548|101346:101082|new|utils.pm:getnewdbh(2760)|database
handle stored in $ENV{dbh}
2012-12-06 11:46:57|2548|101346:101082|new|DataStructure.pm:retrieve_user_data(1352)|attempting
to retrieve and store data for user: user.id = '10'
2012-12-06 11:46:57|2548|101346:101082|new|utils.pm:getnewdbh(2709)|database
requested (vcl) does not match handle stored in $ENV{dbh}
(information_schema:localhost)
2012-12-06 11:46:57|2548|101346:101082|new|utils.pm:getnewdbh(2760)|database
handle stored in $ENV{dbh}
2012-12-06 11:46:57|2548|101346:101082|new|DataStructure.pm:retrieve_user_data(1415)|data
has been retrieved for user: wv4973 (id: 10)

-- 
Thanks,
Alex  Patterson
User Support Services
Operating System Analyst
California State University, East Bay