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
