def test_concurrent_lock(self):
""" Test concurrent locking behavior. """
_locked = threading.Event()
def _thread():
with FileBackedLock(self._file_name, self._fs_type):
_locked.set()
time.sleep(2)
thread = threading.Thread(target=_thread)
thread.start()
_locked.wait()
def _lock_it():
with FileBackedLock(self._file_name, self._fs_type):
self.assertTrue(False, msg="Should never reach")
# another thread holds the lock so expect failure
self.assertRaises(AcquireLockFailure, _lock_it)
# retry lock with wait succeeds
with FileBackedLock(self._file_name,
self._fs_type,
retry=100,
wait_secs=0.1) as lock:
self.assertTrue(lock.acquired())
thread.join()
self.assertFalse(os.path.exists(self._lock_path))
def reap_tmp_images(self):
""" Clean up unused directories in the temp image folder. """
for ds in self._ds_manager.get_datastores():
tmp_image_pattern = os_datastore_path_pattern(ds.id, TMP_IMAGE_FOLDER_NAME_PREFIX)
for image_dir in glob.glob(tmp_image_pattern):
if not os.path.isdir(image_dir):
continue
create_time = os.stat(image_dir).st_ctime
current_time = time.time()
if current_time - self.REAP_TMP_IMAGES_GRACE_PERIOD < create_time:
# Skip folders that are newly created in past x minutes
# For example, during host-to-host transfer, hostd on
# receiving end stores the uploaded file in temp images
# folder but does not lock it with FileBackedLock, so we
# need to allow a grace period before reaping it.
self._logger.info(
"Skip folder: %s, created: %s, now: %s" %
(image_dir, create_time, current_time))
continue
try:
with FileBackedLock(image_dir, ds.type):
if os.path.exists(image_dir):
self._logger.info("Delete folder %s" % image_dir)
shutil.rmtree(image_dir, ignore_errors=True)
except (AcquireLockFailure, InvalidFile):
self._logger.info("Already locked: %s, skipping" % image_dir)
except:
self._logger.info("Unable to remove %s" % image_dir, exc_info=True)
def test_lock(self):
""" Test file based lock behavior. """
# in the with context
with FileBackedLock(self._file_name, self._fs_type) as lock:
self.assertTrue(lock.acquired())
self.assertTrue(os.path.exists(self._lock_path))
self.assertFalse(os.path.exists(self._lock_path))
self.assertFalse(lock.acquired())
# explicitly invoking lock/unlock
lock = FileBackedLock(self._file_name, self._fs_type)
self.assertFalse(lock.acquired())
self.assertFalse(os.path.exists(self._lock_path))
lock.lock()
self.assertTrue(lock.acquired())
self.assertTrue(os.path.exists(self._lock_path))
lock.unlock()
self.assertFalse(lock.acquired())
self.assertFalse(os.path.exists(self._lock_path))
def _move_image(self, image_id, datastore, tmp_dir):
"""
Atomic move of a tmp folder into the image datastore. Handles
concurrent moves by locking a well know derivative of the image_id
while doing the atomic move.
The exclusive file lock ensures that only one move is successful.
Has the following side effects:
a - If the destination image already exists, it is assumed that
someone else successfully copied the image over and the temp
directory is deleted.
b - If we fail to acquire the file lock after retrying 3 times,
or the atomic move fails, the tmp image directory will be left
behind and needs to be garbage collected later.
image_id: String.The image id of the image being moved.
datastore: String. The datastore id of the datastore.
tmp_dir: String. The absolute path of the temp image directory.
raises: OsError if the move fails
AcquireLockFailure, InvalidFile if we fail to lock the
destination image.
"""
ds_type = self._get_datastore_type(datastore)
image_path = os_datastore_path(
datastore, compond_path_join(IMAGE_FOLDER_NAME_PREFIX, image_id))
self._logger.info("_move_image: %s => %s, ds_type: %s" %
(tmp_dir, image_path, ds_type))
if not os.path.exists(tmp_dir):
raise ImageNotFoundException("Temp image %s not found" % tmp_dir)
try:
with FileBackedLock(image_path, ds_type, retry=300,
wait_secs=0.1): # wait lock for 30 seconds
if self._check_image_repair(image_id, datastore):
raise DiskAlreadyExistException("Image already exists")
if ds_type == DatastoreType.VSAN:
# on VSAN, move all files under [datastore]/image_[image_id]/tmp_image_[uuid]/* to
# [datastore]/image_[image_id]/*.
# Also we do not delete tmp_image folder in success case, because VSAN accesses it
# when creating linked VM, even the folder is now empty.
for entry in os.listdir(tmp_dir):
shutil.move(os.path.join(tmp_dir, entry),
os.path.join(image_path, entry))
else:
# on VMFS/NFS/etc, rename [datastore]/tmp_image_[uuid] to [datastore]/tmp_image_[image_id]
self._host_client.move_file(tmp_dir, image_path)
except:
self._logger.exception("Move image %s to %s failed" %
(image_id, image_path))
self._host_client.delete_file(tmp_dir)
raise
def delete_image(self, datastore_id, image_id, grace_period):
self._logger.info("delete_image: Starting to delete image: %s, %s" %
(datastore_id, image_id))
image_dir = self._image_directory(datastore_id, image_id)
ds_type = self._get_datastore_type(datastore_id)
marker_pathname = os.path.join(image_dir,
self.UNUSED_IMAGE_MARKER_FILE_NAME)
timestamp_pathname = os.path.join(image_dir,
self.IMAGE_TIMESTAMP_FILE_NAME)
try:
with FileBackedLock(image_dir, ds_type):
# Read marker file to determine when image scanner marked this image as unused
marker_time = self._read_marker_file(marker_pathname)
self._logger.info(
"delete_image: image was marked as unused at: %s" %
marker_time)
# Subtract grace time to avoid errors due to small difference in clock
# values on different hosts. Pretend the scan started 60 seconds earlier.
marker_time -= grace_period
# Read timestamp mod_time to determine the latest vm creation using this image
timestamp_exists, mod_time = self._get_mod_time(
timestamp_pathname)
self._logger.info(
"delete_image: image was last touched at: %s, %s" %
(timestamp_exists, mod_time))
# Image was touched (due to VM creation) after scanner marked it as unused.
# Remove unused image marker file
if timestamp_exists and mod_time >= marker_time:
self._logger.info(
"delete_image: image is in-use, do not delete")
os.unlink(marker_pathname)
return False
# Delete image directory
self._logger.info(
"delete_image: removing image directory: %s" % image_dir)
self._host_client.delete_file(image_dir)
return True
except Exception:
self._logger.exception("delete_image: failed to delete image")
return False
def test_lock(self):
""" Test file based lock behavior. """
# in the with context
with FileBackedLock(self._file_name, self._fs_type) as lock:
self.assertTrue(lock.acquired())
self.assertTrue(os.path.exists(self._lock_path))
self.assertFalse(os.path.exists(self._lock_path))
self.assertFalse(lock.acquired())
# explicitly invoking lock/unlock
lock = FileBackedLock(self._file_name, self._fs_type)
self.assertFalse(lock.acquired())
self.assertFalse(os.path.exists(self._lock_path))
lock.lock()
self.assertTrue(lock.acquired())
self.assertTrue(os.path.exists(self._lock_path))
lock.unlock()
self.assertFalse(lock.acquired())
self.assertFalse(os.path.exists(self._lock_path))
def test_relock_failure(self):
""" Test file based relocking behavior. """
def _inner_lock():
with FileBackedLock(self._file_name, self._fs_type):
self.assertTrue(False, msg="Should never reach")
with FileBackedLock(self._file_name, self._fs_type) as lock:
# lock is created on successful acquisition
self.assertTrue(os.path.exists(self._lock_path))
self.assertTrue(lock.acquired())
# relock fails
self.assertRaises(AcquireLockFailure, _inner_lock)
# lock still exists and held on inner relock failure
self.assertTrue(os.path.exists(self._lock_path))
self.assertTrue(lock.acquired())
# lock cleaned up
self.assertFalse(os.path.exists(self._lock_path))
self.assertFalse(lock.acquired())
def receive_image(self, image_id, datastore_id, imported_vm_name, metadata):
""" Creates an image using the data from the imported vm.
This is run at the destination host end of the host-to-host
image transfer.
"""
self._vim_client.wait_for_vm_create(imported_vm_name)
vm = self._vim_client.get_vm_obj_in_cache(imported_vm_name)
self._logger.warning("receive_image found vm %s, %s" % (imported_vm_name, vm))
vm_dir = os.path.dirname(datastore_to_os_path(vm.config.files.vmPathName))
vm.Unregister()
ds_type = self._get_datastore_type(datastore_id)
if ds_type == DatastoreType.VSAN:
# on VSAN datastore, vm_dir is [vsanDatastore] image_[image_id], we only need to
# rename the vmdk file to [image_id].vmdk
try:
with FileBackedLock(vm_dir, ds_type, retry=300, wait_secs=0.01): # wait lock for 3 seconds
if self._check_image_repair(image_id, datastore_id):
raise DiskAlreadyExistException("Image already exists")
self._vim_client.move_file(os.path.join(vm_dir, vmdk_add_suffix(imported_vm_name)),
os.path.join(vm_dir, vmdk_add_suffix(image_id)))
except:
self._logger.exception("Move image %s to %s failed" % (image_id, vm_dir))
self._vim_client.delete_file(vm_dir)
raise
else:
self._move_image(image_id, datastore_id, vm_dir)
# Save raw metadata
if metadata:
metadata_path = os_metadata_path(datastore_id, image_id, IMAGE_FOLDER_NAME_PREFIX)
with open(metadata_path, 'w') as f:
f.write(metadata)
self._create_image_timestamp_file_from_ids(datastore_id, image_id)
def _delete_single_image(self, image_sweeper, curdir, image_id, modify=True):
self._logger.info("IMAGE SCANNER: Starting to "
"delete image: %s, %s"
% (curdir, image_id))
# Read content of marker file
try:
marker_pathname = os.path.join(curdir,
self.IMAGE_MARKER_FILE_NAME)
marker_time = self._read_marker_file(marker_pathname)
except Exception as ex:
self._logger.warning("Cannot read marker file: %s, %s"
% (curdir, ex))
return False
self._logger.info("IMAGE SCANNER: Marker time: %s"
% marker_time)
# Subtract grace time to avoid
# errors due to small difference in clock
# values on different hosts. Pretend the scan
# started 60 seconds earlier.
marker_time -= image_sweeper.get_grace_period()
self._logger.info(
"IMAGE SCANNER: Marker time after grace: %s"
% marker_time)
timestamp_pathname = \
os.path.join(curdir,
self.IMAGE_TIMESTAMP_FILE_NAME)
renamed_timestamp_pathname = \
timestamp_pathname + \
self.IMAGE_TIMESTAMP_FILE_RENAME_SUFFIX
# Lock image
datastore_id = image_sweeper.datastore_id
ds_type = self._get_datastore_type(datastore_id)
with FileBackedLock(curdir, ds_type):
# Get mod time of the timestamp file,
# the method returns None if the file doesn't
# exists, throws exception if there are
# other errors
timestamp_exists, mod_time = \
self._get_mod_time(
timestamp_pathname)
if timestamp_exists:
# Marker time is out of date
# skip this image
self._logger.info(
"IMAGE SCANNER: mod time: %s"
% mod_time)
if mod_time >= marker_time:
# Remove marker file
self._logger.info(
"IMAGE SCANNER: mod time too recent")
self._image_sweeper_unlink(marker_pathname)
return False
# Move timestamp file to a new name
if modify:
self._image_sweeper_rename(
timestamp_pathname,
renamed_timestamp_pathname)
else:
# If we could not find the timestamp file
# it may mean that this was a partially
# removed image, log message and continue
self._logger.info("Cannot find timestamp file: %s"
"continuing with image removal"
% timestamp_pathname)
if modify:
# Get mod time of the renamed timestamp file
renamed_timestamp_exists, renamed_mod_time = \
self._get_mod_time(
renamed_timestamp_pathname)
else:
renamed_timestamp_exists = True
renamed_mod_time = mod_time
self._logger.info(
"IMAGE SCANNER: rename timestamp exists: %s, "
"renamed mod time: %s" %
(renamed_timestamp_exists, renamed_mod_time))
# If there was timestamp file but there
# is no renamed-timestamp file something
# bad might have happened, skip this image
if timestamp_exists and \
not renamed_timestamp_exists:
self._logger.warning("Error, missing renamed "
"timestamp file: %s"
% renamed_timestamp_pathname)
return False
# Normal case both timestamp and renamed
# timestamp exist
if timestamp_exists and renamed_timestamp_exists:
# Normal case: both timestamp and renamed
# timestamp files exist. If the mod time on the
# renamed-timestamp has changed skip this image.
if renamed_mod_time != mod_time:
self._logger.info("mod time changed on renamed "
"timestamp file, %s: %d -> %d" %
(renamed_timestamp_pathname,
mod_time, renamed_mod_time))
self._image_sweeper_unlink(marker_pathname)
return False
elif renamed_timestamp_exists:
# Only the renamed timestamp file exists
# Check the mod time of the renamed-timestamp
# file against the marker time
if renamed_mod_time >= marker_time:
self._image_sweeper_unlink(marker_pathname)
return False
# Move directory
self._logger.info("IMAGE SCANNER: removing image: %s"
% curdir)
if modify:
trash_dir = os.path.join(
os_datastore_path(datastore_id, GC_IMAGE_FOLDER),
image_id)
self._image_sweeper_rename(curdir, trash_dir)
# Unlock
# Delete image
if modify:
self._image_sweeper_rm_rf(trash_dir)
return True
def _lock_it():
with FileBackedLock(self._file_name, self._fs_type):
self.assertTrue(False, msg="Should never reach")
def _thread():
with FileBackedLock(self._file_name, self._fs_type):
_locked.set()
time.sleep(2)