Al,

The log you included didn't show any errors.  So, either it did capture the 
image correctly, or it failed later in the log.  Do you see any lines in your 
log after the capture was started that contain:

 ---- WARNING ----

Josh

On Tuesday, January 30, 2018 12:39:28 PM EST Evelio Quiros wrote:
> Ok, the SSH issue has been resolved.
> It gets to the point where the image creation is started, then fails.
> Now I am still getting a failure to capture a Linux image. Log files below:
> 
> -- Al Quiros
> Enterprise Systems
> 
> 
> 
> Added new image to database: 'testing'
>    image.name: vmwarelinux-testing22-v0
>    image.id: 22
>    imagerevision.id: 18
>    imagemeta.id: 21
>    resource.id: 33
> 
> ----------------------------------------------------------------------------
> 
 Inserted imaging request to the database:
> request ID: 18
> reservation ID: 8
> 
> This process will now display the contents of the vcld.log file if the vcld
> daemon is running. If you do not see many lines of additional output, exit
> this process, start the vcld daemon, and monitor the image capture process
> by running the command:
> tail -f /var/log/vcld.log | grep -P '.\|[0-9]+\|[0-9]+\|8\|'
> 
> ----------------------------------------------------------------------------
> 
> |105862|||vcld|utils.pm:xmlrpc_call|9603| username: vclsystem@Local
> 
> 2018-01-30 12:28:41|105862|||vcld|utils.pm:xmlrpc_call|9648|called
> RPC::XML::Client::send_request:
> |105862|||vcld|utils.pm:xmlrpc_call|9648| arguments:
> |XMLRPCfinishBaseImageCapture, 1, 33, 1
> |105862|||vcld|utils.pm:xmlrpc_call|9648| response value:
> |105862|||vcld|utils.pm:xmlrpc_call|9648| : {
> |105862|||vcld|utils.pm:xmlrpc_call|9648| :   "status" => "success"
> |105862|||vcld|utils.pm:xmlrpc_call|9648| : }
> 
> 2018-01-30
> 12:28:41|105862|||vcld|utils.pm:add_imageid_to_newimages|9545|added image
> to owner's new images group, user ID: 1, image resource ID: 33, VM image:
> 1
 2018-01-30 12:28:41|105862|||vcld|utils.pm:insert_request|8303|inserted
> new image/image request into request table, request id=18 2018-01-30
> 12:28:41|105862|||vcld|utils.pm:insert_request|8334|inserted new
> reservation for request 18: 8 2018-01-30
> 12:28:41|105898|||vcld|vcld:main|179|lastcheckin time updated for
> management node 1: 2018-01-30 12:28:41 2018-01-30
> 12:28:41|105898|18|8|image|utils.pm:check_time|1252|request state is
> 'image', returning 'start' 2018-01-30
> 12:28:41|105898|18|8|image|utils.pm:run_command|9322|executed command: 'ps
> -e -o pid,args | grep -P "vcld .\|[0-9]+\|[0-9]+\|8\|"', exit status: 1,
> output: 2018-01-30
> 12:28:41|105898|18|8|image|utils.pm:is_management_node_process_running|9759
> |process is NOT running, identifier: 'vcld .\|[0-9]+\|[0-9]+\|8\|'
> 2018-01-30
> 12:28:41|105898|18|8|image|utils.pm:reservation_being_processed|9258|reserv
> ation 8 is NOT currently being processed
> |105898|18|8|image|utils.pm:reservation_being_processed|9258| reservation
> |ID: 8
 105898|18|8|image|utils.pm:reservation_being_processed|9258| parent
> |reservation ID: 8
> |105898|18|8|image|utils.pm:reservation_being_processed|9258| reservation
> |computerloadlog 'begin' entry exists: no
> |105898|18|8|image|utils.pm:reservation_being_processed|9258| parent
> |reservation computerloadlog 'begin' entry exists: no
> |105898|18|8|image|utils.pm:reservation_being_processed|9258| reservation
> |process running: no
> 2018-01-30 12:28:41|105898|18|8|image|vcld:main|299|reservation 8 is NOT
> already being processed
 2018-01-30
> 12:28:41|105898|18|8|image|utils.pm:get_imagemeta_info|3760|retrieved
> imagemeta info:
> |105898|18|8|image|utils.pm:get_imagemeta_info|3760| : {
> |105898|18|8|image|utils.pm:get_imagemeta_info|3760| :   "architecture" =>
> |"",
 105898|18|8|image|utils.pm:get_imagemeta_info|3760| :   "checkuser"
> |=> 1, 105898|18|8|image|utils.pm:get_imagemeta_info|3760| :   "id" => 21,
> |105898|18|8|image|utils.pm:get_imagemeta_info|3760| :   "postoption" =>
> |"", 105898|18|8|image|utils.pm:get_imagemeta_info|3760| :   "rootaccess"
> |=> 1, 105898|18|8|image|utils.pm:get_imagemeta_info|3760| :  
> |"sethostname" => "", 105898|18|8|image|utils.pm:get_imagemeta_info|3760| :
> |  "subimages" => 0, 105898|18|8|image|utils.pm:get_imagemeta_info|3760| : 
> | "sysprep" => 1 105898|18|8|image|utils.pm:get_imagemeta_info|3760| : }
> 
> 2018-01-30 12:28:41|105898|18|8|image|utils.pm:get_user_info|6696|management
> node's 'Affiliations Using Federated Authentication for Linux Images' list
> is empty, setting FEDERATED_LINUX_AUTHENTICATION=0
 2018-01-30
> 12:28:41|105898|18|8|image|utils.pm:get_image_active_directory_domain_info|
> 14605|image 22 is not configured for Active Directory 2018-01-30
> 12:28:42|105898|18|8|image|utils.pm:get_image_active_directory_domain_info|
> 14605|image 1 is not configured for Active Directory 2018-01-30
> 12:28:42|105898|18|8|image|utils.pm:get_production_imagerevision_info|3648|
> retrieved info from database for production revision for image identifier
> '1', production image: 'noimage' 2018-01-30
> 12:28:42|105898|18|8|image|utils.pm:get_computer_info|7046|retrieved info
> for computer: V1 (1) 2018-01-30
> 12:28:42|105898|18|8|image|utils.pm:get_vmhost_info|4013|retrieved VM host
> 1 info, VM host ID: 1, computer: V1, computer ID: 1 2018-01-30
> 12:28:42|105898|18|8|image|utils.pm:get_computer_info|7046|retrieved info
> for computer: cmp1 (7) 2018-01-30
> 12:28:42|105898|18|8|image|utils.pm:get_reservation_connect_method_info|116
> 38|retrieved connect method info for reservation 8:
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| : {
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   1
> |=> {
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> | "RETRIEVAL_TIME" => "1517333322",
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> | "connectmethodmap" => {
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |   "OSid" => undef,
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |   "OStypeid" => 2,
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |   "autoprovisioned" => undef,
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |   "connectmethodid" => 1,
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |   "disabled" => 0,
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |   "imagerevisionid" => undef
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> | }, 105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638|
> |:     "connectmethodport" => {
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |   1 => {
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |     "connectmethodid" => 1,
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |     "id" => 1,
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |     "port" => 22,
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |     "protocol" => "TCP"
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> |   } 105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638|
> |:     },
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> | "description" => "SSH for Linux & Unix",
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> | "id" => 1,
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> | "name" => "SSH",
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> | "servicename" => "ext_sshd",
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :   
> | "startupscript" => "/etc/init.d/ext_sshd"
> |105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :  
> |} 105898|18|8|image|utils.pm:get_reservation_connect_method_info|11638| :
> |}
> 2018-01-30 12:28:42|105898|18|8|image|utils.pm:get_user_info|6696|management
> node's 'Affiliations Using Federated Authentication for Linux Images' list
> is empty, setting FEDERATED_LINUX_AUTHENTICATION=0
 2018-01-30
> 12:28:42|105898|18|8|image|vcld:main|305|retrieved request information from
> database 2018-01-30
> 12:28:42|105898|18|8|image|utils.pm:delete_computerloadlog_reservation|5775
> |deleted rows from computerloadlog matching loadstate regex 'exited' for
> reservation IDs: 8 2018-01-30
> 12:28:42|105898|18|8|image|utils.pm:insertloadlog|2580|inserted 'begin'
> computerloadlog entry 2018-01-30
> 12:28:42|105898|18|8|image|vcld:make_new_child|519|request will be
> processed by image.pm 2018-01-30
> 12:28:42|105898|18|8|image|vcld:make_new_child|541|created child process
> 105932 for reservation 8, state: image, current number of forked kids: 1
> 2018-01-30 12:28:42|105932|18|8|image|vcld:make_new_child|571|vcld
> environment variable set to 0 for this process 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:is_parent_reservation|1151|this
> is the parent reservation 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:rename_vcld_process|6095|reservation
> count: 1 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:rename_vcld_process|6122|renamed
> process to 'vcld '|105932|18|8|image|' cmp1>V1 vmwarelinux-testing22-v0
> admin' 2018-01-30 12:28:42|105932|18|8|image|vcld:make_new_child|589|loaded
> VCL::image module 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:new|188|VCL::image object created for
> state image, address: 3253e00 2018-01-30
> 12:28:42|105932|18|8|image|State.pm:initialize|86|initializing
> VCL::Module::State object 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:is_parent_reservation|1151|this
> is the parent reservation 2018-01-30
> 12:28:42|105932|18|8|image|State.pm:initialize|103|obtained a database
> handle for this state process, stored as $ENV{dbh} 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:update_reservation_lastcheck|5482|updat
> ed reservation.lastcheck to '2018-01-30 12:28:42' for reservation IDs: 8
> 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:update_request_state|1445|request 18
> state updated to pending/image 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:create_os_object|449|VCL::Module::OS::
> Linux module loaded 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:new|192|VCL::Module::OS::Linux object
> created for image vmwarelinux-testing22-v0, address: 396daa0 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|713|image
> identifier argument was specified: noimage, DataStructure object will
> contain image information for the production imagerevision of this image
> 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:get_production_imagerevision_info|3648|
> retrieved info from database for production revision for image identifier
> 'noimage', production image: 'noimage' 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|743|retrieved data
> for imagerevision ID: 1 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|759|retrieved data
> for image ID: 1 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:create_mn_os_object|538|VCL::Module::O
> S::Linux::ManagementNode module loaded 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:new|199|VCL::Module::OS::Linux::Manage
> mentNode object created, address: 3a35d40 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:hostname_to_ip_address|13943|resolved
> IP address from hostname mgtvcl01.fiu.edu --> 10.106.136.5 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:set_computer_private_ip_address
> |1674|private IP address of mgtvcl01.fiu.edu set to 10.106.136.5 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:create_mn_os_object|543|VCL::Module::O
> S::Linux::ManagementNode OS object created, address: 3a35d40 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:set_mn_os|1177|storing reference to
> managment node OS object (address: 3a35d40) in this VCL::Module::OS::Linux
> object (address: 396daa0) 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:create_os_object|462|VCL::Module::OS::
> Linux OS object created, address: 396daa0 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|675|computer
> identifier argument was specified, retrieving data for computer: 1
> 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:get_computer_info|7046|retrieved info
> for computer: V1 (1) 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|713|image
> identifier argument was specified: 1, DataStructure object will contain
> image information for the production imagerevision of this image 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|743|retrieved data
> for imagerevision ID: 1 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|759|retrieved data
> for image ID: 1 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:create_vmhost_os_object|664|VM host OS
> image Perl package is VCL::Module::OS::Linux::UnixLab, most likely will not
> work correctly, changing to Linux 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:create_vmhost_os_object|669|attempting
> to load VM host OS module: VCL::Module::OS::Linux (image: 1) 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:create_vmhost_os_object|675|VM host OS
> module loaded: VCL::Module::OS::Linux 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:new|192|VCL::Module::OS::Linux object
> created for image noimage, address: 3a35f68 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:set_mn_os|1177|storing reference to
> managment node OS object (address: 3a35d40) in this VCL::Module::OS::Linux
> object (address: 3a35f68) 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:create_vmhost_os_object|688|VCL::Modul
> e::OS::Linux OS object created, address: 3a35f68 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:set_vmhost_os|1212|storing reference
> to VM host OS object (address: 3a35f68) in this VCL::image object (address:
> 3253e00) 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:create_provisioning_object|864|VCL::Mo
> dule::Provisioning::VMware::VMware module loaded 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:new|196|VCL::Module::Provisioning::VMw
> are::VMware object created for computer cmp1, address: 39f6e60 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:set_mn_os|1177|storing reference to
> managment node OS object (address: 3a35d40) in this
> VCL::Module::Provisioning::VMware::VMware object (address: 39f6e60)
> 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|675|computer
> identifier argument was specified, retrieving data for computer: 1
> 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:get_computer_info|7046|retrieved info
> for computer: V1 (1) 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|713|image
> identifier argument was specified: 1, DataStructure object will contain
> image information for the production imagerevision of this image 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|743|retrieved data
> for imagerevision ID: 1 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|759|retrieved data
> for image ID: 1 2018-01-30
> 12:28:42|105932|18|8|image|VMware.pm:get_vmhost_datastructure|1429|created
> DataStructure object for VM host: V1 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:get_vmhost_profile_password|287
> 3|vmprofile.password is set but vmprofile.secretid is NOT, assuming
> vmprofile.password is a pre-VCL 2.5 clear-text password: '' 2018-01-30
> 12:28:42|105932|18|8|image|VMware.pm:initialize|322|initializing
> VCL::Module::Provisioning::VMware::VMware object 2018-01-30
> 12:28:42|105932|18|8|image|VMware.pm:initialize|326|VM profile assigned to
> V1: VMware ESXi - local storage 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:get_computer_current_private_ip_address
> |13915|retrieved private IP address for computer V1 (1) from database:
> 10.106.144.12 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:determine_remote_connection_target|1431
> 6|private IP address is set in database for V1, it will be used as the
> remote connection target: 10.106.144.12 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:nmap_port|2115|port 22 is open on
> 10.106.144.12 (V1) 2018-01-30
> 12:28:42|105932|18|8|image|OS.pm:is_ssh_responding|1082|V1 is responding to
> SSH, port 22: open 2018-01-30
> 12:28:42|105932|18|8|image|VMware.pm:initialize|343|OS on VM host V1 will
> be controlled using VCL::Module::OS::Linux OS object 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|675|computer
> identifier argument was specified, retrieving data for computer: 1
> 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:get_computer_info|7046|retrieved info
> for computer: V1 (1) 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|713|image
> identifier argument was specified: 1, DataStructure object will contain
> image information for the production imagerevision of this image 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|743|retrieved data
> for imagerevision ID: 1 2018-01-30
> 12:28:42|105932|18|8|image|DataStructure.pm:_initialize|759|retrieved data
> for image ID: 1 2018-01-30
> 12:28:42|105932|18|8|image|VMware.pm:get_vmhost_datastructure|1429|created
> DataStructure object for VM host: V1 2018-01-30
> 12:28:42|105932|18|8|image|VMware.pm:get_vmhost_api_object|1532|attempting
> to load VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
> 2018-01-30
> 12:28:42|105932|18|8|image|VMware.pm:get_vmhost_api_object|1538|loaded
> VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
> 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:new|196|VCL::Module::Provisioning::VMw
> are::VIM_SSH object created for computer cmp1, address: 3a70cd0 2018-01-30
> 12:28:42|105932|18|8|image|Module.pm:set_mn_os|1177|storing reference to
> managment node OS object (address: 3a35d40) in this
> VCL::Module::Provisioning::VMware::VIM_SSH object (address: 3a70cd0)
> 2018-01-30
> 12:28:42|105932|18|8|image|utils.pm:run_ssh_command|4243|executing SSH
> command on 10.106.144.12 (V1): '/usr/bin/ssh  -o StrictHostKeyChecking=no
> -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o
> ConnectTimeout=30 -o BatchMode=no -o PasswordAuthentication=no -l root -p
> 22 -x 10.106.144.12 'vim-cmd ; vmware-vim-cmd' 2>&1' 2018-01-30
> 12:28:43|105932|18|8|image|utils.pm:run_ssh_command|4392|command: 'vim-cmd
> ; vmware-vim-cmd', exit_status: 127, output:
> |105932|18|8|image|utils.pm:run_ssh_command|4392| Commands available under
> |/:
 105932|18|8|image|utils.pm:run_ssh_command|4392| hbrsvc/      
