hi all,
in still trying to debug this, i've noticed that my image capture appears to be
successful, but the vm state is 'failed'. i've scoured through vcld.log in an
effort to locate the reason. as a novice, nothing glaring sticks out to me. i
can access the vm after the capture through websphere. i would appreciate any
hints. thanks.
relevant log entries:
2012-08-13 13:29:37|6139|6:6|reload|VIM_SSH.pm:_wait_for_task(771)|task
completed successfully: haTask-9-vim.VirtualMachine.powerOn-24678
2012-08-13 13:29:37|6139|6:6|reload|VIM_SSH.pm:vm_power_on(970)|powered on VM:
/vmfs/volumes/datastore2/vclvm0001-man0_2-v0/vclvm0001-man0_2-v0.vmx
2012-08-13 13:29:37|6139|6:6|reload|utils.pm:insertloadlog(3703)|inserted
computer=5, startvm, registered and powered on vclvm0001-man0
2012-08-13 13:29:37|6139|6:6|reload|Version_6.pm:post_load(185)|beginning
Windows version 6 post-load tasks
2012-08-13 13:29:37|6139|6:6|reload|Version_6.pm:post_load(193)|calling parent
class post_load() subroutine
2012-08-13 13:29:37|6139|6:6|reload|Windows.pm:post_load(620)|beginning Windows
post-load tasks on vclvm0001-man0
2012-08-13 13:29:38|6139|6:6|reload|OS.pm:is_ssh_responding(615)|vclvm0001-man0
is NOT responding to SSH, ports 22 or 24 are both closed
2012-08-13 13:29:38|6139|6:6|reload|OS.pm:wait_for_response(696)|waiting 15
seconds for vclvm0001-man0 to boot
2012-08-13 13:29:53|6139|6:6|reload|OS.pm:wait_for_response(698)|waited 15
seconds for vclvm0001-man0 to boot
2012-08-13 13:29:53|6139|6:6|reload|OS.pm:wait_for_response(702)|waiting for
vclvm0001-man0 to respond to SSH, maximum of 600 seconds
2012-08-13 13:29:53|6139|6:6|reload|Module.pm:code_loop_timeout(879)|waiting for
vclvm0001-man0 to respond to SSH, maximum of 600 seconds
2012-08-13 13:29:54|6139|6:6|reload|OS.pm:is_ssh_responding(615)|vclvm0001-man0
is NOT responding to SSH, ports 22 or 24 are both closed
2012-08-13 13:29:54|6139|6:6|reload|Module.pm:code_loop_timeout(892)|attempt 1:
waiting for vclvm0001-man0 to respond to SSH (1/599 seconds) sleeping for 15 seconds
...
2012-08-13 13:40:01|6139|6:6|reload|OS.pm:is_ssh_responding(615)|vclvm0001-man0
is NOT responding to SSH, ports 22 or 24 are both closed
2012-08-13 13:40:01|6139|6:6|reload|Module.pm:code_loop_timeout(904)|waiting for
vclvm0001-man0 to respond to SSH, code did not return true after waiting 600 seconds
|6139|6:6|reload| ---- WARNING ----
|6139|6:6|reload| 2012-08-13
13:40:01|6139|6:6|reload|OS.pm:wait_for_response(704)|failed to connect to
vclvm0001-man0 via SSH after 600 seconds
|6139|6:6|reload| ( 0) OS.pm, wait_for_response (line: 704)
|6139|6:6|reload| (-1) Version_6.pm, wait_for_response (line: 2078)
|6139|6:6|reload| (-2) Windows.pm, post_load (line: 628)
|6139|6:6|reload| (-3) Version_6.pm, post_load (line: 194)
|6139|6:6|reload| (-4) VMware.pm, load (line: 529)
|6139|6:6|reload| (-5) new.pm, reload_image (line: 665)
|6139|6:6|reload| ---- WARNING ----
|6139|6:6|reload| 2012-08-13
13:40:01|6139|6:6|reload|Windows.pm:post_load(629)|vclvm0001-man0 never
responded to SSH
|6139|6:6|reload| ( 0) Windows.pm, post_load (line: 629)
|6139|6:6|reload| (-1) Version_6.pm, post_load (line: 194)
|6139|6:6|reload| (-2) VMware.pm, load (line: 529)
|6139|6:6|reload| (-3) new.pm, reload_image (line: 665)
|6139|6:6|reload| (-4) new.pm, process (line: 291)
|6139|6:6|reload| (-5) vcld, make_new_child (line: 571)
|6139|6:6|reload| ---- WARNING ----
|6139|6:6|reload| 2012-08-13
13:40:01|6139|6:6|reload|Version_6.pm:post_load(198)|failed to execute parent
class post_load() subroutine
|6139|6:6|reload| ( 0) Version_6.pm, post_load (line: 198)
|6139|6:6|reload| (-1) VMware.pm, load (line: 529)
|6139|6:6|reload| (-2) new.pm, reload_image (line: 665)
|6139|6:6|reload| (-3) new.pm, process (line: 291)
|6139|6:6|reload| (-4) vcld, make_new_child (line: 571)
|6139|6:6|reload| (-5) vcld, main (line: 350)
|6139|6:6|reload| ---- WARNING ----
|6139|6:6|reload| 2012-08-13 13:40:01|6139|6:6|reload|VMware.pm:load(533)|failed
to perform OS post-load tasks on VM vclvm0001-man0 on VM host: vclhv01
|6139|6:6|reload| ( 0) VMware.pm, load (line: 533)
|6139|6:6|reload| (-1) new.pm, reload_image (line: 665)
|6139|6:6|reload| (-2) new.pm, process (line: 291)
|6139|6:6|reload| (-3) vcld, make_new_child (line: 571)
|6139|6:6|reload| (-4) vcld, main (line: 350)
|6139|6:6|reload| ---- WARNING ----
|6139|6:6|reload| 2012-08-13
13:40:01|6139|6:6|reload|new.pm:reload_image(670)|vmwarewin7-win7x64_base2-v0
failed to load on vclvm0001-man0, returning
|6139|6:6|reload| ( 0) new.pm, reload_image (line: 670)
|6139|6:6|reload| (-1) new.pm, process (line: 291)
|6139|6:6|reload| (-2) vcld, make_new_child (line: 571)
|6139|6:6|reload| (-3) vcld, main (line: 350)
2012-08-13 13:40:01|6139|6:6|reload|utils.pm:insertloadlog(3703)|inserted
computer=5, loadimagefailed, vmwarewin7-win7x64_base2-v0 failed to load on
vclvm0001-man0
|6139|6:6|reload| ---- WARNING ----
|6139|6:6|reload| 2012-08-13 13:40:01|6139|6:6|reload|new.pm:process(338)|failed
to load vclvm0001-man0 with vmwarewin7-win7x64_base2-v0
|6139|6:6|reload| ( 0) new.pm, process (line: 338)
|6139|6:6|reload| (-1) vcld, make_new_child (line: 571)
|6139|6:6|reload| (-2) vcld, main (line: 350)
2012-08-13
13:40:01|6139|6:6|reload|DataStructure.pm:get_computer_state_name(2433)|attempting
to retrieve current state of computer vclvm0001-man0 from the database
2012-08-13
13:40:01|6139|6:6|reload|DataStructure.pm:get_computer_state_name(2464)|retrieved current
state of computer vclvm0001-man0 from the database: reloading
2012-08-13 13:40:01|6139|6:6|reload|DataStructure.pm:_automethod(836)|data
structure updated, hash path:
$self->request_data->{reservation}{6}{computer}{state}{name}, data identifier:
computer_state_name, data:
|6139|6:6|reload| : "reloading"
2012-08-13
13:40:01|6139|6:6|reload|utils.pm:get_management_node_info(5489)|retrieving
current management node info for 'localhost' from database, cached data is
stale: 646 seconds old
2012-08-13
13:40:01|6139|6:6|reload|utils.pm:get_management_node_info(5636)|retrieved
management node info: 'localhost' (localhost)
2012-08-13
13:40:01|6139|6:6|reload|DataStructure.pm:get_computer_private_ip_address(1630)|attempting
to retrieve private IP address for computer: vclvm0001-man0
2012-08-13
13:40:01|6139|6:6|reload|DataStructure.pm:get_computer_private_ip_address(1634)|retrieved
contents of /etc/hosts on this management node, contains 120 lines
2012-08-13
13:40:01|6139|6:6|reload|DataStructure.pm:get_computer_private_ip_address(1694)|returning
IP address from /etc/hosts file: 10.128.64.100
2012-08-13 13:40:01|6139|6:6|reload|utils.pm:is_inblockrequest(5793)|zero rows
were returned from database select
2012-08-13
13:40:01|6139|6:6|reload|DataStructure.pm:get_image_affiliation_name(2118)|image
owner id: 1
2012-08-13
13:40:01|6139|6:6|reload|DataStructure.pm:retrieve_user_data(1401)|attempting to
retrieve and store data for user: user.id = '1'
2012-08-13
13:40:01|6139|6:6|reload|DataStructure.pm:retrieve_user_data(1464)|data has been
retrieved for user: admin (id: 1)
2012-08-13 13:40:02|6139|6:6|reload|utils.pm:mail(1253)|SUCCESS -- Sending mail
To: [email protected], PROBLEM --
localhost|6:6|reload|State.pm|vclvm0001-man0>vclhv01|vmwarewin7-win7x64_base2-v0|vclreload
|6139|6:6|reload| ---- CRITICAL ----
|6139|6:6|reload| 2012-08-13
13:40:01|6139|6:6|reload|State.pm:reservation_failed(240)|reservation failed on
vclvm0001-man0: process failed after trying to load or make available
|6139|6:6|reload| ( 0) State.pm, reservation_failed (line: 240)
|6139|6:6|reload| (-1) new.pm, process (line: 341)
|6139|6:6|reload| (-2) vcld, make_new_child (line: 571)
|6139|6:6|reload| (-3) vcld, main (line: 350)
2012-08-13 13:40:02|6139|6:6|reload|utils.pm:insertloadlog(3703)|inserted
computer=5, failed, process failed after trying to load or make available
2012-08-13 13:40:02|6139|6:6|reload|State.pm:reservation_failed(243)|inserted
computerloadlog entry
2012-08-13
13:40:02|6139|6:6|reload|utils.pm:update_computer_state(1587)|computer 5 state
updated to: failed
2012-08-13 13:40:02|6139|6:6|reload|State.pm:reservation_failed(262)|computer
vclvm0001-man0 (5) state set to failed
2012-08-13 13:40:02|6139|6:6|reload|utils.pm:update_request_state(1545)|request
6 state updated to: failed, laststate to: image
2012-08-13 13:40:02|6139|6:6|reload|State.pm:reservation_failed(275)|set request
state to 'failed'/'image'
2012-08-13 13:40:02|6139|6:6|reload|utils.pm:is_inblockrequest(5793)|zero rows
were returned from database select
2012-08-13
13:40:02|6139|6:6|reload|State.pm:reservation_failed(293)|vclvm0001-man0 is NOT
in blockcomputers table
2012-08-13 13:40:02|6139|6:6|reload|State.pm:reservation_failed(296)|exiting 1
2012-08-13
13:40:02|6139|6:6|reload|utils.pm:delete_computerloadlog_reservation(6429)|removing
computerloadlog entries matching loadstate = begin
2012-08-13
13:40:02|6139|6:6|reload|utils.pm:delete_computerloadlog_reservation(6476)|deleted
rows from computerloadlog for reservation id=6
2012-08-13 13:40:02|6139|6:6|reload|State.pm:DESTROY(929)|VCL::new process
duration: 647 seconds
2012-08-13 13:40:02|6139|6:6|reload|VIM_SSH.pm:DESTROY(2123)|vim-cmd call
count: 16
will
