Re: Issues with Inserting Image Reservation Into VCL DB

Mon, 25 Jan 2010 12:34:12 -0800 

Hello Jeff,
It appears that the image was successfully captured and it's at the point where it's trying to reload the new image. 


Is the computer.privateIPaddress value set in the database?  If not, set this 
for vcl-winxp in the computer table and see if the warnings go away.  You can 
also add an entry in the /etc/hosts file on the management node for the private 
address of vcl-winxp.  Either of these should clear up most of the warning 
messages you're seeing.



You don't have to go through the entire imaging process again to troubleshoot 
this.  You can restart the reload process by:
-Kill the existing vcld process for the reservation if it's still running.  The 
PID to kill is displayed as the leftmost field in the log output (1297 in the 
output you included).  Don't kill the main vcld process.
-Set request.state to 'reload', request.start to NOW(), and request.end to some 
time in the future.  The vcld process should begin to process it again.  Start 
'tail -f /var/log/vcld.log' before changing the request state.



Is it hanging indefinitely after it attempts to run the last command (route 
delete 0.0.0.0) included in the log output?  I haven't seen this problem before 
if it is indeed hanging.  The 'route delete' command may be breaking networking 
on the computer and tripping up the SSH command.  I would try running the SSH 
command manually with the -v option to try to figure out what's happening:

ssh -v -i /etc/vcl/vcl.key  -l root -p 22 -x vcl-winxp 'route delete 0.0.0.0'

If this command hangs, try adding the ServerAliveInterval SSH option:

ssh -v -o ServerAliveInterval=15 -i /etc/vcl/vcl.key -l root -p 22 -x vcl-winxp 
'route delete 0.0.0.0'



Give this command at least 20 seconds before killing it if it hangs.  If this 
prevents it from hanging, try manually running the next command VCL would have 
performed:
ssh -i /etc/vcl/vcl.key -l root -p 22 -x vcl-winxp 'route -p ADD 0.0.0.0 MASK 
0.0.0.0 134.154.193.190 METRIC 1'


The output of these commands may be helpful in troubleshooting.

Regards,
Andy Kurth / NCSU VCL


Jeffrey Wisman wrote:

Hi all - Just joined this list.  I've been working on a pilot VCL install at
CSU East Bay, and am hung up on what seems like nearly the last step.  I'm
following instructions at the bottom of this page:
http://cwiki.apache.org/confluence/display/VCL/Create+a+Windows+Base+Image

I'm attempting to insert the image reservation into the VCL DB, and it only
gets as far as this network/route issue.  Is this a DHCP problem?  A hosts
file issue?  Something else?  Please let me know if anyone has seen this
before, or can help troubleshoot.  Here is the last part of the output from
tail -f /var/log/vcld.log



|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:30|1297|11:34|reload|Windows.pm:firewall_enable_ssh_private(4197)|SSH
will not be disabled on public interface because public interface name could
not be determined
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) Windows.pm, firewall_enable_ssh_private (line: 4197)
|1297|11:34|reload| (-2) Windows.pm, post_load (line: 485)
|1297|11:34|reload| (-3) new.pm, reload_image (line: 692)
|1297|11:34|reload| (-4) new.pm, process (line: 266)
|1297|11:34|reload| (-5) vcld, make_new_child (line: 594)
|1297|11:34|reload| (-6) vcld, main (line: 341)

2010-01-23
00:33:30|1297|11:34|reload|Windows.pm:get_network_configuration(4630)|network
configuration has already been retrieved
2010-01-23
00:33:30|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
442)|attempting to retrieve private IP address for computer: vcl-winxp
2010-01-23
00:33:30|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
446)|retrieved contents of /etc/hosts on this management node, contains 6
lines


|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:30|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
466)|did not find any lines in /etc/hosts containing 'vcl-winxp'
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) DataStructure.pm, get_computer_private_ip_address
(line: 1466)
|1297|11:34|reload| (-2) Windows.pm, get_network_configuration (line: 4642)
|1297|11:34|reload| (-3) Windows.pm, get_private_interface_name (line: 4761)
|1297|11:34|reload| (-4) Windows.pm, firewall_enable_ssh_private (line: 4202)
|1297|11:34|reload| (-5) Windows.pm, post_load (line: 485)
|1297|11:34|reload| (-6) new.pm, reload_image (line: 692)

2010-01-23
00:33:30|1297|11:34|reload|Windows.pm:get_network_configuration(4644)|unable
to retrieve computer private IP address from reservation data


