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]> 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]> 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: vmwarelinux-testing18-v0 >> >> image.id: 18 >> >> imagerevision.id: 14 >> >> imagemeta.id: 17 >> >> resource.id: 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:get_variable|12901|variable >> 'cluster_inuse_check' is not set in the database >> >> 2018-01-26 15:02:47|21311|||vcld|utils.pm: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: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:insert_request|8303|inserted >> new image/image request into request table, request id=14 >> >> 2018-01-26 15:02:47|21311|||vcld|utils.pm: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|reservation >> 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|14605|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|14605|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|retrieved >> 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|11638|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 >> >> 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|updated >> 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::Linux >> 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|retrieved >> 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::ManagementNode >> 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 --> 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 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::Linux >> 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_obje >> ct|864|VCL::Module::Provisioning::VMware::VMware module loaded >> >> 2018-01-26 >> 15:02:53|21429|14|4|image|Module.pm:new|196|VCL::Module::Provisioning::VMware::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_profil >> e_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|provisioning >> 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], PROBLEM -- mgtvcl01|14:4|image|image.pm >> |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-testing18-v0 >> Image Capture Failed - failed to create provisioning object >> >> |21429|14|4|image|image.pm:reservation_failed|330| ( 0) image.pm, >> 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]> >> *Reply-To: *"[email protected]" <[email protected]> >> *Date: *Friday, January 26, 2018 at 1:39 PM >> >> *To: *"[email protected]" <[email protected]> >> *Subject: *Re: New 2.5 install error >> >> >> >> Sorry, the symlink was pointing to the old install. >> >> AL >> >> >> >> *From: *Evelio Quiros <[email protected]> >> *Reply-To: *"[email protected]" <[email protected]> >> *Date: *Friday, January 26, 2018 at 1:31 PM >> *To: *"[email protected]" <[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 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]> >> *Reply-To: *"[email protected]" <[email protected]> >> *Date: *Friday, January 26, 2018 at 12:16 PM >> *To: *"[email protected]" <[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]> >> *Reply-To: *"[email protected]" <[email protected]> >> *Date: *Friday, January 26, 2018 at 11:25 AM >> *To: *"[email protected]" <[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=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_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=yjbBQ0F103dSHUJLo4RriZ_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=yjbBQ0F103dSHUJLo4RriZ_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]> wrote: >> >> >> >> 2018-01-26 09:56:28|4156|||vcld|utils.pm >> <https://urldefense.proofpoint.com/v2/url?u=http-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWyvOl1C30l1ngr50&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=http-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWyvOl1C30l1ngr50&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=http-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWyvOl1C30l1ngr50&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=yjbBQ0F103dSHUJLo4RriZ_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=yjbBQ0F103dSHUJLo4RriZ_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=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_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=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_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=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_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=http-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWyvOl1C30l1ngr50&e=> >> :get_management_node_info|4589|retrieving current management node info >> for '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=http-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWyvOl1C30l1ngr50&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=http-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWyvOl1C30l1ngr50&e=> >> :get_management_node_info|4751|retrieved management node info: ' >> mgtvcl01.fiu.edu' (mgtvcl01) >> >> 2018-01-26 09:56:28|4156|||vcld|utils.pm >> <https://urldefense.proofpoint.com/v2/url?u=http-3A__utils.pm&d=DwMFaQ&c=lhMMI368wojMYNABHh1gQQ&r=iomW2cpnE-Hdilsh5YvIBg&m=yjbBQ0F103dSHUJLo4RriZ_DawzJBN2yUcEduHS2cNE&s=Mwh_6EQC3cxk3k5Rb2qYDZB9mETWyvOl1C30l1ngr50&e=> >> :mail|1262|SUCCESS -- Sending mail To: [email protected], PROBLEM -- >> mgtvcl01|utils.pm:insert_request(8056) >> >> >> >> >> >> *From: *Aaron Peeler <[email protected]> >> *Reply-To: *"[email protected]" <[email protected]>, " >> [email protected]" <[email protected]> >> *Date: *Thursday, January 25, 2018 at 7:12 AM >> *To: *"[email protected]" <[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]> 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]>: >> >> 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 <(919)%20513-4090> >> >> 311A Hillsborough >> <https://maps.google.com/?q=311A+Hillsborough&entry=gmail&source=g> >> Building >> >> Campus Box 7109 >> >> Raleigh, NC 27695 >> >> > -- *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
