Nir Soffer has posted comments on this change.
Change subject: Improve logging on some filesystem operations ......................................................................
Patch Set 2:
(10 comments)
I agree with Allon, that we better have the logs *before* the operation, and not after the operation.
If the operation blocks, we will have a clue about what we were doing (e.g. last message seen was creating a symlink).
When the operation fails, we get an error log or an exception is raised, so another log is not needed.
If the operation succeeded, we usually do not need a log, except if we like to know how much time the operation took, but I don't see such need currently.
Note also the capitalization - our logs are mostly capitalized.
http://gerrit.ovirt.org/#/c/26046/2/vdsm/storage/blockVolume.py File vdsm/storage/blockVolume.py:
Line 434: self.validateImagePath() Line 435: volPath = os.path.join(self.imagePath, self.volUUID) Line 436: if not os.path.lexists(volPath): Line 437: os.symlink(lvm.lvPath(self.sdUUID, self.volUUID), volPath) Line 438: self.log.debug("Creating symlink to %s", volPath) Here we need the src path in the log, which will make the code easier to read:
lvPath = lvm.lvPath(self.sdUUID, self.volUUID) self.log.debug("Creating symlink from %s to %s", lvPath, volPath) Line 439: self.volumePath = volPath Line 440: Line 441: def getVolumeTag(self, tagPrefix): Line 442: return _getVolumeTag(self.sdUUID, self.volUUID, tagPrefix)
http://gerrit.ovirt.org/#/c/26046/2/vdsm/storage/fileSD.py File vdsm/storage/fileSD.py:
Line 345: def deleteImage(self, sdUUID, imgUUID, volsImgs): Line 346: currImgDir = self.getImagePath(imgUUID) Line 347: dirName, baseName = os.path.split(currImgDir) Line 348: toDelDir = os.tempnam(dirName, sd.REMOVED_IMAGE_PREFIX + baseName) Line 349: try: Lets log this also Line 350: self.oop.os.rename(currImgDir, toDelDir) Line 351: except OSError as e: Line 352: self.log.error("image: %s can't be moved", currImgDir) Line 353: raise se.ImageDeleteError("%s %s" % (imgUUID, str(e)))
Line 356: try: Line 357: self.oop.os.remove(volPath) Line 358: self.oop.os.remove(volPath + '.meta') Line 359: self.oop.os.remove(volPath + '.lease') Line 360: self.log.debug("Removed volume: %s", volPath) Consider adding log for each oop operation. If one on them got stuck, it will be more clear. Line 361: except OSError: Line 362: self.log.error("vol: %s can't be removed.", Line 363: volPath, exc_info=True) Line 364: try:
Line 360: self.log.debug("Removed volume: %s", volPath) Line 361: except OSError: Line 362: self.log.error("vol: %s can't be removed.", Line 363: volPath, exc_info=True) Line 364: try: And this one also Line 365: self.oop.os.rmdir(toDelDir) Line 366: except OSError as e: Line 367: self.log.error("removed image dir: %s can't be removed", toDelDir) Line 368: raise se.ImageDeleteError("%s %s" % (imgUUID, str(e)))
Line 442: imgRunDir = os.path.join(sdRunDir, imgUUID) Line 443: try: Line 444: os.symlink(srcImgPath, imgRunDir) Line 445: self.log.debug("Created img run dir from %s to %s", srcImgPath, Line 446: imgRunDir) This should use the same log format as other symlinks: "Creating symlink from %s to %s". Line 447: except OSError as e: Line 448: if e.errno == errno.EEXIST: Line 449: self.log.debug("img run dir already exists: %s", imgRunDir) Line 450: else:
Line 464: # (ordered volUUIDs) we fix them all. Line 465: imgDir = os.path.join(self.mountpoint, self.sdUUID, sd.DOMAIN_IMAGES, Line 466: imgUUID) Line 467: volPaths = tuple(os.path.join(imgDir, v) for v in volUUIDs) Line 468: for volPath in volPaths: This looks log worthy - "Fixing permissions on %s" - what do you think? Line 469: self.oop.fileUtils.copyUserModeToGroup(volPath) Line 470: Line 471: return self.createImageLinks(imgDir, imgUUID) Line 472:
Line 606: for volFile in volFiles: Line 607: tLink = os.path.join(basePath, rImg, volFile) Line 608: tVol = os.path.join(basePath, templateImage, volFile) Line 609: self.oop.utils.forceLink(tVol, tLink) Line 610: self.log.debug("Relinking %s to %s", tVol, tLink) Lets use the term "Force linking %s to %f", and "Linking %s to %s" for standard links. Line 611: Line 612: Line 613: def getMountsList(pattern="*"): Line 614: finalPat = os.path.join(sd.StorageDomain.storage_repository,
http://gerrit.ovirt.org/#/c/26046/2/vdsm/storage/fileVolume.py File vdsm/storage/fileVolume.py:
Line 285: """ Line 286: metaPath = self._getMetaVolumePath() Line 287: if self.oop.os.path.lexists(metaPath): Line 288: self.oop.os.unlink(metaPath) Line 289: self.log.debug("Removing metadada: %s", metaPath) I think the path already includes "metadata" Line 290: Line 291: def getMetadataId(self): Line 292: """ Line 293: Get the metadata Id
http://gerrit.ovirt.org/#/c/26046/2/vdsm/storage/sp.py File vdsm/storage/sp.py:
Line 1127: tmp_link_name = os.path.join(self.storage_repository, Line 1128: str(uuid.uuid4())) Line 1129: os.symlink(src, tmp_link_name) # make tmp_link Line 1130: os.rename(tmp_link_name, linkName) Line 1131: self.log.debug("Storage domain linked from %s to %s", src, linkName) _linkStorageDomain is included in the logging message automatically, so we can use standard terms like "Linking %s to %s". Line 1132: Line 1133: @unsecured Line 1134: def _cleanupDomainLinks(self, domain): Line 1135: linkPath = os.path.join(self.poolPath, domain)
Line 1134: def _cleanupDomainLinks(self, domain): Line 1135: linkPath = os.path.join(self.poolPath, domain) Line 1136: try: Line 1137: os.remove(linkPath) Line 1138: self.log.debug("Removed domain link: %s", linkPath) Same as above. Line 1139: except (OSError, IOError): Line 1140: pass Line 1141: Line 1142: @unsecured