Hi All,
I made an imaging reservation on the sandbox image and the image got created
but that new image cant be reloaded on any computer.
I am getting an error.
VMControl error -16: Virtual machine requires user input to continue
I am not sure as to what input I need to provide and I tried few means for
login to the virtual machine but i think I have no access.
I just read online that restarting the virtiual machine might help.. Any
ideas..?
Below is the detailed log when I try to make a reservation on the newly
created image.
2010-07-15 13:56:56|15613|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-07-15 13:56:56
===========================================================
OUTPUT for vcld run on 2010-07-15 13:57:02
===========================================================
2010-07-15 13:57:02|27874|vcld:main(116)|vcld environment variable set to 1
for this process
2010-07-15 13:57:02|27874|utils.pm:rename_vcld_process(7901)|renamed process
to 'vcld vcld'
2010-07-15 13:57:02|27874|utils.pm:get_management_node_info(6815)|management
node info retrieved from database for localhost
2010-07-15 13:57:02|27874|vcld:main(127)|retrieved management node
information from database
2010-07-15 13:57:02|27874|vcld:main(140)|management_node_id environment
variable set: 1
2010-07-15 13:57:02|27874|vcld:main(148)|management node checkin interval is
5 seconds
2010-07-15 13:57:02|27874|vcld:main(149)|vcld started on localhost
2010-07-15 13:57:07|27874|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-07-15 13:57:07
2010-07-15 13:57:12|27874|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-07-15 13:57:12
2010-07-15 13:57:18|27874|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-07-15 13:57:17
2010-07-15
13:57:18|27874|6:6|new|utils.pm:reservation_being_processed(9634)|computerloadlog
'begin' entry does NOT exist for reservation 6
2010-07-15
13:57:18|27874|6:6|new|utils.pm:reservation_being_processed(9686)|reservation
is NOT currently being processed
2010-07-15 13:57:18|27874|6:6|new|vcld:main(276)|reservation 6 is NOT
already being processed
2010-07-15 13:57:18|27874|6:6|new|utils.pm:get_request_info(5354)|standalone
affiliation found: Local
2010-07-15
13:57:18|27874|6:6|new|utils.pm:get_management_node_info(6815)|management
node info retrieved from database for localhost
2010-07-15 13:57:18|27874|6:6|new|vcld:main(281)|retrieved request
information from database
2010-07-15
13:57:18|27874|6:6|new|utils.pm:get_management_node_info(6815)|management
node info retrieved from database for localhost
2010-07-15
13:57:18|27874|6:6|new|DataStructure.pm:is_parent_reservation(854)|returning
true: parent reservation ID for this request: 6
2010-07-15 13:57:18|27874|6:6|new|utils.pm:update_request_state(2186)|request
6 state updated to: pending, laststate to: new
2010-07-15 13:57:18|27874|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, begin, beginning to process, state is new
2010-07-15 13:57:18|27874|6:6|new|vcld:make_new_child(509)|loaded VCL::new
module
2010-07-15 13:57:18|27904|6:6|new|vcld:make_new_child(582)|vcld environment
variable set to 0 for this process
2010-07-15 13:57:18|27904|6:6|new|Module.pm:new(132)|constructor called,
class=VCL::new
2010-07-15 13:57:18|27904|6:6|new|Module.pm:new(154)|VCL::new object created
2010-07-15 13:57:18|27874|6:6|new|vcld:make_new_child(566)|current number of
forked kids: 1
2010-07-15 13:57:18|27904|6:6|new|State.pm:initialize(85)|obtained a
database handle for this state process, stored as $ENV{dbh}
2010-07-15 13:57:18|27904|6:6|new|State.pm:check_image_os(820)|no
corrections need to be made, not an imaging request, returning 1
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:is_parent_reservation(854)|returning
true: parent reservation ID for this request: 6
2010-07-15 13:57:18|27904|6:6|new|utils.pm:rename_vcld_process(7863)|reservation
count: 1
2010-07-15
13:57:18|27904|6:6|new|utils.pm:rename_vcld_process(7882)|PARENTIMAGE:
1
2010-07-15 13:57:18|27904|6:6|new|utils.pm:rename_vcld_process(7883)|SUBIMAGE:
0
2010-07-15 13:57:18|27904|6:6|new|utils.pm:rename_vcld_process(7901)|renamed
process to 'vcld VCL::new 6:6 new'
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:is_parent_reservation(854)|returning
true: parent reservation ID for this request: 6
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:is_parent_reservation(854)|returning
true: parent reservation ID for this request: 6
2010-07-15 13:57:18|27904|6:6|new|State.pm:initialize(121)|attempting to
load provisioning module: VCL::Module::Provisioning::vmware
2010-07-15
13:57:18|27904|6:6|new|State.pm:initialize(127)|VCL::Module::Provisioning::vmware
module loaded
2010-07-15 13:57:18|27904|6:6|new|Module.pm:new(132)|constructor called,
class=VCL::Module::Provisioning::vmware
2010-07-15
13:57:18|27904|6:6|new|Module.pm:new(154)|VCL::Module::Provisioning::vmware
object created
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:initialize(105)|vmware module
initialized
2010-07-15
13:57:18|27904|6:6|new|State.pm:initialize(131)|VCL::Module::Provisioning::vmware
provisioner object created
2010-07-15 13:57:18|27904|6:6|new|State.pm:initialize(145)|attempting to
load OS module: VCL::Module::OS::Linux
2010-07-15
13:57:18|27904|6:6|new|State.pm:initialize(151)|VCL::Module::OS::Linux
module loaded
2010-07-15 13:57:18|27904|6:6|new|Module.pm:new(132)|constructor called,
class=VCL::Module::OS::Linux
2010-07-15 13:57:18|27904|6:6|new|Module.pm:new(154)|VCL::Module::OS::Linux
object created
2010-07-15
13:57:18|27904|6:6|new|State.pm:initialize(154)|VCL::Module::OS::Linux OS
object created
2010-07-15 13:57:18|27904|6:6|new|State.pm:initialize(169)|returning 1
2010-07-15 13:57:18|27904|6:6|new|vcld:make_new_child(591)|VCL::new object
created and initialized
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:is_parent_reservation(854)|returning
true: parent reservation ID for this request: 6
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:get_computer_state_name(1946)|attempting
to retrieve current state of computer vm1 from the database
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:get_computer_state_name(1977)|retrieved
current state of computer vm1 from the database: available
2010-07-15 13:57:18|27904|6:6|new|DataStructure.pm:_automethod(697)|data
structure updated:
$self->request_data->{reservation}{6}{computer}{state}{name}
|27904|6:6|new| computer_state_name = available
2010-07-15
13:57:18|27904|6:6|new|utils.pm:get_management_node_id(9364)|environment
variable: 1
2010-07-15 13:57:18|27904|6:6|new|new.pm:process(134)|reservation is parent
= 1
2010-07-15 13:57:18|27904|6:6|new|new.pm:process(135)|preload only = 0
2010-07-15 13:57:18|27904|6:6|new|new.pm:process(136)|originating request
state = new
2010-07-15 13:57:18|27904|6:6|new|new.pm:process(137)|originating request
laststate = new
2010-07-15 13:57:18|27904|6:6|new|new.pm:process(138)|originating computer
state = available
2010-07-15 13:57:18|27904|6:6|new|new.pm:process(139)|originating computer
type = virtualmachine
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:is_parent_reservation(854)|returning
true: parent reservation ID for this request: 6
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:get_computer_state_name(1946)|attempting
to retrieve current state of computer vm1 from the database
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:get_computer_state_name(1977)|retrieved
current state of computer vm1 from the database: available
2010-07-15 13:57:18|27904|6:6|new|DataStructure.pm:_automethod(697)|data
structure updated:
$self->request_data->{reservation}{6}{computer}{state}{name}
|27904|6:6|new| computer_state_name = available
2010-07-15
13:57:18|27904|6:6|new|utils.pm:get_management_node_id(9364)|environment
variable: 1
2010-07-15 13:57:18|27904|6:6|new|new.pm:computer_not_being_used(788)|vm1
state is available
2010-07-15 13:57:18|27904|6:6|new|new.pm:computer_not_being_used(798)|vm1 is
available, its state is available
2010-07-15 13:57:18|27904|6:6|new|new.pm:process(170)|vm1 is not being used
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:is_parent_reservation(854)|returning
true: parent reservation ID for this request: 6
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:get_computer_state_name(1946)|attempting
to retrieve current state of computer vm1 from the database
2010-07-15
13:57:18|27904|6:6|new|DataStructure.pm:get_computer_state_name(1977)|retrieved
current state of computer vm1 from the database: available
2010-07-15 13:57:18|27904|6:6|new|DataStructure.pm:_automethod(697)|data
structure updated:
$self->request_data->{reservation}{6}{computer}{state}{name}
|27904|6:6|new| computer_state_name = available
2010-07-15
13:57:18|27904|6:6|new|utils.pm:get_management_node_id(9364)|environment
variable: 1
2010-07-15 13:57:18|27904|6:6|new|new.pm:reload_image(514)|calling
VCL::Module::Provisioning::vmware->node_status()
2010-07-15 13:57:18|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, statuscheck, checking status of node
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:node_status(1927)|identity_keys=
/etc/vcl/vclsandbox_rsa,/etc/vcl/bladelinuxkey_id_rsa
2010-07-15
13:57:18|27904|6:6|new|vmware.pm:node_status(1928)|requestedimagename=
vmwarelinux-test12-v0
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:node_status(1929)|image_os_type=
linux
2010-07-15
13:57:18|27904|6:6|new|vmware.pm:node_status(1930)|request_forimaging=
0
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:node_status(1931)|vmpath=
/var/lib/vmware/runningvms
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:node_status(1932)|datastorepath=
/var/lib/vmware/images
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:node_status(1950)|checking if
vm1 is pingable
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:node_status(1953)|vm1 is
pingable (1)
2010-07-15 13:57:18|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -i
/etc/vcl/bladelinuxkey_id_rsa -l root -p 22 -x vmhost1 'vmware-cmd
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
getstate' 2>&1
2010-07-15 13:57:18|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new| /usr/bin/vmware-cmd: Could not connect to VM
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
|27904|6:6|new| (VMControl error -11: No such virtual machine: The config
file
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
is not registered.
|27904|6:6|new| Please register the config file on the server. For example:
|27904|6:6|new| vmware-cmd -s register
"/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx")
2010-07-15 13:57:18|27904|6:6|new|utils.pm:run_ssh_command(6272)|SSH command
executed on vmhost1, command:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -i
/etc/vcl/bladelinuxkey_id_rsa -l root -p 22 -x vmhost1 'vmware-cmd
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
getstate' 2>&1
|27904|6:6|new| returning (11, "/usr/bin/vmware-cmd: Could not...")
2010-07-15
13:57:18|27904|6:6|new|vmware.pm:node_status(1969)|/usr/bin/vmware-cmd:
Could not connect to VM
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:node_status(1969)|(VMControl
error -11: No such virtual machine: The config file
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
is not registered.
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:node_status(1969)|Please
register the config file on the server. For example:
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:node_status(1969)|vmware-cmd -s
register
"/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx")
2010-07-15 13:57:18|27904|6:6|new|vmware.pm:node_status(1980)|vm1 vmstate
reports 0
2010-07-15 13:57:18|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vm1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vm1 'uname -s' 2>&1
2010-07-15 13:57:19|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new| Linux
2010-07-15 13:57:19|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vm1, returning (0, "Linux")
2010-07-15 13:57:19|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vm1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vm1 'cat currentimage.txt' 2>&1
2010-07-15 13:57:19|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new| vmwarelinux-centosbase10-v2
|27904|6:6|new| id=10
|27904|6:6|new| prettyname=CentOS 5.4 Base Image (VMWare)
|27904|6:6|new| imagerevision_id=12
|27904|6:6|new| imagerevision_datecreated=2010-06-07 16:19:25
|27904|6:6|new| computer_id=2
|27904|6:6|new| computer_hostname=vm1
2010-07-15 13:57:19|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vm1, returning (0, "vmwarelinux-centosbase10-v2 id...")
2010-07-15 13:57:19|27904|6:6|new|utils.pm:_getcurrentimage(2679)|stripped
dos newline vmwarelinux-centosbase10-v2
2010-07-15 13:57:19|27904|6:6|new|vmware.pm:node_status(1999)|vm1 reports
current image is currentimage= vmwarelinux-centosbase10-v2
requestedimagename= vmwarelinux-test12-v0
2010-07-15 13:57:19|27904|6:6|new|vmware.pm:node_status(2018)|returning node
status hash reference ($node_status->{status}=RELOAD)
2010-07-15 13:57:19|27904|6:6|new|new.pm:reload_image(529)|node_status
returned a hash reference
2010-07-15 13:57:19|27904|6:6|new|new.pm:reload_image(534)|node_status hash
reference contains key {status}=RELOAD
2010-07-15 13:57:19|27904|6:6|new|new.pm:reload_image(602)|node status is
RELOAD, vm1 will be reloaded
2010-07-15 13:57:19|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, loadimageblade, vm1 must be reloaded with vmwarelinux-test12-v0
2010-07-15 13:57:19|27904|6:6|new|new.pm:reload_image(616)|calling
VCL::Module::Provisioning::vmware->does_image_exist()
2010-07-15 13:57:19|27904|6:6|new|vmware.pm:does_image_exist(2057)|image
repository path: /install/vmware_images
2010-07-15 13:57:19|27904|6:6|new|utils.pm:run_command(9737)|executed
command: du -c /install/vmware_images/*vmwarelinux-test12-v0* 2>&1 | grep
total 2>&1, pid: 27914, exit status: 0, output:
|27904|6:6|new| 2446860 total
2010-07-15
13:57:19|27904|6:6|new|vmware.pm:does_image_exist(2109)|vmwarelinux-test12-v0
exists in /install/vmware_images, size: 2389 MB
2010-07-15 13:57:19|27904|6:6|new|new.pm:reload_image(619)|vmwarelinux-test12-v0
exists on this management node
2010-07-15 13:57:19|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, doesimageexists, confirmed image exists
2010-07-15 13:57:19|27904|6:6|new|utils.pm:update_computer_state(2228)|computer
2 state updated to: reloading
2010-07-15 13:57:19|27904|6:6|new|new.pm:reload_image(652)|computer vm1
state set to reloading
2010-07-15 13:57:19|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, info, computer state updated to reloading
2010-07-15 13:57:19|27904|6:6|new|new.pm:reload_image(663)|calling
VCL::Module::Provisioning::vmware->load() subroutine
2010-07-15 13:57:19|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, info, calling VCL::Module::Provisioning::vmware->load()
subroutine
2010-07-15 13:57:19|27904|6:6|new|vmware.pm:control_VM(1565)|control remove
is defined
2010-07-15 13:57:19|27904|6:6|new|vmware.pm:control_VM(1629)|checking for
base image on vmhost1 /var/lib/vmware/images
2010-07-15 13:57:19|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 'ls -1 /var/lib/vmware/images' 2>&1
2010-07-15 13:57:19|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new| vmwarelinux-centosbase10-v2
|27904|6:6|new| vmwarelinux-test12-v0
|27904|6:6|new| vmwarewinxp-Alice_Innov811-v5
2010-07-15 13:57:19|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vmhost1, returning (0, "vmwarelinux-centosbase10-v2 vm...")
2010-07-15
13:57:19|27904|6:6|new|vmware.pm:control_VM(1635)|vmwarelinux-centosbase10-v2
vmwarelinux-test12-v0 vmwarewinxp-Alice_Innov811-v5
2010-07-15 13:57:19|27904|6:6|new|vmware.pm:control_VM(1645)|base image
exists
2010-07-15
13:57:19|27904|6:6|new|vmware.pm:control_VM(1657)|/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1/vmwarelinux-centosbase10-v2vm1.vmx
directory structure for vmwarelinux-centosbase10-v2vm1 did not exist
2010-07-15 13:57:19|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 'vmware-cmd -l' 2>&1
2010-07-15 13:57:20|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new|
/var/lib/vmware/managementnode/vmwarelinux-centosbase1617-v1.vmx
|27904|6:6|new|
/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1/vmwarelinux-centosbase10-v2vm1.vmx
2010-07-15 13:57:20|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vmhost1, returning (0, "/var/lib/vmware/managementnode...")
2010-07-15 13:57:20|27904|6:6|new|vmware.pm:
control_VM(1675)|/var/lib/vmware/managementnode/vmwarelinux-centosbase1617-v1.vmx
2010-07-15 13:57:20|27904|6:6|new|vmware.pm:
control_VM(1675)|/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1/vmwarelinux-centosbase10-v2vm1.vmx
2010-07-15 13:57:20|27904|6:6|new|vmware.pm:control_VM(1683)|my vmx
/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1/vmwarelinux-centosbase10-v2vm1.vmx
2010-07-15 13:57:20|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 'vmware-cmd
/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1/vmwarelinux-centosbase10-v2vm1.vmx
getstate' 2>&1
2010-07-15 13:57:20|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new| getstate() = on
2010-07-15 13:57:20|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vmhost1, returning (0, "getstate() = on")
2010-07-15 13:57:20|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 'vmware-cmd
/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1/vmwarelinux-centosbase10-v2vm1.vmx
stop hard' 2>&1
2010-07-15 13:57:21|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new| stop(hard) = 1
2010-07-15 13:57:21|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vmhost1, returning (0, "stop(hard) = 1")
2010-07-15 13:57:21|27904|6:6|new|vmware.pm:control_VM(1701)|turned off
/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1/vmwarelinux-centosbase10-v2vm1.vmx
2010-07-15 13:57:21|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 'vmware-cmd -s unregister
/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1/vmwarelinux-centosbase10-v2vm1.vmx
' 2>&1
2010-07-15 13:57:21|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new|
unregister(/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1/vmwarelinux-centosbase10-v2vm1.vmx)
= 1
2010-07-15 13:57:21|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vmhost1, returning (0, "unregister(/var/lib/vmware/run...")
2010-07-15 13:57:21|27904|6:6|new|vmware.pm:control_VM(1741)|vm
/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1/vmwarelinux-centosbase10-v2vm1.vmx
unregistered
2010-07-15 13:57:21|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 '/bin/rm -rf
/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1' 2>&1
2010-07-15 13:57:21|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new| none
2010-07-15 13:57:22|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vmhost1, returning (0, "none")
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:control_VM(1748)|removed
/var/lib/vmware/runningvms/vmwarelinux-centosbase10-v2vm1 from vmhost1
2010-07-15
13:57:22|27904|6:6|new|DataStructure.pm:get_computer_private_ip_address(1418)|returning
private IP address previously retrieved from /etc/hosts: 192.168.50.10
2010-07-15 13:57:22|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, startload, vm1 vmwarelinux-test12-v0
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(216)|identity file set
/etc/vcl/vclsandbox_rsa vmhost imagename rh4image-VMwareserverhostRHEL48-v3
bladekey /etc/vcl/vclsandbox_rsa
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(244)|persistent= 0
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(245)|myvmdir=
vmwarelinux-test12-v0vm1
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(246)|myvmx=
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(247)|mybasedirname=
vmwarelinux-test12-v0
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(248)|myimagename=
vmwarelinux-test12-v0
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(251)|checking for base
image vmwarelinux-test12-v0vm1 on vmhost1
2010-07-15 13:57:22|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, vmround1, checking host for requested image files
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(256)|trying to create
exclusive lock on /tmp/vmhost1vmwarelinux-test12-v0lock while checking if
image files exist on host
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(259)|owning exclusive lock
on /tmp/vmhost1vmwarelinux-test12-v0lock
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(260)|listing datestore
/var/lib/vmware/images
2010-07-15 13:57:22|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 'ls -1 /var/lib/vmware/images' 2>&1
2010-07-15 13:57:22|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new| vmwarelinux-centosbase10-v2
|27904|6:6|new| vmwarelinux-test12-v0
|27904|6:6|new| vmwarewinxp-Alice_Innov811-v5
2010-07-15 13:57:22|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vmhost1, returning (0, "vmwarelinux-centosbase10-v2 vm...")
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(270)|data store contents
/var/lib/vmware/images on vm host:
|27904|6:6|new| vmwarelinux-centosbase10-v2 vmwarelinux-test12-v0
vmwarewinxp-Alice_Innov811-v5
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(283)|base image exists
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(549)|confirm image exist
process complete removing lock on /tmp/vmhost1vmwarelinux-test12-v0lock
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(611)|created tmp directory
/tmp/vmwarelinux-test12-v0vm1
|27904|6:6|new| ---- WARNING ----
|27904|6:6|new| 2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(635)|image
memory value 64 out of the expected range in host machine 8096 setting to
512
|27904|6:6|new| ( 0) utils.pm, notify (line: 737)
|27904|6:6|new| (-1) vmware.pm, load (line: 635)
|27904|6:6|new| (-2) new.pm, reload_image (line: 665)
|27904|6:6|new| (-3) new.pm, process (line: 266)
|27904|6:6|new| (-4) vcld, make_new_child (line: 594)
|27904|6:6|new| (-5) vcld, main (line: 341)
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(646)|sda flag set, setting
adapter to buslogic
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(658)|path is
/install/vmware_images/vmwarelinux-test12-v0/vmwarelinux-test12-v0.vmdk
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(668)|grep:
/install/vmware_images/vmwarelinux-test12-v0/vmwarelinux-test12-v0.vmdk: No
such file or directory
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(676)|adapter= buslogic
drivetype sda
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(753)|wrote vmxarray to
/tmp/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
2010-07-15 13:57:22|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, vmconfigcopy, transferring vmx file to vmhost1
2010-07-15 13:57:22|27904|6:6|new|utils.pm:run_scp_command(6403)|attempt
1/3: executing SCP command: /usr/bin/scp -B -i /etc/vcl/vclsandbox_rsa -P 22
-p -r /tmp/vmwarelinux-test12-v0vm1 vmhost1:"/var/lib/vmware/runningvms"
2>&1
2010-07-15 13:57:22|27904|6:6|new|utils.pm:run_scp_command(6453)|scp
successful: attempt 1/3, exit status: 0, output: none
2010-07-15 13:57:22|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 'ls -1 /var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1;chmod 755
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx'
2>&1
2010-07-15 13:57:22|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new| vmwarelinux-test12-v0vm1.vmx
2010-07-15 13:57:22|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vmhost1, returning (0, "vmwarelinux-test12-v0vm1.vmx")
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(769)|successfully copied
vmx file to vmhost1
2010-07-15 13:57:22|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, vmsetupconfig, setting up vmx file
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(790)|successfully removed
/tmp/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
2010-07-15 13:57:22|27904|6:6|new|vmware.pm:load(791)|successfully removed
tmp directory
2010-07-15 13:57:22|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 'vmware-cmd -s register
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx'
2>&1
2010-07-15 13:57:23|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new|
register(/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx)
= 1
2010-07-15 13:57:23|27904|6:6|new|utils.pm:run_ssh_command(6276)|SSH command
executed on vmhost1, returning (0, "register(/var/lib/vmware/runni...")
2010-07-15 13:57:23|27904|6:6|new|vmware.pm:load(805)|vm
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
registered
2010-07-15 13:57:23|27904|6:6|new|vmware.pm:load(827)|starting vm
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
- pass 1
2010-07-15 13:57:23|27904|6:6|new|utils.pm:run_ssh_command(6180)|executing
SSH command on vmhost1:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 'vmware-cmd
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
start' 2>&1
2010-07-15 13:57:23|27874|vcld:main(165)|lastcheckin time updated for
management node 1: 2010-07-15 13:57:23
2010-07-15 13:57:23|27904|6:6|new|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|27904|6:6|new| VMControl error -16: Virtual machine requires user input to
continue
2010-07-15 13:57:23|27904|6:6|new|utils.pm:run_ssh_command(6272)|SSH command
executed on vmhost1, command:
|27904|6:6|new| /usr/bin/ssh -i /etc/vcl/vclsandbox_rsa -l root -p 22 -x
vmhost1 'vmware-cmd
/var/lib/vmware/runningvms/vmwarelinux-test12-v0vm1/vmwarelinux-test12-v0vm1.vmx
start' 2>&1
|27904|6:6|new| returning (16, "VMControl error -16: Virtual m...")
2010-07-15 13:57:23|27904|6:6|new|vmware.pm:load(843)|vmware-cmd start
failed
|27904|6:6|new| VMControl error -16: Virtual machine requires user input to
continue
|27904|6:6|new| ---- WARNING ----
|27904|6:6|new| 2010-07-15
13:57:23|27904|6:6|new|new.pm:reload_image(670)|vmwarelinux-test12-v0
failed to load on vm1, returning
|27904|6:6|new| ( 0) utils.pm, notify (line: 737)
|27904|6:6|new| (-1) new.pm, reload_image (line: 670)
|27904|6:6|new| (-2) new.pm, process (line: 266)
|27904|6:6|new| (-3) vcld, make_new_child (line: 594)
|27904|6:6|new| (-4) vcld, main (line: 341)
2010-07-15 13:57:23|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, loadimagefailed, vmwarelinux-test12-v0 failed to load on vm1
|27904|6:6|new| ---- WARNING ----
|27904|6:6|new| 2010-07-15 13:57:23|27904|6:6|new|new.pm:process(313)|failed
to load vm1 with vmwarelinux-test12-v0
|27904|6:6|new| ( 0) utils.pm, notify (line: 737)
|27904|6:6|new| (-1) new.pm, process (line: 313)
|27904|6:6|new| (-2) vcld, make_new_child (line: 594)
|27904|6:6|new| (-3) vcld, main (line: 341)
2010-07-15
13:57:23|27904|6:6|new|DataStructure.pm:get_computer_state_name(1946)|attempting
to retrieve current state of computer vm1 from the database
2010-07-15
13:57:23|27904|6:6|new|DataStructure.pm:get_computer_state_name(1977)|retrieved
current state of computer vm1 from the database: reloading
2010-07-15 13:57:23|27904|6:6|new|DataStructure.pm:_automethod(697)|data
structure updated:
$self->request_data->{reservation}{6}{computer}{state}{name}
|27904|6:6|new| computer_state_name = reloading
No recipient addresses found in header
2010-07-15 13:57:23|27904|6:6|new|utils.pm:mail(1348)|SUCCESS -- Sending
mail To: , PROBLEM -- State.pm
|27904|6:6|new| ---- CRITICAL ----
|27904|6:6|new| 2010-07-15
13:57:23|27904|6:6|new|State.pm:reservation_failed(290)|reservation failed
on vm1: process failed after trying to load or make available
|27904|6:6|new| ( 0) utils.pm, notify (line: 737)
|27904|6:6|new| (-1) State.pm, reservation_failed (line: 290)
|27904|6:6|new| (-2) new.pm, process (line: 316)
|27904|6:6|new| (-3) vcld, make_new_child (line: 594)
|27904|6:6|new| (-4) vcld, main (line: 341)
2010-07-15 13:57:23|27904|6:6|new|utils.pm:insertloadlog(4710)|inserted
computer=2, failed, process failed after trying to load or make available
2010-07-15 13:57:23|27904|6:6|new|State.pm:reservation_failed(293)|inserted
computerloadlog entry
2010-07-15 13:57:23|27904|6:6|new|State.pm:reservation_failed(301)|updated
log ending value to 'failed', logid=3
2010-07-15 13:57:23|27904|6:6|new|utils.pm:update_computer_state(2228)|computer
2 state updated to: failed
2010-07-15 13:57:23|27904|6:6|new|State.pm:reservation_failed(312)|computer
vm1 (2) state set to failed
2010-07-15 13:57:23|27904|6:6|new|utils.pm:update_request_state(2186)|request
6 state updated to: failed, laststate to: new
2010-07-15 13:57:23|27904|6:6|new|State.pm:reservation_failed(325)|set
request state to 'failed'/'new'
2010-07-15 13:57:23|27904|6:6|new|utils.pm:is_inblockrequest(6972)|zero rows
were returned from database select
2010-07-15 13:57:23|27904|6:6|new|State.pm:reservation_failed(343)|vm1 is
NOT in blockcomputers table
2010-07-15 13:57:23|27904|6:6|new|State.pm:reservation_failed(346)|exiting 1
2010-07-15 13:57:23|27904|6:6|new|State.pm:DESTROY(905)|destructor called,
ref($self)=VCL::new
2010-07-15
13:57:23|27904|6:6|new|utils.pm:delete_computerloadlog_reservation(7551)|removing
computerloadlog entries matching loadstate = begin
2010-07-15
13:57:23|27904|6:6|new|utils.pm:delete_computerloadlog_reservation(7598)|deleted
rows from computerloadlog for reservation id=6
2010-07-15 13:57:23|27904|6:6|new|State.pm:DESTROY(912)|removed
computerloadlog rows with loadstate=begin for reservation
2010-07-15 13:57:23|27904|6:6|new|State.pm:DESTROY(924)|number of database
handles state process created: 1
2010-07-15 13:57:23|27904|6:6|new|State.pm:DESTROY(933)|process has a
database handle stored in $ENV{dbh}, attempting disconnect
2010-07-15 13:57:23|27904|6:6|new|State.pm:DESTROY(935)|$ENV{dbh}: database
disconnect successful
2010-07-15 13:57:23|27904|6:6|new|State.pm:DESTROY(949)|VCL::new process
27904 exiting
2010-07-15 13:57:23|27874|vcld:REAPER(744)|VCL process exited for
reservation 6
--
Thanks,
Kiran
