A tip is to search for the 1st WARNING statements related to the given request this usually leads to clues.
In this case I see you have invalid MAC addresses assigned to your vm's. |28809|34:34|new| ---- WARNING ---- |28809|34:34|new| 2015-05-04 14:14:58|28809|34:34|new|VIM_SSH.pm:_wait_for_task(785)|task haTask-16-vim.VirtualMachine.powerOn-515205666 did not complete successfully, state: error, error message: 00:0C:29:A2:A6:58 is not an allowed static Ethernet address. It conflicts with VMware reserved MACs. You'll want to use something starting with 00:50:56:XX:YY:ZZ for your vm's. Aaron On Mon, May 4, 2015 at 2:30 PM, Litchfield, Elwin L. <[email protected]> wrote: > What is wrong?? I cleaned the reservation tables before creating the > reservation. After the failure the failed reservation was cleared via the > web page. > > > 2015-04-24 20:34:34|22064|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-24 20:34:34 > 2015-04-25 00:34:34|22064|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-25 00:34:34 > 2015-04-25 01:34:34|22064|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-25 01:34:34 > 2015-04-25 02:34:34|22064|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-25 02:34:34 > 2015-04-27 08:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-27 08:34:34 > 2015-04-27 11:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-27 11:34:34 > 2015-04-27 13:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-27 13:34:34 > 2015-04-27 15:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-27 15:34:34 > 2015-04-27 17:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-27 17:34:34 > 2015-04-27 19:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-27 19:34:34 > 2015-04-27 21:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-27 21:34:34 > 2015-04-28 00:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-28 00:34:34 > 2015-04-28 02:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-28 02:34:34 > 2015-04-28 10:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-28 10:34:34 > 2015-04-28 13:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-28 13:34:34 > 2015-04-28 18:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-28 18:34:34 > 2015-04-28 23:34:34|2329|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-28 23:34:34 > 2015-04-29 07:34:34|2326|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-29 07:34:34 > 2015-04-29 19:34:34|2326|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-29 19:34:34 > 2015-04-30 01:34:34|2326|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-30 01:34:34 > 2015-04-30 04:34:34|2326|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-30 04:34:34 > 2015-04-30 09:34:34|2326|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-30 09:34:34 > 2015-04-30 23:34:34|2326|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-04-30 23:34:34 > 2015-05-01 04:34:34|2326|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-01 04:34:34 > 2015-05-01 10:34:34|2326|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-01 10:34:34 > 2015-05-01 10:34:34|2326|23:23|new|utils.pm:check_time(1103)|reservation > will start in 25-35 minutes (25) > 2015-05-01 10:34:34|2326|23:23|new|vcld:main(268)|preload request has > already been processed > 2015-05-01 13:34:34|2326|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-01 13:34:34 > 2015-05-01 17:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-01 17:34:34 > 2015-05-01 19:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-01 19:34:34 > 2015-05-02 01:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-02 01:34:34 > 2015-05-02 11:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-02 11:34:34 > 2015-05-02 12:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-02 12:34:34 > 2015-05-02 20:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-02 20:34:34 > 2015-05-02 21:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-02 21:34:34 > 2015-05-02 22:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-02 22:34:34 > 2015-05-02 23:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-02 23:34:34 > 2015-05-03 00:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-03 00:34:34 > 2015-05-03 01:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-03 01:34:34 > 2015-05-03 09:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-03 09:34:34 > 2015-05-03 17:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-03 17:34:34 > 2015-05-04 00:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-04 00:34:34 > 2015-05-04 05:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-04 05:34:34 > 2015-05-04 10:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-04 10:34:34 > 2015-05-04 13:34:34|2327|vcld:main(167)|lastcheckin time updated for > management node 1: 2015-05-04 13:34:34 > 2015-05-04 > 14:14:32|2327|34:34|new|utils.pm:reservation_being_processed(8634)|computerloadlog > 'begin' entry does NOT exist for reservation 34 > 2015-05-04 14:14:32|2327|34:34|new|utils.pm:run_command(8706)|executed > command: pgrep -fl 'vcld [0-9]+:34 ', pid: 28792, exit status: 1, output: > 2015-05-04 > 14:14:32|2327|34:34|new|utils.pm:is_management_node_process_running(8939)|process > is NOT running, identifier: 'vcld [0-9]+:34 ' > 2015-05-04 > 14:14:32|2327|34:34|new|utils.pm:reservation_being_processed(8655)|reservation > is NOT currently being processed > 2015-05-04 14:14:32|2327|34:34|new|vcld:main(282)|reservation 34 is NOT > already being processed > 2015-05-04 > 14:14:32|2327|34:34|new|utils.pm:get_management_node_info(5456)|retrieving > current management node info for 'localhost' from database, cached data is > stale: 1229 seconds old > 2015-05-04 > 14:14:32|2327|34:34|new|utils.pm:get_management_node_info(5603)|retrieved > management node info: 'localhost' (localhost) > 2015-05-04 > 14:14:32|2327|34:34|new|utils.pm:get_connect_method_info(10059)|attempting > to retrieve connect method info: > |2327|34:34|new| imagerevision: 12 - vmwarelinux-vm7c2testvcl212-v0 > |2327|34:34|new| OS: 36 - vmwarelinux > |2327|34:34|new| OS type: 2 - linux > 2015-05-04 > 14:14:32|2327|34:34|new|utils.pm:get_connect_method_info(10123)|ssh: > connectmethodid=1, OStypeid=2, OSid=NULL, imagerevisionid=NULL, disabled=0 > 2015-05-04 14:14:32|2327|34:34|new|vcld:main(287)|retrieved request > information from database > 2015-05-04 > 14:14:32|2327|34:34|new|DataStructure.pm:is_parent_reservation(1004)|returning > true: parent reservation ID for this request: 34 > 2015-05-04 > 14:14:32|2327|34:34|new|utils.pm:update_request_state(1545)|request 34 state > updated to: pending, laststate to: new > 2015-05-04 14:14:32|2327|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, begin, beginning to process, state is new > 2015-05-04 14:14:32|2327|34:34|new|vcld:make_new_child(518)|loaded VCL::new > module > 2015-05-04 14:14:32|2327|34:34|new|vcld:make_new_child(542)|current number > of forked kids: 1 > 2015-05-04 14:14:32|28809|34:34|new|vcld:make_new_child(558)|vcld > environment variable set to 0 for this process > 2015-05-04 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(643)|image > ID argument was specified: noimage, DataStructure object will contain image > information for the production imagerevision of this image > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(674)|retrieved data > for imagerevision ID: 1 > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(690)|retrieved data > for image ID: 1 > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:create_mn_os_object(376)|VCL::Module::OS::Linux::ManagementNode > module loaded > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:new(196)|VCL::Module::OS::Linux::ManagementNode > object created for image noimage, address: 3eb5c58 > 2015-05-04 14:14:32|28809|34:34|new|DataStructure.pm:_automethod(847)|data > structure updated, hash path: > $self->request_data->{reservation}{0}{computer}{hostname}, data identifier: > computer_hostname, data: > |28809|34:34|new| : "localhost" > 2015-05-04 14:14:32|28809|34:34|new|DataStructure.pm:_automethod(847)|data > structure updated, hash path: > $self->request_data->{reservation}{0}{computer}{NODENAME}, data identifier: > computer_node_name, data: > |28809|34:34|new| : "localhost" > 2015-05-04 14:14:32|28809|34:34|new|DataStructure.pm:_automethod(847)|data > structure updated, hash path: > $self->request_data->{reservation}{0}{computer}{SHORTNAME}, data identifier: > computer_short_name, data: > |28809|34:34|new| : "localhost" > 2015-05-04 14:14:32|28809|34:34|new|DataStructure.pm:_automethod(847)|data > structure updated, hash path: > $self->request_data->{reservation}{0}{computer}{IPaddress}, data identifier: > computer_ip_address, data: > |28809|34:34|new| : "131.247.30.237" > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:create_mn_os_object(381)|VCL::Module::OS::Linux::ManagementNode > OS object created, address: 3eb5c58 > 2015-05-04 14:14:32|28809|34:34|new|Module.pm:new(192)|VCL::new object > created for state new, address: 393e320 > 2015-05-04 14:14:32|28809|34:34|new|State.pm:initialize(88)|obtained a > database handle for this state process, stored as $ENV{dbh} > 2015-05-04 14:14:32|28809|34:34|new|State.pm:check_image_os(771)|no > corrections need to be made, not an imaging request, returning 1 > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:is_parent_reservation(1004)|returning > true: parent reservation ID for this request: 34 > 2015-05-04 > 14:14:32|28809|34:34|new|utils.pm:rename_vcld_process(6752)|reservation > count: 1 > 2015-05-04 > 14:14:32|28809|34:34|new|utils.pm:rename_vcld_process(6771)|PARENTIMAGE: 1 > 2015-05-04 > 14:14:32|28809|34:34|new|utils.pm:rename_vcld_process(6772)|SUBIMAGE: 0 > 2015-05-04 > 14:14:32|28809|34:34|new|utils.pm:rename_vcld_process(6790)|renamed process > to 'vcld 34:34 new VM7Cent6VCL2>VM7 vmwarelinux-vm7c2testvcl212-v0 admin' > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:is_parent_reservation(1004)|returning > true: parent reservation ID for this request: 34 > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:is_parent_reservation(1004)|returning > true: parent reservation ID for this request: 34 > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:create_os_object(308)|VCL::Module::OS::Linux > module loaded > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:new(196)|VCL::Module::OS::Linux object > created for image vmwarelinux-vm7c2testvcl212-v0, address: 3eb9178 > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:create_os_object(314)|VCL::Module::OS::Linux > OS object created, address: 3eb9178 > 2015-05-04 14:14:32|28809|34:34|new|State.pm:initialize(125)|computer is a > VM, attempting to create VM host OS object > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(619)|computer ID > argument was specified, retrieving data for computer ID: 5 > 2015-05-04 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(643)|image > ID argument was specified: 1, DataStructure object will contain image > information for the production imagerevision of this image > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(674)|retrieved data > for imagerevision ID: 1 > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(690)|retrieved data > for image ID: 1 > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:create_vmhost_os_object(454)|attempting > to load VM host OS module: VCL::Module::OS::Linux::UnixLab (image: 1) > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:create_vmhost_os_object(460)|VM host OS > module loaded: VCL::Module::OS::Linux::UnixLab > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:new(196)|VCL::Module::OS::Linux::UnixLab > object created for image noimage, address: 3eb93e8 > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:create_vmhost_os_object(465)|VCL::Module::OS::Linux::UnixLab > OS object created, address: 3eb93e8 > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:create_provisioning_object(519)|VCL::Module::Provisioning::VMware::VMware > module loaded > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:new(200)|VCL::Module::Provisioning::VMware::VMware > object created for computer VM7Cent6VCL2, address: 3eb9790 > 2015-05-04 14:14:32|28809|34:34|new|VMware.pm:initialize(267)|initializing > VCL::Module::Provisioning::VMware::VMware object > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(619)|computer ID > argument was specified, retrieving data for computer ID: 5 > 2015-05-04 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(643)|image > ID argument was specified: 1, DataStructure object will contain image > information for the production imagerevision of this image > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(674)|retrieved data > for imagerevision ID: 1 > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(690)|retrieved data > for image ID: 1 > 2015-05-04 > 14:14:32|28809|34:34|new|VMware.pm:get_vmhost_datastructure(1397)|created > DataStructure object for VM host: VM7 > 2015-05-04 14:14:32|28809|34:34|new|VMware.pm:initialize(287)|VM profile > assigned to VM7: VMware ESXi - local storage > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(619)|computer ID > argument was specified, retrieving data for computer ID: 5 > 2015-05-04 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(643)|image > ID argument was specified: 1, DataStructure object will contain image > information for the production imagerevision of this image > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(674)|retrieved data > for imagerevision ID: 1 > 2015-05-04 > 14:14:32|28809|34:34|new|DataStructure.pm:_initialize(690)|retrieved data > for image ID: 1 > 2015-05-04 > 14:14:32|28809|34:34|new|VMware.pm:get_vmhost_datastructure(1397)|created > DataStructure object for VM host: VM7 > 2015-05-04 > 14:14:32|28809|34:34|new|VMware.pm:get_vmhost_api_object(1500)|attempting to > load VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK > 2015-05-04 > 14:14:32|28809|34:34|new|VMware.pm:get_vmhost_api_object(1506)|loaded VMware > control module: VCL::Module::Provisioning::VMware::vSphere_SDK > 2015-05-04 > 14:14:32|28809|34:34|new|Module.pm:new(200)|VCL::Module::Provisioning::VMware::vSphere_SDK > object created for computer VM7Cent6VCL2, address: 446b548 > 2015-05-04 14:14:32|28809|34:34|new|vSphere_SDK.pm:initialize(98)|vSphere > SDK for Perl does not appear to be installed on this managment node, unable > to load VMware vSphere SDK Perl modules, error: > |28809|34:34|new| Can't locate VMware/VIRuntime.pm in @INC (@INC contains: > /usr/local/vcl/bin/../../../.. /usr/local/vcl/bin/../.. > /usr/local/vcl/bin/../../.. /usr/local/vcl/bin/.. /usr/local/vcl/bin/../lib > /usr/local/lib64/perl5 /usr/local/share/perl5 /usr/lib64/perl5/vendor_perl > /usr/share/perl5/vendor_perl /usr/lib64/perl5 /usr/share/perl5 .) at (eval > 290) line 1. > |28809|34:34|new| BEGIN failed--compilation aborted at (eval 290) line 1. > 2015-05-04 > 14:14:32|28809|34:34|new|VMware.pm:get_vmhost_api_object(1520)|API object > could not be created: VCL::Module::Provisioning::VMware::vSphere_SDK > 2015-05-04 14:14:33|28809|34:34|new|OS.pm:is_ssh_responding(678)|VM7 is > responding to SSH, port 22: open, port 24: closed > 2015-05-04 14:14:33|28809|34:34|new|VMware.pm:initialize(303)|OS on VM host > VM7 will be controlled using VCL::Module::OS::Linux::UnixLab OS object > 2015-05-04 > 14:14:33|28809|34:34|new|DataStructure.pm:_initialize(619)|computer ID > argument was specified, retrieving data for computer ID: 5 > 2015-05-04 14:14:33|28809|34:34|new|DataStructure.pm:_initialize(643)|image > ID argument was specified: 1, DataStructure object will contain image > information for the production imagerevision of this image > 2015-05-04 > 14:14:33|28809|34:34|new|DataStructure.pm:_initialize(674)|retrieved data > for imagerevision ID: 1 > 2015-05-04 > 14:14:33|28809|34:34|new|DataStructure.pm:_initialize(690)|retrieved data > for image ID: 1 > 2015-05-04 > 14:14:33|28809|34:34|new|VMware.pm:get_vmhost_datastructure(1397)|created > DataStructure object for VM host: VM7 > 2015-05-04 > 14:14:33|28809|34:34|new|VMware.pm:get_vmhost_api_object(1500)|attempting to > load VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH > 2015-05-04 > 14:14:33|28809|34:34|new|VMware.pm:get_vmhost_api_object(1506)|loaded VMware > control module: VCL::Module::Provisioning::VMware::VIM_SSH > 2015-05-04 > 14:14:33|28809|34:34|new|Module.pm:new(200)|VCL::Module::Provisioning::VMware::VIM_SSH > object created for computer VM7Cent6VCL2, address: 446b620 > 2015-05-04 14:14:33|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'vim-cmd ; > vmware-vim-cmd' 2>&1 > 2015-05-04 > 14:14:34|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| Commands available under /: > |28809|34:34|new| hbrsvc/ internalsvc/ solo/ vmsvc/ > |28809|34:34|new| hostsvc/ proxysvc/ vimsvc/ help > |28809|34:34|new| sh: vmware-vim-cmd: not found > 2015-05-04 14:14:34|28809|34:34|new|utils.pm:run_ssh_command(5030)|SSH > command executed on VM7, command: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'vim-cmd ; > vmware-vim-cmd' 2>&1 > |28809|34:34|new| returning (127, "Commands available under /: hb...") > 2015-05-04 14:14:34|28809|34:34|new|VIM_SSH.pm:initialize(138)|VIM > executable available on VM host: vim-cmd > 2015-05-04 > 14:14:34|28809|34:34|new|VIM_SSH.pm:initialize(140)|VCL::Module::Provisioning::VMware::VIM_SSH > object initialized > 2015-05-04 > 14:14:34|28809|34:34|new|VMware.pm:get_vmhost_api_object(1527)|created API > object: VCL::Module::Provisioning::VMware::VIM_SSH > 2015-05-04 14:14:34|28809|34:34|new|VMware.pm:initialize(312)|VM host VM7 > will be controlled using vim-cmd via SSH > 2015-05-04 14:14:34|28809|34:34|new|VMware.pm:initialize(327)|VMware OS and > API objects created for VM host VM7: > |28809|34:34|new| VM host OS object type: VCL::Module::OS::Linux::UnixLab > |28809|34:34|new| VMware API object type: > VCL::Module::Provisioning::VMware::VIM_SSH > 2015-05-04 14:14:34|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'vmware -v' > 2>&1 > 2015-05-04 > 14:14:34|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| VMware ESXi 5.5.0 build-1331820 > 2015-05-04 14:14:34|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "VMware ESXi 5.5.0 build-133182...") > 2015-05-04 > 14:14:34|28809|34:34|new|VMware.pm:get_vmhost_product_name(6634)|VMware > product being used on VM host VM7: 'VMware ESXi 5.5.0 build-1331820' > 2015-05-04 14:14:35|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd hostsvc/datastore/listsummary > 2015-05-04 > 14:14:35|28809|34:34|new|VMware.pm:get_datastore_info(6760)|retrieved > datastore info from VM host: > |28809|34:34|new| : { > |28809|34:34|new| : "BlackArmor_Connect" => { > |28809|34:34|new| : "accessible" => "true", > |28809|34:34|new| : "capacity" => "5898541047808", > |28809|34:34|new| : "datastore" => > "vim.Datastore:192.168.5.23:/DataVolume/VM", > |28809|34:34|new| : "dynamicType" => "<unset>", > |28809|34:34|new| : "freeSpace" => "5860950425600", > |28809|34:34|new| : "maintenanceMode" => "<unset>", > |28809|34:34|new| : "multipleHostAccess" => "<unset>", > |28809|34:34|new| : "normal_path" => "/vmfs/volumes/BlackArmor_Connect", > |28809|34:34|new| : "type" => "NFS", > |28809|34:34|new| : "uncommitted" => 0, > |28809|34:34|new| : "url" => "/vmfs/volumes/ff1e5fec-060d38c8" > |28809|34:34|new| : }, > |28809|34:34|new| : "BlackArmor_ConnectISO" => { > |28809|34:34|new| : "accessible" => "true", > |28809|34:34|new| : "capacity" => "5898541047808", > |28809|34:34|new| : "datastore" => > "vim.Datastore:192.168.5.23:/DataVolume/ISO", > |28809|34:34|new| : "dynamicType" => "<unset>", > |28809|34:34|new| : "freeSpace" => "5878084694016", > |28809|34:34|new| : "maintenanceMode" => "<unset>", > |28809|34:34|new| : "multipleHostAccess" => "<unset>", > |28809|34:34|new| : "normal_path" => > "/vmfs/volumes/BlackArmor_ConnectISO", > |28809|34:34|new| : "type" => "NFS", > |28809|34:34|new| : "uncommitted" => 0, > |28809|34:34|new| : "url" => "/vmfs/volumes/bb84ee19-47a18f64" > |28809|34:34|new| : }, > |28809|34:34|new| : "datastore1" => { > |28809|34:34|new| : "accessible" => "true", > |28809|34:34|new| : "capacity" => "491505319936", > |28809|34:34|new| : "datastore" => > "vim.Datastore:54b943b2-7ee6229d-f173-0019b9ddadff", > |28809|34:34|new| : "dynamicType" => "<unset>", > |28809|34:34|new| : "freeSpace" => "383980142592", > |28809|34:34|new| : "maintenanceMode" => "<unset>", > |28809|34:34|new| : "multipleHostAccess" => "<unset>", > |28809|34:34|new| : "normal_path" => "/vmfs/volumes/datastore1", > |28809|34:34|new| : "type" => "VMFS", > |28809|34:34|new| : "uncommitted" => "5195810688", > |28809|34:34|new| : "url" => > "/vmfs/volumes/54b943b2-7ee6229d-f173-0019b9ddadff" > |28809|34:34|new| : } > |28809|34:34|new| : } > 2015-05-04 > 14:14:35|28809|34:34|new|VMware.pm:get_vmx_base_directory_path(3094)|determined > vmx base directory path: /vmfs/volumes/datastore1 > 2015-05-04 14:14:35|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1' 2>&1 > 2015-05-04 > 14:14:36|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| File: '/vmfs/volumes/datastore1' -> > '54b943b2-7ee6229d-f173-0019b9ddadff' > |28809|34:34|new| Size: 35 Blocks: 0 IO Block: 131072 > symbolic link > |28809|34:34|new| Device: 0h/0d Inode: 2147483647 Links: 1 > |28809|34:34|new| Access: (0755/lrwxr-xr-x) Uid: ( 0/ root) Gid: ( > 0/ root) > |28809|34:34|new| Access: 2015-05-04 18:05:40.000000000 > |28809|34:34|new| Modify: 2015-05-04 18:05:40.000000000 > |28809|34:34|new| Change: 2015-05-04 18:05:40.000000000 > 2015-05-04 14:14:36|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "File: '/vmfs/volumes/datastore...") > 2015-05-04 > 14:14:36|28809|34:34|new|Linux.pm:file_exists(1449)|'/vmfs/volumes/datastore1' > exists on VM7, files: 0, directories: 0, links: 1 > 2015-05-04 14:14:36|28809|34:34|new|VMware.pm:is_vm_dedicated(4257)|VM disk > mode does not need to be dedicated > 2015-05-04 > 14:14:36|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 14:14:36|28809|34:34|new|VMware.pm:initialize(351)|not checking > if vmdk base directory exists because it is the same as the vmx base > directory: /vmfs/volumes/datastore1 > 2015-05-04 > 14:14:36|28809|34:34|new|Module.pm:create_provisioning_object(525)|VCL::Module::Provisioning::VMware::VMware > provisioner object created for VM7Cent6VCL2, address: 3eb9790 > 2015-05-04 14:14:36|28809|34:34|new|State.pm:initialize(154)|returning 1 > 2015-05-04 14:14:36|28809|34:34|new|vcld:make_new_child(568)|VCL::new object > created and initialized > 2015-05-04 > 14:14:36|28809|34:34|new|DataStructure.pm:is_parent_reservation(1004)|returning > true: parent reservation ID for this request: 34 > 2015-05-04 > 14:14:36|28809|34:34|new|DataStructure.pm:get_computer_state_name(2436)|attempting > to retrieve current state of computer VM7Cent6VCL2 from the database > 2015-05-04 > 14:14:36|28809|34:34|new|DataStructure.pm:get_computer_state_name(2467)|retrieved > current state of computer VM7Cent6VCL2 from the database: available > 2015-05-04 14:14:36|28809|34:34|new|DataStructure.pm:_automethod(847)|data > structure updated, hash path: > $self->request_data->{reservation}{34}{computer}{state}{name}, data > identifier: computer_state_name, data: > |28809|34:34|new| : "available" > 2015-05-04 > 14:14:36|28809|34:34|new|DataStructure.pm:get_computer_state_name(2436)|attempting > to retrieve current state of computer VM7Cent6VCL2 from the database > 2015-05-04 > 14:14:36|28809|34:34|new|DataStructure.pm:get_computer_state_name(2467)|retrieved > current state of computer VM7Cent6VCL2 from the database: available > 2015-05-04 14:14:36|28809|34:34|new|DataStructure.pm:_automethod(847)|data > structure updated, hash path: > $self->request_data->{reservation}{34}{computer}{state}{name}, data > identifier: computer_state_name, data: > |28809|34:34|new| : "available" > 2015-05-04 > 14:14:36|28809|34:34|new|new.pm:computer_not_being_used(742)|retrieving info > for reservations assigned to VM7Cent6VCL2 > 2015-05-04 > 14:14:36|28809|34:34|new|utils.pm:get_connect_method_info(10059)|attempting > to retrieve connect method info: > |28809|34:34|new| imagerevision: 12 - vmwarelinux-vm7c2testvcl212-v0 > |28809|34:34|new| OS: 36 - vmwarelinux > |28809|34:34|new| OS type: 2 - linux > 2015-05-04 > 14:14:36|28809|34:34|new|utils.pm:get_connect_method_info(10123)|ssh: > connectmethodid=1, OStypeid=2, OSid=NULL, imagerevisionid=NULL, disabled=0 > 2015-05-04 > 14:14:36|28809|34:34|new|utils.pm:get_request_by_computerid(5991)|retrieved > info and DataStructure object for 34:34 > 2015-05-04 > 14:14:36|28809|34:34|new|new.pm:computer_not_being_used(755)|VM7Cent6VCL2 is > not assigned to any other reservations > 2015-05-04 14:14:36|28809|34:34|new|new.pm:process(127)|VM7Cent6VCL2 is not > being used > 2015-05-04 > 14:14:36|28809|34:34|new|DataStructure.pm:get_computer_state_name(2436)|attempting > to retrieve current state of computer VM7Cent6VCL2 from the database > 2015-05-04 > 14:14:36|28809|34:34|new|DataStructure.pm:get_computer_state_name(2467)|retrieved > current state of computer VM7Cent6VCL2 from the database: available > 2015-05-04 14:14:36|28809|34:34|new|DataStructure.pm:_automethod(847)|data > structure updated, hash path: > $self->request_data->{reservation}{34}{computer}{state}{name}, data > identifier: computer_state_name, data: > |28809|34:34|new| : "available" > 2015-05-04 14:14:36|28809|34:34|new|new.pm:reload_image(511)|calling > VCL::Module::Provisioning::VMware::VMware->node_status() > 2015-05-04 14:14:36|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, statuscheck, checking status of node > 2015-05-04 14:14:36|28809|34:34|new|VMware.pm:node_status(1152)|attempting > to check the status of computer VM7Cent6VCL2, image: > vmwarelinux-vm7c2testvcl212-v0 > 2015-05-04 > 14:14:37|28809|34:34|new|OS.pm:is_ssh_responding(653)|VM7Cent6VCL2 is NOT > responding to SSH, ports 22 or 24 are both closed > 2015-05-04 14:14:37|28809|34:34|new|VMware.pm:node_status(1189)|VM > VM7Cent6VCL2 is not responding to SSH, returning 'RELOAD' > 2015-05-04 14:14:37|28809|34:34|new|new.pm:reload_image(526)|node_status > returned a hash reference > 2015-05-04 14:14:37|28809|34:34|new|new.pm:reload_image(531)|node_status > hash reference contains key {status}=RELOAD > 2015-05-04 14:14:37|28809|34:34|new|new.pm:reload_image(608)|node status is > RELOAD, VM7Cent6VCL2 will be reloaded > 2015-05-04 14:14:37|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, loadimageblade, VM7Cent6VCL2 must be reloaded with > vmwarelinux-vm7c2testvcl212-v0 > 2015-05-04 14:14:37|28809|34:34|new|new.pm:reload_image(622)|calling > VCL::Module::Provisioning::VMware::VMware->does_image_exist() > 2015-05-04 > 14:14:37|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 14:14:37|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1/vmwarelinux\-vm7c2testvcl212\-v0/vmwarelinux\-vm7c2testvcl212\-v0\.vmdk' > 2>&1 > 2015-05-04 > 14:14:37|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| File: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk > |28809|34:34|new| Size: 566 Blocks: 0 IO Block: 131072 regular file > |28809|34:34|new| Device: f9365da309f41293h/17957643519014474387d Inode: > 746594884 Links: 1 > |28809|34:34|new| Access: (0600/-rw-------) Uid: ( 0/ root) Gid: ( 0/ root) > |28809|34:34|new| Access: 2015-05-01 13:36:22.000000000 > |28809|34:34|new| Modify: 2015-05-01 13:39:13.000000000 > |28809|34:34|new| Change: 2015-05-01 13:39:13.000000000 > 2015-05-04 14:14:37|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "File: /vmfs/volumes/datastore1...") > 2015-05-04 > 14:14:37|28809|34:34|new|Linux.pm:file_exists(1449)|'/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk' > exists on VM7, files: 1, directories: 0, links: 0 > 2015-05-04 14:14:37|28809|34:34|new|VMware.pm:does_image_exist(4591)|image > exists in the shared directory on the VM host: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk > 2015-05-04 > 14:14:37|28809|34:34|new|new.pm:reload_image(625)|vmwarelinux-vm7c2testvcl212-v0 > exists on this management node > 2015-05-04 14:14:37|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, doesimageexists, confirmed image exists > 2015-05-04 > 14:14:37|28809|34:34|new|utils.pm:update_computer_state(1587)|computer 7 > state updated to: reloading > 2015-05-04 14:14:37|28809|34:34|new|new.pm:reload_image(658)|computer > VM7Cent6VCL2 state set to reloading > 2015-05-04 14:14:37|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, info, computer state updated to reloading > 2015-05-04 14:14:37|28809|34:34|new|new.pm:reload_image(669)|calling > VCL::Module::Provisioning::VMware::VMware->load() subroutine > 2015-05-04 14:14:37|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, info, calling VCL::Module::Provisioning::VMware::VMware->load() > subroutine > 2015-05-04 > 14:14:37|28809|34:34|new|VMware.pm:get_vmx_base_directory_path(3094)|determined > vmx base directory path: /vmfs/volumes/datastore1 > 2015-05-04 > 14:14:37|28809|34:34|new|VMware.pm:get_vmx_file_path(3034)|determined vmx > file path: > /vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx > 2015-05-04 14:14:37|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, doesimageexists, image exists vmwarelinux-vm7c2testvcl212-v0 > 2015-05-04 14:14:37|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, startload, VM7Cent6VCL2 vmwarelinux-vm7c2testvcl212-v0 > 2015-05-04 > 14:14:37|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 > 14:14:37|28809|34:34|new|VMware.pm:get_vmx_file_paths(5237)|attempting to > find existing vmx files on the VM host > 2015-05-04 14:14:37|28809|34:34|new|OS.pm:find_files(2917)|attempting to > find files on VM7, base directory path: '/vmfs/volumes/datastore1/', > pattern: *.vmx, command: /usr/bin/find "/vmfs/volumes/datastore1/" -type f > -iname "*.vmx" > 2015-05-04 14:14:37|28809|34:34|new|OS.pm:find_files(2945)|files found: 6, > base directory: '/vmfs/volumes/datastore1/', pattern: '*.vmx' > |28809|34:34|new| command: '/usr/bin/find "/vmfs/volumes/datastore1/" -type > f -iname "*.vmx"' > 2015-05-04 14:14:37|28809|34:34|new|VMware.pm:get_vmx_file_paths(5243)|found > 6 vmx files under /vmfs/volumes/datastore1 > |28809|34:34|new| > /vmfs/volumes/datastore1/VM7Cent6VCL1_12-v0/VM7Cent6VCL1_12-v0.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL6/VM7Cent6VCL6.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL7/VM7Cent6VCL7.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL8/VM7Cent6VCL8.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Ubu12VCL3/VM7Ubu12VCL3.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VMW7Cent6VCL3/VMW7Cent6VCL3.vmx > 2015-05-04 14:14:38|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/getallvms > 2015-05-04 14:14:39|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd hostsvc/datastore/listsummary > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:get_datastore_info(6760)|retrieved > datastore info from VM host: > |28809|34:34|new| : { > |28809|34:34|new| : "BlackArmor_Connect" => { > |28809|34:34|new| : "accessible" => "true", > |28809|34:34|new| : "capacity" => "5898541047808", > |28809|34:34|new| : "datastore" => > "vim.Datastore:192.168.5.23:/DataVolume/VM", > |28809|34:34|new| : "dynamicType" => "<unset>", > |28809|34:34|new| : "freeSpace" => "5860950425600", > |28809|34:34|new| : "maintenanceMode" => "<unset>", > |28809|34:34|new| : "multipleHostAccess" => "<unset>", > |28809|34:34|new| : "normal_path" => "/vmfs/volumes/BlackArmor_Connect", > |28809|34:34|new| : "type" => "NFS", > |28809|34:34|new| : "uncommitted" => 0, > |28809|34:34|new| : "url" => "/vmfs/volumes/ff1e5fec-060d38c8" > |28809|34:34|new| : }, > |28809|34:34|new| : "BlackArmor_ConnectISO" => { > |28809|34:34|new| : "accessible" => "true", > |28809|34:34|new| : "capacity" => "5898541047808", > |28809|34:34|new| : "datastore" => > "vim.Datastore:192.168.5.23:/DataVolume/ISO", > |28809|34:34|new| : "dynamicType" => "<unset>", > |28809|34:34|new| : "freeSpace" => "5878084694016", > |28809|34:34|new| : "maintenanceMode" => "<unset>", > |28809|34:34|new| : "multipleHostAccess" => "<unset>", > |28809|34:34|new| : "normal_path" => > "/vmfs/volumes/BlackArmor_ConnectISO", > |28809|34:34|new| : "type" => "NFS", > |28809|34:34|new| : "uncommitted" => 0, > |28809|34:34|new| : "url" => "/vmfs/volumes/bb84ee19-47a18f64" > |28809|34:34|new| : }, > |28809|34:34|new| : "datastore1" => { > |28809|34:34|new| : "accessible" => "true", > |28809|34:34|new| : "capacity" => "491505319936", > |28809|34:34|new| : "datastore" => > "vim.Datastore:54b943b2-7ee6229d-f173-0019b9ddadff", > |28809|34:34|new| : "dynamicType" => "<unset>", > |28809|34:34|new| : "freeSpace" => "383980142592", > |28809|34:34|new| : "maintenanceMode" => "<unset>", > |28809|34:34|new| : "multipleHostAccess" => "<unset>", > |28809|34:34|new| : "normal_path" => "/vmfs/volumes/datastore1", > |28809|34:34|new| : "type" => "VMFS", > |28809|34:34|new| : "uncommitted" => "5195810688", > |28809|34:34|new| : "url" => > "/vmfs/volumes/54b943b2-7ee6229d-f173-0019b9ddadff" > |28809|34:34|new| : } > |28809|34:34|new| : } > 2015-05-04 14:14:39|28809|34:34|new|VIM_SSH.pm:get_registered_vms(837)|found > 6 registered VMs > 2015-05-04 14:14:39|28809|34:34|new|VMware.pm:get_vmx_file_paths(5247)|found > 6 registered vmx files > |28809|34:34|new| > /vmfs/volumes/BlackArmor_Connect/VM7Cent6VCL3/VM7Cent6VCL3.vmx > |28809|34:34|new| > /vmfs/volumes/datastore1/VM7Cent6VCL1_12-v0/VM7Cent6VCL1_12-v0.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL6/VM7Cent6VCL6.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL7/VM7Cent6VCL7.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL8/VM7Cent6VCL8.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Ubu12VCL3/VM7Ubu12VCL3.vmx > 2015-05-04 14:14:39|28809|34:34|new|VMware.pm:get_vmx_file_paths(5252)|found > 7 vmx files on VM host > |28809|34:34|new| > /vmfs/volumes/BlackArmor_Connect/VM7Cent6VCL3/VM7Cent6VCL3.vmx > |28809|34:34|new| > /vmfs/volumes/datastore1/VM7Cent6VCL1_12-v0/VM7Cent6VCL1_12-v0.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL6/VM7Cent6VCL6.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL7/VM7Cent6VCL7.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL8/VM7Cent6VCL8.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Ubu12VCL3/VM7Ubu12VCL3.vmx > |28809|34:34|new| /vmfs/volumes/datastore1/VMW7Cent6VCL3/VMW7Cent6VCL3.vmx > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1562)|checking > existing vmx file: > '/vmfs/volumes/BlackArmor_Connect/VM7Cent6VCL3/VM7Cent6VCL3.vmx' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1568)|ignoring > existing vmx file > '/vmfs/volumes/BlackArmor_Connect/VM7Cent6VCL3/VM7Cent6VCL3.vmx' because it > does not begin with the base directory path: '/vmfs/volumes/datastore1' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1562)|checking > existing vmx file: > '/vmfs/volumes/datastore1/VM7Cent6VCL1_12-v0/VM7Cent6VCL1_12-v0.vmx' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:_get_vmx_file_path_computer_name(7404)|determined > computer name 'VM7Cent6VCL1' from directory name: 'VM7Cent6VCL1_12-v0' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1579)|ignoring > existing vmx file: VM7Cent6VCL1_12-v0.vmx, the directory computer name > 'VM7Cent6VCL1' does not match the reservation computer name 'VM7Cent6VCL2' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1562)|checking > existing vmx file: '/vmfs/volumes/datastore1/VM7Cent6VCL6/VM7Cent6VCL6.vmx' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:_get_vmx_file_path_computer_name(7408)|computer > name could not be determined from directory name: 'VM7Cent6VCL6' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1575)|ignoring > existing vmx file VM7Cent6VCL6.vmx, the computer name could not be > determined from the directory name > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1562)|checking > existing vmx file: '/vmfs/volumes/datastore1/VM7Cent6VCL7/VM7Cent6VCL7.vmx' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:_get_vmx_file_path_computer_name(7408)|computer > name could not be determined from directory name: 'VM7Cent6VCL7' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1575)|ignoring > existing vmx file VM7Cent6VCL7.vmx, the computer name could not be > determined from the directory name > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1562)|checking > existing vmx file: '/vmfs/volumes/datastore1/VM7Cent6VCL8/VM7Cent6VCL8.vmx' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:_get_vmx_file_path_computer_name(7408)|computer > name could not be determined from directory name: 'VM7Cent6VCL8' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1575)|ignoring > existing vmx file VM7Cent6VCL8.vmx, the computer name could not be > determined from the directory name > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1562)|checking > existing vmx file: '/vmfs/volumes/datastore1/VM7Ubu12VCL3/VM7Ubu12VCL3.vmx' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:_get_vmx_file_path_computer_name(7408)|computer > name could not be determined from directory name: 'VM7Ubu12VCL3' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1575)|ignoring > existing vmx file VM7Ubu12VCL3.vmx, the computer name could not be > determined from the directory name > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1562)|checking > existing vmx file: > '/vmfs/volumes/datastore1/VMW7Cent6VCL3/VMW7Cent6VCL3.vmx' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:_get_vmx_file_path_computer_name(7408)|computer > name could not be determined from directory name: 'VMW7Cent6VCL3' > 2015-05-04 > 14:14:39|28809|34:34|new|VMware.pm:remove_existing_vms(1575)|ignoring > existing vmx file VMW7Cent6VCL3.vmx, the computer name could not be > determined from the directory name > 2015-05-04 14:14:39|28809|34:34|new|OS.pm:find_files(2917)|attempting to > find files on VM7, base directory path: '/vmfs/volumes/datastore1/', > pattern: *VM7Cent6VCL2*.vmx, command: /usr/bin/find > "/vmfs/volumes/datastore1/" -type f -iname "*VM7Cent6VCL2*.vmx" > 2015-05-04 14:14:39|28809|34:34|new|OS.pm:find_files(2945)|files found: 0, > base directory: '/vmfs/volumes/datastore1/', pattern: '*VM7Cent6VCL2*.vmx' > |28809|34:34|new| command: '/usr/bin/find "/vmfs/volumes/datastore1/" -type > f -iname "*VM7Cent6VCL2*.vmx"' > 2015-05-04 > 14:14:40|28809|34:34|new|OS.pm:is_ssh_responding(653)|VM7Cent6VCL2 is NOT > responding to SSH, ports 22 or 24 are both closed > 2015-05-04 > 14:14:40|28809|34:34|new|utils.pm:update_computer_imagename(5633)|successfully > retreived image info for noimage > 2015-05-04 > 14:14:40|28809|34:34|new|utils.pm:update_currentimage(5685)|updating > computer 7: image=1, imagerevision=1 > 2015-05-04 > 14:14:40|28809|34:34|new|utils.pm:update_currentimage(5715)|updated > currentimageid and imagerevision id for computer id 7 > 2015-05-04 > 14:14:40|28809|34:34|new|utils.pm:update_computer_imagename(5645)|successfully > updated computerid= 7 image_id= 1 imagerevision_id= 1 > 2015-05-04 14:14:40|28809|34:34|new|VMware.pm:remove_existing_vms(1635)|set > computer VM7Cent6VCL2 current image to 'noimage' > 2015-05-04 > 14:14:40|28809|34:34|new|VMware.pm:check_vmhost_disk_space(2376)|checking if > enough space is available on VM host VM7 > 2015-05-04 > 14:14:40|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 > 14:14:40|28809|34:34|new|VMware.pm:is_vmx_vmdk_volume_shared(2278)|vmx and > vmdk base directory paths are identical: '/vmfs/volumes/datastore1', they > are on the same volume > 2015-05-04 > 14:14:40|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 14:14:40|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat -f > "/vmfs/volumes/datastore1"' 2>&1 > 2015-05-04 > 14:14:41|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| File: "/vmfs/volumes/datastore1" > |28809|34:34|new| ID: 9f41293f9365da3 Namelen: 127 Type: vmfs > |28809|34:34|new| Block size: 1048576 > |28809|34:34|new| Blocks: Total: 468736 Free: 364030 Available: > 364030 > |28809|34:34|new| Inodes: Total: 2147483647 Free: 2147483647 > 2015-05-04 14:14:41|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "File: "/vmfs/volumes/datastore...") > 2015-05-04 14:14:41|28809|34:34|new|Linux.pm:get_available_space(1702)|space > available on volume on VM7 containing '/vmfs/volumes/datastore1': > 381,713,121,280 bytes - 372,766,720.0 KB - 364,030.0 MB - 355.50 GB > 2015-05-04 > 14:14:41|28809|34:34|new|VMware.pm:get_vm_os_configuration(4895)|returning > matching 'linux-x86_64' OS configuration: vmwarelinux, image architecture: > x86_64 > |28809|34:34|new| : { > |28809|34:34|new| : "ethernet-virtualDev" => "e1000", > |28809|34:34|new| : "guestOS" => "otherlinux-64", > |28809|34:34|new| : "scsi-virtualDev" => "lsiLogic" > |28809|34:34|new| : } > 2015-05-04 14:14:41|28809|34:34|new|VMware.pm:get_vm_ram(5055)|image minimum > RAM value (0 MB) is too low for the otherlinux-64 guest OS, adjusting to 512 > MB > 2015-05-04 > 14:14:41|28809|34:34|new|VMware.pm:get_vm_additional_vmx_bytes_required(5721)|536870912 > additional bytes required for VM vmem file > 2015-05-04 > 14:14:41|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 > 14:14:41|28809|34:34|new|VMware.pm:get_repository_vmdk_base_directory_path(4140)|repository > path is not configured in the VM profile > 2015-05-04 > 14:14:41|28809|34:34|new|VMware.pm:get_image_size_bytes(4515)|image > repository path is not configured in the VM profile, image size will NOT be > retrieved from image repository > 2015-05-04 14:14:41|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat -L -c > "%F:%n:%s:%b:%B" > /vmfs/volumes/datastore1/vmwarelinux\-vm7c2testvcl212\-v0/vmwarelinux\-vm7c2testvcl212\-v0*\.vmdk' > 2>&1 > 2015-05-04 > 14:14:41|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| regular > file:/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0-flat.vmdk:17179869184:11800576:512 > |28809|34:34|new| regular > file:/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk:566:0:512 > 2015-05-04 14:14:41|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "regular file:/vmfs/volumes/dat...") > 2015-05-04 14:14:41|28809|34:34|new|Linux.pm:get_file_size(1940)|size of > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0*.vmdk > on VM7: > |28809|34:34|new| file count: 2 > |28809|34:34|new| reserved: 17,179,869,750 bytes - 16,777,216.6 KB - > 16,384.0 MB - 16.00 GB > |28809|34:34|new| used: 6,041,894,912 bytes - 5,900,288.0 KB - 5,762.0 MB - > 5.63 GB > 2015-05-04 > 14:14:41|28809|34:34|new|VMware.pm:get_image_size_bytes(4521)|retrieved the > size of the image from the datastore on the VM host: 6,041,894,912 > 2015-05-04 > 14:14:41|28809|34:34|new|VMware.pm:get_image_size_bytes(4551)|size of > vmwarelinux-vm7c2testvcl212-v0 image: > |28809|34:34|new| 6,041,894,912 bytes > |28809|34:34|new| 5,762 MB > |28809|34:34|new| 5.63 GB > 2015-05-04 > 14:14:41|28809|34:34|new|VMware.pm:get_vm_additional_vmx_bytes_required(5734)|1510473728 > additional bytes required for delta/REDO files because VM disk mode is > shared > 2015-05-04 > 14:14:41|28809|34:34|new|VMware.pm:get_vm_additional_vmx_bytes_required(5737)|estimate > of additional space required for the vmx directory: > |28809|34:34|new| vmem/vswp file: 536,870,912 bytes - 524,288.0 KB - 512.0 > MB - 0.50 GB > |28809|34:34|new| redo files: 1,510,473,728 bytes - 1,475,072.0 KB - 1,440.5 > MB - 1.41 GB > |28809|34:34|new| total: 2,047,344,640 bytes - 1,999,360.0 KB - 1,952.5 MB - > 1.91 GB > 2015-05-04 14:14:41|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1/VM7Cent6VCL2_12\-v0/VM7Cent6VCL2_12\-v0\.vmx' 2>&1 > 2015-05-04 > 14:14:41|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| stat: can't stat > '/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx': No > such file or directory > 2015-05-04 14:14:41|28809|34:34|new|utils.pm:run_ssh_command(5030)|SSH > command executed on VM7, command: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1/VM7Cent6VCL2_12\-v0/VM7Cent6VCL2_12\-v0\.vmx' 2>&1 > |28809|34:34|new| returning (1, "stat: can't stat '/vmfs/volume...") > 2015-05-04 > 14:14:41|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 14:14:41|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1/vmwarelinux\-vm7c2testvcl212\-v0/vmwarelinux\-vm7c2testvcl212\-v0\.vmdk' > 2>&1 > 2015-05-04 > 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| File: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk > |28809|34:34|new| Size: 566 Blocks: 0 IO Block: 131072 regular file > |28809|34:34|new| Device: f9365da309f41293h/17957643519014474387d Inode: > 746594884 Links: 1 > |28809|34:34|new| Access: (0600/-rw-------) Uid: ( 0/ root) Gid: ( 0/ root) > |28809|34:34|new| Access: 2015-05-01 13:36:22.000000000 > |28809|34:34|new| Modify: 2015-05-01 13:39:13.000000000 > |28809|34:34|new| Change: 2015-05-01 13:39:13.000000000 > 2015-05-04 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "File: /vmfs/volumes/datastore1...") > 2015-05-04 > 14:14:42|28809|34:34|new|Linux.pm:file_exists(1449)|'/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk' > exists on VM7, files: 1, directories: 0, links: 0 > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_repository_vmdk_base_directory_path(4140)|repository > path is not configured in the VM profile > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_image_size_bytes(4515)|image > repository path is not configured in the VM profile, image size will NOT be > retrieved from image repository > 2015-05-04 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat -L -c > "%F:%n:%s:%b:%B" > /vmfs/volumes/datastore1/vmwarelinux\-vm7c2testvcl212\-v0/vmwarelinux\-vm7c2testvcl212\-v0*\.vmdk' > 2>&1 > 2015-05-04 > 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| regular > file:/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0-flat.vmdk:17179869184:11800576:512 > |28809|34:34|new| regular > file:/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk:566:0:512 > 2015-05-04 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "regular file:/vmfs/volumes/dat...") > 2015-05-04 14:14:42|28809|34:34|new|Linux.pm:get_file_size(1940)|size of > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0*.vmdk > on VM7: > |28809|34:34|new| file count: 2 > |28809|34:34|new| reserved: 17,179,869,750 bytes - 16,777,216.6 KB - > 16,384.0 MB - 16.00 GB > |28809|34:34|new| used: 6,041,894,912 bytes - 5,900,288.0 KB - 5,762.0 MB - > 5.63 GB > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_image_size_bytes(4521)|retrieved the > size of the image from the datastore on the VM host: 6,041,894,912 > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_image_size_bytes(4551)|size of > vmwarelinux-vm7c2testvcl212-v0 image: > |28809|34:34|new| 6,041,894,912 bytes > |28809|34:34|new| 5,762 MB > |28809|34:34|new| 5.63 GB > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_vm_additional_vmdk_bytes_required(5678)|no > additional space required for vmdk files because they already exist on VM > host > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_vm_additional_vmdk_bytes_required(5683)|VM > requires appoximately 0 additional bytes (0 MB, 0 GB) of disk space on the > VM host for the vmdk directory > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:check_vmhost_disk_space(2409)|enough > space is available on shared vmx/vmdk volume on VM host VM7: > '/vmfs/volumes/datastore1' > |28809|34:34|new| vmx additional space required: 2,047,344,640 > bytes - 1,999,360.0 KB - 1,952.5 MB - 1.91 GB > |28809|34:34|new| vmdk additional space required: 0 bytes - 0.0 KB - > 0.0 MB - 0.00 GB > |28809|34:34|new| total additional space required: 2,047,344,640 > bytes - 1,999,360.0 KB - 1,952.5 MB - 1.91 GB > |28809|34:34|new| shared vmx/vmdk volume available space: 381,713,121,280 > bytes - 372,766,720.0 KB - 364,030.0 MB - 355.50 GB > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1/VM7Cent6VCL2_12\-v0/VM7Cent6VCL2_12\-v0\.vmx' 2>&1 > 2015-05-04 > 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| stat: can't stat > '/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx': No > such file or directory > 2015-05-04 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(5030)|SSH > command executed on VM7, command: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1/VM7Cent6VCL2_12\-v0/VM7Cent6VCL2_12\-v0\.vmx' 2>&1 > |28809|34:34|new| returning (1, "stat: can't stat '/vmfs/volume...") > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 > 14:14:42|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 > 14:14:42|28809|34:34|new|Module.pm:new(203)|VCL::Module::Semaphore object > created, address: 453e818 > 2015-05-04 > 14:14:42|28809|34:34|new|Module.pm:code_loop_timeout(887)|attempting to open > lockfile, maximum of 1200 seconds > 2015-05-04 14:14:42|28809|34:34|new|Semaphore.pm:open_lockfile(175)|opened > and obtained an exclusive lock on file: > /tmp/VM7-vmfs-volumes-datastore1-vmwarelinux-vm7c2testvcl212-v0.semaphore > 2015-05-04 14:14:42|28809|34:34|new|Semaphore.pm:open_lockfile(182)|wrote to > file: > /tmp/VM7-vmfs-volumes-datastore1-vmwarelinux-vm7c2testvcl212-v0.semaphore, > contents: > |28809|34:34|new| '28809 vcld 34:34 new VM7Cent6VCL2>VM7 > vmwarelinux-vm7c2testvcl212-v0 admin' > 2015-05-04 > 14:14:42|28809|34:34|new|Module.pm:code_loop_timeout(900)|attempting to open > lockfile, code returned true > 2015-05-04 14:14:42|28809|34:34|new|Module.pm:get_semaphore(993)|created > 'VM7-/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0' Semaphore > object, memory address: 453e818 > 2015-05-04 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1/vmwarelinux\-vm7c2testvcl212\-v0/vmwarelinux\-vm7c2testvcl212\-v0\.vmdk' > 2>&1 > 2015-05-04 > 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| File: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk > |28809|34:34|new| Size: 566 Blocks: 0 IO Block: 131072 regular file > |28809|34:34|new| Device: f9365da309f41293h/17957643519014474387d Inode: > 746594884 Links: 1 > |28809|34:34|new| Access: (0600/-rw-------) Uid: ( 0/ root) Gid: ( 0/ root) > |28809|34:34|new| Access: 2015-05-01 13:36:22.000000000 > |28809|34:34|new| Modify: 2015-05-01 13:39:13.000000000 > |28809|34:34|new| Change: 2015-05-01 13:39:13.000000000 > 2015-05-04 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "File: /vmfs/volumes/datastore1...") > 2015-05-04 > 14:14:42|28809|34:34|new|Linux.pm:file_exists(1449)|'/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk' > exists on VM7, files: 1, directories: 0, links: 0 > 2015-05-04 14:14:42|28809|34:34|new|VMware.pm:prepare_vmdk(2113)|VM is not > dedicated and shared vmdk file already exists on VM host VM7: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk > 2015-05-04 > 14:14:42|28809|34:34|new|Semaphore.pm:release_lockfile(280)|deleted file: > /tmp/VM7-vmfs-volumes-datastore1-vmwarelinux-vm7c2testvcl212-v0.semaphore > 2015-05-04 14:14:42|28809|34:34|new|Semaphore.pm:DESTROY(377)|destroyed > Semaphore object, memory address: 453e818 > 2015-05-04 14:14:42|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, transfervm, copied vmwarelinux-vm7c2testvcl212-v0 to > VM7Cent6VCL2 > 2015-05-04 14:14:42|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1/VM7Cent6VCL2_12\-v0/VM7Cent6VCL2_12\-v0\.vmx' 2>&1 > 2015-05-04 > 14:14:43|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| stat: can't stat > '/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx': No > such file or directory > 2015-05-04 14:14:43|28809|34:34|new|utils.pm:run_ssh_command(5030)|SSH > command executed on VM7, command: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1/VM7Cent6VCL2_12\-v0/VM7Cent6VCL2_12\-v0\.vmx' 2>&1 > |28809|34:34|new| returning (1, "stat: can't stat '/vmfs/volume...") > 2015-05-04 > 14:14:43|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 14:14:43|28809|34:34|new|VMware.pm:get_vm_ram(5055)|image minimum > RAM value (0 MB) is too low for the otherlinux-64 guest OS, adjusting to 512 > MB > 2015-05-04 > 14:14:43|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 14:14:43|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'stat > /vmfs/volumes/datastore1/vmwarelinux\-vm7c2testvcl212\-v0/vmwarelinux\-vm7c2testvcl212\-v0\.vmx\.reference' > 2>&1 > 2015-05-04 > 14:14:43|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| File: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmx.reference > |28809|34:34|new| Size: 3670 Blocks: 16 IO Block: 131072 regular file > |28809|34:34|new| Device: f9365da309f41293h/17957643519014474387d Inode: > 750789188 Links: 1 > |28809|34:34|new| Access: (0755/-rwxr-xr-x) Uid: ( 0/ root) Gid: ( 0/ root) > |28809|34:34|new| Access: 2015-05-04 17:45:18.000000000 > |28809|34:34|new| Modify: 2015-05-01 13:39:14.000000000 > |28809|34:34|new| Change: 2015-05-01 13:39:14.000000000 > 2015-05-04 14:14:43|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "File: /vmfs/volumes/datastore1...") > 2015-05-04 > 14:14:43|28809|34:34|new|Linux.pm:file_exists(1449)|'/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmx.reference' > exists on VM7, files: 1, directories: 0, links: 0 > 2015-05-04 > 14:14:43|28809|34:34|new|VMware.pm:get_reference_vmx_info(5467)|found > reference vmx file in shared vmdk directory on VM host: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmx.reference > 2015-05-04 14:14:43|28809|34:34|new|VMware.pm:get_vmx_info(5313)|attempting > to retrieve info from vmx file: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmx.reference > 2015-05-04 14:14:43|28809|34:34|new|OS.pm:get_file_contents(1897)|retrieved > 103 lines from file on VM7: > '/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmx.reference' > 2015-05-04 14:14:43|28809|34:34|new|VMware.pm:get_vmx_info(5354)|vmx file > does not contain a computer_id value, attempting to determine matching > computer > 2015-05-04 > 14:14:43|28809|34:34|new|VMware.pm:_get_vmx_file_path_computer_name(7408)|computer > name could not be determined from directory name: > 'vmwarelinux-vm7c2testvcl212-v0' > 2015-05-04 14:14:43|28809|34:34|new|VMware.pm:get_vmx_info(5368)|unable to > determine computer name from vmx file path: > '/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmx.reference' > 2015-05-04 14:14:43|28809|34:34|new|VMware.pm:get_vmx_info(5382)|ignoring > ide1:0, filename property does not end with .vmdk: > /usr/lib/vmware/isoimages/linux.iso > 2015-05-04 14:14:43|28809|34:34|new|VMware.pm:get_vmx_info(5390)|scsi0:0 > mode property not set, setting default value: persistent > 2015-05-04 14:14:43|28809|34:34|new|VMware.pm:get_vmx_info(5399)|vmdk path > appears to be relative: VM7Cent6VCL2.vmdk, prepending the vmx directory: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/VM7Cent6VCL2.vmdk > 2015-05-04 > 14:14:43|28809|34:34|new|VMware.pm:get_reference_vmx_info(5499)|retrieved > reference vmx info from file: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmx.reference > 2015-05-04 > 14:14:43|28809|34:34|new|VMware.pm:get_vm_ethernet_adapter_type(4997)|retrieved > VM ethernet adapter type from reference vmx file: vmxnet3 > 2015-05-04 > 14:14:43|28809|34:34|new|VMware.pm:get_vmdk_base_directory_path_shared(3566)|using > VM profile datastore path as the vmdk base directory path: datastore1 > 2015-05-04 > 14:14:43|28809|34:34|new|VMware.pm:get_vm_disk_adapter_type(4740)|retrieved > VM disk adapter type from reference vmx file: lsilogic > 2015-05-04 > 14:14:43|28809|34:34|new|VMware.pm:get_vm_virtual_hardware_version(4799)|retrieved > VM virtual hardware version from reference vmx file: 8 > 2015-05-04 > 14:14:43|28809|34:34|new|VMware.pm:get_vm_virtual_hardware_version(4802)|unable > to retrieve VM virtual hardware version from reference vmx file, > 'virtualHW.version' key does not exist > 2015-05-04 14:14:43|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'vmware -v' > 2>&1 > 2015-05-04 > 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| VMware ESXi 5.5.0 build-1331820 > 2015-05-04 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "VMware ESXi 5.5.0 build-133182...") > 2015-05-04 > 14:14:44|28809|34:34|new|VMware.pm:get_vmhost_product_name(6634)|VMware > product being used on VM host VM7: 'VMware ESXi 5.5.0 build-1331820' > 2015-05-04 > 14:14:44|28809|34:34|new|VMware.pm:get_vm_virtual_hardware_version(4849)|returning > hardware version: 8 > 2015-05-04 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'vmware -v' > 2>&1 > 2015-05-04 > 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| VMware ESXi 5.5.0 build-1331820 > 2015-05-04 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "VMware ESXi 5.5.0 build-133182...") > 2015-05-04 > 14:14:44|28809|34:34|new|VMware.pm:get_vmhost_product_name(6634)|VMware > product being used on VM host VM7: 'VMware ESXi 5.5.0 build-1331820' > 2015-05-04 > 14:14:44|28809|34:34|new|VMware.pm:get_vm_cpu_configuration(5163)|VM CPU > configuration: > |28809|34:34|new| sockets: 1 > |28809|34:34|new| cores per socket: 1 > |28809|34:34|new| total cores: 1 > 2015-05-04 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'ls -d > --color=never "/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0" 2>&1 || mkdir -p > "/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0" 2>&1 && ls -d --color=never > "/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0"' 2>&1 > 2015-05-04 > 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| ls: /vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0: No such > file or directory > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0 > 2015-05-04 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "ls: /vmfs/volumes/datastore1/V...") > 2015-05-04 > 14:14:44|28809|34:34|new|Linux.pm:create_directory(1569)|directory created > on VM7: '/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0' > 2015-05-04 14:14:44|28809|34:34|new|VMware.pm:prepare_vmx(1724)|vm info: > |28809|34:34|new| display name: VM7Cent6VCL2:vmwarelinux-vm7c2testvcl212-v0 > (shared) > |28809|34:34|new| vmx file path: > /vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx > |28809|34:34|new| vmdk file path: > /vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk > 2015-05-04 > 14:14:44|28809|34:34|new|VMware.pm:get_vm_ethernet_adapter_type(4997)|retrieved > VM ethernet adapter type from reference vmx file: vmxnet3 > 2015-05-04 > 14:14:44|28809|34:34|new|VMware.pm:get_vm_ethernet_adapter_type(4997)|retrieved > VM ethernet adapter type from reference vmx file: vmxnet3 > 2015-05-04 14:14:44|28809|34:34|new|VMware.pm:prepare_vmx(1923)|image > project is: vcl, additional network adapters will not be configured > 2015-05-04 14:14:44|28809|34:34|new|VMware.pm:prepare_vmx(1926)|vmx > parameters: > |28809|34:34|new| : { > |28809|34:34|new| : "#computer_id" => 7, > |28809|34:34|new| : "#image_id" => 12, > |28809|34:34|new| : "#imagerevision_id" => 12, > |28809|34:34|new| : ".encoding" => "UTF-8", > |28809|34:34|new| : "config.version" => 8, > |28809|34:34|new| : "cpuid.coresPerSocket" => 1, > |28809|34:34|new| : "displayName" => > "VM7Cent6VCL2:vmwarelinux-vm7c2testvcl212-v0 (shared)", > |28809|34:34|new| : "ethernet0.address" => "00:0C:29:A2:A6:58", > |28809|34:34|new| : "ethernet0.addressType" => "static", > |28809|34:34|new| : "ethernet0.connectionType" => "custom", > |28809|34:34|new| : "ethernet0.networkName" => "Private", > |28809|34:34|new| : "ethernet0.present" => "TRUE", > |28809|34:34|new| : "ethernet0.virtualDev" => "vmxnet3", > |28809|34:34|new| : "ethernet1.address" => "00:0C:29:A2:A6:62", > |28809|34:34|new| : "ethernet1.addressType" => "static", > |28809|34:34|new| : "ethernet1.connectionType" => "custom", > |28809|34:34|new| : "ethernet1.networkName" => "Public", > |28809|34:34|new| : "ethernet1.present" => "TRUE", > |28809|34:34|new| : "ethernet1.virtualDev" => "vmxnet3", > |28809|34:34|new| : "floppy0.present" => "FALSE", > |28809|34:34|new| : "guestOS" => "otherlinux-64", > |28809|34:34|new| : "gui.exitOnCLIHLT" => "TRUE", > |28809|34:34|new| : "memsize" => 512, > |28809|34:34|new| : "msg.autoAnswer" => "TRUE", > |28809|34:34|new| : "numvcpus" => 1, > |28809|34:34|new| : "pciBridge0.present" => "TRUE", > |28809|34:34|new| : "pciBridge4.functions" => 8, > |28809|34:34|new| : "pciBridge4.present" => "TRUE", > |28809|34:34|new| : "pciBridge4.virtualDev" => "pcieRootPort", > |28809|34:34|new| : "pciBridge5.functions" => 8, > |28809|34:34|new| : "pciBridge5.present" => "TRUE", > |28809|34:34|new| : "pciBridge5.virtualDev" => "pcieRootPort", > |28809|34:34|new| : "pciBridge6.functions" => 8, > |28809|34:34|new| : "pciBridge6.present" => "TRUE", > |28809|34:34|new| : "pciBridge6.virtualDev" => "pcieRootPort", > |28809|34:34|new| : "pciBridge7.functions" => 8, > |28809|34:34|new| : "pciBridge7.present" => "TRUE", > |28809|34:34|new| : "pciBridge7.virtualDev" => "pcieRootPort", > |28809|34:34|new| : "powerType.powerOff" => "soft", > |28809|34:34|new| : "powerType.powerOn" => "hard", > |28809|34:34|new| : "powerType.reset" => "soft", > |28809|34:34|new| : "powerType.suspend" => "hard", > |28809|34:34|new| : "sched.swap.dir" => > "/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/", > |28809|34:34|new| : "scsi0.present" => "TRUE", > |28809|34:34|new| : "scsi0.virtualDev" => "lsilogic", > |28809|34:34|new| : "scsi0:0.fileName" => > "/vmfs/volumes/datastore1/vmwarelinux-vm7c2testvcl212-v0/vmwarelinux-vm7c2testvcl212-v0.vmdk", > |28809|34:34|new| : "scsi0:0.mode" => "persistent", > |28809|34:34|new| : "scsi0:0.present" => "TRUE", > |28809|34:34|new| : "scsi0:0.sharedBus" => "none", > |28809|34:34|new| : "scsi0:0.writeThrough" => "TRUE", > |28809|34:34|new| : "snapshot.redoNotWithParent" => "TRUE", > |28809|34:34|new| : "svga.autodetect" => "TRUE", > |28809|34:34|new| : "toolScripts.afterPowerOn" => "FALSE", > |28809|34:34|new| : "toolScripts.afterResume" => "FALSE", > |28809|34:34|new| : "toolScripts.beforePowerOff" => "FALSE", > |28809|34:34|new| : "toolScripts.beforeSuspend" => "FALSE", > |28809|34:34|new| : "tools.remindInstall" => "FALSE", > |28809|34:34|new| : "tools.syncTime" => "FALSE", > |28809|34:34|new| : "usb.present" => "TRUE", > |28809|34:34|new| : "uuid.action" => "keep", > |28809|34:34|new| : "virtualHW.version" => 8, > |28809|34:34|new| : "vmci0.present" => "TRUE", > |28809|34:34|new| : "workingDir" => > "/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0" > |28809|34:34|new| : } > 2015-05-04 14:14:44|28809|34:34|new|VMware.pm:prepare_vmx(1937)|created > temporary vmx file: /tmp/VM7Cent6VCL2_12-v0.vmx > 2015-05-04 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(4902)|executing > SSH command on VM7: > |28809|34:34|new| /usr/bin/ssh -i /etc/vcl/vcl.key -o > StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o > ConnectionAttempts=1 -o ConnectTimeout=3 -l root -p 22 -x VM7 'ls -d > --color=never "/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0" 2>&1 || mkdir -p > "/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0" 2>&1 && ls -d --color=never > "/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0"' 2>&1 > 2015-05-04 > 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(5020)|run_ssh_command > output: > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0 > |28809|34:34|new| /vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0 > 2015-05-04 14:14:44|28809|34:34|new|utils.pm:run_ssh_command(5034)|SSH > command executed on VM7, returning (0, "/vmfs/volumes/datastore1/VM7Ce...") > 2015-05-04 > 14:14:44|28809|34:34|new|Linux.pm:create_directory(1573)|directory already > exists on VM7: '/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0' > 2015-05-04 > 14:14:44|28809|34:34|new|utils.pm:run_scp_command(5156)|attempting to copy > file via SCP: '/tmp/VM7Cent6VCL2_12-v0.vmx' --> > 'VM7:"/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx"' > 2015-05-04 14:14:45|28809|34:34|new|utils.pm:run_scp_command(5192)|copied > file via SCP: '/tmp/VM7Cent6VCL2_12-v0.vmx' --> > 'VM7:"/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx"' > 2015-05-04 14:14:45|28809|34:34|new|OS.pm:copy_file_to(2843)|copied file > from management node to VM7: '/tmp/VM7Cent6VCL2_12-v0.vmx' --> > VM7:'/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx' > 2015-05-04 14:14:45|28809|34:34|new|VMware.pm:prepare_vmx(1949)|created vmx > file on VM host: > /vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx > 2015-05-04 14:14:45|28809|34:34|new|VMware.pm:prepare_vmx(1952)|deleted > temporary vmx file: /tmp/VM7Cent6VCL2_12-v0.vmx > 2015-05-04 14:14:45|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, vmsetupconfig, prepared vmx file > 2015-05-04 14:14:46|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/getallvms > 2015-05-04 14:14:46|28809|34:34|new|VIM_SSH.pm:get_registered_vms(837)|found > 6 registered VMs > 2015-05-04 14:14:46|28809|34:34|new|VMware.pm:is_vm_registered(4427)|VM is > not registered: > '/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx' > 2015-05-04 14:14:47|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd solo/registervm > "/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx" > 2015-05-04 14:14:48|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/getallvms > 2015-05-04 14:14:48|28809|34:34|new|VIM_SSH.pm:get_registered_vms(837)|found > 7 registered VMs > 2015-05-04 14:14:48|28809|34:34|new|VMware.pm:is_vm_registered(4422)|VM is > registered: > /vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx > 2015-05-04 14:14:48|28809|34:34|new|VIM_SSH.pm:vm_register(1114)|registered > VM: '/vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx' > 2015-05-04 14:14:49|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/getallvms > 2015-05-04 14:14:50|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/snapshot.create 16 'register' > 2015-05-04 14:14:50|28809|34:34|new|VIM_SSH.pm:create_snapshot(1713)|create > snapshot output: > |28809|34:34|new| Create Snapshot: > 2015-05-04 14:14:51|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/getallvms > 2015-05-04 14:14:52|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/get.tasklist 16 > 2015-05-04 14:14:52|28809|34:34|new|VIM_SSH.pm:_wait_for_task(750)|checking > status of task: haTask-16-vim.VirtualMachine.createSnapshot-515205654 > 2015-05-04 14:14:53|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vimsvc/task_info > haTask-16-vim.VirtualMachine.createSnapshot-515205654 > 2015-05-04 14:14:53|28809|34:34|new|VIM_SSH.pm:_wait_for_task(773)|task > completed successfully: > haTask-16-vim.VirtualMachine.createSnapshot-515205654 > 2015-05-04 14:14:53|28809|34:34|new|VIM_SSH.pm:create_snapshot(1729)|created > snapshot of VM: > /vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx, snapshot > name: register > 2015-05-04 14:14:54|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/getallvms > 2015-05-04 14:14:55|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/power.on 16 > 2015-05-04 14:14:56|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/getallvms > 2015-05-04 14:14:57|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vmsvc/get.tasklist 16 > 2015-05-04 14:14:57|28809|34:34|new|VIM_SSH.pm:_wait_for_task(750)|checking > status of task: haTask-16-vim.VirtualMachine.powerOn-515205666 > 2015-05-04 14:14:58|28809|34:34|new|VIM_SSH.pm:_run_vim_cmd(210)|executed > command on VM host VM7: vim-cmd vimsvc/task_info > haTask-16-vim.VirtualMachine.powerOn-515205666 > |28809|34:34|new| ---- WARNING ---- > |28809|34:34|new| 2015-05-04 > 14:14:58|28809|34:34|new|VIM_SSH.pm:_wait_for_task(785)|task > haTask-16-vim.VirtualMachine.powerOn-515205666 did not complete > successfully, state: error, error message: 00:0C:29:A2:A6:58 is not an > allowed static Ethernet address. It conflicts with VMware reserved MACs. > |28809|34:34|new| ( 0) VIM_SSH.pm, _wait_for_task (line: 785) > |28809|34:34|new| (-1) VIM_SSH.pm, vm_power_on (line: 971) > |28809|34:34|new| (-2) VMware.pm, power_on (line: 6465) > |28809|34:34|new| (-3) VMware.pm, load (line: 521) > |28809|34:34|new| (-4) new.pm, reload_image (line: 671) > |28809|34:34|new| (-5) new.pm, process (line: 291) > |28809|34:34|new| ---- WARNING ---- > |28809|34:34|new| 2015-05-04 > 14:14:58|28809|34:34|new|VIM_SSH.pm:vm_power_on(976)|failed to power on VM: > /vmfs/volumes/datastore1/VM7Cent6VCL2_12-v0/VM7Cent6VCL2_12-v0.vmx, the vim > power on task did not complete successfully, vim-cmd vmsvc/power.on 16 > output: > |28809|34:34|new| Powering on VM: > |28809|34:34|new| Power on failed > |28809|34:34|new| ( 0) VIM_SSH.pm, vm_power_on (line: 976) > |28809|34:34|new| (-1) VMware.pm, power_on (line: 6465) > |28809|34:34|new| (-2) VMware.pm, load (line: 521) > |28809|34:34|new| (-3) new.pm, reload_image (line: 671) > |28809|34:34|new| (-4) new.pm, process (line: 291) > |28809|34:34|new| (-5) vcld, make_new_child (line: 571) > |28809|34:34|new| ---- WARNING ---- > |28809|34:34|new| 2015-05-04 > 14:14:58|28809|34:34|new|VMware.pm:load(522)|failed to power on VM > VM7Cent6VCL2 on VM host: VM7 > |28809|34:34|new| ( 0) VMware.pm, load (line: 522) > |28809|34:34|new| (-1) new.pm, reload_image (line: 671) > |28809|34:34|new| (-2) new.pm, process (line: 291) > |28809|34:34|new| (-3) vcld, make_new_child (line: 571) > |28809|34:34|new| (-4) vcld, main (line: 350) > |28809|34:34|new| ---- WARNING ---- > |28809|34:34|new| 2015-05-04 > 14:14:58|28809|34:34|new|new.pm:reload_image(676)|vmwarelinux-vm7c2testvcl212-v0 > failed to load on VM7Cent6VCL2, returning > |28809|34:34|new| ( 0) new.pm, reload_image (line: 676) > |28809|34:34|new| (-1) new.pm, process (line: 291) > |28809|34:34|new| (-2) vcld, make_new_child (line: 571) > |28809|34:34|new| (-3) vcld, main (line: 350) > 2015-05-04 14:14:58|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, loadimagefailed, vmwarelinux-vm7c2testvcl212-v0 failed to load > on VM7Cent6VCL2 > |28809|34:34|new| ---- WARNING ---- > |28809|34:34|new| 2015-05-04 > 14:14:58|28809|34:34|new|new.pm:process(339)|failed to load VM7Cent6VCL2 > with vmwarelinux-vm7c2testvcl212-v0 > |28809|34:34|new| ( 0) new.pm, process (line: 339) > |28809|34:34|new| (-1) vcld, make_new_child (line: 571) > |28809|34:34|new| (-2) vcld, main (line: 350) > 2015-05-04 > 14:14:58|28809|34:34|new|DataStructure.pm:get_computer_state_name(2436)|attempting > to retrieve current state of computer VM7Cent6VCL2 from the database > 2015-05-04 > 14:14:58|28809|34:34|new|DataStructure.pm:get_computer_state_name(2467)|retrieved > current state of computer VM7Cent6VCL2 from the database: reloading > 2015-05-04 14:14:58|28809|34:34|new|DataStructure.pm:_automethod(847)|data > structure updated, hash path: > $self->request_data->{reservation}{34}{computer}{state}{name}, data > identifier: computer_state_name, data: > |28809|34:34|new| : "reloading" > 2015-05-04 > 14:14:58|28809|34:34|new|DataStructure.pm:get_computer_private_ip_address(1641)|attempting > to retrieve private IP address for computer: VM7Cent6VCL2 > 2015-05-04 14:14:58|28809|34:34|new|OS.pm:get_file_contents(1897)|retrieved > 12 lines from file on localhost: '/etc/hosts' > 2015-05-04 > 14:14:58|28809|34:34|new|DataStructure.pm:get_computer_private_ip_address(1697)|returning > IP address from /etc/hosts file: 192.168.10.47 > 2015-05-04 14:14:58|28809|34:34|new|utils.pm:is_inblockrequest(5760)|zero > rows were returned from database select > 2015-05-04 > 14:14:58|28809|34:34|new|DataStructure.pm:get_image_affiliation_name(2121)|image > owner id: 1 > 2015-05-04 > 14:14:58|28809|34:34|new|DataStructure.pm:retrieve_user_data(1412)|attempting > to retrieve and store data for user: user.id = '1' > 2015-05-04 > 14:14:58|28809|34:34|new|DataStructure.pm:retrieve_user_data(1475)|data has > been retrieved for user: admin (id: 1) > 2015-05-04 14:14:58|28809|34:34|new|utils.pm:mail(1253)|SUCCESS -- Sending > mail To: [email protected], PROBLEM -- > localhost|34:34|new|State.pm|VM7Cent6VCL2>VM7|vmwarelinux-vm7c2testvcl212-v0|admin > |28809|34:34|new| ---- CRITICAL ---- > |28809|34:34|new| 2015-05-04 > 14:14:58|28809|34:34|new|State.pm:reservation_failed(240)|reservation failed > on VM7Cent6VCL2: process failed after trying to load or make available > |28809|34:34|new| ( 0) State.pm, reservation_failed (line: 240) > |28809|34:34|new| (-1) new.pm, process (line: 342) > |28809|34:34|new| (-2) vcld, make_new_child (line: 571) > |28809|34:34|new| (-3) vcld, main (line: 350) > 2015-05-04 14:14:58|28809|34:34|new|utils.pm:insertloadlog(3665)|inserted > computer=7, failed, process failed after trying to load or make available > 2015-05-04 > 14:14:58|28809|34:34|new|State.pm:reservation_failed(243)|inserted > computerloadlog entry > 2015-05-04 14:14:58|28809|34:34|new|State.pm:reservation_failed(251)|updated > log ending value to 'failed', logid=30 > 2015-05-04 > 14:14:58|28809|34:34|new|utils.pm:update_computer_state(1587)|computer 7 > state updated to: failed > 2015-05-04 > 14:14:58|28809|34:34|new|State.pm:reservation_failed(262)|computer > VM7Cent6VCL2 (7) state set to failed > 2015-05-04 > 14:14:58|28809|34:34|new|utils.pm:update_request_state(1545)|request 34 > state updated to: failed, laststate to: new > > > > 2015-05-04 14:14:58|28809|34:34|new|State.pm:reservation_failed(275)|set > request state to 'failed'/'new' > > > 2015-05-04 14:14:58|28809|34:34|new|utils.pm:is_inblockrequest(5760)|zero > rows were returned from database select > 2015-05-04 > 14:14:58|28809|34:34|new|State.pm:reservation_failed(293)|VM7Cent6VCL2 is > NOT in blockcomputers table > 2015-05-04 14:14:58|28809|34:34|new|State.pm:reservation_failed(296)|exiting > 1 > 2015-05-04 > 14:14:58|28809|34:34|new|utils.pm:delete_computerloadlog_reservation(6396)|removing > computerloadlog entries matching loadstate = begin > 2015-05-04 > 14:14:58|28809|34:34|new|utils.pm:delete_computerloadlog_reservation(6443)|deleted > rows from computerloadlog for reservation id=34 > 2015-05-04 14:14:58|28809|34:34|new|State.pm:DESTROY(929)|VCL::new process > duration: 26 seconds > 2015-05-04 14:14:58|28809|34:34|new|VIM_SSH.pm:DESTROY(2125)|vim-cmd call > count: 16 > > > Lewis Litchfield > Technology Services – Viking Center Lab > University of South Florida Sarasota-Manatee > 941-359-4231 -- Aaron Peeler Program Manager Virtual Computing Lab NC State University All electronic mail messages in connection with State business which are sent to or received by this account are subject to the NC Public Records Law and may be disclosed to third parties.
