You should read through your error logs. You'll learn much more about the way the system works if you try to track down issues yourself.
unable to access vmx base directory path on VM host localhost: datastore1/win7
It probably has something to do with the way the datastores are configured for the host profile. I haven't used the datastore-on-management node functionality, which based on the fact that it's still referencing localhost, I think you have set up.
Also, fwiw, you may want to consider creating another user, or letting admin own the images instead of vcluser. There's an error at the bottom that says " No recipient addresses found in header " and I'm not sure if that's because vcluser has no email address.
----- Original message -----
From: Ariuntulga Kikoo <[email protected]>
To: [email protected]
Cc:
Subject: Re: create windows base image captured failure
Date: Tue, May 23, 2017 8:07 AM
Run tail -f /var/log/vcld.log to see progress============================================================================ VCL Management Node Daemon (vcld) | 2017-05-23 05:00:58 ============================================================================ bin path: /usr/local/vcl-2.4.2/bin config file: /etc/vcl/vcld.conf log file: /var/log/vcld.log pid file: /var/run/vcld.pid daemon mode: 1 setup mode: 0 verbose mode: 1 ============================================================================ Created VCL daemon process: 16191 2017-05-23 05:00:58|16191|||vcld|utils.pm:rename_vcld_process|6245|renamed process to 'vcld' 2017-05-23 05:00:58|16191|||vcld|vcld:main|120|retrieved management node information from database 2017-05-23 05:00:58|16191|||vcld|vcld:main|133|management_node_id environment variable set: 1 2017-05-23 05:00:58|16191|||vcld|vcld:main|141|management node checkin interval is 12 seconds 2017-05-23 05:00:58|16191|||vcld|vcld:main|142|vcld started on localhost 2017-05-23 05:00:58|16191|||vcld|vcld:main|164|vcld environment variable set to 1 for this process 2017-05-23 05:00:58|16135|||vcld|utils.pm:run_command|9339|executed command: 'service vcld restart', exit status: 0, output: |16135|||vcld|utils.pm:run_command|9339| Restarting vcld (via systemctl): [ OK ] 2017-05-23 05:00:58|16191|||vcld|vcld:main|175|lastcheckin time updated for management node 1: 2017-05-23 05:00:58 2017-05-23 05:01:10|16191|||vcld|vcld:main|175|lastcheckin time updated for management node 1: 2017-05-23 05:01:10 2017-05-23 05:01:16|16135|||vcld|utils.pm:get_computer_ids|8089|1 computer was found matching argument: 192.168.10.131, returning computer ID: 2 2017-05-23 05:01:16|16135|||vcld|utils.pm:get_production_imagerevision_info|3737|retrieved info from database for production revision for image identifier '1', production image: 'noimage' 2017-05-23 05:01:16|16135|||vcld|utils.pm:get_computer_info|7324|skipping retrieval of VM host 1 info for localhost to avoid recursion 2017-05-23 05:01:16|16135|||vcld|utils.pm:get_computer_info|7344|retrieved info for computer: localhost (1) 2017-05-23 05:01:16|16135|||vcld|utils.pm:get_vmhost_info|4090|retrieved VM host 1 info, VM host ID: 1, computer: localhost, computer ID: 1 2017-05-23 05:01:16|16135|||vcld|utils.pm:get_computer_info|7344|retrieved info for computer: root-PC (2) 2017-05-23 05:01:16|16135|||vcld|utils.pm:get_provisioning_osinstalltype_info|14082|retrieved info for OSinstalltypes mapped to provisioning ID 7: : { |16135|||vcld|utils.pm:get_provisioning_osinstalltype_info|14082| : 4 => { |16135|||vcld|utils.pm:get_provisioning_osinstalltype_info|14082| : "id" => 4, |16135|||vcld|utils.pm:get_provisioning_osinstalltype_info|14082| : "name" => "vmware", |16135|||vcld|utils.pm:get_provisioning_osinstalltype_info|14082| : "provisioningOSinstalltype" => { |16135|||vcld|utils.pm:get_provisioning_osinstalltype_info|14082| : "OSinstalltypeid" => 4, |16135|||vcld|utils.pm:get_provisioning_osinstalltype_info|14082| : "provisioningid" => 7 |16135|||vcld|utils.pm:get_provisioning_osinstalltype_info|14082| : } |16135|||vcld|utils.pm:get_provisioning_osinstalltype_info|14082| : } |16135|||vcld|utils.pm:get_provisioning_osinstalltype_info|14082| : } 2017-05-23 05:01:16|16135|||vcld|utils.pm:get_computer_current_private_ip_address|13882|retrieved private IP address for computer root-PC (2) from database: 192.168.10.131 2017-05-23 05:01:16|16135|||vcld|utils.pm:determine_remote_connection_target|14283|private IP address is set in database for root-PC, it will be used as the remote connection target: 192.168.10.131 2017-05-23 05:01:17|16135|||vcld|utils.pm:nmap_port|2173|port 22 is open on 192.168.10.131 (root-PC) 2017-05-23 05:01:18|16135|||vcld|utils.pm:nmap_port|2173|port 24 is open on 192.168.10.131 (root-PC) 2017-05-23 05:01:18|16135|||vcld|utils.pm:get_request_by_computerid|5319|2 is not assigned to any reservations 2017-05-23 05:01:18|16135|||vcld|utils.pm:setup_get_array_choice|10941|choices argument: |16135|||vcld|utils.pm:setup_get_array_choice|10941| Generic Linux (VMware) |16135|||vcld|utils.pm:setup_get_array_choice|10941| OSX Snow Leopard (VMware) |16135|||vcld|utils.pm:setup_get_array_choice|10941| Ubuntu (VMware) |16135|||vcld|utils.pm:setup_get_array_choice|10941| Windows 2003 Server (VMware) |16135|||vcld|utils.pm:setup_get_array_choice|10941| Windows 7 (VMware) |16135|||vcld|utils.pm:setup_get_array_choice|10941| Windows 8.x (VMware) |16135|||vcld|utils.pm:setup_get_array_choice|10941| Windows Server 2008 (VMware) |16135|||vcld|utils.pm:setup_get_array_choice|10941| Windows Server 2012 (VMware) |16135|||vcld|utils.pm:setup_get_array_choice|10941| Windows Vista (VMware) |16135|||vcld|utils.pm:setup_get_array_choice|10941| Windows XP (VMware ESX) |16135|||vcld|utils.pm:setup_get_array_choice|10941| Windows XP (VMware) 2017-05-23 05:01:22|16191|||vcld|vcld:main|175|lastcheckin time updated for management node 1: 2017-05-23 05:01:22 2017-05-23 05:01:34|16191|||vcld|vcld:main|175|lastcheckin time updated for management node 1: 2017-05-23 05:01:34 2017-05-23 05:01:46|16191|||vcld|vcld:main|175|lastcheckin time updated for management node 1: 2017-05-23 05:01:46 2017-05-23 05:01:58|16191|||vcld|vcld:main|175|lastcheckin time updated for management node 1: 2017-05-23 05:01:58 2017-05-23 05:02:01|16135|||vcld|utils.pm:setup_get_array_choice|10941|choices argument: |16135|||vcld|utils.pm:setup_get_array_choice|10941| x86 |16135|||vcld|utils.pm:setup_get_array_choice|10941| x86_64 2017-05-23 05:02:07|16135|||vcld|utils.pm:setup_get_array_choice|10941|choices argument: |16135|||vcld|utils.pm:setup_get_array_choice|10941| Yes |16135|||vcld|utils.pm:setup_get_array_choice|10941| No 2017-05-23 05:02:10|16191|||vcld|vcld:main|175|lastcheckin time updated for management node 1: 2017-05-23 05:02:10 2017-05-23 05:02:14|16135|||vcld|utils.pm:xmlrpc_call|9604|RPC::XML version supports useragent options, setting verify_hostname to 0 2017-05-23 05:02:14|16135|||vcld|utils.pm:xmlrpc_call|9616|created RPC::XML client object: |16135|||vcld|utils.pm:xmlrpc_call|9616| URL: https://localhost/vcl/index.php?mode=xmlrpccall |16135|||vcld|utils.pm:xmlrpc_call|9616| username: vclsystem@Local 2017-05-23 05:02:15|16135|||vcld|utils.pm:xmlrpc_call|9661|called RPC::XML::Client::send_request: |16135|||vcld|utils.pm:xmlrpc_call|9661| arguments: XMLRPCfinishBaseImageCapture, 3, 29, 1 |16135|||vcld|utils.pm:xmlrpc_call|9661| response value: |16135|||vcld|utils.pm:xmlrpc_call|9661| : { |16135|||vcld|utils.pm:xmlrpc_call|9661| : "status" => "success" |16135|||vcld|utils.pm:xmlrpc_call|9661| : } 2017-05-23 05:02:15|16135|||vcld|utils.pm:add_imageid_to_newimages|9558|added image to owner's new images group, user ID: 3, image resource ID: 29, VM image: 1 2017-05-23 05:02:15|16135|||vcld|utils.pm:insert_request|8403|inserted new image/image request into request table, request id=18 2017-05-23 05:02:15|16135|||vcld|utils.pm:insert_request|8434|inserted new reservation for request 18: 18 2017-05-23 05:02:22|16191|||vcld|vcld:main|175|lastcheckin time updated for management node 1: 2017-05-23 05:02:22 2017-05-23 05:02:22|16191|18|18|image|utils.pm:run_command|9339|executed command: 'ps -e -o pid,args | grep -P "vcld .\|[0-9]+\|[0-9]+\|18\|"', exit status: 1, output: 2017-05-23 05:02:22|16191|18|18|image|utils.pm:is_management_node_process_running|9772|process is NOT running, identifier: 'vcld .\|[0-9]+\|[0-9]+\|18\|' 2017-05-23 05:02:22|16191|18|18|image|utils.pm:reservation_being_processed|9275|reservation 18 is NOT currently being processed |16191|18|18|image|utils.pm:reservation_being_processed|9275| reservation ID: 18 |16191|18|18|image|utils.pm:reservation_being_processed|9275| parent reservation ID: 18 |16191|18|18|image|utils.pm:reservation_being_processed|9275| reservation computerloadlog 'begin' entry exists: no |16191|18|18|image|utils.pm:reservation_being_processed|9275| parent reservation computerloadlog 'begin' entry exists: no |16191|18|18|image|utils.pm:reservation_being_processed|9275| reservation process running: no 2017-05-23 05:02:22|16191|18|18|image|vcld:main|294|reservation 18 is NOT already being processed 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_imagemeta_info|3849|retrieved imagemeta info: |16191|18|18|image|utils.pm:get_imagemeta_info|3849| : { |16191|18|18|image|utils.pm:get_imagemeta_info|3849| : "architecture" => "", |16191|18|18|image|utils.pm:get_imagemeta_info|3849| : "checkuser" => 1, |16191|18|18|image|utils.pm:get_imagemeta_info|3849| : "id" => 18, |16191|18|18|image|utils.pm:get_imagemeta_info|3849| : "postoption" => "", |16191|18|18|image|utils.pm:get_imagemeta_info|3849| : "rootaccess" => 1, |16191|18|18|image|utils.pm:get_imagemeta_info|3849| : "sethostname" => "", |16191|18|18|image|utils.pm:get_imagemeta_info|3849| : "subimages" => 0, |16191|18|18|image|utils.pm:get_imagemeta_info|3849| : "sysprep" => 0 |16191|18|18|image|utils.pm:get_imagemeta_info|3849| : } 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_user_info|6962|UID value is not configured for user 'vclsystem', setting UID: 503, standalone: 1 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_management_node_info|4675|retrieving current management node info for 'localhost' from database, cached data is stale: 85 seconds old |16191|18|18|image|utils.pm:get_management_node_info|4767| ---- WARNING ---- |16191|18|18|image|utils.pm:get_management_node_info|4767| 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_management_node_info|4767|zero rows were returned from database select, image library functions will be disabled |16191|18|18|image|utils.pm:get_management_node_info|4767| ( 0) utils.pm, get_management_node_info (line: 4767) |16191|18|18|image|utils.pm:get_management_node_info|4767| (-1) utils.pm, get_image_info (line: 3584) |16191|18|18|image|utils.pm:get_management_node_info|4767| (-2) utils.pm, get_request_info (line: 3020) |16191|18|18|image|utils.pm:get_management_node_info|4767| (-3) vcld, main (line: 299) 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_variable|12882|variable 'user_password_length' is not set in the database 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_variable|12882|variable 'user_password_spchar' is not set in the database 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_management_node_info|4837|retrieved management node info: 'localhost' (localhost) 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_production_imagerevision_info|3737|retrieved info from database for production revision for image identifier '1', production image: 'noimage' 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_computer_info|7324|skipping retrieval of VM host 1 info for localhost to avoid recursion 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_computer_info|7344|retrieved info for computer: localhost (1) 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_vmhost_info|4090|retrieved VM host 1 info, VM host ID: 1, computer: localhost, computer ID: 1 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_computer_info|7344|retrieved info for computer: root-PC (2) 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619|retrieved connect method info for reservation 18: |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : { |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : 2 => { |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "RETRIEVAL_TIME" => "1495540943", |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "connectmethodmap" => { |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "OSid" => undef, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "OStypeid" => 1, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "autoprovisioned" => undef, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "connectmethodid" => 2, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "disabled" => 0, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "imagerevisionid" => undef |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : }, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "connectmethodport" => { |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : 2 => { |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "connectmethodid" => 2, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "id" => 2, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "port" => 3389, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "protocol" => "TCP" |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : } |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : }, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "description" => "Remote Desktop for Windows", |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "id" => 2, |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "name" => "RDP", |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "servicename" => "TermService", |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : "startupscript" => undef |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : } |16191|18|18|image|utils.pm:get_reservation_connect_method_info|11619| : } 2017-05-23 05:02:23|16191|18|18|image|utils.pm:get_user_info|6962|UID value is not configured for user 'vclsystem', setting UID: 503, standalone: 1 2017-05-23 05:02:23|16191|18|18|image|vcld:main|300|retrieved request information from database 2017-05-23 05:02:23|16191|18|18|image|utils.pm:delete_computerloadlog_reservation|5844|deleted rows from computerloadlog matching loadstate regex 'exited' for reservation IDs: 18 2017-05-23 05:02:23|16191|18|18|image|utils.pm:insertloadlog|2758|inserted 'begin' computerloadlog entry 2017-05-23 05:02:23|16191|18|18|image|vcld:make_new_child|514|request will be processed by image.pm 2017-05-23 05:02:23|16191|18|18|image|vcld:make_new_child|536|created child process 16309 for reservation 18, state: image, current number of forked kids: 1 2017-05-23 05:02:23|16309|18|18|image|vcld:make_new_child|556|vcld environment variable set to 0 for this process 2017-05-23 05:02:23|16309|18|18|image|DataStructure.pm:is_parent_reservation|1101|this is the parent reservation 2017-05-23 05:02:23|16309|18|18|image|utils.pm:rename_vcld_process|6207|reservation count: 1 2017-05-23 05:02:23|16309|18|18|image|utils.pm:rename_vcld_process|6226|PARENTIMAGE: 1 2017-05-23 05:02:23|16309|18|18|image|utils.pm:rename_vcld_process|6227|SUBIMAGE: 0 2017-05-23 05:02:23|16309|18|18|image|utils.pm:rename_vcld_process|6245|renamed process to 'vcld '|16309|18|18|image|' root-PC>localhost vmwarewin7-winroot19-v0 vclsystem' 2017-05-23 05:02:23|16309|18|18|image|vcld:make_new_child|575|loaded VCL::image module 2017-05-23 05:02:23|16309|18|18|image|Module.pm:new|184|VCL::image object created for state image, address: 32b60b8 2017-05-23 05:02:23|16309|18|18|image|DataStructure.pm:_initialize|705|image identifier argument was specified: noimage, DataStructure object will contain image information for the production imagerevision of this image 2017-05-23 05:02:23|16309|18|18|image|utils.pm:get_production_imagerevision_info|3737|retrieved info from database for production revision for image identifier 'noimage', production image: 'noimage' 2017-05-23 05:02:23|16309|18|18|image|DataStructure.pm:_initialize|735|retrieved data for imagerevision ID: 1 2017-05-23 05:02:23|16309|18|18|image|DataStructure.pm:_initialize|751|retrieved data for image ID: 1 2017-05-23 05:02:23|16309|18|18|image|Module.pm:create_mn_os_object|481|VCL::Module::OS::Linux::ManagementNode module loaded 2017-05-23 05:02:23|16309|18|18|image|Module.pm:new|195|VCL::Module::OS::Linux::ManagementNode object created, address: 33cce50 2017-05-23 05:02:23|16309|18|18|image|utils.pm:hostname_to_ip_address|13910|resolved IP address from hostname localhost --> 127.0.0.1 2017-05-23 05:02:23|16309|18|18|image|DataStructure.pm:set_computer_private_ip_address|1624|private IP address of localhost set to 127.0.0.1 2017-05-23 05:02:23|16309|18|18|image|Module.pm:create_mn_os_object|486|VCL::Module::OS::Linux::ManagementNode OS object created, address: 33cce50 2017-05-23 05:02:23|16309|18|18|image|Module.pm:set_mn_os|1032|storing reference to managment node OS object (address: 33cce50) in this VCL::image object (address: 32b60b8) 2017-05-23 05:02:23|16309|18|18|image|State.pm:initialize|86|initializing VCL::Module::State object 2017-05-23 05:02:23|16309|18|18|image|DataStructure.pm:is_parent_reservation|1101|this is the parent reservation 2017-05-23 05:02:23|16309|18|18|image|State.pm:initialize|103|obtained a database handle for this state process, stored as $ENV{dbh} 2017-05-23 05:02:23|16309|18|18|image|utils.pm:update_reservation_lastcheck|5551|updated reservation.lastcheck to '2017-05-23 05:02:23' for reservation IDs: 18 2017-05-23 05:02:23|16309|18|18|image|utils.pm:update_request_state|1399|request 18 state updated to pending/image 2017-05-23 05:02:23|16309|18|18|image|DataStructure.pm:is_parent_reservation|1101|this is the parent reservation 2017-05-23 05:02:23|16309|18|18|image|DataStructure.pm:is_parent_reservation|1101|this is the parent reservation 2017-05-23 05:02:24|16309|18|18|image|Module.pm:create_os_object|420|VCL::Module::OS::Windows::Version_6::7 module loaded 2017-05-23 05:02:24|16309|18|18|image|Module.pm:new|188|VCL::Module::OS::Windows::Version_6::7 object created for image vmwarewin7-winroot19-v0, address: 39be790 2017-05-23 05:02:24|16309|18|18|image|Module.pm:set_mn_os|1032|storing reference to managment node OS object (address: 33cce50) in this VCL::Module::OS::Windows::Version_6::7 object (address: 39be790) 2017-05-23 05:02:24|16309|18|18|image|Windows.pm:initialize|212|beginning Windows module initialization 2017-05-23 05:02:24|16309|18|18|image|Windows.pm:initialize|222|Windows module initialization complete 2017-05-23 05:02:24|16135|||vcld|Module.pm:DESTROY|1880|destroying VCL::Module::OS::Windows object, address: 59632a0 2017-05-23 05:02:24|16135|||vcld|State.pm:DESTROY|1046|VCL::image destructor called, address: 544b5a8 2017-05-23 05:02:24|16135|||vcld|Module.pm:DESTROY|1880|destroying VCL::image object, address: 544b5a8 2017-05-23 05:02:24|16135|||vcld|Module.pm:DESTROY|1880|destroying VCL::Module::Provisioning::VMware::VMware object, address: 42e29c0 2017-05-23 05:02:24|16135|||vcld|Module.pm:DESTROY|1880|destroying VCL::Module object, address: 56233a8 2017-05-23 05:02:24|16135|||vcld|Module.pm:DESTROY|1880|destroying VCL::Module::OS::Linux::ManagementNode object, address: 5805a98 2017-05-23 05:02:24|16135|||vcld|Module.pm:DESTROY|1880|destroying VCL::Module::OS::Linux::ManagementNode object, address: 4af5960 2017-05-23 05:02:24|16309|18|18|image|Module.pm:create_os_object|433|VCL::Module::OS::Windows::Version_6::7 OS object created, address: 39be790 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|667|computer identifier argument was specified, retrieving data for computer: 1 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_computer_info|7324|skipping retrieval of VM host 1 info for localhost to avoid recursion 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_computer_info|7344|retrieved info for computer: localhost (1) 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_vmhost_info|4090|retrieved VM host 1 info, VM host ID: 1, computer: localhost, computer ID: 1 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_computer_info|7344|retrieved info for computer: localhost (1) 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|705|image identifier argument was specified: 1, DataStructure object will contain image information for the production imagerevision of this image 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|735|retrieved data for imagerevision ID: 1 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|751|retrieved data for image ID: 1 2017-05-23 05:02:24|16309|18|18|image|Module.pm:create_vmhost_os_object|564|VM host OS image Perl package is VCL::Module::OS::Linux::UnixLab, most likely will not work correctly, changing to Linux 2017-05-23 05:02:24|16309|18|18|image|Module.pm:create_vmhost_os_object|569|attempting to load VM host OS module: VCL::Module::OS::Linux (image: 1) 2017-05-23 05:02:24|16309|18|18|image|Module.pm:create_vmhost_os_object|575|VM host OS module loaded: VCL::Module::OS::Linux 2017-05-23 05:02:24|16309|18|18|image|Module.pm:new|188|VCL::Module::OS::Linux object created for image noimage, address: 405bd40 2017-05-23 05:02:24|16309|18|18|image|Module.pm:set_mn_os|1032|storing reference to managment node OS object (address: 33cce50) in this VCL::Module::OS::Linux object (address: 405bd40) 2017-05-23 05:02:24|16309|18|18|image|Module.pm:create_vmhost_os_object|588|VCL::Module::OS::Linux OS object created, address: 405bd40 2017-05-23 05:02:24|16309|18|18|image|Module.pm:set_vmhost_os|1067|storing reference to VM host OS object (address: 405bd40) in this VCL::image object (address: 32b60b8) 2017-05-23 05:02:24|16309|18|18|image|Module.pm:create_provisioning_object|719|VCL::Module::Provisioning::VMware::VMware module loaded 2017-05-23 05:02:24|16309|18|18|image|Module.pm:new|192|VCL::Module::Provisioning::VMware::VMware object created for computer root-PC, address: 39bead8 2017-05-23 05:02:24|16309|18|18|image|Module.pm:set_mn_os|1032|storing reference to managment node OS object (address: 33cce50) in this VCL::Module::Provisioning::VMware::VMware object (address: 39bead8) 2017-05-23 05:02:24|16309|18|18|image|VMware.pm:initialize|271|initializing VCL::Module::Provisioning::VMware::VMware object 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|667|computer identifier argument was specified, retrieving data for computer: 1 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_computer_info|7324|skipping retrieval of VM host 1 info for localhost to avoid recursion 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_computer_info|7344|retrieved info for computer: localhost (1) 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_vmhost_info|4090|retrieved VM host 1 info, VM host ID: 1, computer: localhost, computer ID: 1 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_computer_info|7344|retrieved info for computer: localhost (1) 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|705|image identifier argument was specified: 1, DataStructure object will contain image information for the production imagerevision of this image 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|735|retrieved data for imagerevision ID: 1 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|751|retrieved data for image ID: 1 2017-05-23 05:02:24|16309|18|18|image|VMware.pm:get_vmhost_datastructure|1233|created DataStructure object for VM host: localhost 2017-05-23 05:02:24|16309|18|18|image|VMware.pm:initialize|290|VM profile assigned to localhost: VMware ESXi - local storage 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|667|computer identifier argument was specified, retrieving data for computer: 1 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_computer_info|7324|skipping retrieval of VM host 1 info for localhost to avoid recursion 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_computer_info|7344|retrieved info for computer: localhost (1) 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_vmhost_info|4090|retrieved VM host 1 info, VM host ID: 1, computer: localhost, computer ID: 1 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_computer_info|7344|retrieved info for computer: localhost (1) 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|705|image identifier argument was specified: 1, DataStructure object will contain image information for the production imagerevision of this image 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|735|retrieved data for imagerevision ID: 1 2017-05-23 05:02:24|16309|18|18|image|DataStructure.pm:_initialize|751|retrieved data for image ID: 1 2017-05-23 05:02:24|16309|18|18|image|VMware.pm:get_vmhost_datastructure|1233|created DataStructure object for VM host: localhost 2017-05-23 05:02:24|16309|18|18|image|VMware.pm:get_vmhost_api_object|1336|attempting to load VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK 2017-05-23 05:02:24|16309|18|18|image|VMware.pm:get_vmhost_api_object|1342|loaded VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK 2017-05-23 05:02:24|16309|18|18|image|Module.pm:new|192|VCL::Module::Provisioning::VMware::vSphere_SDK object created for computer root-PC, address: 468c798 2017-05-23 05:02:24|16309|18|18|image|Module.pm:set_mn_os|1032|storing reference to managment node OS object (address: 33cce50) in this VCL::Module::Provisioning::VMware::vSphere_SDK object (address: 468c798) 2017-05-23 05:02:24|16309|18|18|image|vSphere_SDK.pm:initialize|98|vSphere SDK for Perl does not appear to be installed on this managment node, unable to load VMware vSphere SDK Perl modules, error: |16309|18|18|image|vSphere_SDK.pm:initialize|98| Can't locate VMware/VIRuntime.pm in @INC (@INC contains: /usr/local/vcl-2.4.2/bin/../../../.. /usr/local/vcl-2.4.2/bin/../.. /usr/local/vcl-2.4.2/bin/../../.. /usr/local/vcl-2.4.2/bin/../../../../.. /usr/local/vcl-2.4.2/bin/.. /usr/local/vcl-2.4.2/bin/../lib /usr/local/lib64/perl5 /usr/local/share/perl5 /usr/lib64/perl5/vendor_perl /usr/share/perl5/vendor_perl /usr/lib64/perl5 /usr/share/perl5 .) at (eval 280) line 1. |16309|18|18|image|vSphere_SDK.pm:initialize|98| BEGIN failed--compilation aborted at (eval 280) line 1. 2017-05-23 05:02:24|16309|18|18|image|VMware.pm:get_vmhost_api_object|1357|API object could not be created: VCL::Module::Provisioning::VMware::vSphere_SDK 2017-05-23 05:02:24|16309|18|18|image|utils.pm:get_computer_current_private_ip_address|13882|retrieved private IP address for computer localhost (1) from database: 192.168.10.130 2017-05-23 05:02:24|16309|18|18|image|utils.pm:determine_remote_connection_target|14283|private IP address is set in database for localhost, it will be used as the remote connection target: 192.168.10.130 2017-05-23 05:02:25|16309|18|18|image|utils.pm:nmap_port|2173|port 22 is open on 192.168.10.130 (localhost) 2017-05-23 05:02:25|16309|18|18|image|utils.pm:nmap_port|2173|port 24 is open on 192.168.10.130 (localhost) 2017-05-23 05:02:28|16309|18|18|image|OS.pm:is_ssh_responding|955|localhost is responding to SSH, port 22: open, port 24: open 2017-05-23 05:02:28|16309|18|18|image|VMware.pm:initialize|307|OS on VM host localhost will be controlled using VCL::Module::OS::Linux OS object 2017-05-23 05:02:28|16309|18|18|image|DataStructure.pm:_initialize|667|computer identifier argument was specified, retrieving data for computer: 1 2017-05-23 05:02:28|16309|18|18|image|utils.pm:get_computer_info|7324|skipping retrieval of VM host 1 info for localhost to avoid recursion 2017-05-23 05:02:28|16309|18|18|image|utils.pm:get_computer_info|7344|retrieved info for computer: localhost (1) 2017-05-23 05:02:28|16309|18|18|image|utils.pm:get_vmhost_info|4090|retrieved VM host 1 info, VM host ID: 1, computer: localhost, computer ID: 1 2017-05-23 05:02:28|16309|18|18|image|utils.pm:get_computer_info|7344|retrieved info for computer: localhost (1) 2017-05-23 05:02:28|16309|18|18|image|DataStructure.pm:_initialize|705|image identifier argument was specified: 1, DataStructure object will contain image information for the production imagerevision of this image 2017-05-23 05:02:28|16309|18|18|image|DataStructure.pm:_initialize|735|retrieved data for imagerevision ID: 1 2017-05-23 05:02:28|16309|18|18|image|DataStructure.pm:_initialize|751|retrieved data for image ID: 1 2017-05-23 05:02:28|16309|18|18|image|VMware.pm:get_vmhost_datastructure|1233|created DataStructure object for VM host: localhost 2017-05-23 05:02:28|16309|18|18|image|VMware.pm:get_vmhost_api_object|1336|attempting to load VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH 2017-05-23 05:02:28|16309|18|18|image|VMware.pm:get_vmhost_api_object|1342|loaded VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH 2017-05-23 05:02:28|16309|18|18|image|Module.pm:new|192|VCL::Module::Provisioning::VMware::VIM_SSH object created for computer root-PC, address: 41487d8 2017-05-23 05:02:28|16309|18|18|image|Module.pm:set_mn_os|1032|storing reference to managment node OS object (address: 33cce50) in this VCL::Module::Provisioning::VMware::VIM_SSH object (address: 41487d8) 2017-05-23 05:02:28|16309|18|18|image|utils.pm:run_ssh_command|4302|executing SSH command on 192.168.10.130 (localhost): '/usr/bin/ssh -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -o BatchMode=no -o PasswordAuthentication=no -l root -p 22 -x 192.168.10.130 'vim-cmd ; vmware-vim-cmd' 2>&1' 2017-05-23 05:02:29|16309|18|18|image|utils.pm:run_ssh_command|4451|command: 'vim-cmd ; vmware-vim-cmd', exit_status: 127, output: |16309|18|18|image|utils.pm:run_ssh_command|4451| Commands available under /: |16309|18|18|image|utils.pm:run_ssh_command|4451| hbrsvc/ internalsvc/ solo/ vmsvc/ |16309|18|18|image|utils.pm:run_ssh_command|4451| hostsvc/ proxysvc/ vimsvc/ help |16309|18|18|image|utils.pm:run_ssh_command|4451| sh: vmware-vim-cmd: not found 2017-05-23 05:02:29|16309|18|18|image|VIM_SSH.pm:initialize|141|VIM executable available on VM host: vim-cmd 2017-05-23 05:02:29|16309|18|18|image|VIM_SSH.pm:initialize|143|VCL::Module::Provisioning::VMware::VIM_SSH object initialized 2017-05-23 05:02:29|16309|18|18|image|VMware.pm:get_vmhost_api_object|1364|created API object: VCL::Module::Provisioning::VMware::VIM_SSH 2017-05-23 05:02:29|16309|18|18|image|VMware.pm:initialize|316|VM host localhost will be controlled using vim-cmd via SSH 2017-05-23 05:02:29|16309|18|18|image|VMware.pm:initialize|335|VMware OS and API objects created for VM host localhost: |16309|18|18|image|VMware.pm:initialize|335| VM host OS object type: VCL::Module::OS::Linux |16309|18|18|image|VMware.pm:initialize|335| VMware API object type: VCL::Module::Provisioning::VMware::VIM_SSH 2017-05-23 05:02:29|16309|18|18|image|utils.pm:run_ssh_command|4302|executing SSH command on 192.168.10.130 (localhost): '/usr/bin/ssh -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectionAttempts=1 -o ConnectTimeout=3 -o BatchMode=no -o PasswordAuthentication=no -l root -p 22 -x 192.168.10.130 'vmware -v' 2>&1' 2017-05-23 05:02:29|16309|18|18|image|utils.pm:run_ssh_command|4451|command: 'vmware -v', exit_status: 0, output: |16309|18|18|image|utils.pm:run_ssh_command|4451| VMware ESXi 5.5.0 build-1331820 2017-05-23 05:02:29|16309|18|18|image|VMware.pm:get_vmhost_product_name|6544|VMware product being used on VM host localhost: 'VMware ESXi 5.5.0 build-1331820' 2017-05-23 05:02:29|16309|18|18|image|VMware.pm:get_vmx_base_directory_path|2921|determined vmx base directory path: datastore1/win7 |16309|18|18|image|VMware.pm:initialize|358| ---- WARNING ---- |16309|18|18|image|VMware.pm:initialize|358| 2017-05-23 05:02:29|16309|18|18|image|VMware.pm:initialize|358|unable to access vmx base directory path on VM host localhost: datastore1/win7 |16309|18|18|image|VMware.pm:initialize|358| ( 0) VMware.pm, initialize (line: 358) |16309|18|18|image|VMware.pm:initialize|358| (-1) Module.pm, new (line: 224) |16309|18|18|image|VMware.pm:initialize|358| (-2) Module.pm, create_provisioning_object (line: 727) |16309|18|18|image|VMware.pm:initialize|358| (-3) State.pm, initialize (line: 205) |16309|18|18|image|VMware.pm:initialize|358| (-4) Module.pm, new (line: 224) |16309|18|18|image|VMware.pm:initialize|358| (-5) vcld, (eval) (line: 580) 2017-05-23 05:02:29|16309|18|18|image|Module.pm:DESTROY|1880|destroying VCL::Module::Provisioning::VMware::VMware object, address: 39bead8 |16309|18|18|image|Module.pm:create_provisioning_object|736| ---- WARNING ---- |16309|18|18|image|Module.pm:create_provisioning_object|736| 2017-05-23 05:02:29|16309|18|18|image|Module.pm:create_provisioning_object|736|provisioning object could not be created, returning 0 |16309|18|18|image|Module.pm:create_provisioning_object|736| ( 0) Module.pm, create_provisioning_object (line: 736) |16309|18|18|image|Module.pm:create_provisioning_object|736| (-1) State.pm, initialize (line: 205) |16309|18|18|image|Module.pm:create_provisioning_object|736| (-2) Module.pm, new (line: 224) |16309|18|18|image|Module.pm:create_provisioning_object|736| (-3) vcld, (eval) (line: 580) |16309|18|18|image|Module.pm:create_provisioning_object|736| (-4) vcld, make_new_child (line: 579) |16309|18|18|image|Module.pm:create_provisioning_object|736| (-5) vcld, main (line: 348) 2017-05-23 05:02:29|16309|18|18|image|DataStructure.pm:get_computer_state_name|2012|retrieved current state of computer root-PC from the database: available |16309|18|18|image|image.pm:reservation_failed|419| ---- CRITICAL ---- |16309|18|18|image|image.pm:reservation_failed|419| 2017-05-23 05:02:29|16309|18|18|image|image.pm:reservation_failed|419|vmwarewin7-winroot19-v0 image creation failed - failed to create provisioning object |16309|18|18|image|image.pm:reservation_failed|419| ( 0) image.pm, reservation_failed (line: 419) |16309|18|18|image|image.pm:reservation_failed|419| (-1) State.pm, initialize (line: 216) |16309|18|18|image|image.pm:reservation_failed|419| (-2) Module.pm, new (line: 224) |16309|18|18|image|image.pm:reservation_failed|419| (-3) vcld, (eval) (line: 580) |16309|18|18|image|image.pm:reservation_failed|419| (-4) vcld, make_new_child (line: 579) |16309|18|18|image|image.pm:reservation_failed|419| (-5) vcld, main (line: 348) No recipient addresses found in header 2017-05-23 05:02:30|16309|18|18|image|utils.pm:mail|1279|SUCCESS -- Sending mail To: , VCL -- NOTICE DELAY Image Creation winroot 2017-05-23 05:02:30|16309|18|18|image|utils.pm:update_request_state|1399|request 18 state updated to maintenance/image 2017-05-23 05:02:30|16309|18|18|image|image.pm:reservation_failed|496|request state set to maintenance, laststate to image 2017-05-23 05:02:30|16309|18|18|image|utils.pm:update_computer_state|1458|computer 2 state updated to: maintenance 2017-05-23 05:02:30|16309|18|18|image|image.pm:reservation_failed|504|root-PC state set to maintenance 2017-05-23 05:02:30|16309|18|18|image|image.pm:reservation_failed|511|exiting 2017-05-23 05:02:30|16309|18|18|image|State.pm:DESTROY|1046|VCL::image destructor called, address: 32b60b8 2017-05-23 05:02:30|16309|18|18|image|State.pm:state_exit|864|beginning state module exit tasks |16309|18|18|image|State.pm:state_exit|864| request state argument: <not specified> |16309|18|18|image|State.pm:state_exit|864| computer state argument: <not specified> |16309|18|18|image|State.pm:state_exit|864| log ending argument: <not specified> 2017-05-23 05:02:30|16309|18|18|image|DataStructure.pm:is_parent_reservation|1101|this is the parent reservation 2017-05-23 05:02:30|16309|18|18|image|utils.pm:delete_computerloadlog_reservation|5844|deleted rows from computerloadlog for reservation IDs: 18 2017-05-23 05:02:30|16309|18|18|image|utils.pm:insertloadlog|2758|inserted 'exited' computerloadlog entry 2017-05-23 05:02:30|16309|18|18|image|State.pm:state_exit|1015|calling subroutine: VCL::Module::State::DESTROY, skipping call to exit 2017-05-23 05:02:30|16309|18|18|image|Module.pm:DESTROY|1880|destroying VCL::image object, address: 32b60b8 2017-05-23 05:02:30|16309|18|18|image|State.pm:DESTROY|1099|VCL::image process duration: 7 seconds 2017-05-23 05:02:30|16309|18|18|image|Module.pm:DESTROY|1880|destroying VCL::Module::OS::Windows::Version_6::7 object, address: 39be790 2017-05-23 05:02:30|16309|18|18|image|Module.pm:DESTROY|1880|destroying VCL::Module::Provisioning::VMware::VIM_SSH object, address: 41487d8 2017-05-23 05:02:30|16309|18|18|image|Module.pm:DESTROY|1880|destroying VCL::Module::OS::Linux object, address: 405bd40 2017-05-23 05:02:30|16309|18|18|image|Module.pm:DESTROY|1880|destroying VCL::Module::OS::Linux::ManagementNode object, address: 33cce50 2017-05-23 05:02:31|16191|||vcld|vcld:REAPER|741|VCL process exited for reservation 18, PID: 16309, signal: CHLDwhat happen ???
