A little more information, maybe relevant, maybe not:

I notice that VCL *is* getting to the point of creating a VM directory
in that path.  On the hypervisor:

 # pwd
 /vmfs/volumes/T2_6045_dev_VCL_ds01
 # ls |grep 218
 vmwarelinux-Linuxtemplate2v218-v0

That directory name appears to have been generated by VCL.  In the
directory we have two files:

 # ls
 vmwarelinux-Linuxtemplate2v218-v0-flat.vmdk
 vmwarelinux-Linuxtemplate2v218-v0.vmdk

But, as Mike suggested, the vmx file isn't appearing.

What might account for the fact that VCL can write one set of files but
then fails when it tries to write something else?


On Mon, Jun 18, 2012 at 12:58:25PM -0500, Michael Jinks wrote:
> Thanks Mike.
> 
> Checking the storage profile for this VM host, "Data Store Path" is
> /vmfs/volumes/T2_6045_dev_VCL_ds01.  That directory is present and
> read/write on our ESXi machine.
> 
> "VM Path" is set to "(empty)".  That's what we want if we plan to store
> our VM disks alongside our other VM data, right?
> 
> "VM Disk" is set to "localdisk", in case that matters.
> 
> "Repository Path" is an NFS volume.  We want that to be read-only on the
> hypervisor, read-write on the management node, but for the moment due to
> a configuration oversight it's read-write everywhere.  I don't know if
> that's significant for the present case or not.
> 
> 
> 
> 
> On Fri, Jun 15, 2012 at 07:13:42PM -0400, Mike Haudenschild wrote:
> >    Hi Michael,
> > 
> >    It looks like the problem starts here:
> >    |32473|14:14|reload| 2012-06-15
> >    15:31:21|32473|14:14|reload|VMware.pm:load(395)|failed to prepare vmx
> >    file for vcl-linux-template-2-bak on VM host: vcl0001
> >    This is the second "warning" message in the log snippet.  The first
> >    warning can be ignored.
> >    This is VCL writing the VMX file used to tell VMWare about the VM
> >    during the reload process.  After the image is collected, it brings it
> >    up on that computer in read only mode.  That process appears to have
> >    failed here.  Check that the VM path is configured correctly for the VM
> >    host and that the directory is writable by te VM host.
> >    I'm writing from an airport on an ipad, so I can't fully review your
> >    log easily.
> >    Regards,
> >    Mike
> >    On Friday, June 15, 2012, Michael Jinks wrote:
> > 
> >      I think I may have just run my first successful image capture.
> >      There's
> >      an image directory now in my templates directory, and when I browse
> >      to
> >      "Manage Images" and "Edit Image Profiles", my base image is there.
> >      Hooray!
> >      ...But, shortly after the capture completed, our admin address
> >      received
> >      the message below.  I'm forwarding the whole thing because reading
> >      it
> >      myself I don't see anything that looks like a statement of a
> >      problem,
> >      except for the first "reservation failed" line.  Any idea what went
> >      wrong?  Or, maybe nothing went wrong and this is a spurious error?
> >      Where would I look for clues?
> >      Thanks,
> >      --Michael
> >      ----- Forwarded message from [1]r...@pilot-lab.uchicago.edu -----
> >      reservation failed on vcl-linux-template-2-bak: process failed after
> >      trying to load or make available
> >      --------------------------------------------------------------------
> >      ----
> >      time: 2012-06-15 15:31:21
> >      caller: State.pm:reservation_failed(213)
> >      ( 0) State.pm, reservation_failed (line: 213)
> >      (-1) [2]new.pm, process (line: 298)
> >      (-2) vcld, make_new_child (line: 568)
> >      (-3) vcld, main (line: 346)
> >      --------------------------------------------------------------------
> >      ----
> >      management node: [3]pilot-lab.uchicago.edu
> >      reservation PID: 32473
> >      parent vcld PID: 2506
> >      request ID: 14
> >      reservation ID: 14
> >      request state/laststate: reload/image
> >      request start time: 2012-06-15 15:31:12
> >      request end time: 2012-06-15 16:01: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-Linuxtemplate2v218-v0
> >      image display name: Linux template 2v2
> >      image ID: 18
> >      image revision ID: 16
> >      image size: 30720 MB
> >      use Sysprep: yes
> >      root access: yes
> >      image owner ID: 1
> >      image owner affiliation: Local
> >      image revision date created: 2012-06-15 15:29:23
> >      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-15
> >      15:31:19|32473|14:14|reload|VMware.pm:get_image_size_bytes(3841)|ret
> >      rieved the size of the image from the datastore on the VM host:
> >      32,212,255,246
> >      2012-06-15
> >      15:31:19|32473|14:14|reload|VMware.pm:get_image_size_bytes(3851)|ima
> >      ge size retrieved from both the image repository and VM host
> >      datastore:
> >      |32473|14:14|reload| image repository: 2,397,636,084
> >      |32473|14:14|reload| VM host datastore: 32,212,255,246
> >      2012-06-15
> >      15:31:19|32473|14:14|reload|VMware.pm:get_image_size_bytes(3871)|siz
> >      e of vmwarelinux-Linuxtemplate2v218-v0 image:
> >      |32473|14:14|reload| 32,212,255,246 bytes
> >      |32473|14:14|reload| 30,720 MB
> >      |32473|14:14|reload| 30.00 GB
> >      2012-06-15
> >      15:31:19|32473|14:14|reload|VMware.pm:get_vm_additional_vmx_bytes_re
> >      quired(4713)|8053063811 additional bytes required for REDO files
> >      because VM disk mode is NOT persistent
> >      2012-06-15
> >      15:31:19|32473|14:14|reload|VMware.pm:get_vm_additional_vmx_bytes_re
> >      quired(4716)|estimate of additional space required for the vmx
> >      directory:
> >      |32473|14:14|reload| vmem/vswp file: 536,870,912 bytes, 512.0 MB,
> >      0.50 GB
> >      |32473|14:14|reload| redo files: 8,053,063,811 bytes, 7,680.0 MB,
> >      7.50 GB
> >      |32473|14:14|reload| total: 8,589,934,723 bytes, 8,192.0 MB, 8.00 GB
> >      2012-06-15
> >      15:31:19|32473|14:14|reload|Linux.pm:file_exists(1404)|'/vmfs/volume
> >      s/T2_6045_dev_VCL_ds01/vmwarelinux-Linuxtemplate2v218-v0/vmwarelinux
> >      -Linuxtemplate2v218-v0.vmdk' exists on vcl0001, files: 1,
> >      directories: 0, links: 0
> >      2012-06-15
> >      15:31:19|32473|14:14|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-15
> >      15:31:20|32473|14:14|reload|Linux.pm:file_exists(1404)|'/vmfs/volume
> >      s/nfs-vcl-templates' exists on vcl0001, files: 0, directories: 0,
> >      links: 1
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|VMware.pm:is_repository_mounted_on_vmhos
> >      t(5485)|image repository is mounted on VM host vcl0001:
> >      /vmfs/volumes/nfs-vcl-templates
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|VMware.pm:get_image_size_bytes(3821)|che
> >      cking size of image in image repository mounted on VM host:
> >      vcl0001:/vmfs/volumes/nfs-vcl-templates
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|Linux.pm:get_file_size(2022)|size of
> >      '/vmfs/volumes/nfs-vcl-templates/vmwarelinux-Linuxtemplate2v218-v0/v
> >      mwarelinux-Linuxtemplate2v218-v0*.vmdk' on vcl0001:
> >      |32473|14:14|reload| used: 2,397,636,084 bytes, 2,286.6 MB, 2.23 GB
> >      |32473|14:14|reload| allocated: 3,604,186,624 bytes, 3,437.2 MB,
> >      3.36 GB
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|Linux.pm:get_file_size(2022)|size of
> >      '/vmfs/volumes/T2_6045_dev_VCL_ds01/vmwarelinux-Linuxtemplate2v218-v
> >      0/vmwarelinux-Linuxtemplate2v218-v0*.vmdk' on vcl0001:
> >      |32473|14:14|reload| used: 32,212,255,246 bytes, 30,720.0 MB, 30.00
> >      GB
> >      |32473|14:14|reload| allocated: 32,212,320,256 bytes, 30,720.1 MB,
> >      30.00 GB
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|VMware.pm:get_image_size_bytes(3841)|ret
> >      rieved the size of the image from the datastore on the VM host:
> >      32,212,255,246
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|VMware.pm:get_image_size_bytes(3851)|ima
> >      ge size retrieved from both the image repository and VM host
> >      datastore:
> >      |32473|14:14|reload| image repository: 2,397,636,084
> >      |32473|14:14|reload| VM host datastore: 32,212,255,246
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|VMware.pm:get_image_size_bytes(3871)|siz
> >      e of vmwarelinux-Linuxtemplate2v218-v0 image:
> >      |32473|14:14|reload| 32,212,255,246 bytes
> >      |32473|14:14|reload| 30,720 MB
> >      |32473|14:14|reload| 30.00 GB
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|VMware.pm:get_vm_additional_vmdk_bytes_r
> >      equired(4657)|no additional space required for vmdk files because
> >      they already exist on VM host
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|VMware.pm:get_vm_additional_vmdk_bytes_r
> >      equired(4662)|VM requires appoximately 0 additional bytes (0 MB, 0
> >      GB) of disk space on the VM host for the vmdk directory
> >      2012-06-15
> >      15:31:20|32473|14:14|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'
> >      |32473|14:14|reload| vmx additional space required:
> >      8,589,934,723 bytes, 8,192.0 MB, 8.00 GB
> >      |32473|14:14|reload| vmdk additional space required:         0
> >      bytes, 0.0 MB, 0.00 GB
> >      |32473|14:14|reload| total additional space required:
> >      8,589,934,723 bytes, 8,192.0 MB, 8.00 GB
> >      |32473|14:14|reload| shared vmx/vmdk volume available space:
> >      1,042,964,021,248 bytes, 994,648.0 MB, 971.34 GB
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|Module.pm:create_mn_os_object(335)|manag
> >      ement node OS object has already been created, address: 4062100,
> >      returning 1
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|Module.pm:new(203)|VCL::Module::Semaphor
> >      e object created, address: 439d570
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|Module.pm:code_loop_timeout(742)|attempt
> >      ing to open lockfile, maximum of 1200 seconds
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|Module.pm:code_loop_timeout(759)|attempt
> >      1: attempting to open lockfile
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|Semaphore.pm:open_lockfile(146)|opened
> >      and obtained an exclusive lock on file:
> >      /tmp/vcl0001-vmfs-volumes-T2_6045_dev_VCL_ds01-vmwarelinux-Linuxtemp
> >      late2v218-v0.lock
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|Module.pm:code_loop_timeout(762)|attempt
> >      ing to open lockfile, code returned true
> >      2012-06-15
> >      15:31:20|32473|14:14|reload|Module.pm:get_semaphore(844)|created
> >      Semaphore object, memory address: 439d570
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|Linux.pm:file_exists(1404)|'/vmfs/volume
> >      s/T2_6045_dev_VCL_ds01/vmwarelinux-Linuxtemplate2v218-v0/vmwarelinux
> >      -Linuxtemplate2v218-v0.vmdk' exists on vcl0001, files: 1,
> >      directories: 0, links: 0
> >      2012-06-15
> >      15:31:21|32473|14:14|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-Linuxtemplate2v218-v0
> >      /vmwarelinux-Linuxtemplate2v218-v0.vmdk
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|Semaphore.pm:release_lockfile(248)|delet
> >      ed file:
> >      /tmp/vcl0001-vmfs-volumes-T2_6045_dev_VCL_ds01-vmwarelinux-Linuxtemp
> >      late2v218-v0.lock
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|Semaphore.pm:DESTROY(281)|destroyed
> >      Semaphore object, memory address: 439d570
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|utils.pm:insertloadlog(3875)|inserted
> >      computer=7, transfervm, copied vmwarelinux-Linuxtemplate2v218-v0 to
> >      vcl-linux-template-2-bak
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|VMware.pm:get_vm_ram(4306)|image ram
> >      setting is too low: 0 MB, 512 MB will be used
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|VMware.pm:get_vm_os_configuration(4210)|
> >      retrieved default VM configuration for OS: linux-x86_64
> >      |32473|14:14|reload| : {
> >      |32473|14:14|reload| :   "ethernet-virtualDev" => "e1000",
> >      |32473|14:14|reload| :   "guestOS" => "otherlinux-64",
> >      |32473|14:14|reload| :   "scsi-virtualDev" => "lsiLogic"
> >      |32473|14:14|reload| : }
> >      |32473|14:14|reload| ---- WARNING ----
> >      |32473|14:14|reload| 2012-06-15
> >      15:31:21|32473|14:14|reload|DataStructure.pm:_automethod(812)|corres
> >      ponding data has not been initialized for
> >      get_computer_eth0_mac_address:
> >      $self->request_data->{reservation}{14}{computer}{eth0macaddress}
> >      |32473|14:14|reload| ( 0) DataStructure.pm, _automethod (line: 812)
> >      |32473|14:14|reload| (-1) Autoload.pm, __ANON__ (line: 80)
> >      |32473|14:14|reload| (-2) VMware.pm, prepare_vmx (line: 1457)
> >      |32473|14:14|reload| (-3) VMware.pm, load (line: 394)
> >      |32473|14:14|reload| (-4) [4]new.pm, reload_image (line: 618)
> >      |32473|14:14|reload| (-5) [5]new.pm, process (line: 248)
> >      |32473|14:14|reload| ---- WARNING ----
> >      |32473|14:14|reload| 2012-06-15
> >      15:31:21|32473|14:14|reload|VMware.pm:load(395)|failed to prepare
> >      vmx file for vcl-linux-template-2-bak on VM host: vcl0001
> >      |32473|14:14|reload| ( 0) VMware.pm, load (line: 395)
> >      |32473|14:14|reload| (-1) [6]new.pm, reload_image (line: 618)
> >      |32473|14:14|reload| (-2) [7]new.pm, process (line: 248)
> >      |32473|14:14|reload| (-3) vcld, make_new_child (line: 568)
> >      |32473|14:14|reload| (-4) vcld, main (line: 346)
> >      |32473|14:14|reload| ---- WARNING ----
> >      |32473|14:14|reload| 2012-06-15
> >      15:31:21|32473|14:14|reload|new.pm:reload_image(623)|vmwarelinux-Lin
> >      uxtemplate2v218-v0 failed to load on vcl-linux-template-2-bak,
> >      returning
> >      |32473|14:14|reload| ( 0) [8]new.pm, reload_image (line: 623)
> >      |32473|14:14|reload| (-1) [9]new.pm, process (line: 248)
> >      |32473|14:14|reload| (-2) vcld, make_new_child (line: 568)
> >      |32473|14:14|reload| (-3) vcld, main (line: 346)
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|utils.pm:insertloadlog(3875)|inserted
> >      computer=7, loadimagefailed, vmwarelinux-Linuxtemplate2v218-v0
> >      failed to load on vcl-linux-template-2-bak
> >      |32473|14:14|reload| ---- WARNING ----
> >      |32473|14:14|reload| 2012-06-15
> >      15:31:21|32473|14:14|reload|new.pm:process(295)|failed to load
> >      vcl-linux-template-2-bak with vmwarelinux-Linuxtemplate2v218-v0
> >      |32473|14:14|reload| ( 0) [10]new.pm, process (line: 295)
> >      |32473|14:14|reload| (-1) vcld, make_new_child (line: 568)
> >      |32473|14:14|reload| (-2) vcld, main (line: 346)
> >      2012-06-15
> >      15:31:21|32473|14:14|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-15
> >      15:31:21|32473|14:14|reload|DataStructure.pm:get_computer_state_name
> >      (2336)|retrieved current state of computer vcl-linux-template-2-bak
> >      from the database: reloading
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|DataStructure.pm:_automethod(834)|data
> >      structure updated:
> >      $self->request_data->{reservation}{14}{computer}{state}{name}
> >      |32473|14:14|reload| computer_state_name = reloading
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|DataStructure.pm:get_computer_private_ip
> >      _address(1581)|attempting to retrieve private IP address for
> >      computer: vcl-linux-template-2-bak
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|DataStructure.pm:get_computer_private_ip
> >      _address(1585)|retrieved contents of /etc/hosts on this management
> >      node, contains 17 lines
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|DataStructure.pm:get_computer_private_ip
> >      _address(1645)|returning IP address from /etc/hosts file:
> >      10.50.84.15
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|utils.pm:is_inblockrequest(6163)|zero
> >      rows were returned from database select
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|DataStructure.pm:get_image_affiliation_n
> >      ame(2035)|image owner id: 1
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|utils.pm:getnewdbh(2709)|database
> >      requested (information_schema) does not match handle stored in
> >      $ENV{dbh} (vcl:128.135.107.122)
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|utils.pm:getnewdbh(2760)|database handle
> >      stored in $ENV{dbh}
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|DataStructure.pm:retrieve_user_data(1352
> >      )|attempting to retrieve and store data for user: [11]user.id = '1'
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|utils.pm:getnewdbh(2709)|database
> >      requested (vcl) does not match handle stored in $ENV{dbh}
> >      (information_schema:128.135.107.122)
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|utils.pm:getnewdbh(2760)|database handle
> >      stored in $ENV{dbh}
> >      2012-06-15
> >      15:31:21|32473|14:14|reload|DataStructure.pm:retrieve_user_data(1415
> >      )|data has been retrieved for user: admin (id: 1)
> >      ----- End forwarded message -----
> >      --
> >      Michael Jinks :: [12]mji...@uchicago.edu :: 773-469-9688
> >      University of Chicago IT Services
> > 
> >    --
> > 
> >    --
> > 
> >    Mike Haudenschild
> > 
> >    Education Systems Manager
> > 
> >    Longsight Group
> > 
> >    (740) 599-5005 x809
> > 
> >    [13]m...@longsight.com
> > 
> >    [14]www.longsight.com
> > 
> > References
> > 
> >    1. javascript:;
> >    2. http://new.pm/
> >    3. http://pilot-lab.uchicago.edu/
> >    4. http://new.pm/
> >    5. http://new.pm/
> >    6. http://new.pm/
> >    7. http://new.pm/
> >    8. http://new.pm/
> >    9. http://new.pm/
> >   10. http://new.pm/
> >   11. http://user.id/
> >   12. javascript:;
> >   13. mailto:m...@longsight.com
> >   14. http://www.longsight.com/
> 
> -- 
> Michael Jinks :: mji...@uchicago.edu :: 773-469-9688
> University of Chicago IT Services

-- 
Michael Jinks :: mji...@uchicago.edu :: 773-469-9688
University of Chicago IT Services

Reply via email to