Thanks Aaron. Ah, yes. It didn't occur to me that we'd have to have MAC addresses defined for a machine we're capturing *from*. I figured, well, it's running and has IP addresses...
At any rate, I'm looking around the UI and I can't find any page that will let me enter a MAC address for an existing computer record. Is this something I have to do by hand in the database? On Wed, Jun 20, 2012 at 08:46:40AM -0400, Aaron Peeler wrote: > Hello Michael, > > One thing that stands out in the log is that your MAC addresses are not > defined. > computer eth0 MAC address: <undefined> > computer eth1 MAC address: <undefined> > > This will be needed to correctly create the vmx file and thus get an > address from the private dhcp server that is should be running on your > management node. > > Secondly also make sure you have the dhcp server setup on your > management node for the private network. > > Aaron > > > On Tue, Jun 19, 2012 at 5:53 PM, Michael Jinks <mji...@uchicago.edu> wrote: > > Hi, all. > > > > Trying to resurrect a thread I started on Friday, subject 'Image capture > > succeeds, then "fails"'. ?Mike Haudenschild helped me narrow down the > > problem but so far I haven't been able to find a cause or a fix. > > > > I'm trying to capture my first Linux VM. ?Things go along okay through > > the capture stage, but (thanks Mike) we fail when VCL tries to reserve > > and deploy the new image. > > > > The critical message from the log appears to be: > > > > ?|17491|19:19|reload| ---- WARNING ---- > > ?|17491|19:19|reload| 2012-06-19 > > ?14:10:22|17491|19:19|reload|VMware.pm:load(395)|failed to prepare vmx file > > for vcl-linux-template-2-bak on VM host: vcl0001 > > ?|17491|19:19|reload| ( 0) VMware.pm, load (line: 395) > > ?|17491|19:19|reload| (-1) new.pm, reload_image (line: 618) > > ?|17491|19:19|reload| (-2) new.pm, process (line: 248) > > ?|17491|19:19|reload| (-3) vcld, make_new_child (line: 568) > > ?|17491|19:19|reload| (-4) vcld, main (line: 346) > > > > > > Further down, I'll paste in a complete copy of the log mail I got from > > this attempt. > > > > Our VM storage settings for this VM host are: > > > > ?Repository Path: ? ? ? /vmfs/volumes/nfs-vcl-templates > > ?Data Store Path: ? ? ? /vmfs/volumes/T2_6045_dev_VCL_ds01 > > ?VM Path: ? ? ? /vmfs/volumes/T2_6045_dev_VCL_ds01 > > > > (Note Data Store and VM are explicitly the same; we've also had VM Path > > set to "(empty)" with no apparent difference in behavior.) > > > > Both of those paths are writable on the hypervisor. ?During capture, a > > VM directory appears in both locations. ?In the directory under the > > Repository path, we have many vmdk files, sizes ranging from 842M to > > 1.5k, with names like: > > > > ?vmwarelinux-linuxtemplate2v1226-v0-s001.vmdk > > ?vmwarelinux-linuxtemplate2v1226-v0-s002.vmdk > > ?vmwarelinux-linuxtemplate2v1226-v0-s003.vmdk > > ?[...] > > ?vmwarelinux-linuxtemplate2v1226-v0-s016.vmdk > > ?vmwarelinux-linuxtemplate2v1226-v0.vmdk > > > > My first guess is that we have one vmdk file for each attempted capture, > > and this is a series of xdiffs on the original? > > > > In the Data Store/VM directory, we have: > > > > ?# pwd > > ?/vmfs/volumes/T2_6045_dev_VCL_ds01/vmwarelinux-linuxtemplate2v1226-v0 > > ?# ls -lh > > ?-rw------- ? ?1 root ?root ? 30.0G Jun 19 20:12 > > vmwarelinux-linuxtemplate2v1226-v0-flat.vmdk > > ?-rw------- ? ?1 root ?root ? ? 527 Jun 19 20:12 > > vmwarelinux-linuxtemplate2v1226-v0.vmdk > > > > So, it seems that those locations are accessible and writable, and being > > written. ?What else might cause the vmx file prep to fail? ?I went to > > VMware.pm line 395, but that's a call to a subroutine, prepare_vmx(), > > which is a fairly lengthy chunk of code and doesn't appear to be > > dropping any breadcrumbs as it runs, only the failure message when it > > exits. ?So stepping through that without guidance is going to be a > > challenge. > > > > Meanwhile we've also started trying to capture a Windows image. ?That's > > dying too, but with a different set of error messages. ?I'll post that > > under separate cover. > > > > Thanks for any insight. ?Complete log message follows. > > -m > > > > > > reservation failed on vcl-linux-template-2-bak: process failed after trying > > to load or make available > > ------------------------------------------------------------------------ > > time: 2012-06-19 14:10:22 > > caller: State.pm:reservation_failed(213) > > ( 0) State.pm, reservation_failed (line: 213) > > (-1) new.pm, process (line: 298) > > (-2) vcld, make_new_child (line: 568) > > (-3) vcld, main (line: 346) > > ------------------------------------------------------------------------ > > management node: pilot-lab.uchicago.edu > > reservation PID: 17491 > > parent vcld PID: 2491 > > > > request ID: 19 > > reservation ID: 19 > > request state/laststate: reload/image > > request start time: 2012-06-19 14:10:12 > > request end time: 2012-06-19 14:40:12 > > for imaging: no > > log ID: none > > > > computer: vcl-linux-template-2-bak > > computer id: 7 > > computer type: virtualmachine > > computer eth0 MAC address: <undefined> > > computer eth1 MAC address: <undefined> > > computer private IP address: 10.50.84.15 > > computer public IP address: 10.50.84.15 > > computer in block allocation: no > > provisioning module: VCL::Module::Provisioning::VMware::VMware > > > > vm host: vcl0001 > > vm host ID: 1 > > vm host computer ID: 1 > > vm profile: VMware ESXi - IT Services > > vm profile VM path: /vmfs/volumes/T2_6045_dev_VCL_ds01 > > vm profile repository path: /vmfs/volumes/nfs-vcl-templates > > vm profile datastore path: /vmfs/volumes/T2_6045_dev_VCL_ds01 > > vm profile disk type: localdisk > > > > image: vmwarelinux-linuxtemplate2v1226-v0 > > image display name: linux-template-2v12 > > image ID: 26 > > image revision ID: 22 > > image size: 30720 MB > > use Sysprep: yes > > root access: yes > > image owner ID: 1 > > image owner affiliation: Local > > image revision date created: 2012-06-19 14:08:20 > > image revision production: yes > > OS module: VCL::Module::OS::Linux > > > > user: vclreload > > user name: vcl reload > > user ID: 2 > > user affiliation: Local > > ------------------------------------------------------------------------ > > RECENT LOG ENTRIES FOR THIS PROCESS: > > 2012-06-19 > > 14:10:20|17491|19:19|reload|VMware.pm:get_image_size_bytes(3841)|retrieved > > the size of the image from the datastore on the VM host: 32,212,255,247 > > 2012-06-19 > > 14:10:20|17491|19:19|reload|VMware.pm:get_image_size_bytes(3851)|image size > > retrieved from both the image repository and VM host datastore: > > |17491|19:19|reload| image repository: 2,398,356,996 > > |17491|19:19|reload| VM host datastore: 32,212,255,247 > > 2012-06-19 > > 14:10:20|17491|19:19|reload|VMware.pm:get_image_size_bytes(3871)|size of > > vmwarelinux-linuxtemplate2v1226-v0 image: > > |17491|19:19|reload| 32,212,255,247 bytes > > |17491|19:19|reload| 30,720 MB > > |17491|19:19|reload| 30.00 GB > > 2012-06-19 > > 14:10:20|17491|19:19|reload|VMware.pm:get_vm_additional_vmx_bytes_required(4713)|8053063811 > > additional bytes required for REDO files because VM disk mode is NOT > > persistent > > 2012-06-19 > > 14:10:20|17491|19:19|reload|VMware.pm:get_vm_additional_vmx_bytes_required(4716)|estimate > > of additional space required for the vmx directory: > > |17491|19:19|reload| vmem/vswp file: 536,870,912 bytes, 512.0 MB, 0.50 GB > > |17491|19:19|reload| redo files: 8,053,063,811 bytes, 7,680.0 MB, 7.50 GB > > |17491|19:19|reload| total: 8,589,934,723 bytes, 8,192.0 MB, 8.00 GB > > 2012-06-19 > > 14:10:20|17491|19:19|reload|Linux.pm:file_exists(1404)|'/vmfs/volumes/T2_6045_dev_VCL_ds01/vmwarelinux-linuxtemplate2v1226-v0/vmwarelinux-linuxtemplate2v1226-v0.vmdk' > > exists on vcl0001, files: 1, directories: 0, links: 0 > > 2012-06-19 > > 14:10:20|17491|19:19|reload|VMware.pm:get_image_size_bytes(3819)|VM profile > > vmdisk is set to 'localdisk', attempting to retrieve image size from image > > repository > > 2012-06-19 > > 14:10:21|17491|19:19|reload|Linux.pm:file_exists(1404)|'/vmfs/volumes/nfs-vcl-templates' > > exists on vcl0001, files: 0, directories: 0, links: 1 > > 2012-06-19 > > 14:10:21|17491|19:19|reload|VMware.pm:is_repository_mounted_on_vmhost(5485)|image > > repository is mounted on VM host vcl0001: /vmfs/volumes/nfs-vcl-templates > > 2012-06-19 > > 14:10:21|17491|19:19|reload|VMware.pm:get_image_size_bytes(3821)|checking > > size of image in image repository mounted on VM host: > > vcl0001:/vmfs/volumes/nfs-vcl-templates > > 2012-06-19 14:10:21|17491|19:19|reload|Linux.pm:get_file_size(2022)|size of > > '/vmfs/volumes/nfs-vcl-templates/vmwarelinux-linuxtemplate2v1226-v0/vmwarelinux-linuxtemplate2v1226-v0*.vmdk' > > on vcl0001: > > |17491|19:19|reload| used: 2,398,356,996 bytes, 2,287.3 MB, 2.23 GB > > |17491|19:19|reload| allocated: 3,605,390,848 bytes, 3,438.4 MB, 3.36 GB > > 2012-06-19 14:10:21|17491|19:19|reload|Linux.pm:get_file_size(2022)|size of > > '/vmfs/volumes/T2_6045_dev_VCL_ds01/vmwarelinux-linuxtemplate2v1226-v0/vmwarelinux-linuxtemplate2v1226-v0*.vmdk' > > on vcl0001: > > |17491|19:19|reload| used: 32,212,255,247 bytes, 30,720.0 MB, 30.00 GB > > |17491|19:19|reload| allocated: 32,212,320,256 bytes, 30,720.1 MB, 30.00 GB > > 2012-06-19 > > 14:10:21|17491|19:19|reload|VMware.pm:get_image_size_bytes(3841)|retrieved > > the size of the image from the datastore on the VM host: 32,212,255,247 > > 2012-06-19 > > 14:10:21|17491|19:19|reload|VMware.pm:get_image_size_bytes(3851)|image size > > retrieved from both the image repository and VM host datastore: > > |17491|19:19|reload| image repository: 2,398,356,996 > > |17491|19:19|reload| VM host datastore: 32,212,255,247 > > 2012-06-19 > > 14:10:21|17491|19:19|reload|VMware.pm:get_image_size_bytes(3871)|size of > > vmwarelinux-linuxtemplate2v1226-v0 image: > > |17491|19:19|reload| 32,212,255,247 bytes > > |17491|19:19|reload| 30,720 MB > > |17491|19:19|reload| 30.00 GB > > 2012-06-19 > > 14:10:21|17491|19:19|reload|VMware.pm:get_vm_additional_vmdk_bytes_required(4657)|no > > additional space required for vmdk files because they already exist on VM > > host > > 2012-06-19 > > 14:10:21|17491|19:19|reload|VMware.pm:get_vm_additional_vmdk_bytes_required(4662)|VM > > requires appoximately 0 additional bytes (0 MB, 0 GB) of disk space on the > > VM host for the vmdk directory > > 2012-06-19 > > 14:10:21|17491|19:19|reload|VMware.pm:check_vmhost_disk_space(2070)|enough > > space is available on shared vmx/vmdk volume on VM host vcl0001: > > '/vmfs/volumes/T2_6045_dev_VCL_ds01' > > |17491|19:19|reload| vmx additional space required: ? ? ? ? ?8,589,934,723 > > bytes, 8,192.0 MB, 8.00 GB > > |17491|19:19|reload| vmdk additional space required: ? ? ? ? 0 bytes, 0.0 > > MB, 0.00 GB > > |17491|19:19|reload| total additional space required: ? ? ? ?8,589,934,723 > > bytes, 8,192.0 MB, 8.00 GB > > |17491|19:19|reload| shared vmx/vmdk volume available space: > > 1,042,905,300,992 bytes, 994,592.0 MB, 971.28 GB > > 2012-06-19 > > 14:10:21|17491|19:19|reload|Module.pm:create_mn_os_object(335)|management > > node OS object has already been created, address: 3997f10, returning 1 > > 2012-06-19 > > 14:10:21|17491|19:19|reload|Module.pm:new(203)|VCL::Module::Semaphore > > object created, address: 3cd4360 > > 2012-06-19 > > 14:10:21|17491|19:19|reload|Module.pm:code_loop_timeout(742)|attempting to > > open lockfile, maximum of 1200 seconds > > 2012-06-19 > > 14:10:21|17491|19:19|reload|Module.pm:code_loop_timeout(759)|attempt 1: > > attempting to open lockfile > > 2012-06-19 > > 14:10:21|17491|19:19|reload|Semaphore.pm:open_lockfile(146)|opened and > > obtained an exclusive lock on file: > > /tmp/vcl0001-vmfs-volumes-T2_6045_dev_VCL_ds01-vmwarelinux-linuxtemplate2v1226-v0.lock > > 2012-06-19 > > 14:10:21|17491|19:19|reload|Module.pm:code_loop_timeout(762)|attempting to > > open lockfile, code returned true > > 2012-06-19 14:10:21|17491|19:19|reload|Module.pm:get_semaphore(844)|created > > Semaphore object, memory address: 3cd4360 > > 2012-06-19 > > 14:10:22|17491|19:19|reload|Linux.pm:file_exists(1404)|'/vmfs/volumes/T2_6045_dev_VCL_ds01/vmwarelinux-linuxtemplate2v1226-v0/vmwarelinux-linuxtemplate2v1226-v0.vmdk' > > exists on vcl0001, files: 1, directories: 0, links: 0 > > 2012-06-19 14:10:22|17491|19:19|reload|VMware.pm:prepare_vmdk(1785)|VM is > > not persistent and nonpersistent vmdk file already exists on VM host > > vcl0001: > > /vmfs/volumes/T2_6045_dev_VCL_ds01/vmwarelinux-linuxtemplate2v1226-v0/vmwarelinux-linuxtemplate2v1226-v0.vmdk > > 2012-06-19 > > 14:10:22|17491|19:19|reload|Semaphore.pm:release_lockfile(248)|deleted > > file: > > /tmp/vcl0001-vmfs-volumes-T2_6045_dev_VCL_ds01-vmwarelinux-linuxtemplate2v1226-v0.lock > > 2012-06-19 14:10:22|17491|19:19|reload|Semaphore.pm:DESTROY(281)|destroyed > > Semaphore object, memory address: 3cd4360 > > 2012-06-19 > > 14:10:22|17491|19:19|reload|utils.pm:insertloadlog(3875)|inserted > > computer=7, transfervm, copied vmwarelinux-linuxtemplate2v1226-v0 to > > vcl-linux-template-2-bak > > 2012-06-19 14:10:22|17491|19:19|reload|VMware.pm:get_vm_ram(4306)|image ram > > setting is too low: 0 MB, 512 MB will be used > > 2012-06-19 > > 14:10:22|17491|19:19|reload|VMware.pm:get_vm_os_configuration(4210)|retrieved > > default VM configuration for OS: linux-x86_64 > > |17491|19:19|reload| : { > > |17491|19:19|reload| : ? "ethernet-virtualDev" => "e1000", > > |17491|19:19|reload| : ? "guestOS" => "otherlinux-64", > > |17491|19:19|reload| : ? "scsi-virtualDev" => "lsiLogic" > > |17491|19:19|reload| : } > > |17491|19:19|reload| ---- WARNING ---- > > |17491|19:19|reload| 2012-06-19 > > 14:10:22|17491|19:19|reload|DataStructure.pm:_automethod(812)|corresponding > > data has not been initialized for get_computer_eth0_mac_address: > > $self->request_data->{reservation}{19}{computer}{eth0macaddress} > > |17491|19:19|reload| ( 0) DataStructure.pm, _automethod (line: 812) > > |17491|19:19|reload| (-1) Autoload.pm, __ANON__ (line: 80) > > |17491|19:19|reload| (-2) VMware.pm, prepare_vmx (line: 1457) > > |17491|19:19|reload| (-3) VMware.pm, load (line: 394) > > |17491|19:19|reload| (-4) new.pm, reload_image (line: 618) > > |17491|19:19|reload| (-5) new.pm, process (line: 248) > > |17491|19:19|reload| ---- WARNING ---- > > |17491|19:19|reload| 2012-06-19 > > 14:10:22|17491|19:19|reload|VMware.pm:load(395)|failed to prepare vmx file > > for vcl-linux-template-2-bak on VM host: vcl0001 > > |17491|19:19|reload| ( 0) VMware.pm, load (line: 395) > > |17491|19:19|reload| (-1) new.pm, reload_image (line: 618) > > |17491|19:19|reload| (-2) new.pm, process (line: 248) > > |17491|19:19|reload| (-3) vcld, make_new_child (line: 568) > > |17491|19:19|reload| (-4) vcld, main (line: 346) > > |17491|19:19|reload| ---- WARNING ---- > > |17491|19:19|reload| 2012-06-19 > > 14:10:22|17491|19:19|reload|new.pm:reload_image(623)|vmwarelinux-linuxtemplate2v1226-v0 > > failed to load on vcl-linux-template-2-bak, returning > > |17491|19:19|reload| ( 0) new.pm, reload_image (line: 623) > > |17491|19:19|reload| (-1) new.pm, process (line: 248) > > |17491|19:19|reload| (-2) vcld, make_new_child (line: 568) > > |17491|19:19|reload| (-3) vcld, main (line: 346) > > 2012-06-19 > > 14:10:22|17491|19:19|reload|utils.pm:insertloadlog(3875)|inserted > > computer=7, loadimagefailed, vmwarelinux-linuxtemplate2v1226-v0 failed to > > load on vcl-linux-template-2-bak > > |17491|19:19|reload| ---- WARNING ---- > > |17491|19:19|reload| 2012-06-19 > > 14:10:22|17491|19:19|reload|new.pm:process(295)|failed to load > > vcl-linux-template-2-bak with vmwarelinux-linuxtemplate2v1226-v0 > > |17491|19:19|reload| ( 0) new.pm, process (line: 295) > > |17491|19:19|reload| (-1) vcld, make_new_child (line: 568) > > |17491|19:19|reload| (-2) vcld, main (line: 346) > > 2012-06-19 > > 14:10:22|17491|19:19|reload|DataStructure.pm:get_computer_state_name(2305)|attempting > > to retrieve current state of computer vcl-linux-template-2-bak from the > > database > > 2012-06-19 > > 14:10:22|17491|19:19|reload|DataStructure.pm:get_computer_state_name(2336)|retrieved > > current state of computer vcl-linux-template-2-bak from the database: > > reloading > > 2012-06-19 > > 14:10:22|17491|19:19|reload|DataStructure.pm:_automethod(834)|data > > structure updated: > > $self->request_data->{reservation}{19}{computer}{state}{name} > > |17491|19:19|reload| computer_state_name = reloading > > 2012-06-19 > > 14:10:22|17491|19:19|reload|DataStructure.pm:get_computer_private_ip_address(1581)|attempting > > to retrieve private IP address for computer: vcl-linux-template-2-bak > > 2012-06-19 > > 14:10:22|17491|19:19|reload|DataStructure.pm:get_computer_private_ip_address(1585)|retrieved > > contents of /etc/hosts on this management node, contains 18 lines > > 2012-06-19 > > 14:10:22|17491|19:19|reload|DataStructure.pm:get_computer_private_ip_address(1645)|returning > > IP address from /etc/hosts file: 10.50.84.15 > > 2012-06-19 > > 14:10:22|17491|19:19|reload|utils.pm:is_inblockrequest(6163)|zero rows were > > returned from database select > > 2012-06-19 > > 14:10:22|17491|19:19|reload|DataStructure.pm:get_image_affiliation_name(2035)|image > > owner id: 1 > > 2012-06-19 14:10:22|17491|19:19|reload|utils.pm:getnewdbh(2709)|database > > requested (information_schema) does not match handle stored in $ENV{dbh} > > (vcl:128.135.107.122) > > 2012-06-19 14:10:22|17491|19:19|reload|utils.pm:getnewdbh(2760)|database > > handle stored in $ENV{dbh} > > 2012-06-19 > > 14:10:22|17491|19:19|reload|DataStructure.pm:retrieve_user_data(1352)|attempting > > to retrieve and store data for user: user.id = '1' > > 2012-06-19 14:10:22|17491|19:19|reload|utils.pm:getnewdbh(2709)|database > > requested (vcl) does not match handle stored in $ENV{dbh} > > (information_schema:128.135.107.122) > > 2012-06-19 14:10:22|17491|19:19|reload|utils.pm:getnewdbh(2760)|database > > handle stored in $ENV{dbh} > > 2012-06-19 > > 14:10:22|17491|19:19|reload|DataStructure.pm:retrieve_user_data(1415)|data > > has been retrieved for user: admin (id: 1) > > > > > > -- > Aaron Peeler > Program Manager > Virtual Computing Lab > NC State University > > All electronic mail messages in connection with State business which > are sent to or received by this account are subject to the NC Public > Records Law and may be disclosed to third parties. -- Michael Jinks :: mji...@uchicago.edu :: 773-469-9688 University of Chicago IT Services