diff --git a/blivet/deviceaction.py b/blivet/deviceaction.py index e18a06e..d59b4dc 100644 --- a/blivet/deviceaction.py +++ b/blivet/deviceaction.py @@ -581,6 +581,7 @@ class ActionCreateFormat(DeviceAction): # Get the UUID now that the format is created udev.settle() self.device.updateSysfsPath() + """ info = udev.get_device(self.device.sysfsPath) # only do this if the format has a device known to udev # (the format might not have a normal device at all) @@ -591,7 +592,7 @@ class ActionCreateFormat(DeviceAction): elif self.device.format.type != "tmpfs": # udev lookup failing is a serious issue for anything other than tmpfs log.error("udev lookup failed for device: %s", self.device) - + """ if callbacks and callbacks.create_format_post: msg = _("Created %(type)s on %(device)s") % {"type": self.device.format.type, "device": self.device.path} callbacks.create_format_post(CreateFormatPostData(msg)) @@ -661,9 +662,12 @@ class ActionDestroyFormat(DeviceAction): status = self.device.status self.device.setup(orig=True) self.format.destroy() + log.debug("done with destroy method") udev.settle() + log.debug("tearing down device") if not status: self.device.teardown() + log.debug("done") def cancel(self): if not self._applied: diff --git a/blivet/devices/btrfs.py b/blivet/devices/btrfs.py index b650854..4af822b 100644 --- a/blivet/devices/btrfs.py +++ b/blivet/devices/btrfs.py @@ -405,11 +405,11 @@ class BTRFSVolumeDevice(BTRFSDevice, ContainerDevice, RaidDevice): def _postCreate(self): super(BTRFSVolumeDevice, self)._postCreate() - info = udev.get_device(self.sysfsPath) - if not info: - log.error("failed to get updated udev info for new btrfs volume") - else: - self.format.volUUID = udev.device_get_uuid(info) + #info = udev.get_device(self.sysfsPath) + #if not info: + # log.error("failed to get updated udev info for new btrfs volume") + #else: + # self.format.volUUID = udev.device_get_uuid(info) self.format.exists = True self.originalFormat.exists = True diff --git a/blivet/devices/dm.py b/blivet/devices/dm.py index 67864fc..2b8467c 100644 --- a/blivet/devices/dm.py +++ b/blivet/devices/dm.py @@ -179,6 +179,7 @@ class DMLinearDevice(DMDevice): """ Open, or set up, a device. """ log_method_call(self, self.name, orig=orig, status=self.status, controllable=self.controllable) + log.debug("dm-linear setup: %s size is %s", self.slave, self.slave.currentSize) slave_length = self.slave.currentSize / LINUX_SECTOR_SIZE dm.dm_create_linear(self.name, self.slave.path, slave_length, self.dmUuid) diff --git a/blivet/devices/storage.py b/blivet/devices/storage.py index 71f9683..7bfe803 100644 --- a/blivet/devices/storage.py +++ b/blivet/devices/storage.py @@ -545,6 +545,8 @@ class StorageDevice(Device): doc="The device's size, accounting for pending changes") def readCurrentSize(self): + log_method_call(self, exists=self.exists, path=self.path, + sysfsPath=self.sysfsPath, node_exists=os.path.exists(self.path)) size = Size(0) if self.exists and os.path.exists(self.path) and \ os.path.isdir(self.sysfsPath): diff --git a/blivet/devicetree.py b/blivet/devicetree.py index 33e4096..7c55d13 100644 --- a/blivet/devicetree.py +++ b/blivet/devicetree.py @@ -28,6 +28,7 @@ import pprint import copy from six import add_metaclass import pyudev +from collections import deque from .errors import CryptoError, DeviceError, DeviceTreeError, DiskLabelCommitError, FSError, InvalidDiskLabelError, LUKSError, MDRaidError, StorageError, UnusableConfigurationError from .devices import BTRFSDevice, BTRFSSubVolumeDevice, BTRFSVolumeDevice, BTRFSSnapShotDevice @@ -82,7 +83,7 @@ class DeviceTree(object): :class:`~.deviceaction.DeviceAction` instances can only be registered for leaf devices, except for resize actions. """ - _unsynchronized_methods = ['processActions'] + _unsynchronized_methods = ['processActions', 'ueventCB', 'waitForEventQueue'] def __init__(self, conf=None, passphrase=None, luksDict=None, iscsi=None, dasd=None): @@ -155,6 +156,7 @@ class DeviceTree(object): self.ueventNotifyCB = None self._pyudev_observer = None + self._uevent_queue = deque() def setDiskImages(self, images): """ Set the disk images and reflect them in exclusiveDisks. @@ -362,6 +364,8 @@ class DeviceTree(object): self._preProcessActions() for action in self._actions[:]: + print action + log.info("next action...") log.info("executing action: %s", action) if dryRun: continue @@ -380,22 +384,63 @@ class DeviceTree(object): action.execute(callbacks) + log.debug("setting udev queue") udev.settle() + log.debug("updating device names") for device in self._devices: # make sure we catch any renumbering parted does if device.exists and isinstance(device, PartitionDevice): device.updateName() device.format.device = device.path + log.debug("popping action") self._completed_actions.append(self._actions.pop(0)) + log.debug("done") + + self.waitForEventQueue() self._postProcessActions() ## ## uevent handling ## + def waitForEventQueue(self): + """ Wait until the event queue becomes empty. """ + import time + while self._uevent_queue: + time.sleep(1) + def ueventCB(self, action, info): - print action, udev.device_get_name(info) + """ Enqueue a uevent and handle it as soon as we can get the lock. """ + #print action, udev.device_get_name(info) + self._uevent_queue.append((action, info)) + self._handleUevent() + + def _dequeueEvent(self): + """ Dequeue an event, skipping over repeated events. """ + ret = None + while self._uevent_queue: + next_action, next_info = self._uevent_queue[0] + next_device_name = udev.device_get_name(next_info) + if (ret is not None and + (next_action != ret[0] or + next_device_name != udev.device_get_name(ret[1]))): + break + + ret = self._uevent_queue.popleft() + + return ret + + def _handleUevent(self): + """ Handle the next uevent in the queue. """ + log_method_call(self) + event = self._dequeueEvent() + if event is None: + log.debug("event queue is empty") + return + + action, info = event + log.debug("action=%s, info=%s", action, pprint.pformat(info)) notify = False device = None if action == "add": @@ -407,6 +452,7 @@ class DeviceTree(object): notify = True # TODO: update self.roots elif action == "change": + #log.debug("calling deviceChangedCB...") device = self.deviceChangedCB(info) notify = True else: @@ -495,6 +541,10 @@ class DeviceTree(object): (udev.device_is_md(new_info) or udev.device_is_dm(new_info))): return self.deviceAddedCB(info, force=True) + if not device: + log.warning("device not found: %s", pprint.pformat(info)) + return + if not device.format.exists: # # A policy must be decided upon for external events that conflict @@ -503,7 +553,7 @@ class DeviceTree(object): log.warning("ignoring change uevent on device with reformat scheduled") return - with device.lock: + with blivet_lock: # # Check for changes to the device itself. # @@ -523,9 +573,9 @@ class DeviceTree(object): label = udev.device_get_label(new_info) if device.format.type != "btrfs": - uuid_changed = (device.format.uuid != uuid) + uuid_changed = device.format.uuid and (device.format.uuid != uuid) else: - uuid_changed = (device.format.volUUID != uuid) + uuid_changed = device.format.volUUID and (device.format.volUUID != uuid) partitioned = (device.partitionable and new_info.get("ID_PART_TABLE_TYPE")) new_type = getFormat(udev.device_get_format(new_info)).type @@ -653,7 +703,9 @@ class DeviceTree(object): udev.device_get_name(new)) self.addUdevDevice(new) else: + print device.format.type, uuid # update filesystem label, &c in case they were changed + log.debug("updating %s on %s...", device.format.type, device.name) device.format.uuid = uuid if hasattr(device.format, "label"): @@ -1038,10 +1090,6 @@ class DeviceTree(object): # cciss in sysfs is "cciss!cXdYpZ" but we need "cciss/cXdYpZ" slave_name = udev.device_get_name(slave_info).replace("!", "/") - if udev.device_is_dm(slave_info): - slave_name = dm.name_from_dm_node(slave_name) - elif udev.device_is_md(slave_info): - slave_name = mdraid.name_from_md_node(slave_name) if not slave_info: log.warning("unable to get udev info for %s", slave_name) @@ -1052,6 +1100,11 @@ class DeviceTree(object): self.addUdevDevice(slave_info) slave_dev = self.getDeviceByName(slave_name) if slave_dev is None: + if udev.device_is_dm_lvm(info): + if slave_name not in self.lvInfo: + # we do not expect hidden lvs to be in the tree + continue + # if the current slave is still not in # the tree, something has gone wrong log.error("failure scanning device %s: could not add slave %s", name, slave_name) @@ -1066,7 +1119,6 @@ class DeviceTree(object): def addUdevLVDevice(self, info): name = udev.device_get_name(info) log_method_call(self, name=name) - sysfs_path = udev.device_get_sysfs_path(info) vg_name = udev.device_get_lv_vg_name(info) device = self.getDeviceByName(vg_name, hidden=True) @@ -1074,7 +1126,7 @@ class DeviceTree(object): log.warning("found non-vg device with name %s", vg_name) device = None - self._addSlaveDevices(sysfs_path) + self._addSlaveDevices(info) # LVM provides no means to resolve conflicts caused by duplicated VG # names, so we're just being optimistic here. Woo! @@ -2307,19 +2359,30 @@ class DeviceTree(object): log.debug("%s", filedev) loop_name = loop.get_loop_name(filedev.path) - loop_sysfs = None - if loop_name: - loop_sysfs = "/class/block/%s" % loop_name - loopdev = LoopDevice(name=loop_name, + if not loop_name: + loop.loop_setup(filedev.path) + loop_name = loop.get_loop_name(filedev.path) + + loop_sysfs = "/sys/class/block/%s" % loop_name + + loopdev = self.getDeviceByName(loop_name) + if loopdev is None: + loopdev = LoopDevice(name=loop_name, parents=[filedev], sysfsPath=loop_sysfs, exists=True) - loopdev.setup() + else: + loopdev.parents = [filedev] + + loopdev.updateSysfsPath() + loopdev.updateSize() + log.debug("%s", loopdev) dmdev = DMLinearDevice(name, dmUuid="ANACONDA-%s" % name, parents=[loopdev], exists=True) + dmdev.updateSize() dmdev.setup() dmdev.updateSysfsPath() log.debug("%s", dmdev) diff --git a/blivet/formats/__init__.py b/blivet/formats/__init__.py index 06234b9..5351c8f 100644 --- a/blivet/formats/__init__.py +++ b/blivet/formats/__init__.py @@ -360,6 +360,7 @@ class DeviceFormat(ObjectID): type=self.type, status=self.status) try: rc = run_program(["wipefs", "-f", "-a", self.device]) + log.debug("wiped it") except OSError as e: err = str(e) else: @@ -372,6 +373,7 @@ class DeviceFormat(ObjectID): raise FormatDestroyError(msg) self.exists = False + log.debug("done w/ DeviceFormat.destroy") def setup(self, **kwargs): """ Activate the formatting. diff --git a/blivet/storage_log.py b/blivet/storage_log.py index 6ee694c..cdbbcfb 100644 --- a/blivet/storage_log.py +++ b/blivet/storage_log.py @@ -3,6 +3,8 @@ import logging import sys import traceback +from .threads import blivet_lock + log = logging.getLogger("blivet") log.addHandler(logging.NullHandler()) @@ -20,6 +22,7 @@ def function_name_and_depth(): return ("unknown function?", 0) def log_method_call(d, *args, **kwargs): + blivet_lock.acquire() classname = d.__class__.__name__ (methodname, depth) = function_name_and_depth() spaces = depth * ' ' @@ -37,14 +40,17 @@ def log_method_call(d, *args, **kwargs): fmt_args.extend([k, v]) log.debug(fmt, *fmt_args) + blivet_lock.release() def log_method_return(d, retval): + blivet_lock.acquire() classname = d.__class__.__name__ (methodname, depth) = function_name_and_depth() spaces = depth * ' ' fmt = "%s%s.%s returned %s" fmt_args = (spaces, classname, methodname, retval) log.debug(fmt, *fmt_args) + blivet_lock.release() def log_exception_info(log_func=log.debug, fmt_str=None, fmt_args=None, ignored=True): """Log detailed exception information. @@ -62,6 +68,7 @@ def log_exception_info(log_func=log.debug, fmt_str=None, fmt_args=None, ignored= Note: If the ignored flag is set, each line of the exception information is prepended with an 'IGNORED' prefix. """ + blivet_lock.acquire() fmt_args = fmt_args or [] (_methodname, depth) = function_name_and_depth() indent = depth * ' ' @@ -75,3 +82,5 @@ def log_exception_info(log_func=log.debug, fmt_str=None, fmt_args=None, ignored= for line in (l.rstrip() for entry in tb for l in entry.split("\n") if l): log_func("%s %s", prefix, line) log_func("%sEnd exception details.", prefix) + blivet_lock.release() + diff --git a/examples/common.py b/examples/common.py index 110026f..c492829 100644 --- a/examples/common.py +++ b/examples/common.py @@ -1,6 +1,7 @@ def print_devices(b): for device in sorted(b.devices, key=lambda d: len(d.ancestors)): - print(device) # this is a blivet.devices.StorageDevice instance + #print(device) # this is a blivet.devices.StorageDevice instance + print "%s(%s) %s" % (device.name, device.size, device.fstabSpec) - print() + print diff --git a/examples/partitioning.py b/examples/partitioning.py index 1e4f0db..71bd299 100644 --- a/examples/partitioning.py +++ b/examples/partitioning.py @@ -6,7 +6,7 @@ import blivet from blivet.size import Size from blivet.util import set_up_logging, create_sparse_tempfile -set_up_logging() +#set_up_logging() b = blivet.Blivet() # create an instance of Blivet (don't add system devices) # create two disk image files on which to create new devices @@ -16,6 +16,7 @@ disk2_file = create_sparse_tempfile("disk2", Size("100GiB")) b.config.diskImages["disk2"] = disk2_file b.reset() +b.devicetree.enableUeventMonitoring() try: disk1 = b.devicetree.getDeviceByName("disk1") @@ -47,6 +48,7 @@ try: # write the new partitions to disk and format them as specified b.doIt() + b.devicetree.waitForEventQueue() print_devices(b) finally: b.devicetree.teardownDiskImages()