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 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) 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: 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)|retrieved 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)|image 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)|size 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_required(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_required(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/volumes/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/volumes/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_vmhost(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)|checking 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/vmwarelinux-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-v0/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)|retrieved 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)|image 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)|size 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_required(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_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-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)|management 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::Semaphore object
created, address: 439d570
2012-06-15
15:31:20|32473|14:14|reload|Module.pm:code_loop_timeout(742)|attempting 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-Linuxtemplate2v218-v0.lock
2012-06-15
15:31:20|32473|14:14|reload|Module.pm:code_loop_timeout(762)|attempting 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/volumes/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)|deleted file:
/tmp/vcl0001-vmfs-volumes-T2_6045_dev_VCL_ds01-vmwarelinux-Linuxtemplate2v218-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)|corresponding
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) new.pm, reload_image (line: 618)
|32473|14:14|reload| (-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) new.pm, reload_image (line: 618)
|32473|14:14|reload| (-2) 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-Linuxtemplate2v218-v0
failed to load on vcl-linux-template-2-bak, returning
|32473|14:14|reload| ( 0) new.pm, reload_image (line: 623)
|32473|14:14|reload| (-1) 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) 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_name(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: 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 :: mji...@uchicago.edu :: 773-469-9688
University of Chicago IT Services