|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:30|1297|11:34|reload|Windows.pm:get_private_interface_name(4763)|unable
to retrieve network configuration
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) Windows.pm, get_private_interface_name (line: 4763)
|1297|11:34|reload| (-2) Windows.pm, firewall_enable_ssh_private (line: 4202)
|1297|11:34|reload| (-3) Windows.pm, post_load (line: 485)
|1297|11:34|reload| (-4) new.pm, reload_image (line: 692)
|1297|11:34|reload| (-5) new.pm, process (line: 266)
|1297|11:34|reload| (-6) vcld, make_new_child (line: 594)



|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:30|1297|11:34|reload|Windows.pm:firewall_enable_ssh_private(4220)|priva
te interface name could not be determined, SSH will be enabled for all
profiles
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) Windows.pm, firewall_enable_ssh_private (line: 4220)
|1297|11:34|reload| (-2) Windows.pm, post_load (line: 485)
|1297|11:34|reload| (-3) new.pm, reload_image (line: 692)
|1297|11:34|reload| (-4) new.pm, process (line: 266)
|1297|11:34|reload| (-5) vcld, make_new_child (line: 594)
|1297|11:34|reload| (-6) vcld, main (line: 341)

2010-01-23
00:33:30|1297|11:34|reload|utils.pm:run_ssh_command(6168)|executing SSH
command on vcl-winxp:
|1297|11:34|reload| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vcl-winxp 'netsh.exe firewall set portopening name = "Cygwin SSHD" protocol =
TCP port = 22 profile = ALL' 2>&1
2010-01-23 00:33:35|1226|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-01-23 00:33:35
2010-01-23
00:33:37|1297|11:34|reload|utils.pm:run_ssh_command(6250)|run_ssh_command
output:
|1297|11:34|reload| Ok.
2010-01-23 00:33:37|1297|11:34|reload|utils.pm:run_ssh_command(6264)|SSH
command executed on vcl-winxp, returning (0, "Ok.")
2010-01-23
00:33:37|1297|11:34|reload|Windows.pm:firewall_enable_ssh_private(4232)|confi
gured firewall to allow SSH on private interface
2010-01-23
00:33:37|1297|11:34|reload|Windows.pm:get_network_configuration(4630)|network
configuration has already been retrieved
2010-01-23
00:33:37|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
442)|attempting to retrieve private IP address for computer: vcl-winxp
2010-01-23
00:33:37|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
446)|retrieved contents of /etc/hosts on this management node, contains 6
lines


|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:37|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
466)|did not find any lines in /etc/hosts containing 'vcl-winxp'
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) DataStructure.pm, get_computer_private_ip_address
(line: 1466)
|1297|11:34|reload| (-2) Windows.pm, get_network_configuration (line: 4642)
|1297|11:34|reload| (-3) Windows.pm, get_public_interface_name (line: 4791)
|1297|11:34|reload| (-4) Windows.pm, firewall_enable_ping_private (line:
3935)
|1297|11:34|reload| (-5) Windows.pm, post_load (line: 496)
|1297|11:34|reload| (-6) new.pm, reload_image (line: 692)

2010-01-23
00:33:37|1297|11:34|reload|Windows.pm:get_network_configuration(4644)|unable
to retrieve computer private IP address from reservation data


|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:37|1297|11:34|reload|Windows.pm:get_public_interface_name(4793)|unable
to retrieve network configuration
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) Windows.pm, get_public_interface_name (line: 4793)
|1297|11:34|reload| (-2) Windows.pm, firewall_enable_ping_private (line:
3935)
|1297|11:34|reload| (-3) Windows.pm, post_load (line: 496)
|1297|11:34|reload| (-4) new.pm, reload_image (line: 692)
|1297|11:34|reload| (-5) new.pm, process (line: 266)
|1297|11:34|reload| (-6) vcld, make_new_child (line: 594)



|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:37|1297|11:34|reload|Windows.pm:firewall_enable_ping_private(3946)|ping
will not be disabled on public interface because public interface name could
not be determined
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) Windows.pm, firewall_enable_ping_private (line:
3946)
|1297|11:34|reload| (-2) Windows.pm, post_load (line: 496)
|1297|11:34|reload| (-3) new.pm, reload_image (line: 692)
|1297|11:34|reload| (-4) new.pm, process (line: 266)
|1297|11:34|reload| (-5) vcld, make_new_child (line: 594)
|1297|11:34|reload| (-6) vcld, main (line: 341)

2010-01-23
00:33:37|1297|11:34|reload|Windows.pm:get_network_configuration(4630)|network
configuration has already been retrieved
2010-01-23
00:33:37|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
442)|attempting to retrieve private IP address for computer: vcl-winxp
2010-01-23
00:33:37|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
446)|retrieved contents of /etc/hosts on this management node, contains 6
lines