> |internalsvc/  solo/         vmsvc/
> |105932|18|8|image|utils.pm:run_ssh_command|4392| hostsvc/      proxysvc/  
> |  vimsvc/       help 105932|18|8|image|utils.pm:run_ssh_command|4392| sh:
> |vmware-vim-cmd: not found
> 2018-01-30 12:28:43|105932|18|8|image|VIM_SSH.pm:initialize|141|VIM
> executable available on VM host: vim-cmd
 2018-01-30
> 12:28:43|105932|18|8|image|VIM_SSH.pm:initialize|143|VCL::Module::Provision
> ing::VMware::VIM_SSH object initialized 2018-01-30
> 12:28:43|105932|18|8|image|VMware.pm:get_vmhost_api_object|1560|created API
> object: VCL::Module::Provisioning::VMware::VIM_SSH 2018-01-30
> 12:28:43|105932|18|8|image|VMware.pm:initialize|352|VM host V1 will be
> controlled using vim-cmd via SSH 2018-01-30
> 12:28:43|105932|18|8|image|VMware.pm:initialize|371|VMware OS and API
> objects created for VM host V1:
> |105932|18|8|image|VMware.pm:initialize|371| VM host OS object type:
> |VCL::Module::OS::Linux
 105932|18|8|image|VMware.pm:initialize|371| VMware
> |API object type: VCL::Module::Provisioning::VMware::VIM_SSH
> 2018-01-30 12:28:44|105932|18|8|image|VIM_SSH.pm:_run_vim_cmd|303|executed
> command on VM host V1: vim-cmd hostsvc/hostsummary, exit status: 0
> 2018-01-30
> 12:28:44|105932|18|8|image|VIM_SSH.pm:get_vmware_product_name|4176|VMware
> product being used on VM host V1: 'VMware ESXi 6.0.0 build-2809209'
> 2018-01-30 12:28:45|105932|18|8|image|VIM_SSH.pm:_run_vim_cmd|303|executed
> command on VM host V1: vim-cmd hostsvc/datastore/listsummary, exit status:
> 0 2018-01-30
> 12:28:45|105932|18|8|image|VMware.pm:get_datastore_info|7166|retrieved
> datastore info from VM host: datastore1 2018-01-30
> 12:28:45|105932|18|8|image|Linux.pm:file_exists|1708|file or directory does
> not exist on V1: '/vmfs/volumes/datastore1/V1' 2018-01-30
> 12:28:45|105932|18|8|image|VMware.pm:get_vmx_base_directory_path|3142|direc
> tory named 'V1' does not exist under the vmx base directory path:
> /vmfs/volumes/datastore1 2018-01-30
> 12:28:45|105932|18|8|image|VMware.pm:get_vmx_base_directory_path|3146|deter
> mined vmx base directory path: /vmfs/volumes/datastore1 2018-01-30
> 12:28:45|105932|18|8|image|Linux.pm:file_exists|1722|'/vmfs/volumes/datasto
> re1' exists on V1, files: 0, directories: 0, links: 1 2018-01-30
> 12:28:45|105932|18|8|image|VMware.pm:is_vm_dedicated|4341|VM disk mode does
> not need to be dedicated 2018-01-30
> 12:28:45|105932|18|8|image|VMware.pm:initialize|399|not checking if vmdk
> base directory exists because it is the same as the vmx base directory:
> /vmfs/volumes/datastore1 2018-01-30
> 12:28:45|105932|18|8|image|Module.pm:create_provisioning_object|877|VCL::Mo
> dule::Provisioning::VMware::VMware provisioning object created for cmp1,
> address: 39f6e60 2018-01-30
> 12:28:45|105932|18|8|image|vcld:make_new_child|598|VCL::image object
> created and initialized 2018-01-30
> 12:28:45|105932|18|8|image|utils.pm:get_affiliation_info|10287|retrieved
> info for affiliation Global:
> |105932|18|8|image|utils.pm:get_affiliation_info|10287| : {
> |105932|18|8|image|utils.pm:get_affiliation_info|10287| :   "dataUpdateText"
> |=> "",
 105932|18|8|image|utils.pm:get_affiliation_info|10287| :  
> |"helpaddress" => undef,
> |105932|18|8|image|utils.pm:get_affiliation_info|10287| :   "id" => 2,
> |105932|18|8|image|utils.pm:get_affiliation_info|10287| :   "name" =>
> |"Global", 105932|18|8|image|utils.pm:get_affiliation_info|10287| :  
> |"shibname" => undef,
> |105932|18|8|image|utils.pm:get_affiliation_info|10287| :   "shibonly" =>
> |0, 105932|18|8|image|utils.pm:get_affiliation_info|10287| :  
> |"sitewwwaddress" => undef,
> |105932|18|8|image|utils.pm:get_affiliation_info|10287| :   "theme" =>
> |"dropdownmenus" 105932|18|8|image|utils.pm:get_affiliation_info|10287| : }
> 
> 2018-01-30 12:28:45|105932|18|8|image|utils.pm:get_variable|12927|data type
> of variable 'adminmessage|image_creation_started': HASH reference
> 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section: '[image_name]',
> $self->get_image_name(0) = 'vmwarelinux-testing22-v0' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|268
> 6|replaced all matching sections of input string with values retrieved from
> this DataStructure object:
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| input
> |string: 'VCL IMAGE Creation Started: [image_name]'
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |output string: 'VCL IMAGE Creation Started: vmwarelinux-testing22-v0'
> 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section: '[request_id]',
> $self->get_request_id(0) = '18'
 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section: '[reservation_id]',
> $self->get_reservation_id(0) = '8' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section: '[process_pid]',
> $self->get_process_pid(0) = '105932' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section: '[image_id]',
> $self->get_image_id(0) = '22' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section: '[image_name]',
> $self->get_image_name(0) = 'vmwarelinux-testing22-v0' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section: '[image_size]',
> $self->get_image_size(0) = '1' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section:
> '[imagerevision_id]', $self->get_imagerevision_id(0) = '18' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section:
> '[management_node_short_name]', $self->get_management_node_short_name(0) =
> 'mgtvcl01' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section: '[user_login_id]',
> $self->get_user_login_id(0) = 'admin' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section: '[user_id]',
> $self->get_user_id(0) = '1' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section: '[computer_id]',
> $self->get_computer_id(0) = '7' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section:
> '[computer_short_name]', $self->get_computer_short_name(0) = 'cmp1'
> 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|266
> 9|determined replacement value for substitution section:
> '[imagemeta_sysprep]', $self->get_imagemeta_sysprep(0) = '1' 2018-01-30
> 12:28:45|105932|18|8|image|DataStructure.pm:substitute_string_variables|268
> 6|replaced all matching sections of input string with values retrieved from
> this DataStructure object:
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| input
> |string: 'VCL Image Creation Started
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Request ID: [request_id]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Reservation ID: [reservation_id]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| PID:
> |[process_pid]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| Image
> |ID: [image_id]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| Image
> |name: [image_name]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| Base
> |image size: [image_size]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| Base
> |revision ID: [imagerevision_id]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Management node: [management_node_short_name]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Username: [user_login_id]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| User
> |ID: [user_id]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Computer ID: [computer_id]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Computer name: [computer_short_name]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| Use
> |Sysprep: [imagemeta_sysprep]
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| '
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |output string: 'VCL Image Creation Started
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Request ID: 18
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Reservation ID: 8
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| PID:
> |105932
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| Image
> |ID: 22
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| Image
> |name: vmwarelinux-testing22-v0
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| Base
> |image size: 1
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| Base
> |revision ID: 18
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Management node: mgtvcl01
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Username: admin
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| User
> |ID: 1 105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Computer ID: 7
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686|
> |Computer name: cmp1
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| Use
> |Sysprep: 1
> |105932|18|8|image|DataStructure.pm:substitute_string_variables|2686| '
> 2018-01-30
> 12:28:45|105932|18|8|image|Module.pm:_get_message_variable|1923|retrieved
> admin message variable: adminmessage|image_creation_started, returning
> array:
> |105932|18|8|image|Module.pm:_get_message_variable|1923| subject: VCL IMAGE
> |Creation Started: vmwarelinux-testing22-v0
> |105932|18|8|image|Module.pm:_get_message_variable|1923| message:
> |105932|18|8|image|Module.pm:_get_message_variable|1923| VCL Image Creation
> |Started
 105932|18|8|image|Module.pm:_get_message_variable|1923| Request
> |ID: 18 105932|18|8|image|Module.pm:_get_message_variable|1923| Reservation
> |ID: 8 105932|18|8|image|Module.pm:_get_message_variable|1923| PID: 105932
> |105932|18|8|image|Module.pm:_get_message_variable|1923| Image ID: 22
> |105932|18|8|image|Module.pm:_get_message_variable|1923| Image name:
> |vmwarelinux-testing22-v0
> |105932|18|8|image|Module.pm:_get_message_variable|1923| Base image size: 1
> |105932|18|8|image|Module.pm:_get_message_variable|1923| Base revision ID:
> |18 105932|18|8|image|Module.pm:_get_message_variable|1923| Management
> |node: mgtvcl01 105932|18|8|image|Module.pm:_get_message_variable|1923|
> |Username: admin 105932|18|8|image|Module.pm:_get_message_variable|1923|
> |User ID: 1 105932|18|8|image|Module.pm:_get_message_variable|1923|
> |Computer ID: 7 105932|18|8|image|Module.pm:_get_message_variable|1923|
> |Computer name: cmp1
> |105932|18|8|image|Module.pm:_get_message_variable|1923| Use Sysprep: 1
> 2018-01-30 12:28:46|105932|18|8|image|utils.pm:mail|1314|SUCCESS -- Sending
> mail To: [email protected], VCL IMAGE Creation Started:
> vmwarelinux-testing22-v0
 2018-01-30
> 12:28:46|105932|18|8|image|Linux.pm:file_exists|1708|file or directory does
> not exist on V1:
> '/vmfs/volumes/datastore1/vmwarelinux-testing22-v0/vmwarelinux-testing22-v0
> .vmdk' 2018-01-30
> 12:28:46|105932|18|8|image|VMware.pm:does_image_exist|4691|image does NOT
> exist in datastore on VM host V1:
> /vmfs/volumes/datastore1/vmwarelinux-testing22-v0/vmwarelinux-testing22-v0.
> vmdk 2018-01-30 12:28:46|105932|18|8|image|Linux.pm:file_exists|1708|file or
> directory does not exist on V1:
> '/vmfs/volumes/datastore1/vmwarelinux-testing22-v0/vmwarelinux-testing22-v0
> .vmdk' 2018-01-30
> 12:28:46|105932|18|8|image|VMware.pm:does_image_exist|4702|image does NOT
> exist with truncated name in datastore on VM host V1:
> /vmfs/volumes/datastore1/vmwarelinux-testing22-v0/vmwarelinux-testing22-v0.
> vmdk 2018-01-30
> 12:28:46|105932|18|8|image|VMware.pm:get_repository_vmdk_base_directory_pat
> h|4224|repository path is not configured in the VM profile 2018-01-30
> 12:28:46|105932|18|8|image|VMware.pm:get_repository_vmdk_directory_path|426
> 5|image repository vmdk directory path cannot be determined because
> repository path is not configured in the VM profile 2018-01-30
> 12:28:46|105932|18|8|image|VMware.pm:does_image_exist|4708|image does not
> exist on the VM host and image repository path is not configured in the VM
> profile 2018-01-30 12:28:46|105932|18|8|image|image.pm:process|136|image
> vmwarelinux-testing22-v0 does not exist 2018-01-30
> 12:28:46|105932|18|8|image|utils.pm:get_computer_current_private_ip_address
> |13915|retrieved private IP address for computer cmp1 (7) from database:
> 10.106.144.101 2018-01-30
> 12:28:46|105932|18|8|image|utils.pm:determine_remote_connection_target|1431
> 6|private IP address is set in database for cmp1, it will be used as the
> remote connection target: 10.106.144.101 2018-01-30
> 12:28:46|105932|18|8|image|Linux.pm:file_exists|1708|file or directory does
> not exist on cmp1: '/usr/local/vcl/vcl_post_reservation' 2018-01-30
> 12:28:46|105932|18|8|image|Linux.pm:post_reservation|690|script does NOT
> exist: /usr/local/vcl/vcl_post_reservation 2018-01-30
> 12:28:46|105932|18|8|image|OS.pm:run_stage_scripts|4540|attempting to
> execute custom scripts for 'post_reservation' stage if any exist 2018-01-30
> 12:28:46|105932|18|8|image|Module.pm:get_package_hierarchy|1390|returning
> for VCL::Module::OS::Linux:
> |105932|18|8|image|Module.pm:get_package_hierarchy|1390|
> |VCL::Module::OS::Linux
> |105932|18|8|image|Module.pm:get_package_hierarchy|1390| VCL::Module::OS
> |105932|18|8|image|Module.pm:get_package_hierarchy|1390| VCL::Module
> 2018-01-30
> 12:28:46|105932|18|8|image|OS.pm:get_source_configuration_directories|619|p
> ackage source configuration directory:
> /usr/local/vcl-2.5/bin/../tools/Linux
 2018-01-30
