Hello, Happy New Year to you all.
I am having trouble capturing a Windows 2003 Server image. I setup Windows 2003 on the VM server and installed and configured Cygwin. I setup the gen-keys, and my Management node can SSH to the server fine without a password. When I tried to capture the new base image, it begins the process, and a little while later it reports having failed. I had been able to capture a linux image and a windows XP base image without any trouble, so I know VCL itself is working ok. Any ideas on what might be wrong ? Included below is the last part of the vcl log…. 2011-12-27 14:42:28|16120|34:34|image|Module.pm:code_loop_timeout(759)|attempt 9: waiting for vclimg12 to respond to SSH 2011-12-27 14:42:34|13511|vcld:main(167)|lastcheckin time updated for management node 1: 2011-12-27 14:42:34 2011-12-27 14:42:41|16120|34:34|image|OS.pm:is_ssh_responding(401)|vclimg12 is responding to SSH, port 22: open, port 24: closed 2011-12-27 14:42:41|16120|34:34|image|Module.pm:code_loop_timeout(762)|waiting for vclimg12 to respond to SSH, code returned true 2011-12-27 14:42:41|16120|34:34|image|Windows.pm:reboot(3454)|vclimg12 responded to ssh 2011-12-27 14:42:41|16120|34:34|image|Windows.pm:reboot(3471)|reboot complete on vclimg12, took 318 seconds 2011-12-27 14:42:41|16120|34:34|image|Windows.pm:disable_pagefile(2077)|computer was rebooted after disabling pagefile in the registry 2011-12-27 14:42:41|16120|34:34|image|utils.pm:run_ssh_command(5380)|executing SSH command on vclimg12: |16120|34:34|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -l root -p 22 -x vclimg12 'for i in `ls /cygdrive 2>/dev/null`; do echo $i; done;' 2>&1 2011-12-27 14:42:42|16120|34:34|image|Windows.pm:get_volume_list(7958)|retrieved drive letter list under /cygdrive: |16120|34:34|image| c 2011-12-27 14:42:45|16120|34:34|image|Windows.pm:file_exists(1340)|file exists on vclimg12: 'c:/pagefile.sys' 2011-12-27 14:42:45|16120|34:34|image|Windows.pm:delete_file(1102)|attempting to delete file: 'c:/pagefile.sys' 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:file_exists(1336)|file does NOT exist on vclimg12: 'c:/pagefile.sys' 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:delete_file(1157)|deleted file: 'c:/pagefile.sys' 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:disable_pagefile(2094)|deleted pagefile.sys on all c: 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved 2011-12-27 14:43:32|16120|34:34|image|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.0.0.42 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: Intel(R) PRO/1000 MT Network Connection, address(es): 10.0.0.42 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:get_private_interface_name(5177)|returning private interface name: Local Area Connection 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:firewall_disable_rdp(4856)|RDP will be disabled on private interface: Local Area Connection 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved 2011-12-27 14:43:32|16120|34:34|image|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.0.0.42 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: Intel(R) PRO/1000 MT Network Connection, address(es): 10.0.0.42 2011-12-27 14:43:32|16120|34:34|image|utils.pm:is_valid_ip_address(9266)|IP address is valid: 10.106.128.49 2011-12-27 14:43:32|16120|34:34|image|utils.pm:is_public_ip_address(9375)|private IP address: 10.106.128.49, returning 0 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:get_network_configuration(5117)|interface found with non-public address not matching private address for reservation: Local Area Connection 2, address(es): 10.106.128.49 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:get_network_configuration(5124)|interface will be returned if another with a public address isn't found 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:get_public_interface_name(5207)|returning public interface name: Local Area Connection 2 2011-12-27 14:43:32|16120|34:34|image|Windows.pm:firewall_disable_rdp(4872)|RDP will be disabled on public interface: Local Area Connection 2 2011-12-27 14:43:32|16120|34:34|image|utils.pm:run_ssh_command(5380)|executing SSH command on vclimg12: |16120|34:34|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -l root -p 22 -x vclimg12 'C:/Windows/System32/netsh.exe firewall delete portopening protocol = TCP port = 3389 interface = "Local Area Connection" ;C:/Windows/System32/netsh.exe firewall delete portopening protocol = TCP port = 3389 interface = "Local Area Connection 2" ;C:/Windows/System32/netsh.exe firewall delete portopening protocol = TCP port = 3389 profile = ALL' 2>&1 2011-12-27 14:43:34|16120|34:34|image|utils.pm:run_ssh_command(5464)|run_ssh_command output: |16120|34:34|image| Ok. |16120|34:34|image| Ok. |16120|34:34|image| Ok. 2011-12-27 14:43:34|16120|34:34|image|utils.pm:run_ssh_command(5478)|SSH command executed on vclimg12, returning (0, "Ok. Ok. Ok.") 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:firewall_disable_rdp(4893)|configured firewall to disallow RDP 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved 2011-12-27 14:43:34|16120|34:34|image|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.0.0.42 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: Intel(R) PRO/1000 MT Network Connection, address(es): 10.0.0.42 2011-12-27 14:43:34|16120|34:34|image|utils.pm:is_valid_ip_address(9266)|IP address is valid: 10.106.128.49 2011-12-27 14:43:34|16120|34:34|image|utils.pm:is_public_ip_address(9375)|private IP address: 10.106.128.49, returning 0 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:get_network_configuration(5117)|interface found with non-public address not matching private address for reservation: Local Area Connection 2, address(es): 10.106.128.49 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:get_network_configuration(5124)|interface will be returned if another with a public address isn't found 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:get_public_interface_name(5207)|returning public interface name: Local Area Connection 2 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:firewall_enable_ssh(4529)|SSH will be disabled on public interface: Local Area Connection 2 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:get_network_configuration(5040)|network configuration has already been retrieved 2011-12-27 14:43:34|16120|34:34|image|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.0.0.42 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:get_network_configuration(5075)|private interface found: Local Area Connection, description: Intel(R) PRO/1000 MT Network Connection, address(es): 10.0.0.42 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:get_private_interface_name(5177)|returning private interface name: Local Area Connection 2011-12-27 14:43:34|16120|34:34|image|Windows.pm:firewall_enable_ssh(4545)|SSH will be disabled on private interface: Local Area Connection 2011-12-27 14:43:34|16120|34:34|image|utils.pm:run_ssh_command(5380)|executing SSH command on vclimg12: |16120|34:34|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -l root -p 22 -x vclimg12 'C:/Windows/System32/netsh.exe firewall delete portopening protocol = TCP port = 22 interface = "Local Area Connection 2" ;C:/Windows/System32/netsh.exe firewall delete portopening protocol = TCP port = 22 interface = "Local Area Connection" ;C:/Windows/System32/netsh.exe firewall set portopening name = "Cygwin SSHD" protocol = TCP port = 22 mode = ENABLE scope = ALL' 2>&1 2011-12-27 14:43:34|13511|vcld:main(167)|lastcheckin time updated for management node 1: 2011-12-27 14:43:34 2011-12-27 14:43:36|16120|34:34|image|utils.pm:run_ssh_command(5464)|run_ssh_command output: |16120|34:34|image| Ok. |16120|34:34|image| Ok. |16120|34:34|image| The service has not been started. 2011-12-27 14:43:36|16120|34:34|image|utils.pm:run_ssh_command(5474)|SSH command executed on vclimg12, command: |16120|34:34|image| /usr/bin/ssh -i /etc/vcl/vcl.key -o StrictHostKeyChecking=no -l root -p 22 -x vclimg12 'C:/Windows/System32/netsh.exe firewall delete portopening protocol = TCP port = 22 interface = "Local Area Connection 2" ;C:/Windows/System32/netsh.exe firewall delete portopening protocol = TCP port = 22 interface = "Local Area Connection" ;C:/Windows/System32/netsh.exe firewall set portopening name = "Cygwin SSHD" protocol = TCP port = 22 mode = ENABLE scope = ALL' 2>&1 |16120|34:34|image| returning (1, "Ok. Ok. The service has not be...") |16120|34:34|image| ---- WARNING ---- |16120|34:34|image| 2011-12-27 14:43:36|16120|34:34|image|Windows.pm:firewall_enable_ssh(4579)|failed to configure firewall to allow SSH from all addresses, exit status: 1, output: |16120|34:34|image| Ok. Ok. The service has not been started. |16120|34:34|image| ( 0) Windows.pm, firewall_enable_ssh (line: 4579) |16120|34:34|image| (-1) Windows.pm, pre_capture (line: 507) |16120|34:34|image| (-2) Version_5.pm, pre_capture (line: 105) |16120|34:34|image| (-3) VMware.pm, capture (line: 556) |16120|34:34|image| (-4) image.pm, process (line: 162) |16120|34:34|image| (-5) vcld, make_new_child (line: 568) |16120|34:34|image| ---- WARNING ---- |16120|34:34|image| 2011-12-27 14:43:36|16120|34:34|image|Windows.pm:pre_capture(508)|unable to enable SSH from any IP address |16120|34:34|image| ( 0) Windows.pm, pre_capture (line: 508) |16120|34:34|image| (-1) Version_5.pm, pre_capture (line: 105) |16120|34:34|image| (-2) VMware.pm, capture (line: 556) |16120|34:34|image| (-3) image.pm, process (line: 162) |16120|34:34|image| (-4) vcld, make_new_child (line: 568) |16120|34:34|image| (-5) vcld, main (line: 346) |16120|34:34|image| ---- WARNING ---- |16120|34:34|image| 2011-12-27 14:43:36|16120|34:34|image|Version_5.pm:pre_capture(109)|failed to execute parent class pre_capture() subroutine |16120|34:34|image| ( 0) Version_5.pm, pre_capture (line: 109) |16120|34:34|image| (-1) VMware.pm, capture (line: 556) |16120|34:34|image| (-2) image.pm, process (line: 162) |16120|34:34|image| (-3) vcld, make_new_child (line: 568) |16120|34:34|image| (-4) vcld, main (line: 346) |16120|34:34|image| ---- WARNING ---- |16120|34:34|image| 2011-12-27 14:43:36|16120|34:34|image|VMware.pm:capture(557)|failed to complete OS module's pre_capture tasks |16120|34:34|image| ( 0) VMware.pm, capture (line: 557) |16120|34:34|image| (-1) image.pm, process (line: 162) |16120|34:34|image| (-2) vcld, make_new_child (line: 568) |16120|34:34|image| (-3) vcld, main (line: 346) |16120|34:34|image| ---- WARNING ---- |16120|34:34|image| 2011-12-27 14:43:36|16120|34:34|image|image.pm:process(166)|vmwarewin2003-base2k312-v0 image failed to be captured by provisioning module |16120|34:34|image| ( 0) image.pm, process (line: 166) |16120|34:34|image| (-1) vcld, make_new_child (line: 568) |16120|34:34|image| (-2) vcld, main (line: 346) 2011-12-27 14:43:36|16120|34:34|image|DataStructure.pm:get_computer_private_ip_address(1557)|returning private IP address previously retrieved: 10.0.0.42 2011-12-27 14:43:36|16120|34:34|image|utils.pm:is_inblockrequest(6163)|zero rows were returned from database select 2011-12-27 14:43:36|16120|34:34|image|DataStructure.pm:get_image_affiliation_name(2035)|image owner id: 1 2011-12-27 14:43:36|16120|34:34|image|utils.pm:getnewdbh(2709)|database requested (information_schema) does not match handle stored in $ENV{dbh} (vcl:vcldb.fiu.edu) 2011-12-27 14:43:36|16120|34:34|image|utils.pm:getnewdbh(2760)|database handle stored in $ENV{dbh} 2011-12-27 14:43:36|16120|34:34|image|DataStructure.pm:retrieve_user_data(1352)|attempting to retrieve and store data for user: user.id = '1' 2011-12-27 14:43:36|16120|34:34|image|utils.pm:getnewdbh(2709)|database requested (vcl) does not match handle stored in $ENV{dbh} (information_schema:vcldb.fiu.edu) 2011-12-27 14:43:36|16120|34:34|image|utils.pm:getnewdbh(2760)|database handle stored in $ENV{dbh} 2011-12-27 14:43:36|16120|34:34|image|DataStructure.pm:retrieve_user_data(1415)|data has been retrieved for user: admin (id: 1) 2011-12-27 14:43:37|16120|34:34|image|utils.pm:mail(1255)|SUCCESS -- Sending mail To: evq...@fiu.edu, PROBLEM -- 34:34|image|image.pm|vclimg12>idp01.fiu.edu|vmwarewin2003-base2k312-v0|admin |16120|34:34|image| ---- CRITICAL ---- |16120|34:34|image| 2011-12-27 14:43:36|16120|34:34|image|image.pm:reservation_failed(385)|vmwarewin2003-base2k312-v0 image creation failed |16120|34:34|image| ( 0) image.pm, reservation_failed (line: 385) |16120|34:34|image| (-1) image.pm, process (line: 167) |16120|34:34|image| (-2) vcld, make_new_child (line: 568) |16120|34:34|image| (-3) vcld, main (line: 346) 2011-12-27 14:43:37|16120|34:34|image|utils.pm:mail(1255)|SUCCESS -- Sending mail To: root@localhost, VCL -- NOTICE DELAY Image Creation base2k3 2011-12-27 14:43:37|16120|34:34|image|utils.pm:mail(1255)|SUCCESS -- Sending mail To: evq...@fiu.edu, VCL -- NOTICE FAILED Image Creation base2k3 2011-12-27 14:43:37|16120|34:34|image|utils.pm:update_request_state(1991)|request 34 state updated to: maintenance, laststate to: image 2011-12-27 14:43:37|16120|34:34|image|image.pm:reservation_failed(437)|request state set to maintenance, laststate to image 2011-12-27 14:43:37|16120|34:34|image|utils.pm:update_computer_state(2033)|computer 23 state updated to: maintenance 2011-12-27 14:43:37|16120|34:34|image|image.pm:reservation_failed(445)|vclimg12 state set to maintenance 2011-12-27 14:43:37|16120|34:34|image|image.pm:reservation_failed(452)|exiting 2011-12-27 14:43:37|16120|34:34|image|State.pm:DESTROY(829)|VCL::image destructor called, address: 25f4da0 2011-12-27 14:43:37|16120|34:34|image|utils.pm:delete_computerloadlog_reservation(6742)|removing computerloadlog entries matching loadstate = begin 2011-12-27 14:43:37|16120|34:34|image|utils.pm:delete_computerloadlog_reservation(6789)|deleted rows from computerloadlog for reservation id=34 2011-12-27 14:43:37|16120|34:34|image|State.pm:DESTROY(848)|number of database handles state process created: 3 2011-12-27 14:43:37|16120|34:34|image|State.pm:DESTROY(876)|VCL::image process duration: 1911 seconds 2011-12-27 14:43:37|16120|34:34|image|VIM_SSH.pm:DESTROY(1685)|vim-cmd call count: 6 2011-12-27 14:43:37|13511|vcld:REAPER(718)|VCL process exited for reservation 34, PID: 16120, signal: CHLD