|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:37|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
466)|did not find any lines in /etc/hosts containing 'vcl-winxp'
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) DataStructure.pm, get_computer_private_ip_address
(line: 1466)
|1297|11:34|reload| (-2) Windows.pm, get_network_configuration (line: 4642)
|1297|11:34|reload| (-3) Windows.pm, get_private_interface_name (line: 4761)
|1297|11:34|reload| (-4) Windows.pm, firewall_enable_ping_private (line:
3951)
|1297|11:34|reload| (-5) Windows.pm, post_load (line: 496)
|1297|11:34|reload| (-6) new.pm, reload_image (line: 692)

2010-01-23
00:33:37|1297|11:34|reload|Windows.pm:get_network_configuration(4644)|unable
to retrieve computer private IP address from reservation data


|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:37|1297|11:34|reload|Windows.pm:get_private_interface_name(4763)|unable
to retrieve network configuration
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) Windows.pm, get_private_interface_name (line: 4763)
|1297|11:34|reload| (-2) Windows.pm, firewall_enable_ping_private (line:
3951)
|1297|11:34|reload| (-3) Windows.pm, post_load (line: 496)
|1297|11:34|reload| (-4) new.pm, reload_image (line: 692)
|1297|11:34|reload| (-5) new.pm, process (line: 266)
|1297|11:34|reload| (-6) vcld, make_new_child (line: 594)



|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:37|1297|11:34|reload|Windows.pm:firewall_enable_ping_private(3967)|priv
ate interface name could not be determined, ping will be enabled for all
profiles
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) Windows.pm, firewall_enable_ping_private (line:
3967)
|1297|11:34|reload| (-2) Windows.pm, post_load (line: 496)
|1297|11:34|reload| (-3) new.pm, reload_image (line: 692)
|1297|11:34|reload| (-4) new.pm, process (line: 266)
|1297|11:34|reload| (-5) vcld, make_new_child (line: 594)
|1297|11:34|reload| (-6) vcld, main (line: 341)

2010-01-23
00:33:37|1297|11:34|reload|utils.pm:run_ssh_command(6168)|executing SSH
command on vcl-winxp:
|1297|11:34|reload| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vcl-winxp 'netsh.exe firewall set icmpsetting type = 8 mode = ENABLE profile
= ALL ;' 2>&1
2010-01-23 00:33:40|1226|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-01-23 00:33:40
2010-01-23
00:33:43|1297|11:34|reload|utils.pm:run_ssh_command(6250)|run_ssh_command
output:
|1297|11:34|reload| Ok.
2010-01-23 00:33:43|1297|11:34|reload|utils.pm:run_ssh_command(6264)|SSH
command executed on vcl-winxp, returning (0, "Ok.")
2010-01-23
00:33:43|1297|11:34|reload|Windows.pm:firewall_enable_ping_private(3979)|conf
igured firewall to allow ping on private interface
2010-01-23
00:33:43|1297|11:34|reload|Windows.pm:get_public_default_gateway(4890)|IP
configuration mode in use: dynamicDHCP
2010-01-23
00:33:43|1297|11:34|reload|Windows.pm:get_network_configuration(4630)|network
configuration has already been retrieved
2010-01-23
00:33:43|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
442)|attempting to retrieve private IP address for computer: vcl-winxp
2010-01-23
00:33:43|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
446)|retrieved contents of /etc/hosts on this management node, contains 6
lines


|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:43|1297|11:34|reload|DataStructure.pm:get_computer_private_ip_address(1
466)|did not find any lines in /etc/hosts containing 'vcl-winxp'
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) DataStructure.pm, get_computer_private_ip_address
(line: 1466)
|1297|11:34|reload| (-2) Windows.pm, get_network_configuration (line: 4642)
|1297|11:34|reload| (-3) Windows.pm, get_public_default_gateway (line: 4894)
|1297|11:34|reload| (-4) Windows.pm, set_public_default_route (line: 7429)
|1297|11:34|reload| (-5) Windows.pm, post_load (line: 507)
|1297|11:34|reload| (-6) new.pm, reload_image (line: 692)

2010-01-23
00:33:43|1297|11:34|reload|Windows.pm:get_network_configuration(4644)|unable
to retrieve computer private IP address from reservation data


|1297|11:34|reload| ---- WARNING ---- 
|1297|11:34|reload| 2010-01-23