> 12:28:46|105932|18|8|image|OS.pm:get_source_configuration_directories|615|s
> ource configuration directory is not defined for VCL::Module::OS 2018-01-30
> 12:28:46|105932|18|8|image|OS.pm:get_source_configuration_directories|615|s
> ource configuration directory is not defined for VCL::Module 2018-01-30
> 12:28:47|105932|18|8|image|OS.pm:get_tools_file_paths|4331|attempting for
> find tools files:
> |105932|18|8|image|OS.pm:get_tools_file_paths|4331| pattern:
> |/Scripts/post_reservation/
> |105932|18|8|image|OS.pm:get_tools_file_paths|4331| architecture: x86_64
> |105932|18|8|image|OS.pm:get_tools_file_paths|4331| other architecture: x86
> 2018-01-30 12:28:48|105898|||vcld|vcld:main|179|lastcheckin time updated for
> management node 1: 2018-01-30 12:28:48
 2018-01-30
> 12:28:48|105932|18|8|image|OS.pm:find_files|4197|base directory does not
> exist on cmp1: /root/VCL/ 2018-01-30
> 12:28:48|105932|18|8|image|OS.pm:find_files|4217|files found under
> /root/VCL/ matching pattern '*': 0 2018-01-30
> 12:28:48|105932|18|8|image|OS.pm:find_files|4217|files found under
> /usr/local/vcl-2.5/bin/../tools/Linux/ matching pattern '*': 0 2018-01-30
> 12:28:48|105932|18|8|image|OS.pm:get_tools_file_paths|4403|determined list
> of tools files intended for cmp1, pattern: /Scripts/post_reservation/,
> architecture: x86_64: 2018-01-30
> 12:28:48|105932|18|8|image|OS.pm:run_stage_scripts_on_computer|4639|no
> custom scripts reside on this management node for vmwarelinux-testing22-v0
> 2018-01-30 12:28:48|105932|18|8|image|OS.pm:find_files|4217|files found
> under
> /usr/local/vcl-2.5/bin/../tools/ManagementNode/Scripts/post_reservation/
> matching pattern '*': 0 2018-01-30
> 12:28:48|105932|18|8|image|ManagementNode.pm:run_stage_scripts_on_managemen
> t_node|488|no files exist in directory:
> /usr/local/vcl-2.5/bin/../tools/ManagementNode/Scripts/post_reservation
> 2018-01-30 12:28:48|105932|18|8|image|image.pm:process|163|calling
> provisioning module's capture() subroutine 2018-01-30
> 12:28:48|105932|18|8|image|VMware.pm:get_repository_vmdk_base_directory_pat
> h|4224|repository path is not configured in the VM profile 2018-01-30
> 12:28:48|105932|18|8|image|VMware.pm:is_repository_mounted_on_vmhost|7107|u
> nable to determine if image repository is mounted on VM host V1, repository
> path is not configured in the VM profile 2018-01-30
> 12:28:48|105932|18|8|image|utils.pm:nmap_port|2115|port 22 is open on
> 10.106.144.101 (cmp1) 2018-01-30
> 12:28:48|105932|18|8|image|OS.pm:is_ssh_responding|1082|cmp1 is responding
> to SSH, port 22: open 2018-01-30
> 12:28:48|105932|18|8|image|OS.pm:get_os_type|3618|Linux OS is currently
> installed on cmp1, output:
> |105932|18|8|image|OS.pm:get_os_type|3618| Linux cmp1 2.6.32-696.el6.x86_64
> |#1 SMP Tue Mar 21 19:29:05 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
> 2018-01-30
> 12:28:48|105932|18|8|image|VMware.pm:get_active_vmx_file_path|1207|'linux'
> OS type currently installed on cmp1 matches the OS type of the image
> assigned to this reservation
 2018-01-30
> 12:28:48|105932|18|8|image|Linux.pm:get_network_configuration|2544|attempti
> ng to retrieve network configuration, no cache: 0 2018-01-30
> 12:28:48|105932|18|8|image|utils.pm:run_ssh_command|4243|executing SSH
> command on 10.106.144.101 (cmp1): '/usr/bin/ssh  -o
> StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o
> ConnectionAttempts=1 -o ConnectTimeout=30 -o BatchMode=no -o
> PasswordAuthentication=no -l root -p 22 -x 10.106.144.101 '/sbin/ifconfig
> -a' 2>&1' 2018-01-30
> 12:28:49|105932|18|8|image|utils.pm:run_ssh_command|4392|command:
> '/sbin/ifconfig -a', exit_status: 0, output:
> |105932|18|8|image|utils.pm:run_ssh_command|4392| eth0      Link
> |encap:Ethernet  HWaddr 00:0C:29:68:42:C2
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           inet
> |addr:10.106.136.25  Bcast:10.106.144.255  Mask:255.255.248.0
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           inet6 addr:
> |fe80::20c:29ff:fe68:42c2/64 Scope:Link
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           UP BROADCAST
> |RUNNING MULTICAST  MTU:1500  Metric:1
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           RX packets:1702
> |errors:0 dropped:0 overruns:0 frame:0
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           TX packets:241
> |errors:0 dropped:0 overruns:0 carrier:0
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           collisions:0
> |txqueuelen:1000 105932|18|8|image|utils.pm:run_ssh_command|4392|          
> |RX bytes:168204 (164.2 KiB)  TX bytes:22737 (22.2 KiB)
> |105932|18|8|image|utils.pm:run_ssh_command|4392| eth1      Link
> |encap:Ethernet  HWaddr 00:0C:29:68:42:CC
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           inet
> |addr:10.106.144.101  Bcast:10.106.151.255  Mask:255.255.248.0
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           inet6 addr:
> |fe80::20c:29ff:fe68:42cc/64 Scope:Link
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           UP BROADCAST
> |RUNNING MULTICAST  MTU:1500  Metric:1
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           RX packets:2132
> |errors:0 dropped:0 overruns:0 frame:0
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           TX packets:812
> |errors:0 dropped:0 overruns:0 carrier:0
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           collisions:0
> |txqueuelen:1000 105932|18|8|image|utils.pm:run_ssh_command|4392|          
> |RX bytes:273158 (266.7 KiB)  TX bytes:143278 (139.9 KiB)
> |105932|18|8|image|utils.pm:run_ssh_command|4392| lo        Link
> |encap:Local Loopback 105932|18|8|image|utils.pm:run_ssh_command|4392|     
> |     inet addr:127.0.0.1  Mask:255.0.0.0
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           inet6 addr:
> |::1/128 Scope:Host 105932|18|8|image|utils.pm:run_ssh_command|4392|       
> |   UP LOOPBACK RUNNING  MTU:65536  Metric:1
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           RX packets:85
> |errors:0 dropped:0 overruns:0 frame:0
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           TX packets:85
> |errors:0 dropped:0 overruns:0 carrier:0
> |105932|18|8|image|utils.pm:run_ssh_command|4392|           collisions:0
> |txqueuelen:0 105932|18|8|image|utils.pm:run_ssh_command|4392|           RX
> |bytes:11066 (10.8 KiB)  TX bytes:11066 (10.8 KiB)
> 2018-01-30
> 12:28:49|105932|18|8|image|utils.pm:run_ssh_command|4243|executing SSH
> command on 10.106.144.101 (cmp1): '/usr/bin/ssh  -o
> StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o
> ConnectionAttempts=1 -o ConnectTimeout=30 -o BatchMode=no -o
> PasswordAuthentication=no -l root -p 22 -x 10.106.144.101 '/sbin/route -n'
> 2>&1'
 2018-01-30
> 12:28:49|105932|18|8|image|utils.pm:run_ssh_command|4392|command:
> '/sbin/route -n', exit_status: 0, output:
> |105932|18|8|image|utils.pm:run_ssh_command|4392| Kernel IP routing table
> |105932|18|8|image|utils.pm:run_ssh_command|4392| Destination     Gateway   
> |     Genmask         Flags Metric Ref    Use Iface
> |105932|18|8|image|utils.pm:run_ssh_command|4392| 10.106.144.0    0.0.0.0  
> |      255.255.248.0   U     0      0        0 eth1
> |105932|18|8|image|utils.pm:run_ssh_command|4392| 10.106.136.0    0.0.0.0  
> |      255.255.248.0   U     0      0        0 eth0
> |105932|18|8|image|utils.pm:run_ssh_command|4392| 169.254.0.0     0.0.0.0  
> |      255.255.0.0     U     1002   0        0 eth0
> |105932|18|8|image|utils.pm:run_ssh_command|4392| 169.254.0.0     0.0.0.0  
> |      255.255.0.0     U     1003   0        0 eth1
> |105932|18|8|image|utils.pm:run_ssh_command|4392| 0.0.0.0        
> |10.106.136.1    0.0.0.0         UG    0      0        0 eth0
> 2018-01-30
> 12:28:49|105932|18|8|image|Linux.pm:get_network_configuration|2624|found
> default route configured for 'eth0' interface: 10.106.136.1
 2018-01-30
> 12:28:49|105932|18|8|image|utils.pm:run_ssh_command|4243|executing SSH
> command on 10.106.144.101 (cmp1): '/usr/bin/ssh  -o
> StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o
> ConnectionAttempts=1 -o ConnectTimeout=30 -o BatchMode=no -o
> PasswordAuthentication=no -l root -p 22 -x 10.106.144.101 'brctl show'
> 2>&1' 2018-01-30
> 12:28:49|105932|18|8|image|utils.pm:run_ssh_command|4392|command: 'brctl
> show', exit_status: 0, output:
> |105932|18|8|image|utils.pm:run_ssh_command|4392| bridge name    bridge id  
> |                   STP enabled            interfaces
> 2018-01-30
> 12:28:49|105932|18|8|image|Linux.pm:get_network_bridge_info|3560|retrieved
> network bridge configuration from cmp1:: {}
 2018-01-30
> 12:28:49|105932|18|8|image|Linux.pm:get_network_configuration|2658|retrieve
> d network configuration:
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| : {
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :   "eth0" => {
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :    
> |"broadcast_address" => "10.106.144.255",
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :    
> |"default_gateway" => "10.106.136.1",
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :    
> |"ip_address" => {
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :      
> |"10.106.136.25" => "255.255.248.0"
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :     },
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :     "name" =>
> |"eth0", 105932|18|8|image|Linux.pm:get_network_configuration|2658| :    
> |"physical_address" => "00:0c:29:68:42:c2"
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :   },
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :   "eth1" => {
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :    
> |"broadcast_address" => "10.106.151.255",
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :    
> |"ip_address" => {
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :      
> |"10.106.144.101" => "255.255.248.0"
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :     },
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :     "name" =>
> |"eth1", 105932|18|8|image|Linux.pm:get_network_configuration|2658| :    
> |"physical_address" => "00:0c:29:68:42:cc"
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :   },
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :   "lo" => {
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| :     "name" =>
> |"lo" 105932|18|8|image|Linux.pm:get_network_configuration|2658| :   }
> |105932|18|8|image|Linux.pm:get_network_configuration|2658| : }
> 
> 2018-01-30
> 12:28:49|105932|18|8|image|DataStructure.pm:get_computer_private_ip_address
> |1580|private IP address for cmp1 (7) stored in this object matches IP
> address stored in %ENV: 10.106.144.101
 2018-01-30
