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