00:33:43|1297|11:34|reload|Windows.pm:get_public_default_gateway(4908)|unable
to retrieve public network configuration currently in use on vcl-winxp
|1297|11:34|reload| ( 0) utils.pm, notify (line: 728)
|1297|11:34|reload| (-1) Windows.pm, get_public_default_gateway (line: 4908)
|1297|11:34|reload| (-2) Windows.pm, set_public_default_route (line: 7429)
|1297|11:34|reload| (-3) Windows.pm, post_load (line: 507)
|1297|11:34|reload| (-4) new.pm, reload_image (line: 692)
|1297|11:34|reload| (-5) new.pm, process (line: 266)
|1297|11:34|reload| (-6) vcld, make_new_child (line: 594)

2010-01-23
00:33:43|1297|11:34|reload|DataStructure.pm:get_management_node_public_defaul
t_gateway(1783)|returning default gateway from route command: 134.154.193.190
2010-01-23
00:33:43|1297|11:34|reload|Windows.pm:get_public_default_gateway(4917)|return
ing management node's default gateway address: 134.154.193.190
2010-01-23
00:33:43|1297|11:34|reload|utils.pm:run_ssh_command(6168)|executing SSH
command on vcl-winxp:
|1297|11:34|reload| /usr/bin/ssh -i /etc/vcl/vcl.key  -l root -p 22 -x
vcl-winxp 'route delete 0.0.0.0' 2>&1
2010-01-23 00:33:45|1226|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-01-23 00:33:45
2010-01-23 00:33:50|1226|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-01-23 00:33:50
2010-01-23 00:33:55|1226|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-01-23 00:33:55
2010-01-23 00:34:00|1226|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-01-23 00:34:00
2010-01-23 00:34:05|1226|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-01-23 00:34:05
2010-01-23 00:34:10|1226|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-01-23 00:34:10






And the database state:

mysql> select * from request;
+----+---------+--------+-------------+-------+------------+------+---------+
---------------------+---------------------+---------------------+-----------
---+
| id | stateid | userid | laststateid | logid | forimaging | test | preload |
start               | end                 | daterequested       |
datemodified |
+----+---------+--------+-------------+-------+------------+------+---------+
---------------------+---------------------+---------------------+-----------
---+
| 11 |      14 |      2 |          19 |     0 |          0 |    0 |       0 |
2010-01-23 00:31:59 | 2010-01-23 01:01:59 | 2010-01-23 00:31:59 | NULL

| 
+----+---------+--------+-------------+-------+------------+------+---------+

---------------------+---------------------+---------------------+-----------
---+
1 row in set (0.00 sec)

mysql> select * from reservation;
+----+-----------+------------+---------+-----------------+------------------
+----------+---------------------+------+
| id | requestid | computerid | imageid | imagerevisionid | managementnodeid
| remoteIP | lastcheck           | pw   |
+----+-----------+------------+---------+-----------------+------------------
+----------+---------------------+------+
| 34 |        11 |         13 |      10 |              10 |                1

| NULL     | 0000-00-00 00:00:00 | NULL | 
+----+-----------+------------+---------+-----------------+------------------

+----------+---------------------+------+
1 row in set (0.00 sec)


And finally, here is the directory structure (after executing the commands)
of the VMWare server:
/vmfs/volumes/4ae7602f-490f0fcb-52ef-00144fd1e4ed # ls -l
drwxr-xr-x    1 root     root                420 Jan 23 08:31 golden
drwxr-xr-x    1 root     root                420 Jan 23 08:31 inuse
drwxr-xr-x    1 root     root               4340 Dec  3 18:30
vcl.csueastbay.edu
drwxr-xr-x    1 root     root               4340 Dec  3 18:08
vcldb.csueastbay.edu
drwxr-xr-x    1 root     root               4340 Dec  3 18:23
vclmgmt.csueastbay.edu
drwxr-xr-x    1 root     root               2660 Jan 23 08:22
vmwarewinxp-base7-v0
/vmfs/volumes/4ae7602f-490f0fcb-52ef-00144fd1e4ed # cd golden/
/vmfs/volumes/4ae7602f-490f0fcb-52ef-00144fd1e4ed/golden # ls -l
drwxr-xr-x    1 root     root                280 Jan 23 08:31
vmwarewinxp-base7-v0
/vmfs/volumes/4ae7602f-490f0fcb-52ef-00144fd1e4ed/golden # cd ..
/vmfs/volumes/4ae7602f-490f0fcb-52ef-00144fd1e4ed # cd inuse/
/vmfs/volumes/4ae7602f-490f0fcb-52ef-00144fd1e4ed/inuse # ls -l
drwxr-xr-x    1 root     root                420 Jan 23 08:31 vcl-winxp


Let me know if more output from the logs would be helpful, or any other
information.


Thanks,
Jeff Wisman



--
Andy Kurth
Virtual Computing Lab
Office of Information Technology
North Carolina State University
[email protected]
919.513.4090






















					Reply via email to