> 12:28:49|105932|18|8|image|OS.pm:get_private_interface_name|1930|determined
> private interface name: eth1 (10.106.144.101) 2018-01-30
> 12:28:49|105932|18|8|image|Linux.pm:get_network_configuration|2544|attempti
> ng to retrieve network configuration, no cache: 0 2018-01-30
> 12:28:49|105932|18|8|image|OS.pm:get_mac_address|2329|returning private MAC
> address: 00:0c:29:68:42:cc 2018-01-30
> 12:28:49|105932|18|8|image|OS.pm:get_public_network_configuration|2282|atte
> mpting to retrieve public network configuration, no cache: 0, ignore error:
> 0 2018-01-30
> 12:28:49|105932|18|8|image|OS.pm:get_public_interface_name|1961|attempting
> to determine public interface name, no cache: 0, ignore error: 0 2018-01-30
> 12:28:49|105932|18|8|image|Linux.pm:get_network_configuration|2544|attempti
> ng to retrieve network configuration, no cache: 0 2018-01-30
> 12:28:49|105932|18|8|image|DataStructure.pm:get_computer_private_ip_address
> |1580|private IP address for cmp1 (7) stored in this object matches IP
> address stored in %ENV: 10.106.144.101 2018-01-30
> 12:28:49|105932|18|8|image|OS.pm:get_public_interface_name|2042|'eth0'
> could potentially be public interface, not assigned private IP address
> 2018-01-30
> 12:28:49|105932|18|8|image|Linux.pm:get_network_configuration|2544|attempti
> ng to retrieve network configuration, no cache: 0 2018-01-30
> 12:28:49|105932|18|8|image|DataStructure.pm:get_computer_private_ip_address
> |1580|private IP address for cmp1 (7) stored in this object matches IP
> address stored in %ENV: 10.106.144.101 2018-01-30
> 12:28:49|105932|18|8|image|OS.pm:_get_public_interface_name_helper|2124|'et
> h0' is more likely the public interface, it is NOT assigned the private IP
> address: 10.106.144.101 2018-01-30
> 12:28:49|105932|18|8|image|OS.pm:get_public_interface_name|1995|interface
> 'lo' ignored because its name is 'lo' 2018-01-30
> 12:28:49|105932|18|8|image|OS.pm:get_public_interface_name|2060|determined
> the public interface name: 'eth0' 2018-01-30
> 12:28:49|105932|18|8|image|Linux.pm:get_network_configuration|2544|attempti
> ng to retrieve network configuration, no cache: 0 2018-01-30
> 12:28:49|105932|18|8|image|OS.pm:get_mac_address|2329|returning public MAC
> address: 00:0c:29:68:42:c2 2018-01-30
> 12:28:49|105932|18|8|image|VMware.pm:get_vmx_file_paths|5528|attempting to
> find existing vmx files on the VM host 2018-01-30
> 12:28:50|105932|18|8|image|Linux.pm:file_exists|1708|file or directory does
> not exist on V1: '/vmfs/volumes/datastore1/V1' 2018-01-30
> 12:28:50|105932|18|8|image|VMware.pm:get_vmx_base_directory_path|3142|direc
> tory named 'V1' does not exist under the vmx base directory path:
> /vmfs/volumes/datastore1 2018-01-30
> 12:28:50|105932|18|8|image|VMware.pm:get_vmx_base_directory_path|3146|deter
> mined vmx base directory path: /vmfs/volumes/datastore1 2018-01-30
> 12:28:50|105932|18|8|image|OS.pm:find_files|4217|files found under
> /vmfs/volumes/datastore1/ matching pattern '*.vmx': 1 2018-01-30
> 12:28:51|105932|18|8|image|VIM_SSH.pm:_run_vim_cmd|303|executed command on
> VM host V1: vim-cmd vmsvc/getallvms, exit status: 0 2018-01-30
> 12:28:52|105932|18|8|image|VIM_SSH.pm:_run_vim_cmd|303|executed command on
> VM host V1: vim-cmd hostsvc/datastore/listsummary, exit status: 0
> 2018-01-30
> 12:28:52|105932|18|8|image|VMware.pm:get_datastore_info|7166|retrieved
> datastore info from VM host: datastore1 2018-01-30
> 12:28:52|105932|18|8|image|VIM_SSH.pm:get_registered_vms|1123|found 1
> registered VMs 2018-01-30
> 12:28:52|105932|18|8|image|VMware.pm:get_vmx_file_paths|5543|found 1 vmx
> files on VM host
> |105932|18|8|image|VMware.pm:get_vmx_file_paths|5543|
> |/vmfs/volumes/datastore1/test/test.vmx
> 2018-01-30
> 12:28:52|105932|18|8|image|VMware.pm:get_active_vmx_file_path|1230|retrieve
> d vmx file paths currently residing on the VM host:
> |105932|18|8|image|VMware.pm:get_active_vmx_file_path|1230|
> |/vmfs/volumes/datastore1/test/test.vmx
> 2018-01-30
> 12:28:52|105932|18|8|image|VMware.pm:get_active_vmx_file_path|1237|sorted
> vmx file paths so that directories containing cmp1 are checked first:
> |105932|18|8|image|VMware.pm:get_active_vmx_file_path|1237|
> |/vmfs/volumes/datastore1/test/test.vmx
> 2018-01-30 12:28:52|105932|18|8|image|VMware.pm:get_vmx_info|5604|attempting
> to retrieve info from vmx file: /vmfs/volumes/datastore1/test/test.vmx
> 2018-01-30
> 12:28:52|105932|18|8|image|OS.pm:get_file_contents|3088|retrieved 76 lines
> from file on V1: '/vmfs/volumes/datastore1/test/test.vmx' 2018-01-30
> 12:28:52|105932|18|8|image|VMware.pm:get_vmx_info|5645|vmx file does not
> contain a computer_id value, attempting to determine matching computer
> 2018-01-30
> 12:28:52|105932|18|8|image|VMware.pm:_get_file_path_computer_name|7913|dire
> ctory name 'test' does not appear to contain a computer name, argument:
> /vmfs/volumes/datastore1/test/test.vmx 2018-01-30
> 12:28:52|105932|18|8|image|VMware.pm:_get_file_path_computer_name|7924|comp
> uter name could not be determined from path:
> /vmfs/volumes/datastore1/test/test.vmx 2018-01-30
> 12:28:52|105932|18|8|image|VMware.pm:get_vmx_info|5659|unable to determine
> computer name from vmx file path: '/vmfs/volumes/datastore1/test/test.vmx'
> 2018-01-30 12:28:52|105932|18|8|image|VMware.pm:get_vmx_info|5673|ignoring
> ide1:0, filename property does not end with .vmdk:
> /vmfs/volumes/5a68e58a-1e6caf5e-c304-7cd30abf01ba/iso/CentOS-6.9-x86_64-min
> imal.iso
> |105932|18|8|image|VMware.pm:get_vmx_info|5673| : {
> |105932|18|8|image|VMware.pm:get_vmx_info|5673| :   "devicetype" =>
> |"cdrom-image",
 105932|18|8|image|VMware.pm:get_vmx_info|5673| :  
> |"filename" =>
> |"/vmfs/volumes/5a68e58a-1e6caf5e-c304-7cd30abf01ba/iso/CentOS-6.9-x86_64-m
> |inimal.iso", 105932|18|8|image|VMware.pm:get_vmx_info|5673| :   "present"
> |=> "TRUE" 105932|18|8|image|VMware.pm:get_vmx_info|5673| : }
> 
> 2018-01-30 12:28:52|105932|18|8|image|VMware.pm:get_vmx_info|5681|scsi0:0
> mode property not set, setting default value: persistent
 2018-01-30
> 12:28:52|105932|18|8|image|VMware.pm:get_vmx_info|5690|vmdk path appears to
> be relative: test.vmdk, prepending the vmx directory:
> /vmfs/volumes/datastore1/test/test.vmdk 2018-01-30
> 12:28:52|105932|18|8|image|VMware.pm:get_active_vmx_file_path|1268|comparin
> g MAC addresses
> |105932|18|8|image|VMware.pm:get_active_vmx_file_path|1268| used by cmp1:
> |105932|18|8|image|VMware.pm:get_active_vmx_file_path|1268| 000c296842c2
> |105932|18|8|image|VMware.pm:get_active_vmx_file_path|1268| 000c296842cc
> |105932|18|8|image|VMware.pm:get_active_vmx_file_path|1268| configured in
> |test.vmx:
 105932|18|8|image|VMware.pm:get_active_vmx_file_path|1268|
> |000c296842c2 105932|18|8|image|VMware.pm:get_active_vmx_file_path|1268|
> |000c296842cc
> 2018-01-30 12:28:53|105932|18|8|image|VIM_SSH.pm:_run_vim_cmd|303|executed
> command on VM host V1: vim-cmd vmsvc/getallvms, exit status: 0
 2018-01-30
> 12:28:53|105932|18|8|image|VIM_SSH.pm:get_registered_vms|1123|found 1
> registered VMs 2018-01-30
> 12:28:53|105932|18|8|image|VMware.pm:is_vm_registered|4516|VM is
> registered: /vmfs/volumes/datastore1/test/test.vmx 2018-01-30
> 12:28:54|105898|||vcld|vcld:main|179|lastcheckin time updated for
> management node 1: 2018-01-30 12:28:54 2018-01-30
> 12:28:54|105932|18|8|image|VIM_SSH.pm:_run_vim_cmd|303|executed command on
> VM host V1: vim-cmd vmsvc/getallvms, exit status: 0 2018-01-30
> 12:28:55|105932|18|8|image|VIM_SSH.pm:_run_vim_cmd|303|executed command on
> VM host V1: vim-cmd vmsvc/power.getstate 1, exit status: 0 2018-01-30
> 12:28:55|105932|18|8|image|VIM_SSH.pm:get_vm_power_state|1172|vmsvc/power.g
> etstate 1:
> |105932|18|8|image|VIM_SSH.pm:get_vm_power_state|1172| Retrieved runtime
> |info
 105932|18|8|image|VIM_SSH.pm:get_vm_power_state|1172| Powered on
> 
> 2018-01-30 12:28:55|105932|18|8|image|VIM_SSH.pm:get_vm_power_state|1175|VM
> is powered on: /vmfs/volumes/datastore1/test/test.vmx
 2018-01-30
> 12:28:55|105932|18|8|image|VMware.pm:get_active_vmx_file_path|1289|found
> matching MAC address between cmp1 (powered on) and test.vmx:
> |105932|18|8|image|VMware.pm:get_active_vmx_file_path|1289| 000c296842c2
> |105932|18|8|image|VMware.pm:get_active_vmx_file_path|1289| 000c296842cc
> 
> 2018-01-30
> 12:28:55|105932|18|8|image|VMware.pm:get_active_vmx_file_path|1301|found
> vmx file being used by cmp1 (powered on):
> /vmfs/volumes/datastore1/test/test.vmx
 2018-01-30
> 12:28:55|105932|18|8|image|VMware.pm:check_file_paths|4124|successfully
> retrieved vmx file path components:
> |105932|18|8|image|VMware.pm:check_file_paths|4124| VM profile VM path:     
> |          'datastore1'
 105932|18|8|image|VMware.pm:check_file_paths|4124|
> |VM profile datastore path:         'datastore1'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmx file path:         
> |           '/vmfs/volumes/datastore1/test/test.vmx'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmx directory path:    
> |           '/vmfs/volumes/datastore1/test'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmx base directory
> |path:           '/vmfs/volumes/datastore1'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmx directory name:    
> |           'test' 105932|18|8|image|VMware.pm:check_file_paths|4124| vmx
> |file name:                     'test.vmx'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmx datastore URL path:
> |           '/vmfs/volumes/5a68e58a-1e6caf5e-c304-7cd30abf01ba'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmx datastore URL:     
> |           '5a68e58a-1e6caf5e-c304-7cd30abf01ba'
> 2018-01-30 12:28:55|105932|18|8|image|VMware.pm:set_vmx_file_path|3423|set
> overridden vmx file path: '/vmfs/volumes/datastore1/test/test.vmx'
> |105932|18|8|image|VMware.pm:set_vmx_file_path|3423|
> |/vmfs/volumes/datastore1/test/test.vmx
> 2018-01-30 12:28:55|105932|18|8|image|VMware.pm:get_vmx_info|5600|returning
> previously retrieved info from vmx file:
> /vmfs/volumes/datastore1/test/test.vmx
 2018-01-30
