Here is the extended log file as promised.
Best,
Kris Augustus
CCNA, RHCE, A+
Lab Supervisor
College of TECS
East Carolina University
252-737-1978
[email protected]<mailto:[email protected]>
Intelligence plus character- that is the goal of true education.
Dr. Martin Luther King Jr.
2009-05-14 17:31:03|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:31:03
2009-05-14 17:31:15|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:31:15
2009-05-14
17:31:20|5506|33:33|new|utils.pm:run_ssh_command(6776)|run_ssh_command output:
2009-05-14 17:31:20|5506|33:33|new|utils.pm:run_ssh_command(6784)|SSH command
executed on 172.17.0.1, returning (0, "none")
2009-05-14 17:31:20|5506|33:33|new|utils.pm:run_ssh_command(6695)|executing SSH
command on 172.17.0.1:
2009-05-14
17:31:21|5506|33:33|new|utils.pm:run_ssh_command(6776)|run_ssh_command output:
2009-05-14 17:31:21|5506|33:33|new|utils.pm:run_ssh_command(6784)|SSH command
executed on 172.17.0.1, returning (0, "ddb.adapterType = "lsilogic"")
2009-05-14 17:31:21|5506|33:33|new|esx.pm:load(266)|adapter= lsilogic
2009-05-14 17:31:21|5506|33:33|new|esx.pm:load(311)|wrote vmxarray to
/tmp/TECS-ESX-4600-2.vmx
2009-05-14 17:31:21|5506|33:33|new|utils.pm:run_scp_command(6896)|attempt 1/3:
executing SCP command: /usr/bin/scp -B -i /etc/vcl/bladelinuxkey_id_rsa -P 22
-p -r /tmp/TECS-ESX-4600-2.vmx
172.17.0.1:/mnt/vcl/inuse/TECS-ESX-4600-2/esx3-linuxtest-v0.vmx 2>&1
2009-05-14 17:31:21|5506|33:33|new|utils.pm:run_scp_command(6942)|scp
successful: attempt 1/3, exit status: 0, output: none
2009-05-14 17:31:21|5506|33:33|new|esx.pm:load(336)|Register Command:
/usr/lib/vmware-viperl/apps/vm/vmregister.pl --server 'TECS-ESX-4600-2'
--username vcl --password 'xxxxxxxx' --vmxpath
'[VCL]/inuse/TECS-ESX-4600-2/esx3-linuxtest-v0.vmx' --operation register
--vmname TECS-ESX-4600-2 --pool Resources --hostname 'TECS-ESX-4600-2'
--datacenter 'ha-datacenter'
2009-05-14 17:31:27|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:31:27
2009-05-14 17:31:29|5506|33:33|new|esx.pm:load(339)|Registered:
2009-05-14 17:31:29|5506|33:33|new|esx.pm:load(348)|Power on command:
/usr/lib/vmware-viperl/apps/vm/vmcontrol.pl --server 'TECS-ESX-4600-2' --vmname
TECS-ESX-4600-2 --operation poweron --username vcl --password 'xxxxxxxx'
2009-05-14 17:31:36|5506|33:33|new|esx.pm:load(351)|Powered on: Virtual Machine
TECS-ESX-4600-2 not found.
2009-05-14 17:31:39|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:31:39
2009-05-14 17:31:44|5506|33:33|new|utils.pm:mail(1301)|SUCCESS -- Sending mail
To: , PROBLEM -- esx.pm
|5506|33:33|new| 2009-05-14 17:31:44|5506|33:33|new|esx.pm:load(359)|Could not
query for VM in VI PERL API
|5506|33:33|new| 2009-05-14
17:31:44|5506|33:33|new|new.pm:reload_image(669)|esx3-linuxtest-v0 failed to
load on TECS-ESX-4600-2, returning
2009-05-14 17:31:44|5506|33:33|new|utils.pm:insertloadlog(5324)|inserted
computer=1, loadimagefailed, esx3-linuxtest-v0 failed to load on TECS-ESX-4600-2
|5506|33:33|new| 2009-05-14 17:31:44|5506|33:33|new|new.pm:process(313)|failed
to load TECS-ESX-4600-2 with esx3-linuxtest-v0
2009-05-14 17:31:44|5506|33:33|new|utils.pm:mail(1301)|SUCCESS -- Sending mail
To: , PROBLEM -- State.pm
|5506|33:33|new| 2009-05-14
17:31:44|5506|33:33|new|State.pm:reservation_failed(285)|reservation failed on
TECS-ESX-4600-2: process failed after trying to load or make available
2009-05-14 17:31:44|5506|33:33|new|utils.pm:insertloadlog(5324)|inserted
computer=1, failed, process failed after trying to load or make available
2009-05-14 17:31:44|5506|33:33|new|State.pm:reservation_failed(288)|inserted
computerloadlog entry
2009-05-14 17:31:44|5506|33:33|new|State.pm:reservation_failed(296)|updated log
ending value to 'failed', logid=18
2009-05-14
17:31:44|5506|33:33|new|utils.pm:update_computer_state(2325)|computer 1 state
updated to: failed
2009-05-14 17:31:44|5506|33:33|new|State.pm:reservation_failed(307)|computer
TECS-ESX-4600-2 (1) state set to failed
2009-05-14 17:31:44|5506|33:33|new|utils.pm:update_request_state(2283)|request
33 state updated to: failed, laststate to: new
2009-05-14 17:31:44|5506|33:33|new|State.pm:reservation_failed(315)|set request
state to 'failed'/'new'
2009-05-14 17:31:44|5506|33:33|new|utils.pm:is_inblockrequest(7384)|zero rows
were returned from database select
2009-05-14
17:31:44|5506|33:33|new|State.pm:reservation_failed(333)|TECS-ESX-4600-2 is NOT
in blockcomputers table
2009-05-14 17:31:44|5506|33:33|new|State.pm:reservation_failed(336)|exiting 1
2009-05-14 17:31:44|5506|33:33|new|State.pm:DESTROY(442)|destructor called,
ref($self)=VCL::new
2009-05-14
17:31:44|5506|33:33|new|utils.pm:delete_computerloadlog_reservation(8041)|removing
computerloadlog entries matching loadstate = begin
2009-05-14
17:31:44|5506|33:33|new|utils.pm:delete_computerloadlog_reservation(8088)|deleted
rows from computerloadlog for reservation id=33
2009-05-14 17:31:44|5506|33:33|new|State.pm:DESTROY(445)|removed
computerloadlog rows with loadstate=begin for reservation
2009-05-14 17:31:44|5506|33:33|new|State.pm:DESTROY(453)|number of database
handles state process created: 1
2009-05-14 17:31:44|5506|33:33|new|State.pm:DESTROY(462)|process has a database
handle stored in $ENV{dbh}, attempting disconnect
2009-05-14 17:31:44|5506|33:33|new|State.pm:DESTROY(464)|$ENV{dbh}: database
disconnect successful
2009-05-14 17:31:44|2065|vcld:REAPER(750)|VCL process exited for reservation 33
2009-05-14 17:31:44|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:31:44
2009-05-14 17:31:56|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:31:56
2009-05-14 17:32:08|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:32:08
2009-05-14 17:32:20|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:32:20
2009-05-14 17:32:32|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:32:32
2009-05-14 17:32:44|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:32:44
2009-05-14 17:32:57|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:32:57
2009-05-14 17:33:09|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:33:09
2009-05-14 17:33:21|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:33:21
2009-05-14 17:33:33|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:33:33
2009-05-14 17:33:45|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:33:45
2009-05-14 17:33:57|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:33:57
2009-05-14 17:34:09|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:34:09
2009-05-14 17:34:21|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:34:21
2009-05-14 17:34:33|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:34:33
2009-05-14 17:34:45|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:34:45
2009-05-14 17:34:57|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:34:57
2009-05-14 17:35:09|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:35:09
2009-05-14 17:35:21|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:35:21
2009-05-14 17:35:33|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:35:33
2009-05-14 17:35:45|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:35:45
2009-05-14 17:35:57|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:35:57
2009-05-14 17:36:09|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:36:09
2009-05-14 17:36:21|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:36:21
2009-05-14 17:36:33|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:36:33
2009-05-14 17:36:45|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:36:45
2009-05-14 17:36:57|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:36:57
2009-05-14 17:37:09|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:37:09
2009-05-14 17:37:21|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:37:21
2009-05-14 17:37:33|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:37:33
2009-05-14 17:37:45|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:37:45
2009-05-14 17:37:57|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:37:57
2009-05-14 17:38:09|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:38:09
2009-05-14 17:38:21|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:38:21
2009-05-14 17:38:33|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:38:33
2009-05-14 17:38:45|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:38:45
2009-05-14 17:38:57|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:38:57
2009-05-14 17:39:10|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:39:09
2009-05-14 17:39:22|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:39:22
2009-05-14 17:39:34|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:39:34
2009-05-14 17:39:46|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:39:46
2009-05-14 17:39:58|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:39:58
2009-05-14 17:40:10|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:40:10
2009-05-14 17:40:22|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:40:22
2009-05-14 17:40:34|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:40:34
2009-05-14 17:40:46|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:40:46
2009-05-14 17:40:58|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:40:58
2009-05-14 17:41:10|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:41:10
2009-05-14 17:41:22|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:41:22
2009-05-14 17:41:34|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:41:34
2009-05-14 17:41:46|2065|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:41:46
OUTPUT for vcld run on 2009-05-14 17:41:56
2009-05-14 17:41:56|6209|vcld:main(117)|vcld environment variable set to 1 for
this process
2009-05-14 17:41:56|6209|utils.pm:rename_vcld_process(8390)|renamed process to
'vcld vcld'
2009-05-14 17:41:56|6209|utils.pm:get_management_node_info(7277)|management
node info retrieved from database for 150
2009-05-14 17:41:56|6209|vcld:main(128)|retrieved management node information
from database
2009-05-14 17:41:56|6209|vcld:main(141)|management_node_id environment variable
set: 1
2009-05-14 17:41:56|6209|vcld:main(149)|management node checkin interval is 12
seconds
2009-05-14 17:41:56|6209|vcld:main(150)|vcld started on 150.xxx.xxx.186
OUTPUT for vcld run on 2009-05-14 17:42:25
2009-05-14 17:42:25|6380|vcld:main(117)|vcld environment variable set to 1 for
this process
2009-05-14 17:42:25|6380|utils.pm:rename_vcld_process(8390)|renamed process to
'vcld vcld'
2009-05-14 17:42:25|6380|utils.pm:get_management_node_info(7277)|management
node info retrieved from database for 150
2009-05-14 17:42:25|6380|vcld:main(128)|retrieved management node information
from database
2009-05-14 17:42:25|6380|vcld:main(141)|management_node_id environment variable
set: 1
2009-05-14 17:42:25|6380|vcld:main(149)|management node checkin interval is 12
seconds
2009-05-14 17:42:25|6380|vcld:main(150)|vcld started on 150.xxx.xxx.186
2009-05-14 17:42:37|6380|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:42:37
2009-05-14 17:42:49|6380|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:42:49
2009-05-14 17:43:01|6380|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:43:01
2009-05-14 17:43:14|6380|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:43:14
2009-05-14 17:43:14|6380|34:34|new|utils.pm:check_time(1167)|reservation start
time was in the past 17 minutes (-13)
2009-05-14
17:43:14|6380|34:34|new|utils.pm:reservation_being_processed(9818)|computerloadlog
'begin' entry does NOT exist for reservation 34
2009-05-14
17:43:14|6380|34:34|new|utils.pm:reservation_being_processed(9870)|reservation
is NOT currently being processed
2009-05-14 17:43:14|6380|34:34|new|vcld:main(282)|reservation 34 is NOT already
being processed
|6380|34:34|new| 2009-05-14
17:43:14|6380|34:34|new|utils.pm:get_request_info(5845)|preferredimageid is not
set for computer id=1
2009-05-14 17:43:14|6380|34:34|new|utils.pm:get_request_info(5991)|non-NCSU
user affiliation found: Local
2009-05-14
17:43:14|6380|34:34|new|utils.pm:get_management_node_info(7277)|management node
info retrieved from database for 150
2009-05-14 17:43:14|6380|34:34|new|vcld:main(287)|retrieved request information
from database
2009-05-14
17:43:14|6380|34:34|new|utils.pm:get_management_node_info(7277)|management node
info retrieved from database for 150
2009-05-14
17:43:14|6380|34:34|new|DataStructure.pm:is_parent_reservation(785)|returning
true: parent reservation ID for this request: 34
2009-05-14 17:43:14|6380|34:34|new|utils.pm:update_request_state(2283)|request
34 state updated to: pending, laststate to: new
2009-05-14 17:43:14|6380|34:34|new|vcld:main(327)|request state updated to
pending, laststate new
2009-05-14 17:43:14|6380|34:34|new|utils.pm:insertloadlog(5324)|inserted
computer=1, begin, beginning to process, state is new
2009-05-14 17:43:14|6380|34:34|new|vcld:main(340)|inserted 'begin' entry into
computerloadlog for reservation 34
2009-05-14 17:43:14|6380|34:34|new|vcld:make_new_child(511)|creating new process
2009-05-14 17:43:14|6380|34:34|new|vcld:make_new_child(515)|loaded VCL::new
module
2009-05-14 17:43:14|6423|34:34|new|vcld:make_new_child(588)|vcld environment
variable set to 0 for this process
2009-05-14 17:43:14|6423|34:34|new|Module.pm:new(80)|constructor called,
class=VCL::new
2009-05-14 17:43:14|6423|34:34|new|Module.pm:new(102)|VCL::new object created
2009-05-14 17:43:14|6380|34:34|new|vcld:make_new_child(572)|current number of
forked kids: 1
2009-05-14 17:43:14|6423|34:34|new|State.pm:initialize(86)|obtained a database
handle for this state process, stored as $ENV{dbh}
2009-05-14 17:43:14|6423|34:34|new|State.pm:check_image_os(361)|no corrections
need to be made, not an imaging request, returning 1
2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:is_parent_reservation(785)|returning
true: parent reservation ID for this request: 34
2009-05-14
17:43:14|6423|34:34|new|utils.pm:rename_vcld_process(8352)|reservation count: 1
2009-05-14
17:43:14|6423|34:34|new|utils.pm:rename_vcld_process(8371)|PARENTIMAGE: 1
2009-05-14 17:43:14|6423|34:34|new|utils.pm:rename_vcld_process(8372)|SUBIMAGE: 0
2009-05-14 17:43:14|6423|34:34|new|utils.pm:rename_vcld_process(8390)|renamed
process to 'vcld VCL::new 34:34 new'
2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:is_parent_reservation(785)|returning
true: parent reservation ID for this request: 34
2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:is_parent_reservation(785)|returning
true: parent reservation ID for this request: 34
2009-05-14 17:43:14|6423|34:34|new|State.pm:initialize(122)|attempting to load
provisioning module: VCL::Module::Provisioning::esx
2009-05-14 17:43:14|6423|34:34|new|esx.pm:initialize(117)|vmware ESX module
initialized
2009-05-14
17:43:14|6423|34:34|new|State.pm:initialize(129)|VCL::Module::Provisioning::esx
module successfully loaded
2009-05-14 17:43:14|6423|34:34|new|Module.pm:new(80)|constructor called,
class=VCL::Module::Provisioning::esx
2009-05-14
17:43:14|6423|34:34|new|Module.pm:new(102)|VCL::Module::Provisioning::esx
object created
2009-05-14 17:43:14|6423|34:34|new|esx.pm:initialize(117)|vmware ESX module
initialized
2009-05-14
17:43:14|6423|34:34|new|State.pm:initialize(133)|VCL::Module::Provisioning::esx
provisioner object successfully created
2009-05-14 17:43:14|6423|34:34|new|State.pm:initialize(147)|attempting to load
OS module: VCL::Module::OS::Linux
2009-05-14 17:43:14|6423|34:34|new|Module.pm:new(80)|constructor called,
class=VCL::Module::OS::Linux
2009-05-14 17:43:14|6423|34:34|new|Module.pm:new(102)|VCL::Module::OS::Linux
object created
2009-05-14
17:43:14|6423|34:34|new|State.pm:initialize(155)|VCL::Module::OS::Linux OS
object successfully created
2009-05-14 17:43:14|6423|34:34|new|State.pm:initialize(170)|returning 1
2009-05-14 17:43:14|6423|34:34|new|vcld:make_new_child(597)|VCL::new object
created and initialized
2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:is_parent_reservation(785)|returning
true: parent reservation ID for this request: 34
|6423|34:34|new| 2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:_automethod(610)|corresponding data
has not been initialized for get_computer_preferredimage_id:
$self->request_data->{reservation}{34}{computer}{preferredimage}{id}
|6423|34:34|new| 2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:_automethod(610)|corresponding data
has not been initialized for get_computer_preferredimage_name:
$self->request_data->{reservation}{34}{computer}{preferredimage}{name}
2009-05-14
17:43:14|6423|34:34|new|utils.pm:get_management_node_id(9383)|environment
variable: 1
2009-05-14 17:43:14|6423|34:34|new|new.pm:process(135)|reservation is parent = 1
2009-05-14 17:43:14|6423|34:34|new|new.pm:process(136)|preload only = 0
2009-05-14 17:43:14|6423|34:34|new|new.pm:process(137)|originating request
state = new
2009-05-14 17:43:14|6423|34:34|new|new.pm:process(138)|originating request
laststate = new
2009-05-14 17:43:14|6423|34:34|new|new.pm:process(139)|originating computer
state = available
2009-05-14 17:43:14|6423|34:34|new|new.pm:process(140)|originating computer
type = blade
2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:is_parent_reservation(785)|returning
true: parent reservation ID for this request: 34
|6423|34:34|new| 2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:_automethod(610)|corresponding data
has not been initialized for get_computer_preferredimage_id:
$self->request_data->{reservation}{34}{computer}{preferredimage}{id}
|6423|34:34|new| 2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:_automethod(610)|corresponding data
has not been initialized for get_computer_preferredimage_name:
$self->request_data->{reservation}{34}{computer}{preferredimage}{name}
2009-05-14
17:43:14|6423|34:34|new|utils.pm:get_management_node_id(9383)|environment
variable: 1
2009-05-14
17:43:14|6423|34:34|new|new.pm:computer_not_being_used(779)|TECS-ESX-4600-2
state is available
2009-05-14
17:43:14|6423|34:34|new|new.pm:computer_not_being_used(789)|TECS-ESX-4600-2 is
available, its state is available
2009-05-14 17:43:14|6423|34:34|new|new.pm:process(170)|TECS-ESX-4600-2 is not
being used
2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:is_parent_reservation(785)|returning
true: parent reservation ID for this request: 34
|6423|34:34|new| 2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:_automethod(610)|corresponding data
has not been initialized for get_computer_preferredimage_id:
$self->request_data->{reservation}{34}{computer}{preferredimage}{id}
|6423|34:34|new| 2009-05-14
17:43:14|6423|34:34|new|DataStructure.pm:_automethod(610)|corresponding data
has not been initialized for get_computer_preferredimage_name:
$self->request_data->{reservation}{34}{computer}{preferredimage}{name}
2009-05-14
17:43:14|6423|34:34|new|utils.pm:get_management_node_id(9383)|environment
variable: 1
2009-05-14 17:43:14|6423|34:34|new|new.pm:reload_image(513)|calling
VCL::Module::Provisioning::esx->node_status()
2009-05-14 17:43:14|6423|34:34|new|utils.pm:insertloadlog(5324)|inserted
computer=1, statuscheck, checking status of node
2009-05-14 17:43:14|6423|34:34|new|esx.pm:node_status(646)|Entering
node_status, checking status of TECS-ESX-4600-2
2009-05-14 17:43:14|6423|34:34|new|esx.pm:node_status(647)|request_for_imaging: 0
2009-05-14 17:43:14|6423|34:34|new|esx.pm:node_status(648)|requeseted image
name: esx3-linuxtest-v0
2009-05-14 17:43:14|6423|34:34|new|esx.pm:node_status(678)|checking if
TECS-ESX-4600-2 is pingable
2009-05-14 17:43:14|6423|34:34|new|esx.pm:node_status(681)|TECS-ESX-4600-2 is
pingable (1)
2009-05-14 17:43:14|6423|34:34|new|esx.pm:node_status(695)|Trying to ssh...
2009-05-14 17:43:14|6423|34:34|new|esx.pm:node_status(733)|status set to RELOAD
2009-05-14 17:43:14|6423|34:34|new|esx.pm:node_status(741)|returning node
status hash reference ($node_status->{status}=RELOAD)
2009-05-14 17:43:14|6423|34:34|new|new.pm:reload_image(528)|node_status
returned a hash reference
2009-05-14 17:43:14|6423|34:34|new|new.pm:reload_image(533)|node_status hash
reference contains key {status}=RELOAD
2009-05-14 17:43:14|6423|34:34|new|new.pm:reload_image(601)|node status is
RELOAD, TECS-ESX-4600-2 will be reloaded
2009-05-14 17:43:15|6423|34:34|new|utils.pm:insertloadlog(5324)|inserted
computer=1, loadimageblade, TECS-ESX-4600-2 must be reloaded with
esx3-linuxtest-v0
2009-05-14 17:43:15|6423|34:34|new|new.pm:reload_image(615)|calling
VCL::Module::Provisioning::esx->does_image_exist()
2009-05-14 17:43:15|6423|34:34|new|utils.pm:run_ssh_command(6695)|executing SSH
command on 172.17.0.1:
2009-05-14
17:43:15|6423|34:34|new|utils.pm:run_ssh_command(6776)|run_ssh_command output:
2009-05-14 17:43:15|6423|34:34|new|utils.pm:run_ssh_command(6784)|SSH command
executed on 172.17.0.1, returning (0, "aquota.group aquota.user esx3-...")
2009-05-14 17:43:15|6423|34:34|new|esx.pm:does_image_exist(775)|image
esx3-linuxtest-v0 exists
2009-05-14 17:43:15|6423|34:34|new|new.pm:reload_image(618)|esx3-linuxtest-v0
exists on this management node
2009-05-14 17:43:15|6423|34:34|new|utils.pm:insertloadlog(5324)|inserted
computer=1, doesimageexists, confirmed image exists
2009-05-14
17:43:15|6423|34:34|new|utils.pm:update_computer_state(2325)|computer 1 state
updated to: reloading
2009-05-14 17:43:15|6423|34:34|new|new.pm:reload_image(651)|computer
TECS-ESX-4600-2 state set to reloading
2009-05-14 17:43:15|6423|34:34|new|utils.pm:insertloadlog(5324)|inserted
computer=1, info, computer state updated to reloading
2009-05-14 17:43:15|6423|34:34|new|new.pm:reload_image(662)|calling
VCL::Module::Provisioning::esx->load() subroutine
2009-05-14 17:43:15|6423|34:34|new|utils.pm:insertloadlog(5324)|inserted
computer=1, info, calling VCL::Module::Provisioning::esx->load() subroutine
2009-05-14
17:43:15|6423|34:34|new|esx.pm:load(142)|****************************************************
|6423|34:34|new| 2009-05-14
17:43:15|6423|34:34|new|DataStructure.pm:_automethod(610)|corresponding data
has not been initialized for get_computer_eth0_mac_address:
$self->request_data->{reservation}{34}{computer}{eth0macaddress}
|6423|34:34|new| 2009-05-14
17:43:15|6423|34:34|new|DataStructure.pm:_automethod(610)|corresponding data
has not been initialized for get_computer_eth1_mac_address:
$self->request_data->{reservation}{34}{computer}{eth1macaddress}
2009-05-14 17:43:15|6423|34:34|new|esx.pm:load(170)|DATASTORE IP is 172.17.0.1
and DATASTORE_SHARE_PATH is /mnt/vcl
2009-05-14 17:43:15|6423|34:34|new|esx.pm:load(171)|Entered ESX module, loading
esx3-linuxtest-v0 on TECS-ESX-4600-2 (on TECS-ESX-4600-2) for reservation 34
2009-05-14 17:43:15|6423|34:34|new|esx.pm:load(172)|Datastore:
172.17.0.1:/mnt/vcl
2009-05-14 17:43:15|6423|34:34|new|esx.pm:load(183)|VM info command:
/usr/lib/vmware-viperl/apps/vm/vminfo.pl --server 'TECS-ESX-4600-2' --vmname
TECS-ESX-4600-2 --username vcl --password 'xxxxxxxx'
2009-05-14 17:43:23|6423|34:34|new|esx.pm:load(186)|VM info output: Virtual
Machine TECS-ESX-4600-2 not found.
2009-05-14 17:43:23|6423|34:34|new|utils.pm:run_ssh_command(6695)|executing SSH
command on 172.17.0.1:
2009-05-14 17:43:26|6380|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:43:26
2009-05-14
17:43:27|6423|34:34|new|utils.pm:run_ssh_command(6776)|run_ssh_command output:
2009-05-14 17:43:27|6423|34:34|new|utils.pm:run_ssh_command(6784)|SSH command
executed on 172.17.0.1, returning (0, "none")
2009-05-14 17:43:27|6423|34:34|new|esx.pm:load(222)|Removed old vm folder
2009-05-14 17:43:27|6423|34:34|new|utils.pm:run_ssh_command(6695)|executing SSH
command on 172.17.0.1:
2009-05-14
17:43:27|6423|34:34|new|utils.pm:run_ssh_command(6776)|run_ssh_command output:
2009-05-14 17:43:27|6423|34:34|new|utils.pm:run_ssh_command(6784)|SSH command
executed on 172.17.0.1, returning (0, "none")
2009-05-14 17:43:27|6423|34:34|new|utils.pm:run_ssh_command(6695)|executing SSH
command on 172.17.0.1:
2009-05-14
17:43:28|6423|34:34|new|utils.pm:run_ssh_command(6776)|run_ssh_command output:
2009-05-14 17:43:28|6423|34:34|new|utils.pm:run_ssh_command(6784)|SSH command
executed on 172.17.0.1, returning (0, "none")
2009-05-14 17:43:28|6423|34:34|new|esx.pm:load(238)|COPIED VMDK SUCCESSFULLY
2009-05-14 17:43:28|6423|34:34|new|utils.pm:run_ssh_command(6695)|executing SSH
command on 172.17.0.1:
2009-05-14 17:43:38|6380|vcld:main(166)|lastcheckin time updated for management
node 1: 2009-05-14 17:43:38
