commit: 205d41608e55f78b620f8c3a0cb204c88df041ee Author: Mike Gilbert <floppym <AT> gentoo <DOT> org> AuthorDate: Sat Jul 9 04:26:12 2022 +0000 Commit: Mike Gilbert <floppym <AT> gentoo <DOT> org> CommitDate: Mon Aug 1 17:30:28 2022 +0000 URL: https://gitweb.gentoo.org/proj/portage.git/commit/?id=205d4160
Avoid calling root-level logging functions Instead, establish a named logger in each module. This will allow for easier filtering of log messages if we ever expand the use of the logging module. Closes: https://github.com/gentoo/portage/pull/849 Signed-off-by: Mike Gilbert <floppym <AT> gentoo.org> bin/doins.py | 8 +++-- lib/portage/_emirrordist/Config.py | 10 +++---- lib/portage/_emirrordist/ContentDB.py | 6 ++-- lib/portage/_emirrordist/DeletionIterator.py | 8 +++-- lib/portage/_emirrordist/DeletionTask.py | 28 +++++++++--------- lib/portage/_emirrordist/FetchTask.py | 44 +++++++++++++++------------- lib/portage/_emirrordist/MirrorDistTask.py | 36 +++++++++++------------ lib/portage/eapi.py | 2 ++ lib/portage/util/shelve.py | 4 ++- 9 files changed, 79 insertions(+), 67 deletions(-) diff --git a/bin/doins.py b/bin/doins.py index 087756218..7905c5c0d 100644 --- a/bin/doins.py +++ b/bin/doins.py @@ -26,6 +26,8 @@ import sys from portage.util import movefile from portage.util.file_copy import copyfile +logger = logging.getLogger("portage.bin.doins") + def _warn(helper, msg): """Output warning message to stderr. @@ -199,7 +201,7 @@ class _InsInProcessInstallRunner: if self._parsed_options.preserve_timestamps: _set_timestamps(sstat, dest) except Exception: - logging.exception( + logger.exception( "Failed to copy file: " "_parsed_options=%r, source=%r, dest_dir=%r", self._parsed_options, source, @@ -383,7 +385,7 @@ class _InstallRunner: except Exception: if self._helpers_can_die: raise - logging.exception("install_dir failed.") + logger.exception("install_dir failed.") def _doins(opts, install_runner, relpath, source_root): @@ -428,7 +430,7 @@ def _doins(opts, install_runner, relpath, source_root): os.symlink(linkto, dest) return True except Exception: - logging.exception( + logger.exception( "Failed to create symlink: " "opts=%r, relpath=%r, source_root=%r", opts, relpath, diff --git a/lib/portage/_emirrordist/Config.py b/lib/portage/_emirrordist/Config.py index 78b7a482a..734313c07 100644 --- a/lib/portage/_emirrordist/Config.py +++ b/lib/portage/_emirrordist/Config.py @@ -12,6 +12,8 @@ from portage.package.ebuild.fetch import MirrorLayoutConfig from portage.util import grabdict, grablines from .ContentDB import ContentDB +logger = logging.getLogger(__name__) + class Config: def __init__(self, options, portdb, event_loop): @@ -89,13 +91,11 @@ class Config: def _open_log(self, log_desc, log_path, mode): if log_path is None or getattr(self.options, "dry_run", False): - log_func = logging.info + log_func = logger.info line_format = "%s: %%s" % log_desc add_newline = False if log_path is not None: - logging.warning( - "dry-run: %s log " "redirected to logging.info" % log_desc - ) + logger.warning("dry-run: %s log redirected to logging.info" % log_desc) else: self._open_files.append(io.open(log_path, mode=mode, encoding="utf_8")) line_format = "%s\n" @@ -137,7 +137,7 @@ class Config: db = dbshelve.open(db_file, flags=open_flag) if dry_run: - logging.warning("dry-run: %s db opened in readonly mode" % db_desc) + logger.warning("dry-run: %s db opened in readonly mode" % db_desc) if not isinstance(db, dict): volatile_db = dict((k, db[k]) for k in db) db.close() diff --git a/lib/portage/_emirrordist/ContentDB.py b/lib/portage/_emirrordist/ContentDB.py index 6a5efbe95..ac6140257 100644 --- a/lib/portage/_emirrordist/ContentDB.py +++ b/lib/portage/_emirrordist/ContentDB.py @@ -8,6 +8,8 @@ import typing from portage.package.ebuild.fetch import DistfileName +logger = logging.getLogger(__name__) + class ContentDB: """ @@ -110,10 +112,10 @@ class ContentDB: pass if remaining: - logging.debug(("drop '%s' revision(s) from content db") % filename) + logger.debug(("drop '%s' revision(s) from content db") % filename) self._shelve[distfile_key] = remaining else: - logging.debug(("drop '%s' from content db") % filename) + logger.debug(("drop '%s' from content db") % filename) try: del self._shelve[distfile_key] except KeyError: diff --git a/lib/portage/_emirrordist/DeletionIterator.py b/lib/portage/_emirrordist/DeletionIterator.py index 59abce82f..6273ad281 100644 --- a/lib/portage/_emirrordist/DeletionIterator.py +++ b/lib/portage/_emirrordist/DeletionIterator.py @@ -9,6 +9,8 @@ from portage import os from portage.package.ebuild.fetch import DistfileName from .DeletionTask import DeletionTask +logger = logging.getLogger(__name__) + class DeletionIterator: def __init__(self, config): @@ -61,7 +63,7 @@ class DeletionIterator: break else: if exceptions: - logging.error( + logger.error( "stat failed on '%s' in distfiles: %s\n" % (filename, "; ".join(str(x) for x in exceptions)) ) @@ -103,7 +105,7 @@ class DeletionIterator: deletion_entry = deletion_db.get(filename) if deletion_entry is None: - logging.debug("add '%s' to deletion db" % filename) + logger.debug("add '%s' to deletion db" % filename) deletion_db[filename] = start_time elif deletion_entry + deletion_delay <= start_time: @@ -123,4 +125,4 @@ class DeletionIterator: except KeyError: pass else: - logging.debug("drop '%s' from deletion db" % filename) + logger.debug("drop '%s' from deletion db" % filename) diff --git a/lib/portage/_emirrordist/DeletionTask.py b/lib/portage/_emirrordist/DeletionTask.py index 7066e57a7..a5d96a9d9 100644 --- a/lib/portage/_emirrordist/DeletionTask.py +++ b/lib/portage/_emirrordist/DeletionTask.py @@ -9,6 +9,8 @@ from portage.package.ebuild.fetch import ContentHashLayout from portage.util._async.FileCopier import FileCopier from _emerge.CompositeTask import CompositeTask +logger = logging.getLogger(__name__) + class DeletionTask(CompositeTask): @@ -18,19 +20,17 @@ class DeletionTask(CompositeTask): if self.config.options.recycle_dir is not None: recycle_path = os.path.join(self.config.options.recycle_dir, self.distfile) if self.config.options.dry_run: - logging.info( + logger.info( ("dry-run: move '%s' from " "distfiles to recycle") % self.distfile ) else: - logging.debug( - ("move '%s' from " "distfiles to recycle") % self.distfile - ) + logger.debug(("move '%s' from " "distfiles to recycle") % self.distfile) try: # note: distfile_path can be a symlink here os.rename(os.path.realpath(self.distfile_path), recycle_path) except OSError as e: if e.errno != errno.EXDEV: - logging.error( + logger.error( ("rename %s from distfiles to " "recycle failed: %s") % (self.distfile, e) ) @@ -52,14 +52,14 @@ class DeletionTask(CompositeTask): success = True if self.config.options.dry_run: - logging.info(("dry-run: delete '%s' from " "distfiles") % self.distfile) + logger.info(("dry-run: delete '%s' from " "distfiles") % self.distfile) else: - logging.debug(("delete '%s' from " "distfiles") % self.distfile) + logger.debug(("delete '%s' from " "distfiles") % self.distfile) try: os.unlink(self.distfile_path) except OSError as e: if e.errno not in (errno.ENOENT, errno.ESTALE): - logging.error( + logger.error( "%s unlink failed in distfiles: %s" % (self.distfile, e) ) success = False @@ -85,13 +85,13 @@ class DeletionTask(CompositeTask): os.unlink(copier.src_path) except OSError as e: if e.errno not in (errno.ENOENT, errno.ESTALE): - logging.error( + logger.error( "%s unlink failed in distfiles: %s" % (self.distfile, e) ) success = False else: - logging.error( + logger.error( ("%s copy from distfiles " "to recycle failed: %s") % (self.distfile, copier.future.exception()) ) @@ -109,7 +109,7 @@ class DeletionTask(CompositeTask): success = True for layout in self.config.layouts: if isinstance(layout, ContentHashLayout) and not self.distfile.digests: - logging.debug(("_delete_links: '%s' has " "no digests") % self.distfile) + logger.debug(("_delete_links: '%s' has " "no digests") % self.distfile) continue distfile_path = os.path.join( self.config.options.distfiles, layout.get_path(self.distfile) @@ -118,7 +118,7 @@ class DeletionTask(CompositeTask): os.unlink(distfile_path) except OSError as e: if e.errno not in (errno.ENOENT, errno.ESTALE): - logging.error( + logger.error( "%s unlink failed in distfiles: %s" % (self.distfile, e) ) success = False @@ -144,7 +144,7 @@ class DeletionTask(CompositeTask): except KeyError: pass else: - logging.debug(("drop '%s' from " "distfiles db") % self.distfile) + logger.debug(("drop '%s' from " "distfiles db") % self.distfile) if self.config.content_db is not None: self.config.content_db.remove(self.distfile) @@ -155,4 +155,4 @@ class DeletionTask(CompositeTask): except KeyError: pass else: - logging.debug(("drop '%s' from " "deletion db") % self.distfile) + logger.debug(("drop '%s' from " "deletion db") % self.distfile) diff --git a/lib/portage/_emirrordist/FetchTask.py b/lib/portage/_emirrordist/FetchTask.py index 304837332..89fd1657e 100644 --- a/lib/portage/_emirrordist/FetchTask.py +++ b/lib/portage/_emirrordist/FetchTask.py @@ -17,6 +17,8 @@ from portage.util._async.PipeLogger import PipeLogger from portage.util._async.PopenProcess import PopenProcess from _emerge.CompositeTask import CompositeTask +logger = logging.getLogger(__name__) + default_hash_name = portage.const.MANIFEST2_HASH_DEFAULT # Use --no-check-certificate since Manifest digests should provide @@ -91,7 +93,7 @@ class FetchTask(CompositeTask): self.scheduler.output( msg + "\n", background=True, log_path=self._log_path ) - logging.error(msg) + logger.error(msg) else: break @@ -100,7 +102,7 @@ class FetchTask(CompositeTask): if not size_ok: if self.config.options.dry_run: if st is not None: - logging.info( + logger.info( ("dry-run: delete '%s' with " "wrong size from distfiles") % (self.distfile,) ) @@ -115,7 +117,7 @@ class FetchTask(CompositeTask): ) if self._unlink_file(unlink_path, "distfiles"): if st is not None: - logging.debug( + logger.debug( ("delete '%s' with " "wrong size from distfiles") % (self.distfile,) ) @@ -172,14 +174,14 @@ class FetchTask(CompositeTask): if self.config.options.dry_run: if os.path.exists(recycle_file): - logging.info("dry-run: delete '%s' from recycle" % (self.distfile,)) + logger.info("dry-run: delete '%s' from recycle" % (self.distfile,)) else: try: os.unlink(recycle_file) except OSError: pass else: - logging.debug("delete '%s' from recycle" % (self.distfile,)) + logger.debug("delete '%s' from recycle" % (self.distfile,)) def _distfiles_digester_exit(self, digester): @@ -195,7 +197,7 @@ class FetchTask(CompositeTask): # from the administrator. msg = "%s distfiles digester failed unexpectedly" % (self.distfile,) self.scheduler.output(msg + "\n", background=True, log_path=self._log_path) - logging.error(msg) + logger.error(msg) self.config.log_failure("%s\t%s\t%s" % (self.cpv, self.distfile, msg)) self.config.file_failures[self.distfile] = self.cpv self.wait() @@ -312,7 +314,7 @@ class FetchTask(CompositeTask): self.scheduler.output( msg + "\n", background=True, log_path=self._log_path ) - logging.error(msg) + logger.error(msg) else: size_ok = st.st_size == self.digests["size"] self._current_stat = st @@ -345,7 +347,7 @@ class FetchTask(CompositeTask): current_mirror.name, ) self.scheduler.output(msg + "\n", background=True, log_path=self._log_path) - logging.error(msg) + logger.error(msg) else: bad_digest = self._find_bad_digest(digester.digests) if bad_digest is not None: @@ -359,18 +361,18 @@ class FetchTask(CompositeTask): self.scheduler.output( msg + "\n", background=True, log_path=self._log_path ) - logging.error(msg) + logger.error(msg) elif self.config.options.dry_run: # Report success without actually touching any files if self._same_device( current_mirror.location, self.config.options.distfiles ): - logging.info( + logger.info( ("dry-run: hardlink '%s' from %s " "to distfiles") % (self.distfile, current_mirror.name) ) else: - logging.info( + logger.info( "dry-run: copy '%s' from %s to distfiles" % (self.distfile, current_mirror.name) ) @@ -387,7 +389,7 @@ class FetchTask(CompositeTask): if self._hardlink_atomic( src, dest, "%s to %s" % (current_mirror.name, "distfiles") ): - logging.debug( + logger.debug( "hardlink '%s' from %s to distfiles" % (self.distfile, current_mirror.name) ) @@ -424,10 +426,10 @@ class FetchTask(CompositeTask): copier.future.exception(), ) self.scheduler.output(msg + "\n", background=True, log_path=self._log_path) - logging.error(msg) + logger.error(msg) else: - logging.debug( + logger.debug( "copy '%s' from %s to distfiles" % (self.distfile, current_mirror.name) ) @@ -447,7 +449,7 @@ class FetchTask(CompositeTask): self.scheduler.output( msg + "\n", background=True, log_path=self._log_path ) - logging.error(msg) + logger.error(msg) self._success() self.returncode = os.EX_OK @@ -460,7 +462,7 @@ class FetchTask(CompositeTask): if self.config.options.dry_run: # Simply report success. - logging.info("dry-run: fetch '%s' from '%s'" % (self.distfile, uri)) + logger.info("dry-run: fetch '%s' from '%s'" % (self.distfile, uri)) self._success() self.returncode = os.EX_OK self._async_wait() @@ -543,7 +545,7 @@ class FetchTask(CompositeTask): self._fetch_tmp_dir_info, ) self.scheduler.output(msg + "\n", background=True, log_path=self._log_path) - logging.error(msg) + logger.error(msg) else: bad_digest = self._find_bad_digest(digester.digests) if bad_digest is not None: @@ -608,7 +610,7 @@ class FetchTask(CompositeTask): copier.future.exception(), ) self.scheduler.output(msg + "\n", background=True, log_path=self._log_path) - logging.error(msg) + logger.error(msg) self.config.log_failure("%s\t%s\t%s" % (self.cpv, self.distfile, msg)) self.config.file_failures[self.distfile] = self.cpv self.returncode = 1 @@ -662,7 +664,7 @@ class FetchTask(CompositeTask): self.scheduler.output( msg + "\n", background=True, log_path=self._log_path ) - logging.error(msg) + logger.error(msg) return False return True @@ -720,7 +722,7 @@ class FetchTask(CompositeTask): self.scheduler.output( msg + "\n", background=True, log_path=self._log_path ) - logging.error(msg) + logger.error(msg) return False try: @@ -734,7 +736,7 @@ class FetchTask(CompositeTask): self.scheduler.output( msg + "\n", background=True, log_path=self._log_path ) - logging.error(msg) + logger.error(msg) return False finally: try: diff --git a/lib/portage/_emirrordist/MirrorDistTask.py b/lib/portage/_emirrordist/MirrorDistTask.py index 28164e645..9423125df 100644 --- a/lib/portage/_emirrordist/MirrorDistTask.py +++ b/lib/portage/_emirrordist/MirrorDistTask.py @@ -17,6 +17,8 @@ from _emerge.CompositeTask import CompositeTask from .FetchIterator import FetchIterator from .DeletionIterator import DeletionIterator +logger = logging.getLogger(__name__) + class MirrorDistTask(CompositeTask): @@ -99,14 +101,14 @@ class MirrorDistTask(CompositeTask): st = os.stat(recycle_file) except OSError as e: if e.errno not in (errno.ENOENT, errno.ESTALE): - logging.error( + logger.error( ("stat failed for '%s' in " "recycle: %s") % (filename, e) ) continue value = recycle_db_cache.pop(filename, None) if value is None: - logging.debug(("add '%s' to " "recycle db") % filename) + logger.debug(("add '%s' to " "recycle db") % filename) recycle_db[filename] = (st.st_size, start_time) else: r_size, r_time = value @@ -114,27 +116,25 @@ class MirrorDistTask(CompositeTask): recycle_db[filename] = (st.st_size, start_time) elif r_time + r_deletion_delay < start_time: if self._config.options.dry_run: - logging.info( - ("dry-run: delete '%s' from " "recycle") % filename - ) - logging.info(("drop '%s' from " "recycle db") % filename) + logger.info(("dry-run: delete '%s' from " "recycle") % filename) + logger.info(("drop '%s' from " "recycle db") % filename) else: try: os.unlink(recycle_file) except OSError as e: if e.errno not in (errno.ENOENT, errno.ESTALE): - logging.error( + logger.error( ("delete '%s' from " "recycle failed: %s") % (filename, e) ) else: - logging.debug(("delete '%s' from " "recycle") % filename) + logger.debug(("delete '%s' from " "recycle") % filename) try: del recycle_db[filename] except KeyError: pass else: - logging.debug( + logger.debug( ("drop '%s' from " "recycle db") % filename ) @@ -147,7 +147,7 @@ class MirrorDistTask(CompositeTask): except KeyError: pass else: - logging.debug(("drop non-existent '%s' from " "recycle db") % filename) + logger.debug(("drop non-existent '%s' from " "recycle db") % filename) def _scheduled_deletion_log(self): @@ -169,7 +169,7 @@ class MirrorDistTask(CompositeTask): date_files.append(filename) if dry_run: - logging.warning( + logger.warning( "dry-run: scheduled-deletions log " "will be summarized via logging.info" ) @@ -178,7 +178,7 @@ class MirrorDistTask(CompositeTask): for date in sorted(date_map): date_files = date_map[date] if dry_run: - logging.info( + logger.info( ("dry-run: scheduled deletions for %s: %s files") % (date, len(date_files)) ) @@ -202,12 +202,12 @@ class MirrorDistTask(CompositeTask): added_file_count = self._config.added_file_count added_byte_count = self._config.added_byte_count - logging.info("finished in %i seconds" % elapsed_time) - logging.info("failed to fetch %i files" % fail_count) - logging.info("deleted %i files" % delete_count) - logging.info("deletion of %i files scheduled" % scheduled_deletion_count) - logging.info("added %i files" % added_file_count) - logging.info("added %i bytes total" % added_byte_count) + logger.info("finished in %i seconds" % elapsed_time) + logger.info("failed to fetch %i files" % fail_count) + logger.info("deleted %i files" % delete_count) + logger.info("deletion of %i files scheduled" % scheduled_deletion_count) + logger.info("added %i files" % added_file_count) + logger.info("added %i bytes total" % added_byte_count) def _cleanup(self): """ diff --git a/lib/portage/eapi.py b/lib/portage/eapi.py index 2c1701870..969cf9027 100644 --- a/lib/portage/eapi.py +++ b/lib/portage/eapi.py @@ -7,6 +7,8 @@ from typing import Optional from portage import eapi_is_supported +logger = logging.getLogger(__name__) + def eapi_has_iuse_defaults(eapi: str) -> bool: return _get_eapi_attrs(eapi).iuse_defaults diff --git a/lib/portage/util/shelve.py b/lib/portage/util/shelve.py index 6100c8719..85d5829f3 100644 --- a/lib/portage/util/shelve.py +++ b/lib/portage/util/shelve.py @@ -5,6 +5,8 @@ import logging import pickle import shelve +logger = logging.getLogger(__name__) + def open_shelve(db_file, flag="r"): """ @@ -36,7 +38,7 @@ def dump(args): try: value = src[key] except KeyError: - logging.exception(key) + logger.exception(key) continue pickle.dump((key, value), dest) finally:
