Hello,
I'm having an issue with one of my VM's it fails from time to time
with different images. I'm not sure whats going on.
Any insight would be helpfull.
Thank you
-Alex
Here is the log
2011-02-01 16:28:04|6620|36146:35882|reload|vmware.pm:load(883)|vmguest-65
ROUND 1 checks loop 64 of 40
2011-02-01
16:28:04|6620|36146:35882|reload|utils.pm:run_ssh_command(6180)|executing
SSH command on vclesx02:
|6620|36146:35882|reload| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p
22 -x vclesx02 'vmware-cmd
/virtualmachines/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65.vmx
getstate' 2>&1
2011-02-01
16:28:04|7852|36147:35883|reserved|DataStructure.pm:get_reservation_remote_ip(956)|reservation
remote IP is not defined
2011-02-01
16:28:05|6620|36146:35882|reload|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|6620|36146:35882|reload| Use of uninitialized value in string eq at
/usr/lib64/perl5/site_perl/5.8.8/x86_64-linux-thread-multi/VMware/VmPerl.pm
line 114.
|6620|36146:35882|reload| getstate() = on
2011-02-01 16:28:05|6620|36146:35882|reload|utils.pm:run_ssh_command(6276)|SSH
command executed on vclesx02, returning (0, "Use of uninitialized
value in ...")
2011-02-01 16:28:05|6620|36146:35882|reload|vmware.pm:load(887)|rechecking
state of vm vmguest-65
/virtualmachines/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65.vmx
2011-02-01 16:28:05|6620|36146:35882|reload|vmware.pm:load(892)|vm
vmguest-65 reports on
2011-02-01 16:28:05|6620|36146:35882|reload|vmware.pm:load(903)|sshd
is NOT active on vmguest-65 yet
2011-02-01
16:28:09|7852|36147:35883|reserved|DataStructure.pm:get_reservation_remote_ip(956)|reservation
remote IP is not defined
2011-02-01 16:28:11|12372|vcld:main(165)|lastcheckin time updated for
management node 1: 2011-02-01 16:28:11
2011-02-01
16:28:14|7852|36147:35883|reserved|DataStructure.pm:get_reservation_remote_ip(956)|reservation
remote IP is not defined
2011-02-01 16:28:15|6620|36146:35882|reload|vmware.pm:load(883)|vmguest-65
ROUND 1 checks loop 65 of 40
2011-02-01
16:28:15|6620|36146:35882|reload|utils.pm:run_ssh_command(6180)|executing
SSH command on vclesx02:
|6620|36146:35882|reload| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p
22 -x vclesx02 'vmware-cmd
/virtualmachines/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65.vmx
getstate' 2>&1
2011-02-01
16:28:15|6620|36146:35882|reload|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|6620|36146:35882|reload| Use of uninitialized value in string eq at
/usr/lib64/perl5/site_perl/5.8.8/x86_64-linux-thread-multi/VMware/VmPerl.pm
line 114.
|6620|36146:35882|reload| getstate() = on
2011-02-01 16:28:15|6620|36146:35882|reload|utils.pm:run_ssh_command(6276)|SSH
command executed on vclesx02, returning (0, "Use of uninitialized
value in ...")
2011-02-01 16:28:15|6620|36146:35882|reload|vmware.pm:load(887)|rechecking
state of vm vmguest-65
/virtualmachines/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65.vmx
2011-02-01 16:28:15|6620|36146:35882|reload|vmware.pm:load(892)|vm
vmguest-65 reports on
2011-02-01 16:28:15|6620|36146:35882|reload|vmware.pm:load(903)|sshd
is NOT active on vmguest-65 yet
2011-02-01 16:28:16|12372|vcld:main(165)|lastcheckin time updated for
management node 1: 2011-02-01 16:28:16
2011-02-01
16:28:19|7852|36147:35883|reserved|DataStructure.pm:get_reservation_remote_ip(956)|reservation
remote IP is not defined
2011-02-01 16:28:21|12372|vcld:main(165)|lastcheckin time updated for
management node 1: 2011-02-01 16:28:21
2011-02-01
16:28:24|7852|36147:35883|reserved|DataStructure.pm:get_reservation_remote_ip(956)|reservation
remote IP is not defined
2011-02-01 16:28:25|6620|36146:35882|reload|vmware.pm:load(883)|vmguest-65
ROUND 1 checks loop 66 of 40
2011-02-01
16:28:25|6620|36146:35882|reload|utils.pm:run_ssh_command(6180)|executing
SSH command on vclesx02:
|6620|36146:35882|reload| /usr/bin/ssh -i /etc/vcl/vcl.key -l root -p
22 -x vclesx02 'vmware-cmd
/virtualmachines/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65.vmx
getstate' 2>&1
2011-02-01
16:28:26|6620|36146:35882|reload|utils.pm:run_ssh_command(6262)|run_ssh_command
output:
|6620|36146:35882|reload| Use of uninitialized value in string eq at
/usr/lib64/perl5/site_perl/5.8.8/x86_64-linux-thread-multi/VMware/VmPerl.pm
line 114.
|6620|36146:35882|reload| getstate() = on
2011-02-01 16:28:26|6620|36146:35882|reload|utils.pm:run_ssh_command(6276)|SSH
command executed on vclesx02, returning (0, "Use of uninitialized
value in ...")
2011-02-01 16:28:26|6620|36146:35882|reload|vmware.pm:load(887)|rechecking
state of vm vmguest-65
/virtualmachines/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65.vmx
2011-02-01 16:28:26|6620|36146:35882|reload|vmware.pm:load(892)|vm
vmguest-65 reports on
2011-02-01 16:28:26|6620|36146:35882|reload|vmware.pm:load(903)|sshd
is NOT active on vmguest-65 yet
No recipient addresses found in header
2011-02-01 16:28:26|6620|36146:35882|reload|utils.pm:mail(1348)|SUCCESS
-- Sending mail To: , PROBLEM -- vmware.pm
|6620|36146:35882|reload| ---- CRITICAL ----
|6620|36146:35882|reload| 2011-02-01
16:28:26|6620|36146:35882|reload|vmware.pm:load(1002)|could not load
/virtualmachines/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65/vmwarewinxp-AdobeDreamweaverCS456-v1vmguest-65.vmx
on vmguest-65 on host vclesx02
|6620|36146:35882|reload| ( 0) utils.pm, notify (line: 737)
|6620|36146:35882|reload| (-1) vmware.pm, load (line: 1002)
|6620|36146:35882|reload| (-2) new.pm, reload_image (line: 665)
|6620|36146:35882|reload| (-3) new.pm, process (line: 266)
|6620|36146:35882|reload| (-4) vcld, make_new_child (line: 594)
|6620|36146:35882|reload| (-5) vcld, main (line: 341)
2011-02-01
16:28:26|6620|36146:35882|reload|utils.pm:insertloadlog(4710)|inserted
computer=69, failed, could not load vmx on vclesx02
|6620|36146:35882|reload| ---- WARNING ----
|6620|36146:35882|reload| 2011-02-01
16:28:26|6620|36146:35882|reload|new.pm:reload_image(670)|vmwarewinxp-AdobeDreamweaverCS456-v1
failed to load on vmguest-65, returning
|6620|36146:35882|reload| ( 0) utils.pm, notify (line: 737)
|6620|36146:35882|reload| (-1) new.pm, reload_image (line: 670)
|6620|36146:35882|reload| (-2) new.pm, process (line: 266)
|6620|36146:35882|reload| (-3) vcld, make_new_child (line: 594)
|6620|36146:35882|reload| (-4) vcld, main (line: 341)
2011-02-01
16:28:26|6620|36146:35882|reload|utils.pm:insertloadlog(4710)|inserted
computer=69, loadimagefailed, vmwarewinxp-AdobeDreamweaverCS456-v1
failed to load on vmguest-65
|6620|36146:35882|reload| ---- WARNING ----
|6620|36146:35882|reload| 2011-02-01
16:28:26|6620|36146:35882|reload|new.pm:process(313)|failed to load
vmguest-65 with vmwarewinxp-AdobeDreamweaverCS456-v1
|6620|36146:35882|reload| ( 0) utils.pm, notify (line: 737)
|6620|36146:35882|reload| (-1) new.pm, process (line: 313)
|6620|36146:35882|reload| (-2) vcld, make_new_child (line: 594)
|6620|36146:35882|reload| (-3) vcld, main (line: 341)
2011-02-01
16:28:26|6620|36146:35882|reload|DataStructure.pm:get_computer_state_name(1946)|attempting
to retrieve current state of computer vmguest-65 from the database
2011-02-01
16:28:26|6620|36146:35882|reload|DataStructure.pm:get_computer_state_name(1977)|retrieved
current state of computer vmguest-65 from the database: reloading
2011-02-01
16:28:26|6620|36146:35882|reload|DataStructure.pm:_automethod(697)|data
structure updated:
$self->request_data->{reservation}{35882}{computer}{state}{name}
|6620|36146:35882|reload| computer_state_name = reloading
No recipient addresses found in header
2011-02-01 16:28:26|6620|36146:35882|reload|utils.pm:mail(1348)|SUCCESS
-- Sending mail To: , PROBLEM -- State.pm
|6620|36146:35882|reload| ---- CRITICAL ----
|6620|36146:35882|reload| 2011-02-01
16:28:26|6620|36146:35882|reload|State.pm:reservation_failed(290)|reservation
failed on vmguest-65: process failed after trying to load or make
available
|6620|36146:35882|reload| ( 0) utils.pm, notify (line: 737)
|6620|36146:35882|reload| (-1) State.pm, reservation_failed (line: 290)
|6620|36146:35882|reload| (-2) new.pm, process (line: 316)
|6620|36146:35882|reload| (-3) vcld, make_new_child (line: 594)
|6620|36146:35882|reload| (-4) vcld, main (line: 341)
2011-02-01
16:28:26|6620|36146:35882|reload|utils.pm:insertloadlog(4710)|inserted
computer=69, failed, process failed after trying to load or make
available
2011-02-01
16:28:26|6620|36146:35882|reload|State.pm:reservation_failed(293)|inserted
computerloadlog entry
2011-02-01
16:28:26|6620|36146:35882|reload|utils.pm:update_computer_state(2228)|computer
69 state updated to: failed
2011-02-01
16:28:26|6620|36146:35882|reload|State.pm:reservation_failed(312)|computer
vmguest-65 (69) state set to failed
2011-02-01
16:28:26|6620|36146:35882|reload|utils.pm:update_request_state(2186)|request
36146 state updated to: failed, laststate to: inuse
2011-02-01 16:28:26|6620|36146:35882|reload|State.pm:reservation_failed(325)|set
request state to 'failed'/'inuse'
2011-02-01
16:28:26|6620|36146:35882|reload|utils.pm:is_inblockrequest(6972)|zero
rows were returned from database select
2011-02-01
16:28:26|6620|36146:35882|reload|State.pm:reservation_failed(343)|vmguest-65
is NOT in blockcomputers table
2011-02-01
16:28:26|6620|36146:35882|reload|State.pm:reservation_failed(346)|exiting
1
2011-02-01 16:28:26|6620|36146:35882|reload|State.pm:DESTROY(905)|destructor
called, ref($self)=VCL::new
2011-02-01
16:28:26|6620|36146:35882|reload|utils.pm:delete_computerloadlog_reservation(7551)|removing
computerloadlog entries matching loadstate = begin
2011-02-01
16:28:26|6620|36146:35882|reload|utils.pm:delete_computerloadlog_reservation(7598)|deleted
rows from computerloadlog for reservation id=35882
2011-02-01 16:28:26|6620|36146:35882|reload|State.pm:DESTROY(912)|removed
computerloadlog rows with loadstate=begin for reservation
2011-02-01 16:28:26|6620|36146:35882|reload|State.pm:DESTROY(924)|number
of database handles state process created: 1
2011-02-01 16:28:26|6620|36146:35882|reload|State.pm:DESTROY(933)|process
has a database handle stored in $ENV{dbh}, attempting disconnect
2011-02-01 16:28:26|6620|36146:35882|reload|State.pm:DESTROY(935)|$ENV{dbh}:
database disconnect successful
2011-02-01 16:28:26|6620|36146:35882|reload|State.pm:DESTROY(949)|VCL::new
process 6620 exiting
--
Thanks,
Alex Patterson
User Support Services
Operating System Analyst
California State University, East Bay