> 12:28:55|105932|18|8|image|VMware.pm:capture|858|vmx info for VM cmp1 being
> captured:
> |105932|18|8|image|VMware.pm:capture|858| : {
> |105932|18|8|image|VMware.pm:capture|858| :   ".encoding" => "UTF-8",
> |105932|18|8|image|VMware.pm:capture|858| :   "cleanshutdown" => "FALSE",
> |105932|18|8|image|VMware.pm:capture|858| :   "config.version" => 8,
> |105932|18|8|image|VMware.pm:capture|858| :   "displayname" => "test",
> |105932|18|8|image|VMware.pm:capture|858| :   "ethernet0.addresstype" =>
> |"generated",
 105932|18|8|image|VMware.pm:capture|858| :  
> |"ethernet0.generatedaddress" => "00:0c:29:68:42:c2",
> |105932|18|8|image|VMware.pm:capture|858| :  
> |"ethernet0.generatedaddressoffset" => 0,
> |105932|18|8|image|VMware.pm:capture|858| :   "ethernet0.networkname" =>
> |"New VCL Public", 105932|18|8|image|VMware.pm:capture|858| :  
> |"ethernet0.pcislotnumber" => 160, 105932|18|8|image|VMware.pm:capture|858|
> |:   "ethernet0.present" => "TRUE",
> |105932|18|8|image|VMware.pm:capture|858| :   "ethernet0.uptcompatibility"
> |=> "TRUE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"ethernet0.virtualdev" => "vmxnet3",
> |105932|18|8|image|VMware.pm:capture|858| :   "ethernet1.addresstype" =>
> |"generated", 105932|18|8|image|VMware.pm:capture|858| :  
> |"ethernet1.generatedaddress" => "00:0c:29:68:42:cc",
> |105932|18|8|image|VMware.pm:capture|858| :  
> |"ethernet1.generatedaddressoffset" => 10,
> |105932|18|8|image|VMware.pm:capture|858| :   "ethernet1.networkname" =>
> |"New VCL Private", 105932|18|8|image|VMware.pm:capture|858| :  
> |"ethernet1.pcislotnumber" => 192, 105932|18|8|image|VMware.pm:capture|858|
> |:   "ethernet1.present" => "TRUE",
> |105932|18|8|image|VMware.pm:capture|858| :   "ethernet1.uptcompatibility"
> |=> "TRUE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"ethernet1.virtualdev" => "vmxnet3",
> |105932|18|8|image|VMware.pm:capture|858| :   "floppy0.clientdevice" =>
> |"TRUE", 105932|18|8|image|VMware.pm:capture|858| :   "floppy0.filename" =>
> |"vmware-null-remote-floppy", 105932|18|8|image|VMware.pm:capture|858| :  
> |"floppy0.startconnected" => "FALSE",
> |105932|18|8|image|VMware.pm:capture|858| :   "guestos" => "centos-64",
> |105932|18|8|image|VMware.pm:capture|858| :   "hpet0.present" => "TRUE",
> |105932|18|8|image|VMware.pm:capture|858| :   "ide1:0.devicetype" =>
> |"cdrom-image", 105932|18|8|image|VMware.pm:capture|858| :  
> |"ide1:0.filename" =>
> |"/vmfs/volumes/5a68e58a-1e6caf5e-c304-7cd30abf01ba/iso/CentOS-6.9-x86_64-m
> |inimal.iso", 105932|18|8|image|VMware.pm:capture|858| :   "ide1:0.present"
> |=> "TRUE", 105932|18|8|image|VMware.pm:capture|858| :   "memsize" => 2048,
> |105932|18|8|image|VMware.pm:capture|858| :   "migrate.hostlog" =>
> |"./test-13f0a75e.hlog",
 105932|18|8|image|VMware.pm:capture|858| :  
> |"monitor.phys_bits_used" => 42, 105932|18|8|image|VMware.pm:capture|858| :
> |  "nvram" => "test.nvram", 105932|18|8|image|VMware.pm:capture|858| :  
> |"pcibridge0.pcislotnumber" => 17, 105932|18|8|image|VMware.pm:capture|858|
> |:   "pcibridge0.present" => "TRUE",
> |105932|18|8|image|VMware.pm:capture|858| :   "pcibridge4.functions" => 8,
> |105932|18|8|image|VMware.pm:capture|858| :   "pcibridge4.pcislotnumber" =>
> |21, 105932|18|8|image|VMware.pm:capture|858| :   "pcibridge4.present" =>
> |"TRUE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"pcibridge4.virtualdev" => "pcieRootPort",
> |105932|18|8|image|VMware.pm:capture|858| :   "pcibridge5.functions" => 8,
> |105932|18|8|image|VMware.pm:capture|858| :   "pcibridge5.pcislotnumber" =>
> |22, 105932|18|8|image|VMware.pm:capture|858| :   "pcibridge5.present" =>
> |"TRUE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"pcibridge5.virtualdev" => "pcieRootPort",
> |105932|18|8|image|VMware.pm:capture|858| :   "pcibridge6.functions" => 8,
> |105932|18|8|image|VMware.pm:capture|858| :   "pcibridge6.pcislotnumber" =>
> |23, 105932|18|8|image|VMware.pm:capture|858| :   "pcibridge6.present" =>
> |"TRUE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"pcibridge6.virtualdev" => "pcieRootPort",
> |105932|18|8|image|VMware.pm:capture|858| :   "pcibridge7.functions" => 8,
> |105932|18|8|image|VMware.pm:capture|858| :   "pcibridge7.pcislotnumber" =>
> |24, 105932|18|8|image|VMware.pm:capture|858| :   "pcibridge7.present" =>
> |"TRUE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"pcibridge7.virtualdev" => "pcieRootPort",
> |105932|18|8|image|VMware.pm:capture|858| :   "replay.filename" => "",
> |105932|18|8|image|VMware.pm:capture|858| :   "replay.supported" =>
> |"FALSE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"sched.swap.derivedname" =>
> |"/vmfs/volumes/5a68e58a-1e6caf5e-c304-7cd30abf01ba/test/test-13f0a75e.vswp
> |", 105932|18|8|image|VMware.pm:capture|858| :   "scsi0.pcislotnumber" =>
> |16, 105932|18|8|image|VMware.pm:capture|858| :   "scsi0.present" =>
> |"TRUE", 105932|18|8|image|VMware.pm:capture|858| :   "scsi0.virtualdev" =>
> |"lsilogic", 105932|18|8|image|VMware.pm:capture|858| :  
> |"scsi0:0.devicetype" => "scsi-hardDisk",
> |105932|18|8|image|VMware.pm:capture|858| :   "scsi0:0.filename" =>
> |"test.vmdk", 105932|18|8|image|VMware.pm:capture|858| :  
> |"scsi0:0.present" => "TRUE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"scsi0:0.redo" => "", 105932|18|8|image|VMware.pm:capture|858| :  
> |"softpoweroff" => "FALSE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"svga.present" => "TRUE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"toolscripts.afterpoweron" => "TRUE",
> |105932|18|8|image|VMware.pm:capture|858| :   "toolscripts.afterresume" =>
> |"TRUE", 105932|18|8|image|VMware.pm:capture|858| :  
> |"toolscripts.beforepoweroff" => "TRUE",
> |105932|18|8|image|VMware.pm:capture|858| :   "toolscripts.beforesuspend"
> |=> "TRUE", 105932|18|8|image|VMware.pm:capture|858| :   "uuid.bios" => "56
> |4d e1 b9 3a ae 2d 61-a5 ae 03 cd 2f 68 42 c2",
> |105932|18|8|image|VMware.pm:capture|858| :   "uuid.location" => "56 4d e1
> |b9 3a ae 2d 61-a5 ae 03 cd 2f 68 42 c2",
> |105932|18|8|image|VMware.pm:capture|858| :   "vc.uuid" => "52 0d f8 2f 72
> |d5 ec ff-94 d5 66 13 68 f5 a7 28",
> |105932|18|8|image|VMware.pm:capture|858| :  
> |"virtualhw.productcompatibility" => "hosted",
> |105932|18|8|image|VMware.pm:capture|858| :   "virtualhw.version" => 11,
> |105932|18|8|image|VMware.pm:capture|858| :   "vmci0.id" => 795361986,
> |105932|18|8|image|VMware.pm:capture|858| :   "vmci0.pcislotnumber" => 32,
> |105932|18|8|image|VMware.pm:capture|858| :   "vmci0.present" => "TRUE",
> |105932|18|8|image|VMware.pm:capture|858| :   "vmdk" => {
> |105932|18|8|image|VMware.pm:capture|858| :     "scsi0:0" => {
> |105932|18|8|image|VMware.pm:capture|858| :       "devicetype" =>
> |"scsi-hardDisk",
 105932|18|8|image|VMware.pm:capture|858| :       "mode"
> |=> "persistent", 105932|18|8|image|VMware.pm:capture|858| :      
> |"present" => "TRUE", 105932|18|8|image|VMware.pm:capture|858| :      
> |"redo" => "",
> |105932|18|8|image|VMware.pm:capture|858| :       "vmdk_directory_path" =>
> |"/vmfs/volumes/datastore1/test",
 105932|18|8|image|VMware.pm:capture|858|
> |:       "vmdk_file_base_name" => "test",
> |105932|18|8|image|VMware.pm:capture|858| :       "vmdk_file_name" =>
> |"test.vmdk", 105932|18|8|image|VMware.pm:capture|858| :      
> |"vmdk_file_path" => "/vmfs/volumes/datastore1/test/test.vmdk"
> |105932|18|8|image|VMware.pm:capture|858| :     }
> |105932|18|8|image|VMware.pm:capture|858| :   },
> |105932|18|8|image|VMware.pm:capture|858| :   "vmotion.checkpointfbsize" =>
> |4194304,
 105932|18|8|image|VMware.pm:capture|858| :  
> |"vmotion.checkpointsvgaprimarysize" => 4194304,
> |105932|18|8|image|VMware.pm:capture|858| :   "vmx_directory_path" =>
> |"/vmfs/volumes/datastore1/test", 105932|18|8|image|VMware.pm:capture|858|
> |:   "vmx_file_name" => "test.vmx" 105932|18|8|image|VMware.pm:capture|858|
> |: }
> 
> 2018-01-30 12:28:55|105932|18|8|image|VMware.pm:capture|877|vmdk file path
> configured for VM cmp1 being captured:
> /vmfs/volumes/datastore1/test/test.vmdk
 2018-01-30
> 12:28:55|105932|18|8|image|VMware.pm:_get_datastore_names|7197|datastore
> names: datastore1 2018-01-30
> 12:28:55|105932|18|8|image|VMware.pm:get_vmdk_base_directory_path_dedicated
> |3693|using VM profile datastore path as the vmdk base directory path:
> datastore1 2018-01-30
> 12:28:55|105932|18|8|image|VMware.pm:_get_datastore_names|7197|datastore
> names: datastore1 2018-01-30
> 12:28:55|105932|18|8|image|VMware.pm:get_vmdk_base_directory_path_dedicated
> |3693|using VM profile datastore path as the vmdk base directory path:
> datastore1 2018-01-30
> 12:28:55|105932|18|8|image|VMware.pm:check_file_paths|4124|successfully
> retrieved vmdk file path components:
> |105932|18|8|image|VMware.pm:check_file_paths|4124| VM profile VM path:     
> |          'datastore1'
 105932|18|8|image|VMware.pm:check_file_paths|4124|
> |VM profile datastore path:         'datastore1'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmdk file path:        
> |           '/vmfs/volumes/datastore1/test/test.vmdk'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmdk directory path:   
> |           '/vmfs/volumes/datastore1/test'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmdk base directory
> |path:          '/vmfs/volumes/datastore1'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmdk directory name:   
> |           'test' 105932|18|8|image|VMware.pm:check_file_paths|4124| vmdk
> |file name:                    'test.vmdk'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmdk file prefix:      
> |           'test' 105932|18|8|image|VMware.pm:check_file_paths|4124|
> |dedicated vmdk file path:         
> |'/vmfs/volumes/datastore1/test/test.vmdk'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| dedicated vmdk
> |directory path:     '/vmfs/volumes/datastore1/test'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| dedicated vmdk
> |directory name:     'test'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| shared vmdk file path: 
> |          
> |'/vmfs/volumes/datastore1/vmwarelinux-testing22-v0/vmwarelinux-testing22-v
> |0.vmdk' 105932|18|8|image|VMware.pm:check_file_paths|4124| shared vmdk
> |directory path:        '/vmfs/volumes/datastore1/vmwarelinux-testing22-v0'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| shared vmdk directory
> |name:        'vmwarelinux-testing22-v0'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmdk datastore URL
> |path:           '/vmfs/volumes/5a68e58a-1e6caf5e-c304-7cd30abf01ba'
> |105932|18|8|image|VMware.pm:check_file_paths|4124| vmdk datastore URL:    
> |           '5a68e58a-1e6caf5e-c304-7cd30abf01ba'
> 2018-01-30 12:28:55|105932|18|8|image|VMware.pm:set_vmdk_file_path|4053|set
> overridden vmdk file path: '/vmfs/volumes/datastore1/test/test.vmdk'
> 2018-01-30 12:28:55|105932|18|8|image|VMware.pm:capture|901|mode of vmdk to
> be captured is valid: persistent 2018-01-30
> 12:28:55|105932|18|8|image|Linux.pm:file_exists|1708|file or directory does
> not exist on V1:
> '/vmfs/volumes/datastore1/vmwarelinux-testing22-v0/vmwarelinux-testing22-v0
> .vmdk' 2018-01-30
> 12:28:56|105932|18|8|image|Linux.pm:file_exists|1722|'/etc/redhat-release'
> exists on cmp1, files: 0, directories: 0, links: 1 2018-01-30
> 12:28:56|105932|18|8|image|OS.pm:get_file_contents|3088|retrieved 1 lines
> from file on cmp1: '/etc/redhat-release' 2018-01-30
> 12:28:56|105932|18|8|image|Linux.pm:get_product_name|6703|determined Linux
> distribution name installed on cmp1: 'CentOS release 6.9 (Final)'
> 2018-01-30 12:28:56|105932|18|8|image|OS.pm:pre_capture|92|beginning common
> image capture preparation tasks 2018-01-30
> 12:28:57|105932|18|8|image|utils.pm:nmap_port|2115|port 22 is open on
> 10.106.144.101 (cmp1) 2018-01-30
> 12:28:57|105932|18|8|image|OS.pm:is_ssh_responding|1082|cmp1 is responding
> to SSH, port 22: open 2018-01-30
> 12:28:57|105932|18|8|image|utils.pm:run_ssh_command|4243|executing SSH
> command on 10.106.144.101 (cmp1): '/usr/bin/ssh  -o
> StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o
> ConnectionAttempts=1 -o ConnectTimeout=30 -o BatchMode=no -o
> PasswordAuthentication=no -l root -p 22 -x 10.106.144.101 'rm -rfv
> /root/VCL' 2>&1' 2018-01-30
> 12:28:57|105932|18|8|image|utils.pm:run_ssh_command|4392|command: 'rm -rfv
> /root/VCL', exit_status: 0, output: 2018-01-30
> 12:28:57|105932|18|8|image|Linux.pm:delete_file|1777|deleted '/root/VCL' on
> cmp1 2018-01-30
> 12:28:58|105932|18|8|image|OS.pm:create_text_file|2934|created text file on
> cmp1: ~/currentimage.txt 2018-01-30
> 12:28:58|105932|18|8|image|OS.pm:run_stage_scripts|4540|attempting to
> execute custom scripts for 'pre_capture' stage if any exist 2018-01-30
> 12:28:58|105932|18|8|image|Module.pm:get_package_hierarchy|1390|returning
> for VCL::Module::OS::Linux:
> |105932|18|8|image|Module.pm:get_package_hierarchy|1390|
> |VCL::Module::OS::Linux
> |105932|18|8|image|Module.pm:get_package_hierarchy|1390| VCL::Module::OS
> |105932|18|8|image|Module.pm:get_package_hierarchy|1390| VCL::Module
> 2018-01-30
> 12:28:58|105932|18|8|image|OS.pm:get_source_configuration_directories|619|p
> ackage source configuration directory:
> /usr/local/vcl-2.5/bin/../tools/Linux
 2018-01-30
> 12:28:58|105932|18|8|image|OS.pm:get_source_configuration_directories|615|s
> ource configuration directory is not defined for VCL::Module::OS 2018-01-30
> 12:28:58|105932|18|8|image|OS.pm:get_source_configuration_directories|615|s
> ource configuration directory is not defined for VCL::Module 2018-01-30
> 12:28:59|105932|18|8|image|OS.pm:get_tools_file_paths|4331|attempting for
> find tools files:
> |105932|18|8|image|OS.pm:get_tools_file_paths|4331| pattern:
> |/Scripts/pre_capture/
 105932|18|8|image|OS.pm:get_tools_file_paths|4331|
> |architecture: x86_64 105932|18|8|image|OS.pm:get_tools_file_paths|4331|
> |other architecture: x86
> 2018-01-30 12:28:59|105932|18|8|image|OS.pm:find_files|4197|base directory
> does not exist on cmp1: /root/VCL/
 2018-01-30
