That was it !
Thank you. Windows 2003 Server was successfully captured.
I would not have thought that the Windows Firewall was an issue.
Thanks again,
Al Quiros
On 12/28/11 8:50 AM, "Andy Kurth" <andy_ku...@ncsu.edu> wrote:
>I have seen this before. For some reason, the firewall isn't enabled
>by default for new Windows 2003 installations and the firewall
>services aren't running. Enable the firewall via the Control Panel.
>Make sure TCP port 22 is open and that SSH is still working and then
>restart the capture process.
>
>Don't rerun 'vcld -setup' once you have run it once for a given base
>image because it will result in extra unnecessary image entries in the
>database. Instead, manually change the request table in the database.
> Find the imaging request that was created by 'vcld -setup'. The
>request.state value will be 10 (maintenance) and request.laststate
>will be 16 (image). change request.state to 16 and the normal running
>vcld process will restart the capture.
>
>-Andy
>
>On Tue, Dec 27, 2011 at 3:11 PM, Evelio Quiros <evq...@fiu.edu> wrote:
>> 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)|net
>>work
>> configuration has already been retrieved
>> 2011-12-27
>>
>>14:43:32|16120|34:34|image|DataStructure.pm:get_computer_private_ip_addre
>>ss(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)|pri
>>vate
>> 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)|re
>>turning
>> 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)|net
>>work
>> configuration has already been retrieved
>> 2011-12-27
>>
>>14:43:32|16120|34:34|image|DataStructure.pm:get_computer_private_ip_addre
>>ss(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)|pri
>>vate
>> 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)|int
>>erface
>> 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)|int
>>erface
>> 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)|ret
>>urning
>> 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)|configur
>>ed
>> firewall to disallow RDP
>> 2011-12-27
>>
>>14:43:34|16120|34:34|image|Windows.pm:get_network_configuration(5040)|net
>>work
>> configuration has already been retrieved
>> 2011-12-27
>>
>>14:43:34|16120|34:34|image|DataStructure.pm:get_computer_private_ip_addre
>>ss(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)|pri
>>vate
>> 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)|int
>>erface
>> 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)|int
>>erface
>> 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)|ret
>>urning
>> 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)|net
>>work
>> configuration has already been retrieved
>> 2011-12-27
>>
>>14:43:34|16120|34:34|image|DataStructure.pm:get_computer_private_ip_addre
>>ss(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)|pri
>>vate
>> 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)|re
>>turning
>> 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_addre
>>ss(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(20
>>35)|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)|atte
>>mpting
>> 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|ad
>>min
>> |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(67
>>42)|removing
>> computerloadlog entries matching loadstate = begin
>> 2011-12-27
>>
>>14:43:37|16120|34:34|image|utils.pm:delete_computerloadlog_reservation(67
>>89)|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
>>
