Hello,
We have a VCL 2.2 system running on Cent OS 5.5 and using VMware Server
2.0.2 for provisioning.
I have a windows xp base image which I am try to reserve. The image creation
goes fine, but when the VM boots up the ssh service is disabled. I tried to
manually start the service but the service does not start. Eventually the
management node times out and the reservation fails.
Any ideas what I am missing here?
Thanks.
The vcl logs is:
reservation failed on vclvmh1: process failed after trying to load or make
available
Time: 2011-02-25 10:06:52
PID: 8463
Caller: State.pm:reservation_failed(287)
( 0) utils.pm, notify (line: 630)
(-1) State.pm, reservation_failed (line: 287)
(-2) new.pm, process (line: 332)
(-3) vcld, make_new_child (line: 595)
(-4) vcld, main (line: 342)
RECENT LOG ENTRIES FOR THIS PROCESS:
2011-02-25
10:04:01|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 48: code
returned false, seconds elapsed/remaining: 730/170, sleeping for 15 seconds
2011-02-25
10:04:16|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 49:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:04:16|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:04:16|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:04:16|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:04:16|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 49: code
returned false, seconds elapsed/remaining: 745/155, sleeping for 15 seconds
2011-02-25
10:04:31|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 50:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:04:31|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:04:32|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:04:32|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:04:32|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 50: code
returned false, seconds elapsed/remaining: 761/139, sleeping for 15 seconds
2011-02-25
10:04:47|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 51:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:04:47|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:04:47|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:04:47|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:04:47|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 51: code
returned false, seconds elapsed/remaining: 776/124, sleeping for 15 seconds
2011-02-25
10:05:02|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 52:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:05:02|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:05:03|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:05:03|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:05:03|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 52: code
returned false, seconds elapsed/remaining: 792/108, sleeping for 15 seconds
2011-02-25
10:05:18|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 53:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:05:18|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:05:19|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:05:19|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:05:19|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 53: code
returned false, seconds elapsed/remaining: 808/92, sleeping for 15 seconds
2011-02-25
10:05:34|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 54:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:05:34|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:05:34|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:05:34|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:05:34|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 54: code
returned false, seconds elapsed/remaining: 823/77, sleeping for 15 seconds
2011-02-25
10:05:49|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 55:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:05:49|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:05:50|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:05:50|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:05:50|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 55: code
returned false, seconds elapsed/remaining: 839/61, sleeping for 15 seconds
2011-02-25
10:06:05|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 56:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:06:05|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:06:05|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:06:05|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:06:05|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 56: code
returned false, seconds elapsed/remaining: 854/46, sleeping for 15 seconds
2011-02-25
10:06:20|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 57:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:06:20|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:06:21|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:06:21|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:06:21|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 57: code
returned false, seconds elapsed/remaining: 870/30, sleeping for 15 seconds
2011-02-25
10:06:36|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 58:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:06:36|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:06:37|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:06:37|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:06:37|8463|45:45|reload|Module.pm:code_loop_timeout(409)|attempt 58: code
returned false, seconds elapsed/remaining: 886/14, sleeping for 15 seconds
2011-02-25
10:06:52|8463|45:45|reload|Module.pm:code_loop_timeout(413)|attempt 59:
waiting for vclvmh1 to respond to SSH
2011-02-25 10:06:52|8463|45:45|reload|utils.pm:nmap_port(2707)|port 22 is
closed on vclvmh1
2011-02-25 10:06:52|8463|45:45|reload|utils.pm:nmap_port(2707)|port 24 is
closed on vclvmh1
2011-02-25 10:06:52|8463|45:45|reload|OS.pm:is_ssh_responding(416)|vclvmh1
is NOT responding to SSH, ports 22 or 24 are both closed
2011-02-25
10:06:52|8463|45:45|reload|Module.pm:code_loop_timeout(421)|waiting for
vclvmh1 to respond to SSH, code did not return true after waiting 900
seconds
|8463|45:45|reload| ---- WARNING ----
|8463|45:45|reload| 2011-02-25
|8463|10:06:52|8463|45:45|reload|OS.pm:wait_for_response(485)|failed to
|8463|connect to vclvmh1 via SSH after 900 seconds 45:45|reload| ( 0)
|8463|utils.pm, notify (line: 630) 45:45|reload| (-1) OS.pm,
|8463|wait_for_response (line: 485) 45:45|reload| (-2) Windows.pm,
|8463|post_load (line: 558) 45:45|reload| (-3) VMware.pm, load (line:
|8463|362) 45:45|reload| (-4) new.pm, reload_image (line: 687)
|8463|45:45|reload| (-5) new.pm, process (line: 282) 45:45|reload| (-6)
|8463|vcld, make_new_child (line: 595) 45:45|reload| ---- WARNING ----
|8463|45:45|reload| 2011-02-25
|8463|10:06:52|8463|45:45|reload|Windows.pm:post_load(559)|vclvmh1 never
|8463|responded to SSH 45:45|reload| ( 0) utils.pm, notify (line: 630)
|8463|45:45|reload| (-1) Windows.pm, post_load (line: 559) 45:45|reload|
|8463|(-2) VMware.pm, load (line: 362) 45:45|reload| (-3) new.pm,
|8463|reload_image (line: 687) 45:45|reload| (-4) new.pm, process (line:
|8463|282) 45:45|reload| (-5) vcld, make_new_child (line: 595)
|8463|45:45|reload| (-6) vcld, main (line: 342) 45:45|reload| ----
|8463|WARNING ---- 45:45|reload| 2011-02-25
|8463|10:06:52|8463|45:45|reload|VMware.pm:load(367)|failed to perform
|8463|OS post-load tasks on VM vclvmh1 on VM host: vhost2 45:45|reload|
|8463|( 0) utils.pm, notify (line: 630) 45:45|reload| (-1) VMware.pm,
|8463|load (line: 367) 45:45|reload| (-2) new.pm, reload_image (line:
|8463|687) 45:45|reload| (-3) new.pm, process (line: 282) 45:45|reload|
|8463|(-4) vcld, make_new_child (line: 595) 45:45|reload| (-5) vcld,
|8463|main (line: 342) 45:45|reload| ---- WARNING ---- 45:45|reload|
|8463|2011-02-25
|8463|10:06:52|8463|45:45|reload|new.pm:reload_image(692)|vmwarewinxp-xp
|8463|basev000312-v0 failed to load on vclvmh1, returning 45:45|reload|
|8463|( 0) utils.pm, notify (line: 630) 45:45|reload| (-1) new.pm,
|8463|reload_image (line: 692) 45:45|reload| (-2) new.pm, process (line:
|8463|282) 45:45|reload| (-3) vcld, make_new_child (line: 595)
|8463|45:45|reload| (-4) vcld, main (line: 342)
2011-02-25 10:06:52|8463|45:45|reload|utils.pm:insertloadlog(3933)|inserted
computer=4, loadimagefailed, vmwarewinxp-xpbasev000312-v0 failed to load on
vclvmh1
|8463|45:45|reload| ---- WARNING ----
|8463|45:45|reload| 2011-02-25
|8463|10:06:52|8463|45:45|reload|new.pm:process(329)|failed to load
|8463|vclvmh1 with vmwarewinxp-xpbasev000312-v0 45:45|reload| ( 0)
|8463|utils.pm, notify (line: 630) 45:45|reload| (-1) new.pm, process
|8463|(line: 329) 45:45|reload| (-2) vcld, make_new_child (line: 595)
|8463|45:45|reload| (-3) vcld, main (line: 342)
2011-02-25
10:06:52|8463|45:45|reload|DataStructure.pm:get_computer_state_name(2227)|at
tempting to retrieve current state of computer vclvmh1 from the database
2011-02-25
10:06:52|8463|45:45|reload|DataStructure.pm:get_computer_state_name(2258)|re
trieved current state of computer vclvmh1 from the database: reloading
2011-02-25 10:06:52|8463|45:45|reload|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{45}{computer}{state}{name}
|8463|45:45|reload| computer_state_name = reloading
Junaid Ali
System Engineer,
Office of Technology Services/IIT,
10W, 31st Street,
Stuart Building Room # 007,
Chicago, IL - 60616
Ph (O): 312-567-5836
Ph (F): 312-567-5968