> 12:28:59|105932|18|8|image|OS.pm:find_files|4217|files found under
> /root/VCL/ matching pattern '*': 0 2018-01-30
> 12:28:59|105932|18|8|image|OS.pm:find_files|4217|files found under
> /usr/local/vcl-2.5/bin/../tools/Linux/ matching pattern '*': 0 2018-01-30
> 12:28:59|105932|18|8|image|OS.pm:get_tools_file_paths|4403|determined list
> of tools files intended for cmp1, pattern: /Scripts/pre_capture/,
> architecture: x86_64: 2018-01-30
> 12:28:59|105932|18|8|image|OS.pm:run_stage_scripts_on_computer|4639|no
> custom scripts reside on this management node for vmwarelinux-testing22-v0
> 2018-01-30 12:28:59|105932|18|8|image|OS.pm:find_files|4217|files found
> under /usr/local/vcl-2.5/bin/../tools/ManagementNode/Scripts/pre_capture/
> matching pattern '*': 0 2018-01-30
> 12:28:59|105932|18|8|image|ManagementNode.pm:run_stage_scripts_on_managemen
> t_node|488|no files exist in directory:
> /usr/local/vcl-2.5/bin/../tools/ManagementNode/Scripts/pre_capture
> 2018-01-30
> 12:28:59|105932|18|8|image|OS.pm:get_reservation_info_json_file_path|4998|d
> etermined reservation info JSON file path file path for
> VCL::Module::OS::Linux OS module: /root/reservation_info.json 2018-01-30
> 12:28:59|105932|18|8|image|utils.pm:run_ssh_command|4243|executing SSH
> command on 10.106.144.101 (cmp1): '/usr/bin/ssh  -o
> StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o
> ConnectionAttempts=1 -o ConnectTimeout=30 -o BatchMode=no -o
> PasswordAuthentication=no -l root -p 22 -x 10.106.144.101 'rm -rfv
> /root/reservation_info\.json' 2>&1' 2018-01-30
> 12:28:59|105932|18|8|image|utils.pm:run_ssh_command|4392|command: 'rm -rfv
> /root/reservation_info\.json', exit_status: 0, output: 2018-01-30
> 12:28:59|105932|18|8|image|Linux.pm:delete_file|1777|deleted
> '/root/reservation_info.json' on cmp1 2018-01-30
> 12:29:00|105898|||vcld|vcld:main|179|lastcheckin time updated for
> management node 1: 2018-01-30 12:29:00 2018-01-30
> 12:29:00|105932|18|8|image|OS.pm:pre_capture|143|completed common image
> capture preparation tasks 
> 
> 
> From: Andy Kurth <[email protected]>
> Reply-To: "[email protected]" <[email protected]>
> Date: Monday, January 29, 2018 at 10:57 AM
> To: "[email protected]" <[email protected]>
> Subject: Re: New 2.5 install error
> 
> Hi Al,
> Mike is correct in that you're currently blocked due to an SSH issue.  The
> management node is trying to SSH into your VM host named "V1".  It's using
> the private IP address stored in the database to connect: 10.106.144.12. 
> The sequence is actually failing before it even attempts to call ssh.  The
> code is first calling nmap to check if port 22 is open.  I believe the
> actual command it is attempting would be:
 /usr/bin/nmap 10.106.144.12 -P0
> -p 22-T Aggressive -n
> 
> So, get the nmap command to work first.  The output must contain either
> "open" or "filtered" such as:
 22/tcp filtered ssh
> 
> After checking nmap, the code will then attempt to actually SSH in.  Try to
> manually SSH into both your VM host and the VM being captured before
> proceeding to potentially save some additional troubleshooting iterations. 
> You must be able to login without a password.  You may need to add the path
> of the private SSH identity key file configured for your management node
> profile's "End Node SSH Identity Key Files" setting  (this gets added
> automatically by the code):
 ssh -i /etc/vcl/vcl.key 10.106.144.12
> 
> You'll need to look up the private IP address of your cmp1 computer and try
> to SSH in using it.  It wasn't included in the log output.
 
> You may be aware since it sounds like you're upgrading from a fairly recent
> version, but once SSH is working you don't need to run vcld -setup again
> nor futz with the database manually to reattempt the capture.  Go to the
> VCL website Dashboard page.  At the bottom you should see the reservation
> under "Failed Imaging Reservations".  Click the button to reattempt.
 
> -Andy
> 
> On Fri, Jan 26, 2018 at 3:19 PM, Mike Jennings
> <[email protected]<mailto:[email protected]>> wrote:
 It looks like your
> management node is unable to ssh to the image over the private interface. 
> 2018-01-26 15:02:54|21429|14|4|image|utils.pm:nmap_port|2123|port 22 is
> closed on 10.106.144.12 (V1)
 2018-01-26
> 15:02:54|21429|14|4|image|OS.pm:is_ssh_responding|1057|V1 is NOT responding
> to SSH, port 22 is closed 2018-01-26
> 15:02:54|21429|14|4|image|VMware.pm:initialize|347|unable to control OS of
> VM host V1 using VCL::Module::OS::Linux::UnixLab OS object because VM host
> is not responding to SSH 
> Mike
> 
> On Fri, Jan 26, 2018 at 3:07 PM, Evelio Quiros
> <[email protected]<mailto:[email protected]>> wrote:
 Ok, sorry for the confusion
> before. I have wiped out the old install and reinstalled the management
> node. 
> Now a new error appears.. Here is the log from an attempt at image capture:
> 
> 
> Added new image to database: 'testing'
>   
> image.name<https://urldefense.proofpoint.com/v2/url?u=http-3A__image.name&d
> =DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=Pmi7xJNHMqh4x5h6
> i9APPLAENZrTP4LEiGZIpyye0J4&s=98fObFqvztGbwrAqUzWnqKYLemoZlvJxBCiGznsfjvg&e=
> >: vmwarelinux-testing18-v0
> image.id<https://urldefense.proofpoint.com/v2/url?u=http-3A__image.id&d=DwM
> FaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=Pmi7xJNHMqh4x5h6i9AP
> PLAENZrTP4LEiGZIpyye0J4&s=WaMGGGLyWGEUpV3ATMQf_wJpgkm1vQeoP5zVlA7lnfU&e=>:
> 18
> imagerevision.id<https://urldefense.proofpoint.com/v2/url?u=http-3A__imager
> evision.id&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=Pmi7
> xJNHMqh4x5h6i9APPLAENZrTP4LEiGZIpyye0J4&s=mmaleBu74k1A-fpJBWanNS2DIdTMhVDh2O
> OXrNEHZiQ&e=>: 14
> imagemeta.id<https://urldefense.proofpoint.com/v2/url?u=http-3A__imagemeta.
> id&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=Pmi7xJNHMqh4
> x5h6i9APPLAENZrTP4LEiGZIpyye0J4&s=fT0hBvX0ShKRmAkwakVTiDesIkOxNBOhob6hr2Yqj6
> w&e=>: 17
> resource.id<https://urldefense.proofpoint.com/v2/url?u=http-3A__resource.id
> &d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=Pmi7xJNHMqh4x5
> h6i9APPLAENZrTP4LEiGZIpyye0J4&s=9VAyyKvyv79zFTgMsoUegYghnkQYmylADAo0Q3H-vag&
> e=>: 29 
> ----------------------------------------------------------------------------
> 
 Inserted imaging request to the database:
> request ID: 14
> reservation ID: 4
> 
> This process will now display the contents of the vcld.log file if the vcld
> daemon is running. If you do not see many lines of additional output, exit
> this process, start the vcld daemon, and monitor the image capture process
> by running the command:
> tail -f /var/log/vcld.log | grep -P '.\|[0-9]+\|[0-9]+\|4\|'
> 
> ----------------------------------------------------------------------------
> 
 2018-01-26
> 15:02:47|21364|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=h
> ttp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&
> m=Pmi7xJNHMqh4x5h6i9APPLAENZrTP4LEiGZIpyye0J4&s=BcZMXhIrZ6twhPnEf8JJxBePfJXo
> 0KoGGW_MvNbvtds&e=>:get_variable|12901|variable 'cluster_inuse_check' is not
> set in the database 2018-01-26
> 15:02:47|21311|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=h
> ttp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&
> m=Pmi7xJNHMqh4x5h6i9APPLAENZrTP4LEiGZIpyye0J4&s=BcZMXhIrZ6twhPnEf8JJxBePfJXo
> 0KoGGW_MvNbvtds&e=>:xmlrpc_call|9648|called RPC::XML::Client::send_request:
> |21311|||vcld|utils.pm:xmlrpc_call|9648| arguments:
> |XMLRPCfinishBaseImageCapture, 1, 29, 1
> |21311|||vcld|utils.pm:xmlrpc_call|9648| response value:
> |21311|||vcld|utils.pm:xmlrpc_call|9648| : {
> |21311|||vcld|utils.pm:xmlrpc_call|9648| :   "status" => "success"
> |21311|||vcld|utils.pm:xmlrpc_call|9648| : }
> 
> 2018-01-26
> 15:02:47|21311|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=h
> ttp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&
> m=Pmi7xJNHMqh4x5h6i9APPLAENZrTP4LEiGZIpyye0J4&s=BcZMXhIrZ6twhPnEf8JJxBePfJXo
> 0KoGGW_MvNbvtds&e=>:add_imageid_to_newimages|9545|added image to owner's new
> images group, user ID: 1, image resource ID: 29, VM image: 1
 2018-01-26
> 15:02:47|21311|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=h
> ttp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&
> m=Pmi7xJNHMqh4x5h6i9APPLAENZrTP4LEiGZIpyye0J4&s=BcZMXhIrZ6twhPnEf8JJxBePfJXo
> 0KoGGW_MvNbvtds&e=>:insert_request|8303|inserted new image/image request
> into request table, request id=14 2018-01-26
> 15:02:47|21311|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=h
> ttp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&
> m=Pmi7xJNHMqh4x5h6i9APPLAENZrTP4LEiGZIpyye0J4&s=BcZMXhIrZ6twhPnEf8JJxBePfJXo
> 0KoGGW_MvNbvtds&e=>:insert_request|8334|inserted new reservation for request
> 14: 4 2018-01-26 15:02:53|21364|||vcld|vcld:main|179|lastcheckin time
> updated for management node 1: 2018-01-26 15:02:53 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:check_time|1252|request state is
> 'image', returning 'start' 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:run_command|9322|executed command: 'ps
> -e -o pid,args | grep -P "vcld .\|[0-9]+\|[0-9]+\|4\|"', exit status: 1,
> output: 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:is_management_node_process_running|9759|
> process is NOT running, identifier: 'vcld .\|[0-9]+\|[0-9]+\|4\|' 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:reservation_being_processed|9258|reserva
> tion 4 is NOT currently being processed
> |21364|14|4|image|utils.pm:reservation_being_processed|9258| reservation ID:
> |4
 21364|14|4|image|utils.pm:reservation_being_processed|9258| parent
> |reservation ID: 4
> |21364|14|4|image|utils.pm:reservation_being_processed|9258| reservation
> |computerloadlog 'begin' entry exists: no
> |21364|14|4|image|utils.pm:reservation_being_processed|9258| parent
> |reservation computerloadlog 'begin' entry exists: no
> |21364|14|4|image|utils.pm:reservation_being_processed|9258| reservation
> |process running: no
> 2018-01-26 15:02:53|21364|14|4|image|vcld:main|299|reservation 4 is NOT
> already being processed
 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:get_imagemeta_info|3760|retrieved
> imagemeta info:
> |21364|14|4|image|utils.pm:get_imagemeta_info|3760| : {
> |21364|14|4|image|utils.pm:get_imagemeta_info|3760| :   "architecture" =>
> |"",
 21364|14|4|image|utils.pm:get_imagemeta_info|3760| :   "checkuser" =>
> |1, 21364|14|4|image|utils.pm:get_imagemeta_info|3760| :   "id" => 17,
> |21364|14|4|image|utils.pm:get_imagemeta_info|3760| :   "postoption" => "",
> |21364|14|4|image|utils.pm:get_imagemeta_info|3760| :   "rootaccess" => 1,
> |21364|14|4|image|utils.pm:get_imagemeta_info|3760| :   "sethostname" =>
> |"", 21364|14|4|image|utils.pm:get_imagemeta_info|3760| :   "subimages" =>
> |0, 21364|14|4|image|utils.pm:get_imagemeta_info|3760| :   "sysprep" => 1
> |21364|14|4|image|utils.pm:get_imagemeta_info|3760| : }
> 
> 2018-01-26 15:02:53|21364|14|4|image|utils.pm:get_user_info|6696|management
> node's 'Affiliations Using Federated Authentication for Linux Images' list
> is empty, setting FEDERATED_LINUX_AUTHENTICATION=0
 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:get_image_active_directory_domain_info|1
> 4605|image 18 is not configured for Active Directory 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:get_image_active_directory_domain_info|1
> 4605|image 1 is not configured for Active Directory 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:get_production_imagerevision_info|3648|r
> etrieved info from database for production revision for image identifier
> '1', production image: 'noimage' 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:get_computer_info|7046|retrieved info
> for computer: V1 (1) 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:get_vmhost_info|4013|retrieved VM host 1
> info, VM host ID: 1, computer: V1, computer ID: 1 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:get_computer_info|7046|retrieved info
> for computer: cmp1 (7) 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:get_reservation_connect_method_info|1163
> 8|retrieved connect method info for reservation 4:
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| : {
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :   1
> |=> {
 21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638|
> |:     "RETRIEVAL_TIME" => "1516996973",
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |"connectmethodmap" => {
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |  "OSid" => undef,
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |  "OStypeid" => 2,
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |  "autoprovisioned" => undef,
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |  "connectmethodid" => 1,
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |  "disabled" => 0,
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |  "imagerevisionid" => undef
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |}, 21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| : 
> |   "connectmethodport" => {
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |  1 => {
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |    "connectmethodid" => 1,
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |    "id" => 1,
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |    "port" => 22,
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |    "protocol" => "TCP"
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |  } 21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :
> |    },
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |"description" => "SSH for Linux & Unix",
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |"id" => 1,
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |"name" => "SSH",
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |"servicename" => "ext_sshd",
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :    
> |"startupscript" => "/etc/init.d/ext_sshd"
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| :   }
> |21364|14|4|image|utils.pm:get_reservation_connect_method_info|11638| : }
> 2018-01-26 15:02:53|21364|14|4|image|utils.pm:get_user_info|6696|management
> node's 'Affiliations Using Federated Authentication for Linux Images' list
> is empty, setting FEDERATED_LINUX_AUTHENTICATION=0
 2018-01-26
