Hi Lei,
The issue in the log output is related to ssh is not responding.
Double check that you can log into vmguest-1 or vmguest-3 via ssh (you
have a couple of different reservations in your log output).
Things to check are to;
make sure your vmguest-X machines are getting the correct dhcp IP address.
make sure cygwin sshd service is started.
Aaron
On Wed, Nov 2, 2011 at 2:22 PM, Huang,Lei <lhu...@pvamu.edu> wrote:
> Hi All,
>
> I have encountered another problem after upgraded to 2.2.1. Per Aaron's
> suggestion, I changed my Vmguests provisioning engine to Vmware from
> Vmware Server GSX. However, my Windows XP image failed to reserve after
> the change. From the log, I found that it looks for
> 'C:/Windows/System32/qwinsta.exe' and 'C:/Windows/System32/sc.exe config
> sshd start= auto'. However, both them are not found on my XP image. Do I
> need to update my XP image? The image works fine on Vmware Server GSX
> provision engine. The following is the log.
>
> Thanks,
> Lei
>
> ======================
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:21|15314|780:780|new|Windows.pm:is_64_bit(8095)|unable to find
> registry value line in reg.exe output:
> |15314|780:780|new| bash: reg.exe: command not found
> |15314|780:780|new| ( 0) Windows.pm, is_64_bit (line: 8095)
> |15314|780:780|new| (-1) Windows.pm, get_system32_path (line: 8146)
> |15314|780:780|new| (-2) Windows.pm, user_logged_in (line: 8342)
> |15314|780:780|new| (-3) Windows.pm, wait_for_logoff (line: 8440)
> |15314|780:780|new| (-4) Windows.pm, post_load (line: 602)
> |15314|780:780|new| (-5) VMware.pm, load (line: 415)
>
> 2011-11-02
> 12:58:21|15314|780:780|new|Windows.pm:get_system32_path(8152)|32-bit
> Windows OS installed on vmguest-3, using C:/Windows/System32
> 2011-11-02
> 12:58:21|15314|780:780|new|Windows.pm:user_logged_in(8356)|checking if
> root is logged in to vmguest-3
> 2011-11-02
> 12:58:21|15314|780:780|new|utils.pm:run_ssh_command(5380)|executing SSH
> command on vmguest-3:
> |15314|780:780|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o
> StrictHostKeyChecking=no -l root -p 22 -x vmguest-3
> 'C:/Windows/System32/qwinsta.exe' 2>&1
> 2011-11-02
> 12:58:25|15241|779:779|new|Module.pm:code_loop_timeout(759)|attempt 5:
> waiting for vmguest-1 to respond to SSH
> 2011-11-02
> 12:58:25|15241|779:779|new|OS.pm:is_ssh_responding(386)|vmguest-1 is NOT
> responding to SSH, ports 22 or 24 are both closed
> 2011-11-02
> 12:58:25|15241|779:779|new|Module.pm:code_loop_timeout(755)|attempt 5:
> code returned false, seconds elapsed/remaining: 34/866, sleeping for 8
> seconds
> 2011-11-02 12:58:26|12831|vcld:main(167)|lastcheckin time updated for
> management node 1: 2011-11-02 12:58:26
> 2011-11-02
> 12:58:26|15410|778:778|reserved|DataStructure.pm:get_reservation_remote_ip(
> 1093)|reservation remote IP is not defined
> 2011-11-02
> 12:58:27|15314|780:780|new|utils.pm:run_ssh_command(5464)|run_ssh_command
> output:
> |15314|780:780|new| bash: C:/Windows/System32/qwinsta.exe: No such file or
> directory
> 2011-11-02 12:58:27|15314|780:780|new|utils.pm:run_ssh_command(5474)|SSH
> command executed on vmguest-3, command:
> |15314|780:780|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o
> StrictHostKeyChecking=no -l root -p 22 -x vmguest-3
> 'C:/Windows/System32/qwinsta.exe' 2>&1
> |15314|780:780|new| returning (127, "bash: C:/Windows/System32/qwin...")
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:27|15314|780:780|new|Windows.pm:user_logged_in(8361)|failed to run
> qwinsta.exe on vmguest-3, exit status: 127, output:
> |15314|780:780|new| bash: C:/Windows/System32/qwinsta.exe: No such file or
> directory
> |15314|780:780|new| ( 0) Windows.pm, user_logged_in (line: 8361)
> |15314|780:780|new| (-1) Windows.pm, wait_for_logoff (line: 8440)
> |15314|780:780|new| (-2) Windows.pm, post_load (line: 602)
> |15314|780:780|new| (-3) VMware.pm, load (line: 415)
> |15314|780:780|new| (-4) new.pm, reload_image (line: 618)
> |15314|780:780|new| (-5) new.pm, process (line: 248)
>
> 2011-11-02
> 12:58:27|15314|780:780|new|Windows.pm:wait_for_logoff(8441)|root is NOT
> logged in to vmguest-3, returning 1
> 2011-11-02
> 12:58:27|15314|780:780|new|utils.pm:run_ssh_command(5380)|executing SSH
> command on vmguest-3:
> |15314|780:780|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o
> StrictHostKeyChecking=no -l root -p 22 -x vmguest-3
> 'C:/Windows/System32/qwinsta.exe' 2>&1
> 2011-11-02 12:58:31|12831|vcld:main(167)|lastcheckin time updated for
> management node 1: 2011-11-02 12:58:31
> 2011-11-02
> 12:58:31|15410|778:778|reserved|DataStructure.pm:get_reservation_remote_ip(
> 1093)|reservation remote IP is not defined
> 2011-11-02
> 12:58:32|15314|780:780|new|utils.pm:run_ssh_command(5464)|run_ssh_command
> output:
> |15314|780:780|new| bash: C:/Windows/System32/qwinsta.exe: No such file or
> directory
> 2011-11-02 12:58:32|15314|780:780|new|utils.pm:run_ssh_command(5474)|SSH
> command executed on vmguest-3, command:
> |15314|780:780|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o
> StrictHostKeyChecking=no -l root -p 22 -x vmguest-3
> 'C:/Windows/System32/qwinsta.exe' 2>&1
> |15314|780:780|new| returning (127, "bash: C:/Windows/System32/qwin...")
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:32|15314|780:780|new|Windows.pm:logoff_users(1437)|failed to run
> qwinsta.exe on vmguest-3, exit status: 127, output:
> |15314|780:780|new| bash: C:/Windows/System32/qwinsta.exe: No such file or
> directory
> |15314|780:780|new| ( 0) Windows.pm, logoff_users (line: 1437)
> |15314|780:780|new| (-1) Windows.pm, post_load (line: 615)
> |15314|780:780|new| (-2) VMware.pm, load (line: 415)
> |15314|780:780|new| (-3) new.pm, reload_image (line: 618)
> |15314|780:780|new| (-4) new.pm, process (line: 248)
> |15314|780:780|new| (-5) vcld, make_new_child (line: 568)
>
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:32|15314|780:780|new|Windows.pm:post_load(615)|failed to log off all
> currently logged in users
> |15314|780:780|new| ( 0) Windows.pm, post_load (line: 615)
> |15314|780:780|new| (-1) VMware.pm, load (line: 415)
> |15314|780:780|new| (-2) new.pm, reload_image (line: 618)
> |15314|780:780|new| (-3) new.pm, process (line: 248)
> |15314|780:780|new| (-4) vcld, make_new_child (line: 568)
> |15314|780:780|new| (-5) vcld, main (line: 346)
>
> 2011-11-02
> 12:58:33|15241|779:779|new|Module.pm:code_loop_timeout(759)|attempt 6:
> waiting for vmguest-1 to respond to SSH
> 2011-11-02
> 12:58:34|15241|779:779|new|OS.pm:is_ssh_responding(386)|vmguest-1 is NOT
> responding to SSH, ports 22 or 24 are both closed
> 2011-11-02
> 12:58:34|15241|779:779|new|Module.pm:code_loop_timeout(755)|attempt 6:
> code returned false, seconds elapsed/remaining: 43/857, sleeping for 8
> seconds
> 2011-11-02 12:58:36|12831|vcld:main(167)|lastcheckin time updated for
> management node 1: 2011-11-02 12:58:36
> 2011-11-02
> 12:58:36|15410|778:778|reserved|DataStructure.pm:get_reservation_remote_ip(
> 1093)|reservation remote IP is not defined
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:37|15314|780:780|new|Windows.pm:set_file_owner(1398)|error occurred
> setting root as the owner of /home/root, error output:
> |15314|780:780|new| bash: /usr/bin/chown.exe: No such file or directory
> |15314|780:780|new| ( 0) Windows.pm, set_file_owner (line: 1398)
> |15314|780:780|new| (-1) Windows.pm, post_load (line: 625)
> |15314|780:780|new| (-2) VMware.pm, load (line: 415)
> |15314|780:780|new| (-3) new.pm, reload_image (line: 618)
> |15314|780:780|new| (-4) new.pm, process (line: 248)
> |15314|780:780|new| (-5) vcld, make_new_child (line: 568)
>
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:37|15314|780:780|new|Windows.pm:post_load(625)|unable to set root as
> the owner of /home/root
> |15314|780:780|new| ( 0) Windows.pm, post_load (line: 625)
> |15314|780:780|new| (-1) VMware.pm, load (line: 415)
> |15314|780:780|new| (-2) new.pm, reload_image (line: 618)
> |15314|780:780|new| (-3) new.pm, process (line: 248)
> |15314|780:780|new| (-4) vcld, make_new_child (line: 568)
> |15314|780:780|new| (-5) vcld, main (line: 346)
>
> 2011-11-02
> 12:58:37|15314|780:780|new|utils.pm:run_ssh_command(5380)|executing SSH
> command on vmguest-3:
> |15314|780:780|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o
> StrictHostKeyChecking=no -l root -p 22 -x vmguest-3
> 'C:/Windows/System32/sc.exe config sshd start= auto' 2>&1
> 2011-11-02 12:58:41|12831|vcld:main(167)|lastcheckin time updated for
> management node 1: 2011-11-02 12:58:41
> 2011-11-02
> 12:58:41|15410|778:778|reserved|DataStructure.pm:get_reservation_remote_ip(
> 1093)|reservation remote IP is not defined
> 2011-11-02
> 12:58:42|15241|779:779|new|Module.pm:code_loop_timeout(759)|attempt 7:
> waiting for vmguest-1 to respond to SSH
> 2011-11-02
> 12:58:42|15241|779:779|new|OS.pm:is_ssh_responding(386)|vmguest-1 is NOT
> responding to SSH, ports 22 or 24 are both closed
> 2011-11-02
> 12:58:42|15241|779:779|new|Module.pm:code_loop_timeout(755)|attempt 7:
> code returned false, seconds elapsed/remaining: 51/849, sleeping for 8
> seconds
> 2011-11-02
> 12:58:43|15314|780:780|new|utils.pm:run_ssh_command(5464)|run_ssh_command
> output:
> |15314|780:780|new| bash: C:/Windows/System32/sc.exe: No such file or
> directory
> 2011-11-02 12:58:43|15314|780:780|new|utils.pm:run_ssh_command(5474)|SSH
> command executed on vmguest-3, command:
> |15314|780:780|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o
> StrictHostKeyChecking=no -l root -p 22 -x vmguest-3
> 'C:/Windows/System32/sc.exe config sshd start= auto' 2>&1
> |15314|780:780|new| returning (127, "bash: C:/Windows/System32/sc.e...")
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:43|15314|780:780|new|Windows.pm:set_service_startup_mode(3644)|failed
> to set sshd service startup mode to auto, exit status: 127, output:
> |15314|780:780|new| bash: C:/Windows/System32/sc.exe: No such file or
> directory
> |15314|780:780|new| ( 0) Windows.pm, set_service_startup_mode (line: 3644)
> |15314|780:780|new| (-1) Windows.pm, post_load (line: 639)
> |15314|780:780|new| (-2) VMware.pm, load (line: 415)
> |15314|780:780|new| (-3) new.pm, reload_image (line: 618)
> |15314|780:780|new| (-4) new.pm, process (line: 248)
> |15314|780:780|new| (-5) vcld, make_new_child (line: 568)
>
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:43|15314|780:780|new|Windows.pm:post_load(640)|unable to set sshd
> service startup mode to auto
> |15314|780:780|new| ( 0) Windows.pm, post_load (line: 640)
> |15314|780:780|new| (-1) VMware.pm, load (line: 415)
> |15314|780:780|new| (-2) new.pm, reload_image (line: 618)
> |15314|780:780|new| (-3) new.pm, process (line: 248)
> |15314|780:780|new| (-4) vcld, make_new_child (line: 568)
> |15314|780:780|new| (-5) vcld, main (line: 346)
>
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:43|15314|780:780|new|VMware.pm:load(419)|failed to perform OS
> post-load tasks on VM vmguest-3 on VM host: CSB303
> |15314|780:780|new| ( 0) VMware.pm, load (line: 419)
> |15314|780:780|new| (-1) new.pm, reload_image (line: 618)
> |15314|780:780|new| (-2) new.pm, process (line: 248)
> |15314|780:780|new| (-3) vcld, make_new_child (line: 568)
> |15314|780:780|new| (-4) vcld, main (line: 346)
>
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:43|15314|780:780|new|new.pm:reload_image(623)|vmwarewinxp-WindowsXPwi
> thVisualStudio32-v0 failed to load on vmguest-3, returning
> |15314|780:780|new| ( 0) new.pm, reload_image (line: 623)
> |15314|780:780|new| (-1) new.pm, process (line: 248)
> |15314|780:780|new| (-2) vcld, make_new_child (line: 568)
> |15314|780:780|new| (-3) vcld, main (line: 346)
>
> 2011-11-02
> 12:58:43|15314|780:780|new|utils.pm:insertloadlog(3875)|inserted
> computer=4, loadimagefailed, vmwarewinxp-WindowsXPwithVisualStudio32-v0
> failed to load on vmguest-3
>
> |15314|780:780|new| ---- WARNING ----
> |15314|780:780|new| 2011-11-02
> 12:58:43|15314|780:780|new|new.pm:process(295)|failed to load vmguest-3
> with vmwarewinxp-WindowsXPwithVisualStudio32-v0
> |15314|780:780|new| ( 0) new.pm, process (line: 295)
> |15314|780:780|new| (-1) vcld, make_new_child (line: 568)
> |15314|780:780|new| (-2) vcld, main (line: 346)
>
> 2011-11-02
> 12:58:43|15314|780:780|new|DataStructure.pm:get_computer_state_name(2305)|a
> ttempting to retrieve current state of computer vmguest-3 from the database
> 2011-11-02
> 12:58:43|15314|780:780|new|DataStructure.pm:get_computer_state_name(2336)|r
> etrieved current state of computer vmguest-3 from the database: reloading
> 2011-11-02
> 12:58:43|15314|780:780|new|DataStructure.pm:_automethod(834)|data
> structure updated:
> $self->request_data->{reservation}{780}{computer}{state}{name}
> |15314|780:780|new| computer_state_name = reloading
> 2011-11-02
> 12:58:43|15314|780:780|new|DataStructure.pm:get_computer_private_ip_address
> (1581)|attempting to retrieve private IP address for computer: vmguest-3
> 2011-11-02
> 12:58:43|15314|780:780|new|DataStructure.pm:get_computer_private_ip_address
> (1585)|retrieved contents of /etc/hosts on this management node, contains
> 44 lines
> 2011-11-02
> 12:58:43|15314|780:780|new|DataStructure.pm:get_computer_private_ip_address
> (1645)|returning IP address from /etc/hosts file: 10.10.10.4
> 2011-11-02
> 12:58:43|15314|780:780|new|utils.pm:is_inblockrequest(6163)|zero rows were
> returned from database select
> 2011-11-02
> 12:58:43|15314|780:780|new|DataStructure.pm:get_image_affiliation_name(2035
> )|image owner id: 1
> 2011-11-02 12:58:43|15314|780:780|new|utils.pm:getnewdbh(2709)|database
> requested (information_schema) does not match handle stored in $ENV{dbh}
> (vcl:localhost)
> 2011-11-02 12:58:43|15314|780:780|new|utils.pm:getnewdbh(2760)|database
> handle stored in $ENV{dbh}
> 2011-11-02
> 12:58:43|15314|780:780|new|DataStructure.pm:retrieve_user_data(1352)|attemp
> ting to retrieve and store data for user: user.id = '1'
> 2011-11-02 12:58:43|15314|780:780|new|utils.pm:getnewdbh(2709)|database
> requested (vcl) does not match handle stored in $ENV{dbh}
> (information_schema:localhost)
> 2011-11-02 12:58:43|15314|780:780|new|utils.pm:getnewdbh(2760)|database
> handle stored in $ENV{dbh}
> 2011-11-02
> 12:58:43|15314|780:780|new|DataStructure.pm:retrieve_user_data(1415)|data
> has been retrieved for user: admin (id: 1)
> 2011-11-02 12:58:43|15314|780:780|new|utils.pm:mail(1268)|SUCCESS --
> Sending mail To: 0, PROBLEM --
> 780:780|new|State.pm|vmguest-3>CSB303|vmwarewinxp-WindowsXPwithVisualStudio
> 32-v0|admin
>
>
>
>
>
> |15314|780:780|new| ---- CRITICAL ----
> |15314|780:780|new| 2011-11-02
> 12:58:43|15314|780:780|new|State.pm:reservation_failed(213)|reservation
> failed on vmguest-3: process failed after trying to load or make available
> |15314|780:780|new| ( 0) State.pm, reservation_failed (line: 213)
> |15314|780:780|new| (-1) new.pm, process (line: 298)
> |15314|780:780|new| (-2) vcld, make_new_child (line: 568)
> |15314|780:780|new| (-3) vcld, main (line: 346)
>
>
--
Aaron Peeler
Program Manager
Virtual Computing Lab
NC State University
All electronic mail messages in connection with State business which
are sent to or received by this account are subject to the NC Public
Records Law and may be disclosed to third parties.