> 15:02:53|21364|14|4|image|vcld:main|305|retrieved request information from
> database 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:delete_computerloadlog_reservation|5775|
> deleted rows from computerloadlog matching loadstate regex 'exited' for
> reservation IDs: 4 2018-01-26
> 15:02:53|21364|14|4|image|utils.pm:insertloadlog|2580|inserted 'begin'
> computerloadlog entry 2018-01-26
> 15:02:53|21364|14|4|image|vcld:make_new_child|519|request will be processed
> by
> image.pm<https://urldefense.proofpoint.com/v2/url?u=http-3A__image.pm&d=DwM
> FaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=Pmi7xJNHMqh4x5h6i9AP
> PLAENZrTP4LEiGZIpyye0J4&s=ULlCaoZgjSwR17hvnIjvhfvNgTI9iDOOCn3Y9LlXCdQ&e=>
> 2018-01-26 15:02:53|21364|14|4|image|vcld:make_new_child|541|created child
> process 21429 for reservation 4, state: image, current number of forked
> kids: 1 2018-01-26 15:02:53|21429|14|4|image|vcld:make_new_child|571|vcld
> environment variable set to 0 for this process 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:is_parent_reservation|1151|this
> is the parent reservation 2018-01-26
> 15:02:53|21429|14|4|image|utils.pm:rename_vcld_process|6095|reservation
> count: 1 2018-01-26
> 15:02:53|21429|14|4|image|utils.pm:rename_vcld_process|6122|renamed process
> to 'vcld '|21429|14|4|image|' cmp1>V1 vmwarelinux-testing18-v0 admin'
> 2018-01-26 15:02:53|21429|14|4|image|vcld:make_new_child|589|loaded
> VCL::image module 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:new|188|VCL::image object created for
> state image, address: 3364fb0 2018-01-26
> 15:02:53|21429|14|4|image|State.pm:initialize|86|initializing
> VCL::Module::State object 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:is_parent_reservation|1151|this
> is the parent reservation 2018-01-26
> 15:02:53|21429|14|4|image|State.pm:initialize|103|obtained a database
> handle for this state process, stored as $ENV{dbh} 2018-01-26
> 15:02:53|21429|14|4|image|utils.pm:update_reservation_lastcheck|5482|update
> d reservation.lastcheck to '2018-01-26 15:02:53' for reservation IDs: 4
> 2018-01-26
> 15:02:53|21429|14|4|image|utils.pm:update_request_state|1445|request 14
> state updated to pending/image 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:create_os_object|449|VCL::Module::OS::L
> inux module loaded 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:new|192|VCL::Module::OS::Linux object
> created for image vmwarelinux-testing18-v0, address: 3a804d0 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|713|image identifier
> argument was specified: noimage, DataStructure object will contain image
> information for the production imagerevision of this image 2018-01-26
> 15:02:53|21429|14|4|image|utils.pm:get_production_imagerevision_info|3648|r
> etrieved info from database for production revision for image identifier
> 'noimage', production image: 'noimage' 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|743|retrieved data
> for imagerevision ID: 1 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|759|retrieved data
> for image ID: 1 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:create_mn_os_object|538|VCL::Module::OS
> ::Linux::ManagementNode module loaded 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:new|199|VCL::Module::OS::Linux::Managem
> entNode object created, address: 3b47bb0 2018-01-26
> 15:02:53|21429|14|4|image|utils.pm:hostname_to_ip_address|13943|resolved IP
> address from hostname mgtvcl01.fiu.edu<http://mgtvcl01.fiu.edu> -->
> 10.106.136.5 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:set_computer_private_ip_address|
> 1674|private IP address of mgtvcl01.fiu.edu<http://mgtvcl01.fiu.edu> set to
> 10.106.136.5 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:create_mn_os_object|543|VCL::Module::OS
> ::Linux::ManagementNode OS object created, address: 3b47bb0 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:set_mn_os|1177|storing reference to
> managment node OS object (address: 3b47bb0) in this VCL::Module::OS::Linux
> object (address: 3a804d0) 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:create_os_object|462|VCL::Module::OS::L
> inux OS object created, address: 3a804d0 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|675|computer
> identifier argument was specified, retrieving data for computer: 1
> 2018-01-26
> 15:02:53|21429|14|4|image|utils.pm:get_computer_info|7046|retrieved info
> for computer: V1 (1) 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|713|image identifier
> argument was specified: 1, DataStructure object will contain image
> information for the production imagerevision of this image 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|743|retrieved data
> for imagerevision ID: 1 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|759|retrieved data
> for image ID: 1 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:create_vmhost_os_object|664|VM host OS
> image Perl package is VCL::Module::OS::Linux::UnixLab, most likely will not
> work correctly, changing to Linux 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:create_vmhost_os_object|669|attempting
> to load VM host OS module: VCL::Module::OS::Linux (image: 1) 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:create_vmhost_os_object|675|VM host OS
> module loaded: VCL::Module::OS::Linux 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:new|192|VCL::Module::OS::Linux object
> created for image noimage, address: 3b47dd8 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:set_mn_os|1177|storing reference to
> managment node OS object (address: 3b47bb0) in this VCL::Module::OS::Linux
> object (address: 3b47dd8) 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:create_vmhost_os_object|688|VCL::Module
> ::OS::Linux OS object created, address: 3b47dd8 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:set_vmhost_os|1212|storing reference to
> VM host OS object (address: 3b47dd8) in this VCL::image object (address:
> 3364fb0) 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:create_provisioning_object|864|VCL::Mod
> ule::Provisioning::VMware::VMware module loaded 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:new|196|VCL::Module::Provisioning::VMwa
> re::VMware object created for computer cmp1, address: 3b0cc88 2018-01-26
> 15:02:53|21429|14|4|image|Module.pm:set_mn_os|1177|storing reference to
> managment node OS object (address: 3b47bb0) in this
> VCL::Module::Provisioning::VMware::VMware object (address: 3b0cc88)
> 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|675|computer
> identifier argument was specified, retrieving data for computer: 1
> 2018-01-26
> 15:02:53|21429|14|4|image|utils.pm:get_computer_info|7046|retrieved info
> for computer: V1 (1) 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|713|image identifier
> argument was specified: 1, DataStructure object will contain image
> information for the production imagerevision of this image 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|743|retrieved data
> for imagerevision ID: 1 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:_initialize|759|retrieved data
> for image ID: 1 2018-01-26
> 15:02:53|21429|14|4|image|VMware.pm:get_vmhost_datastructure|1429|created
> DataStructure object for VM host: V1 2018-01-26
> 15:02:53|21429|14|4|image|DataStructure.pm:get_vmhost_profile_password|2873
> |vmprofile.password is set but vmprofile.secretid is NOT, assuming
> vmprofile.password is a pre-VCL 2.5 clear-text password: '' 2018-01-26
> 15:02:53|21429|14|4|image|VMware.pm:initialize|322|initializing
> VCL::Module::Provisioning::VMware::VMware object 2018-01-26
> 15:02:53|21429|14|4|image|VMware.pm:initialize|326|VM profile assigned to
> V1: KVM - local storage 2018-01-26
> 15:02:53|21429|14|4|image|utils.pm:get_computer_current_private_ip_address|
> 13915|retrieved private IP address for computer V1 (1) from database:
> 10.106.144.12 2018-01-26
> 15:02:53|21429|14|4|image|utils.pm:determine_remote_connection_target|14316
> |private IP address is set in database for V1, it will be used as the remote
> connection target: 10.106.144.12 2018-01-26
> 15:02:54|21429|14|4|image|utils.pm:nmap_port|2123|port 22 is closed on
> 10.106.144.12 (V1) 2018-01-26
> 15:02:54|21429|14|4|image|OS.pm:is_ssh_responding|1057|V1 is NOT responding
> to SSH, port 22 is closed 2018-01-26
> 15:02:54|21429|14|4|image|VMware.pm:initialize|347|unable to control OS of
> VM host V1 using VCL::Module::OS::Linux::UnixLab OS object because VM host
> is not responding to SSH 2018-01-26
> 15:02:54|21429|14|4|image|Module.pm:DESTROY|2391|destroying
> VCL::Module::Provisioning::VMware::VMware object, address: 3b0cc88
> |21429|14|4|image|Module.pm:create_provisioning_object|881| ---- WARNING
> |----
 21429|14|4|image|Module.pm:create_provisioning_object|881|
> |2018-01-26
> |15:02:54|21429|14|4|image|Module.pm:create_provisioning_object|881|provisi
> |oning object could not be created, returning 0
> |21429|14|4|image|Module.pm:create_provisioning_object|881| ( 0) Module.pm,
> |create_provisioning_object (line: 881)
> |21429|14|4|image|Module.pm:create_provisioning_object|881| (-1) State.pm,
> |initialize (line: 209)
> |21429|14|4|image|Module.pm:create_provisioning_object|881| (-2) Module.pm,
> |new (line: 228) 21429|14|4|image|Module.pm:create_provisioning_object|881|
> |(-3) vcld, (eval) (line: 594)
> |21429|14|4|image|Module.pm:create_provisioning_object|881| (-4) vcld,
> |make_new_child (line: 593)
> |21429|14|4|image|Module.pm:create_provisioning_object|881| (-5) vcld, main
> |(line: 353)
> 2018-01-26
> 15:02:54|21429|14|4|image|utils.pm:get_affiliation_info|10287|retrieved
> info for affiliation Global:
> |21429|14|4|image|utils.pm:get_affiliation_info|10287| : {
> |21429|14|4|image|utils.pm:get_affiliation_info|10287| :   "dataUpdateText"
> |=> "",
 21429|14|4|image|utils.pm:get_affiliation_info|10287| :  
> |"helpaddress" => undef,
> |21429|14|4|image|utils.pm:get_affiliation_info|10287| :   "id" => 2,
> |21429|14|4|image|utils.pm:get_affiliation_info|10287| :   "name" =>
> |"Global", 21429|14|4|image|utils.pm:get_affiliation_info|10287| :  
> |"shibname" => undef, 21429|14|4|image|utils.pm:get_affiliation_info|10287|
> |:   "shibonly" => 0, 21429|14|4|image|utils.pm:get_affiliation_info|10287|
> |:   "sitewwwaddress" => undef,
> |21429|14|4|image|utils.pm:get_affiliation_info|10287| :   "theme" =>
> |"dropdownmenus" 21429|14|4|image|utils.pm:get_affiliation_info|10287| : }
> 
> 2018-01-26
> 15:02:54|21429|14|4|image|DataStructure.pm:get_computer_private_ip_address|
> 1595|returning private IP address of cmp1 (7) already stored in this
> DataStructure object: 10.106.144.101
 2018-01-26
> 15:02:54|21429|14|4|image|utils.pm:is_inblockrequest|4933|zero rows were
> returned from database select 2018-01-26
> 15:02:54|21429|14|4|image|DataStructure.pm:get_image_affiliation_name|1703|
> image owner id: 1 2018-01-26
> 15:02:54|21429|14|4|image|utils.pm:mail|1314|SUCCESS -- Sending mail To:
> [email protected]<mailto:[email protected]>, PROBLEM --
> mgtvcl01|14:4|image|image.pm<https://urldefense.proofpoint.com/v2/url?u=htt
> p-3A__image.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=
> Pmi7xJNHMqh4x5h6i9APPLAENZrTP4LEiGZIpyye0J4&s=ULlCaoZgjSwR17hvnIjvhfvNgTI9iD
> OOCn3Y9LlXCdQ&e=>|cmp1>V1|vmwarelinux-testing18-v0|admin
> |21429|14|4|image|image.pm:reservation_failed|330| ---- CRITICAL ----
> |21429|14|4|image|image.pm:reservation_failed|330| 2018-01-26
> |15:02:54|21429|14|4|image|image.pm:reservation_failed|330|vmwarelinux-test
> |ing18-v0 Image Capture Failed - failed to create provisioning object
> |21429|14|4|image|image.pm:reservation_failed|330| ( 0)
> |image.pm<https://urldefense.proofpoint.com/v2/url?u=http-3A__image.pm&d=Dw
> |MFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=Pmi7xJNHMqh4x5h6i9
> |APPLAENZrTP4LEiGZIpyye0J4&s=ULlCaoZgjSwR17hvnIjvhfvNgTI9iDOOCn3Y9LlXCdQ&e=>
> |, reservation_failed (line: 330)
> |21429|14|4|image|image.pm:reservation_failed|330| (-1) State.pm,
> |initialize (line: 220) 21429|14|4|image|image.pm:reservation_failed|330|
> |(-2) Module.pm, new (line: 228)
> |21429|14|4|image|image.pm:reservation_failed|330| (-3) vcld, (eval) (line:
> |594) 21429|14|4|image|image.pm:reservation_failed|330| (-4) vcld,
> |make_new_child (line: 593)
> |21429|14|4|image|image.pm:reservation_failed|330| (-5) vcld, main (line:
> |353)
> 2018-01-26 15:02:54|21429|14|4|image|utils.pm:is_variable_set|12830|variable
> is NOT set: usermessage|image_creation_delayed|Local
 2018-01-26
> 15:02:54|21429|14|4|image|Module.pm:_get_message_variable|1875|affiliation-
> specific variable is NOT set in database:
> usermessage|image_creation_delayed|Local 2018-01-26
> 15:02:54|21429|14|4|image|utils.pm:get_variable|12927|data type of variable
> 'usermessage|image_creation_delayed|Global': HASH reference 2018-01-26
> 15:02:54|21429|14|4|image|DataStructure.pm:substitute_string_variables|2669
> |determined replacement value for substitution section:
> '[image_prettyname]', $self->get_image_prettyname(0) = 'testing' 2018-01-26
> 15:02:54|21429|14|4|image|DataStructure.pm:substitute_string_variables|2686
> |replaced all matching sections of input string with values retrieved from
> this DataStructure object:
> |21429|14|4|image|DataStructure.pm:substitute_string_variables|2686| input
> |string: 'VCL -- NOTICE DELAY Image Creation [image_prettyname]'
> |21429|14|4|image|DataStructure.pm:substitute_string_variables|2686| output
> |string: 'VCL -- NOTICE DELAY Image Creation testing'
> 2018-01-26
> 15:02:54|21429|14|4|image|DataStructure.pm:substitute_string_variables|2669
> |determined replacement value for substitution section:
> '[image_prettyname]', $self->get_image_prettyname(0) = 'testing'
 
> 
> From: Evelio Quiros <[email protected]<mailto:[email protected]>>
> Reply-To: "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>
 Date: Friday, January
> 26, 2018 at 1:39 PM
> 
> To: "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>
 Subject: Re: New 2.5
> install error
> 
> Sorry, the symlink was pointing to the old install.
> AL
> 
> From: Evelio Quiros <[email protected]<mailto:[email protected]>>
> Reply-To: "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>
 Date: Friday, January
> 26, 2018 at 1:31 PM
> To: "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>
 Subject: Re: New 2.5
> install error
> 
> This is a new installation.
> I copied the management node code to their correct location during the
> install.
 The version of
> utils.pm<https://urldefense.proofpoint.com/v2/url?u=http-3A__utils.pm&d=DwM
> FaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=Pmi7xJNHMqh4x5h6i9AP
> PLAENZrTP4LEiGZIpyye0J4&s=BcZMXhIrZ6twhPnEf8JJxBePfJXo0KoGGW_MvNbvtds&e=> is
> from the 2.5 version. The machine was added to the computer list, and I am
> trying to capture the image for it. 
> 
> From: Evelio Quiros <[email protected]<mailto:[email protected]>>
> Reply-To: "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>
 Date: Friday, January
> 26, 2018 at 12:16 PM
> To: "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>
 Subject: Re: New 2.5
> install error
> 
> This is a re-install from 2.4.2. what steps did I miss when trying to
> update? For all intents and purposes, this is supposed to be a fresh
> install.
 Do I need to wipe out the entire install and start again ?
> 
> 
> 
> From: Andy Kurth <[email protected]<mailto:[email protected]>>
> Reply-To: "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>
 Date: Friday, January
> 26, 2018 at 11:25 AM
> To: "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>
 Subject: Re: New 2.5
> install error
> 
> Was this a fresh 2.5 install or upgrade?  It appears as though your version
> of
> utils.pm<https://urldefense.proofpoint.com/v2/url?u=http-3A__utils.pm&d=DwM
> FaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4Rr
> iZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWyvOl1C30l1ngr50&e=> is
> outdated.  Your output doesn't match what is currently being done by the
> 2.5 code's insert_request subroutine that generated the error. The
> subroutine in 2.5 isn't trying to set request.logid to 0:​​
 
> INSERT INTO
> request
> (
>       request.stateid,
>       request.laststateid,
>       request.userid,
>       request.forimaging,
>       request.test,
>       request.preload,
>       request.start,
>       request.end,
>       request.daterequested
> )
> VALUES
> (
>       (SELECT id FROM state WHERE
> state.name<https://urldefense.proofpoint.com/v2/url?u=http-3A__state.name&d
> =DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJL
> o4RriZ_DawzJBN2yUcEduHS2cNE&s=EFdbG6I8Kox389TUA8rvO6B1lA1nPLDjYVyoK0bRoiY&e=
> > = '$request_state_name'),
 (SELECT id FROM state WHERE
> state.name<https://urldefense.proofpoint.com/v2/url?u=http-3A__state.name&d
> =DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJL
> o4RriZ_DawzJBN2yUcEduHS2cNE&s=EFdbG6I8Kox389TUA8rvO6B1lA1nPLDjYVyoK0bRoiY&e=
> > = '$request_laststate_name'), (SELECT id FROM user WHERE user.unityid =
> '$user_unityid'), '0',
>       '0',
>       '0',
>       TIMESTAMPADD(MINUTE, $start_minutes_in_future, NOW()),
>       TIMESTAMPADD(MINUTE, $end_minutes_in_future, NOW()),
>       NOW()
>    )
> 
> ​-Andy
> 
> On Fri, Jan 26, 2018 at 10:02 AM, Evelio Quiros
> <[email protected]<mailto:[email protected]>> wrote:
 
> 2018-01-26
> 09:56:28|4156|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=ht
> tp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m
> =yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWy
> vOl1C30l1ngr50&e=>:xmlrpc_call|9202|created RPC::XML client object:
> |4156|||vcld|utils.pm:xmlrpc_call|9202| URL:
> |https://webvcl01.fiu.edu/vcl/index.php?mode=xmlrpccall
> |4156|||vcld|utils.pm:xmlrpc_call|9202| username: vclsystem@Local
> 
> 2018-01-26
> 09:56:28|4156|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=ht
> tp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m
> =yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWy
> vOl1C30l1ngr50&e=>:xmlrpc_call|9247|called RPC::XML::Client::send_request:
> |4156|||vcld|utils.pm:xmlrpc_call|9247| arguments:
> |XMLRPCfinishBaseImageCapture, 1, 23, 1
> |4156|||vcld|utils.pm:xmlrpc_call|9247| response value:
> |4156|||vcld|utils.pm:xmlrpc_call|9247| : {
> |4156|||vcld|utils.pm:xmlrpc_call|9247| :   "status" => "success"
> |4156|||vcld|utils.pm:xmlrpc_call|9247| : }
> 
> 
> 
> |4156|||vcld|utils.pm:database_execute|2852| ---- WARNING ----
> |4156|||vcld|utils.pm:database_execute|2852| 2018-01-26
> |09:56:28|4156|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=h
> |ttp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg
> |&m=yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mE
> |TWyvOl1C30l1ngr50&e=>:database_execute|2852|could not execute SQL
> |statement:
 4156|||vcld|utils.pm:database_execute|2852| INSERT INTO
> |4156|||vcld|utils.pm:database_execute|2852| request
> |4156|||vcld|utils.pm:database_execute|2852| (
> |4156|||vcld|utils.pm:database_execute|2852| request.stateid,
> |4156|||vcld|utils.pm:database_execute|2852| request.laststateid,
> |4156|||vcld|utils.pm:database_execute|2852| request.userid,
> |4156|||vcld|utils.pm:database_execute|2852| request.logid,
> |4156|||vcld|utils.pm:database_execute|2852| request.forimaging,
> |4156|||vcld|utils.pm:database_execute|2852| request.test,
> |4156|||vcld|utils.pm:database_execute|2852| request.preload,
> |4156|||vcld|utils.pm:database_execute|2852| request.start,
> |4156|||vcld|utils.pm:database_execute|2852| request.end,
> |4156|||vcld|utils.pm:database_execute|2852| request.daterequested
> |4156|||vcld|utils.pm:database_execute|2852| )
> |4156|||vcld|utils.pm:database_execute|2852| VALUES
> |4156|||vcld|utils.pm:database_execute|2852| (
> |4156|||vcld|utils.pm:database_execute|2852| (SELECT id FROM state WHERE
> |state.name<https://urldefense.proofpoint.com/v2/url?u=http-3A__state.name&;
> |d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHU
> |JLo4RriZ_DawzJBN2yUcEduHS2cNE&s=EFdbG6I8Kox389TUA8rvO6B1lA1nPLDjYVyoK0bRoiY
> |&e=> = 'image'),
 4156|||vcld|utils.pm:database_execute|2852| (SELECT id
> |FROM state WHERE
> |state.name<https://urldefense.proofpoint.com/v2/url?u=http-3A__state.name&;
> |d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHU
> |JLo4RriZ_DawzJBN2yUcEduHS2cNE&s=EFdbG6I8Kox389TUA8rvO6B1lA1nPLDjYVyoK0bRoiY
> |&e=> = 'image'), 4156|||vcld|utils.pm:database_execute|2852| (SELECT id
> |FROM user WHERE user.unityid = 'admin'),
> |4156|||vcld|utils.pm:database_execute|2852| '0',
> |4156|||vcld|utils.pm:database_execute|2852| '0',
> |4156|||vcld|utils.pm:database_execute|2852| '0',
> |4156|||vcld|utils.pm:database_execute|2852| '0',
> |4156|||vcld|utils.pm:database_execute|2852| TIMESTAMPADD(MINUTE, 0,
> |NOW()),
 4156|||vcld|utils.pm:database_execute|2852| TIMESTAMPADD(MINUTE,
> |60, NOW()), 4156|||vcld|utils.pm:database_execute|2852| NOW()
> |4156|||vcld|utils.pm:database_execute|2852| )
> |4156|||vcld|utils.pm:database_execute|2852| Cannot add or update a child
> |row: a foreign key constraint fails (`vcl`.`request`, CONSTRAINT
> |`request_ibfk_4` FOREIGN KEY (`logid`) REFERENCES `log` (`id`) ON UPDATE
> |CASCADE)
 4156|||vcld|utils.pm:database_execute|2852| ( 0)
> |utils.pm<https://urldefense.proofpoint.com/v2/url?u=http-3A__utils.pm&d=Dw
> |MFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4
> |RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWyvOl1C30l1ngr50&e=>
> |, database_execute (line: 2852) 4156|||vcld|utils.pm:database_execute|2852|
> |(-1)
> |utils.pm<https://urldefense.proofpoint.com/v2/url?u=http-3A__utils.pm&d=Dw
> |MFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4
> |RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWyvOl1C30l1ngr50&e=>
> |, insert_request (line: 8051) 4156|||vcld|utils.pm:database_execute|2852|
> |(-2)
> |image.pm<https://urldefense.proofpoint.com/v2/url?u=http-3A__image.pm&d=Dw
> |MFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4
> |RriZ_DawzJBN2yUcEduHS2cNE&s=qDz5X4b_oQ7RyuDhYKROeYLSl1YdFp3DzDjA2pINVHc&e=>
> |, setup_capture_base_image (line: 980)
> |4156|||vcld|utils.pm:database_execute|2852| (-3) vcld,
> |setup_management_node (line: 929)
> 
> 2018-01-26
> 09:56:28|4156|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=ht
> tp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m
> =yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWy
> vOl1C30l1ngr50&e=>:get_management_node_info|4589|retrieving current
> management node info for 'mgtvcl01.fiu.edu<http://mgtvcl01.fiu.edu>' from
> database, cached data is stale: 64 seconds old
 2018-01-26
> 09:56:28|4156|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=ht
> tp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m
> =yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWy
> vOl1C30l1ngr50&e=>:get_variable|12093|variable 'cluster_inuse_check' is not
> set in the database 2018-01-26
> 09:56:28|4156|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=ht
> tp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m
> =yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWy
> vOl1C30l1ngr50&e=>:get_management_node_info|4751|retrieved management node
> info: 'mgtvcl01.fiu.edu<http://mgtvcl01.fiu.edu>' (mgtvcl01) 2018-01-26
> 09:56:28|4156|||vcld|utils.pm<https://urldefense.proofpoint.com/v2/url?u=ht
> tp-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m
> =yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWy
> vOl1C30l1ngr50&e=>:mail|1262|SUCCESS -- Sending mail To:
> [email protected]<mailto:[email protected]>, PROBLEM --
> mgtvcl01|utils.pm:insert_request(8056) 
> 
> From: Aaron Peeler <[email protected]<mailto:[email protected]>>
> Reply-To: "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>,
> "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>
 Date: Thursday, January 25,
> 2018 at 7:12 AM
> To: "[email protected]<mailto:[email protected]>"
> <[email protected]<mailto:[email protected]>>
 Subject: Re: New 2.5
> install error
> 
> Hi Al,
> 
> Can you send  the log snippet for that imaging request?
> 
> Aaron
> 
> On Jan 25, 2018 3:58 AM, "António Aragão"
> <[email protected]<mailto:[email protected]>> wrote:
 Test if you can
> insert the request using mysql client from the management node. 
> Kind regards.
> 
> 2018-01-24 19:18 GMT+00:00 Evelio Quiros
> <[email protected]<mailto:[email protected]>>:
 Hello,
> 
> In vcld –setupI try to capture a linux image on a VMware host.
> I get as far as adding the image to the database, then I get ERROR: failed
> to insert new imaging request. The management node can SSH to the VM and to
> the VM host. The host has SSH turned on, and the key is in place for
> passwordless connections. Vcld is running, and the management node is
> checking the DB. This is a new installation, and have followed the steps in
> the guide.
 
> Any ideas on what I could check for ?
> 
> Thanks
> Al Quiros
> 
> 
> 
> 
> 
> 
> --
> António Aragão
> (Especialista de Informática)
> Universidade do Minho
> Departamento de Informática
> Edificio 7 - 1.07 (DI-1.03)
> Campus de Gualtar
> Braga
> Telefone: +351 253 6044 86
> 
> 
> 
> 
> --
> Andy Kurth
> Research Storage Specialist
> NC State University
> Office of Information Technology
> 
> P: 919-513-4090<tel:(919)%20513-4090>
> 311A
> Hillsborough<https://urldefense.proofpoint.com/v2/url?u=https-3A__maps.goog
> le.com_-3Fq-3D311A-2BHillsborough-26entry-3Dgmail-26source-3Dg&d=DwMFaQ&c=lh
> MMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=Pmi7xJNHMqh4x5h6i9APPLAENZrT
> P4LEiGZIpyye0J4&s=jto5e2dTag_Z--uwqGNXtk5eBjGlVQsu-n4qx0hwW1U&e=> Building
> Campus Box 7109
> Raleigh, NC 27695
> [https://docs.google.com/uc?export=download&id=0B1RAxkyXdSMEX21iNU45NUhNSkk&;
> revid=0B1RAxkyXdSMEdFhLeG9GNHVNM21YajA4djFXK0YzejQ4N2FrPQ]
 
> 
> 
> 
> --
> Andy Kurth
> Research Storage Specialist
> NC State University
> Office of Information Technology
> 
> P: 919-513-4090
> 311A Hillsborough Building
> Campus Box 7109
> Raleigh, NC 27695
> [https://docs.google.com/uc?export=download&id=0B1RAxkyXdSMEX21iNU45NUhNSkk&;
> revid=0B1RAxkyXdSMEdFhLeG9GNHVNM21YajA4djFXK0YzejQ4N2FrPQ]

-- 
-------------------------------
Josh Thompson
Systems Programmer
Platform Computing | VCL Developer
North Carolina State University

[email protected]
919-515-5323

my GPG/PGP key can be found at pgp.mit.edu

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.

Attachment: signature.asc
Description: This is a digitally signed message part.

Reply via email to