From 03f6cb4e7e106bc227ad781a515338097fba26f9 Mon Sep 17 00:00:00 2001 From: torzdf <36920800+torzdf@users.noreply.github.com> Date: Thu, 28 Jul 2022 23:53:31 +0100 Subject: [PATCH] setup.py: implement logging --- .install/linux/faceswap_setup_x64.sh | 2 +- .install/windows/install.nsi | 2 +- docs/full/modules.rst | 2 + docs/full/setup.rst | 8 + docs/full/update_deps.rst | 8 + lib/gui/custom_widgets.py | 24 +- lib/gui/menu.py | 59 +- lib/logger.py | 201 +++++-- requirements/_requirements_base.txt | 2 +- setup.cfg | 2 + setup.py | 787 ++++++++++++++++----------- update_deps.py | 38 +- 12 files changed, 732 insertions(+), 403 deletions(-) create mode 100644 docs/full/setup.rst create mode 100644 docs/full/update_deps.rst diff --git a/.install/linux/faceswap_setup_x64.sh b/.install/linux/faceswap_setup_x64.sh index 980540fb..49e3450c 100644 --- a/.install/linux/faceswap_setup_x64.sh +++ b/.install/linux/faceswap_setup_x64.sh @@ -385,7 +385,7 @@ setup_faceswap() { # Run faceswap setup script info "Setting up Faceswap..." if [ $VERSION != "cpu" ] ; then args="--$VERSION" ; else args="" ; fi - python "$DIR_FACESWAP/setup.py" --installer $args + python -u "$DIR_FACESWAP/setup.py" --installer $args } create_gui_launcher () { diff --git a/.install/windows/install.nsi b/.install/windows/install.nsi index 277a0228..eda5f6c2 100644 --- a/.install/windows/install.nsi +++ b/.install/windows/install.nsi @@ -448,7 +448,7 @@ Function SetupFaceSwap StrCpy $0 "$0 --$setupType" ${EndIf} SetDetailsPrint listonly - ExecDos::exec /NOUNLOAD /ASYNC /DETAILED "$\"$dirConda\scripts\activate.bat$\" && conda activate $\"$envName$\" && python $\"$INSTDIR\setup.py$\" $0 && conda deactivate" + ExecDos::exec /NOUNLOAD /ASYNC /DETAILED "$\"$dirConda\scripts\activate.bat$\" && conda activate $\"$envName$\" && python -u $\"$INSTDIR\setup.py$\" $0 && conda deactivate" pop $0 ExecDos::wait $0 pop $0 diff --git a/docs/full/modules.rst b/docs/full/modules.rst index 8dd05810..1286cb4a 100644 --- a/docs/full/modules.rst +++ b/docs/full/modules.rst @@ -8,3 +8,5 @@ faceswap plugins/plugins scripts tools/tools + setup + update_deps diff --git a/docs/full/setup.rst b/docs/full/setup.rst new file mode 100644 index 00000000..baa29b9f --- /dev/null +++ b/docs/full/setup.rst @@ -0,0 +1,8 @@ +************ +setup module +************ + +.. automodule:: setup + :members: + :undoc-members: + :show-inheritance: \ No newline at end of file diff --git a/docs/full/update_deps.rst b/docs/full/update_deps.rst new file mode 100644 index 00000000..aea4753e --- /dev/null +++ b/docs/full/update_deps.rst @@ -0,0 +1,8 @@ +****************** +update_deps module +****************** + +.. automodule:: update_deps + :members: + :undoc-members: + :show-inheritance: \ No newline at end of file diff --git a/lib/gui/custom_widgets.py b/lib/gui/custom_widgets.py index 01e19c09..007a7678 100644 --- a/lib/gui/custom_widgets.py +++ b/lib/gui/custom_widgets.py @@ -238,6 +238,7 @@ class _SysOutRouter(): self._console = console self._out_type = out_type self._recolor = re.compile(r".+?(\s\d+:\d+:\d+\s)(?P[A-Z]+)\s") + self._ansi_escape = re.compile(r"\x1B(?:[@-Z\\-_]|\[[0-?]*[ -/]*[@-~])") logger.debug("Initialized %s", self.__class__.__name__) def _get_tag(self, string): @@ -254,6 +255,7 @@ class _SysOutRouter(): def write(self, string): """ Capture stdout/stderr """ + string = self._ansi_escape.sub("", string) self._console.insert(tk.END, string, self._get_tag(string)) self._console.see(tk.END) @@ -315,9 +317,8 @@ class _WidgetRedirector: tk_.createcommand(wgt, self.dispatch) def __repr__(self): - return "%s(%s<%s>)" % (self.__class__.__name__, - self.widget.__class__.__name__, - self.widget._w) # pylint:disable=protected-access + return (f"{self.__class__.__name__}({self.widget.__class__.__name__}" + f"<{self.widget._w}>)") # pylint:disable=protected-access def close(self): "de-register operations and revert redirection created by .__init__." @@ -409,8 +410,7 @@ class _OriginalCommand: self.orig_and_operation = (redirect.orig, operation) def __repr__(self): - return "%s(%r, %r)" % (self.__class__.__name__, - self.redirect, self.operation) + return f"{self.__class__.__name__}({self.redirect}, {self.operation})" def __call__(self, *args): return self.tk_call(self.orig_and_operation + args) @@ -619,12 +619,8 @@ class Tooltip: # pylint:disable=too-few-public-methods x_1, y_1 = mouse_x + tip_delta[0], mouse_y + tip_delta[1] x_2, y_2 = x_1 + width, y_1 + height - x_delta = x_2 - s_width - if x_delta < 0: - x_delta = 0 - y_delta = y_2 - s_height - if y_delta < 0: - y_delta = 0 + x_delta = max(x_2 - s_width, 0) + y_delta = max(y_2 - s_height, 0) offscreen = (x_delta, y_delta) != (0, 0) @@ -670,7 +666,7 @@ class Tooltip: # pylint:disable=too-few-public-methods text = self._text if self._text_variable and self._text_variable.get(): - text += "\n\nCurrent value: '{}'".format(self._text_variable.get()) + text += f"\n\nCurrent value: '{self._text_variable.get()}'" label = tk.Label(win, text=text, justify=tk.LEFT, @@ -687,7 +683,7 @@ class Tooltip: # pylint:disable=too-few-public-methods xpos, ypos = tip_pos_calculator(widget, label) - self._topwidget.wm_geometry("+%d+%d" % (xpos, ypos)) + self._topwidget.wm_geometry(f"+{xpos}+{ypos}") def _hide(self): """ Hide the tooltip """ @@ -819,7 +815,7 @@ class PopupProgress(tk.Toplevel): center = np.array(( (self.master.winfo_width() // 2) - (self.winfo_width() // 2), (self.master.winfo_height() // 2) - (self.winfo_height() // 2))) + offset - self.wm_geometry("+{}+{}".format(*center)) + self.wm_geometry(f"+{center[0]}+{center[1]}") get_config().set_cursor_busy() self.grab_set() diff --git a/lib/gui/menu.py b/lib/gui/menu.py index f5f6aa16..370313d3 100644 --- a/lib/gui/menu.py +++ b/lib/gui/menu.py @@ -166,10 +166,10 @@ class FileMenu(tk.Menu): # pylint:disable=too-many-ancestors kwargs = dict(filename=filename) else: load_func = self._config.tasks.load - lbl = "{} Task".format(command) + lbl = f"{command} Task" kwargs = dict(filename=filename, current_tab=False) self.recent_menu.add_command( - label="{} ({})".format(filename, lbl.title()), + label=f"{filename} ({lbl.title()})", command=lambda kw=kwargs, fn=load_func: fn(**kw)) if removed_files: for recent_item in removed_files: @@ -188,7 +188,7 @@ class FileMenu(tk.Menu): # pylint:disable=too-many-ancestors def clear_recent_files(serializer, menu_file): """ Creates or clears recent file list """ logger.debug("clearing recent files list: '%s'", menu_file) - serializer.save(menu_file, list()) + serializer.save(menu_file, []) def refresh_recent_menu(self): """ Refresh recent menu on save/load of files """ @@ -263,9 +263,9 @@ class HelpMenu(tk.Menu): # pylint:disable=too-many-ancestors error then `None` is returned """ gitcmd = "git branch -a" - cmd = Popen(gitcmd, shell=True, stdout=PIPE, stderr=STDOUT, cwd=_WORKING_DIR) - stdout, _ = cmd.communicate() - retcode = cmd.poll() + with Popen(gitcmd, shell=True, stdout=PIPE, stderr=STDOUT, cwd=_WORKING_DIR) as cmd: + stdout, _ = cmd.communicate() + retcode = cmd.poll() if retcode != 0: logger.debug("Unable to list git branches. return code: %s, message: %s", retcode, stdout.decode().strip().replace("\n", " - ")) @@ -315,10 +315,10 @@ class HelpMenu(tk.Menu): # pylint:disable=too-many-ancestors The branch to switch to """ logger.info("Switching branch to '%s'...", branch) - gitcmd = "git checkout {}".format(branch) - cmd = Popen(gitcmd, shell=True, stdout=PIPE, stderr=STDOUT, cwd=_WORKING_DIR) - stdout, _ = cmd.communicate() - retcode = cmd.poll() + gitcmd = f"git checkout {branch}" + with Popen(gitcmd, shell=True, stdout=PIPE, stderr=STDOUT, cwd=_WORKING_DIR) as cmd: + stdout, _ = cmd.communicate() + retcode = cmd.poll() if retcode != 0: logger.error("Unable to switch branch. return code: %s, message: %s", retcode, stdout.decode().strip().replace("\n", " - ")) @@ -358,7 +358,7 @@ class HelpMenu(tk.Menu): # pylint:disable=too-many-ancestors from lib.sysinfo import sysinfo # pylint:disable=import-outside-toplevel info = sysinfo except Exception as err: # pylint:disable=broad-except - info = "Error obtaining system info: {}".format(str(err)) + info = f"Error obtaining system info: {str(err)}" self.clear_console() logger.debug("Obtained system information: %s", info) print(info) @@ -382,7 +382,7 @@ class HelpMenu(tk.Menu): # pylint:disable=too-many-ancestors success = False if self.check_for_updates(encoding): success = self.do_update(encoding) - update_deps.main(logger=logger) + update_deps.main(is_gui=True) if success: logger.info("Please restart Faceswap to complete the update.") self.root.config(cursor="") @@ -395,9 +395,9 @@ class HelpMenu(tk.Menu): # pylint:disable=too-many-ancestors update = False msg = "" gitcmd = "git remote update && git status -uno" - cmd = Popen(gitcmd, shell=True, stdout=PIPE, stderr=STDOUT, cwd=_WORKING_DIR) - stdout, _ = cmd.communicate() - retcode = cmd.poll() + with Popen(gitcmd, shell=True, stdout=PIPE, stderr=STDOUT, cwd=_WORKING_DIR) as cmd: + stdout, _ = cmd.communicate() + retcode = cmd.poll() if retcode != 0: msg = ("Git is not installed or you are not running a cloned repo. " "Unable to check for updates") @@ -427,15 +427,20 @@ class HelpMenu(tk.Menu): # pylint:disable=too-many-ancestors """ Update Faceswap """ logger.info("A new version is available. Updating...") gitcmd = "git pull" - cmd = Popen(gitcmd, shell=True, stdout=PIPE, stderr=STDOUT, bufsize=1, cwd=_WORKING_DIR) - while True: - output = cmd.stdout.readline().decode(encoding) - if output == "" and cmd.poll() is not None: - break - if output: - logger.debug("'%s' output: '%s'", gitcmd, output.strip()) - print(output.strip()) - retcode = cmd.poll() + with Popen(gitcmd, + shell=True, + stdout=PIPE, + stderr=STDOUT, + bufsize=1, + cwd=_WORKING_DIR) as cmd: + while True: + output = cmd.stdout.readline().decode(encoding) + if output == "" and cmd.poll() is not None: + break + if output: + logger.debug("'%s' output: '%s'", gitcmd, output.strip()) + print(output.strip()) + retcode = cmd.poll() logger.debug("'%s' returncode: %s", gitcmd, retcode) if retcode != 0: logger.info("An error occurred during update. return code: %s", retcode) @@ -482,7 +487,7 @@ class TaskBar(ttk.Frame): # pylint: disable=too-many-ancestors frame.pack(side=tk.LEFT, anchor=tk.W, expand=False, padx=2) for loadtype in ("load", "save", "save_as", "clear", "reload"): - btntype = "{}2".format(loadtype) + btntype = f"{loadtype}2" logger.debug("Adding button: '%s'", btntype) loader, kwargs = self._loader_and_kwargs(loadtype) @@ -507,7 +512,7 @@ class TaskBar(ttk.Frame): # pylint: disable=too-many-ancestors kwargs = dict(save_as=True) else: loader = btntype - kwargs = dict() + kwargs = {} logger.debug("btntype: %s, loader: %s, kwargs: %s", btntype, loader, kwargs) return loader, kwargs @@ -516,7 +521,7 @@ class TaskBar(ttk.Frame): # pylint: disable=too-many-ancestors frame = ttk.Frame(self._btn_frame) frame.pack(side=tk.LEFT, anchor=tk.W, expand=False, padx=2) for name in ("extract", "train", "convert"): - btntype = "settings_{}".format(name) + btntype = f"settings_{name}" btntype = btntype if btntype in get_images().icons else "settings" logger.debug("Adding button: '%s'", btntype) btn = ttk.Button( diff --git a/lib/logger.py b/lib/logger.py index 452080c3..255f0131 100644 --- a/lib/logger.py +++ b/lib/logger.py @@ -4,16 +4,19 @@ import collections import logging from logging.handlers import RotatingFileHandler import os +import platform +import re import sys +import time import traceback from datetime import datetime -from tqdm import tqdm +from typing import Union class FaceswapLogger(logging.Logger): """ A standard :class:`logging.logger` with additional "verbose" and "trace" levels added. """ - def __init__(self, name): + def __init__(self, name: str) -> None: for new_level in (("VERBOSE", 15), ("TRACE", 5)): level_name, level_num = new_level if hasattr(logging, level_name): @@ -22,7 +25,7 @@ class FaceswapLogger(logging.Logger): setattr(logging, level_name, level_num) super().__init__(name) - def verbose(self, msg, *args, **kwargs): + def verbose(self, msg: str, *args, **kwargs) -> None: # pylint:disable=wrong-spelling-in-docstring """ Create a log message at severity level 15. @@ -38,7 +41,7 @@ class FaceswapLogger(logging.Logger): if self.isEnabledFor(15): self._log(15, msg, args, **kwargs) - def trace(self, msg, *args, **kwargs): + def trace(self, msg: str, *args, **kwargs) -> None: # pylint:disable=wrong-spelling-in-docstring """ Create a log message at severity level 5. @@ -55,6 +58,102 @@ class FaceswapLogger(logging.Logger): self._log(5, msg, args, **kwargs) +class ColoredFormatter(logging.Formatter): + """ Overrides the stand :class:`logging.Formatter` to enable colored labels for message level + labels on supported platforms + + Parameters + ---------- + fmt: str + The format string for the message as a whole + pad_newlines: bool, Optional + If ``True`` new lines will be padded to appear in line with the log message, if ``False`` + they will be left aligned + + kwargs: dict + Standard :class:`logging.Formatter` keyword arguments + """ + def __init__(self, fmt: str, pad_newlines: bool = False, **kwargs) -> None: + super().__init__(fmt, **kwargs) + self._use_color = platform.system().lower() in ("linux", "darwin") + self._level_colors = dict(CRITICAL="\033[31m", # red + ERROR="\033[31m", # red + WARNING="\033[33m", # yellow + INFO="\033[32m", # green + VERBOSE="\033[34m") # blue + self._default_color = "\033[0m" + self._newline_padding = self._get_newline_padding(pad_newlines, fmt) + + def _get_newline_padding(self, pad_newlines: bool, fmt: str) -> int: + """ Parses the format string to obtain padding for newlines if requested + + Parameters + ---------- + fmt: str + The format string for the message as a whole + pad_newlines: bool, Optional + If ``True`` new lines will be padded to appear in line with the log message, if + ``False`` they will be left aligned + + Returns + ------- + int + The amount of padding to apply to the front of newlines + """ + if not pad_newlines: + return 0 + msg_idx = fmt.find("%(message)") + 1 + filtered = fmt[:msg_idx - 1] + spaces = filtered.count(" ") + pads = [int(pad.replace("s", "")) for pad in re.findall(r"\ds", filtered)] + if "asctime" in filtered: + pads.append(self._get_sample_time_string()) + return sum(pads) + spaces + + def _get_sample_time_string(self) -> int: + """ Obtain a sample time string and calculate correct padding. + + This may be inaccurate wheb ticking over an integer from single to double digits, but that + shouldn't be a huge issue. + + Returns + ------- + int + The length of the formatted date-time string + """ + sample_time = time.time() + date_format = self.datefmt if self.datefmt else self.default_time_format + datestring = time.strftime(date_format, logging.Formatter.converter(sample_time)) + if not self.datefmt and self.default_msec_format: + msecs = (sample_time - int(sample_time)) * 1000 + datestring = self.default_msec_format % (datestring, msecs) + return len(datestring) + + def format(self, record: logging.LogRecord) -> str: + """ Color the log message level if supported otherwise return the standard log message. + + Parameters + ---------- + record: :class:`logging.LogRecord` + The incoming log record to be formatted for entry into the logger. + + Returns + ------- + str + The formatted log message + """ + formatted = super().format(record) + levelname = record.levelname + if self._use_color and levelname in self._level_colors: + formatted = re.sub(levelname, + f"{self._level_colors[levelname]}{levelname}{self._default_color}", + formatted, + 1) + if self._newline_padding: + formatted = formatted.replace("\n", f"\n{' ' * self._newline_padding}") + return formatted + + class FaceswapFormatter(logging.Formatter): """ Overrides the standard :class:`logging.Formatter`. @@ -63,7 +162,7 @@ class FaceswapFormatter(logging.Formatter): Rewrites some upstream warning messages to debug level to avoid spamming the console. """ - def format(self, record): + def format(self, record: logging.LogRecord) -> str: """ Strip new lines from log records and rewrite certain warning messages to debug level. Parameters @@ -102,7 +201,7 @@ class FaceswapFormatter(logging.Formatter): return msg @classmethod - def _rewrite_warnings(cls, record): + def _rewrite_warnings(cls, record: logging.LogRecord) -> logging.LogRecord: """ Change certain warning messages from WARNING to DEBUG to avoid passing non-important information to output. @@ -133,7 +232,7 @@ class FaceswapFormatter(logging.Formatter): return record @classmethod - def _lower_external(cls, record): + def _lower_external(cls, record: logging.LogRecord) -> logging.LogRecord: """ Some external libs log at a higher level than we would really like, so lower their log level. @@ -162,7 +261,7 @@ class RollingBuffer(collections.deque): """File-like that keeps a certain number of lines of text in memory for writing out to the crash log. """ - def write(self, buffer): + def write(self, buffer: str) -> None: """ Splits lines from the incoming buffer and writes them out to the rolling buffer. Parameters @@ -178,7 +277,7 @@ class TqdmHandler(logging.StreamHandler): """ Overrides :class:`logging.StreamHandler` to use :func:`tqdm.tqdm.write` rather than writing to :func:`sys.stderr` so that log messages do not mess up tqdm progress bars. """ - def emit(self, record): + def emit(self, record: logging.LogRecord) -> None: """ Format the incoming message and pass to :func:`tqdm.tqdm.write`. Parameters @@ -186,11 +285,13 @@ class TqdmHandler(logging.StreamHandler): record : :class:`logging.LogRecord` The incoming log record to be formatted for entry into the logger. """ + # tqdm is imported here as it won't be installed when setup.py is running + from tqdm import tqdm # pylint:disable=import-outside-toplevel msg = self.format(record) tqdm.write(msg) -def _set_root_logger(loglevel=logging.INFO): +def _set_root_logger(loglevel: int = logging.INFO) -> logging.Logger: """ Setup the root logger. Parameters @@ -208,7 +309,7 @@ def _set_root_logger(loglevel=logging.INFO): return rootlogger -def log_setup(loglevel, log_file, command, is_gui=False): +def log_setup(loglevel, log_file: str, command: str, is_gui: bool = False) -> None: """ Set up logging for Faceswap. Sets up the root logger, the formatting for the crash logger and the file logger, and sets up @@ -230,19 +331,32 @@ def log_setup(loglevel, log_file, command, is_gui=False): numeric_loglevel = get_loglevel(loglevel) root_loglevel = min(logging.DEBUG, numeric_loglevel) rootlogger = _set_root_logger(loglevel=root_loglevel) - log_format = FaceswapFormatter("%(asctime)s %(processName)-15s %(threadName)-30s " - "%(module)-15s %(funcName)-30s %(levelname)-8s %(message)s", - datefmt="%m/%d/%Y %H:%M:%S") - f_handler = _file_handler(numeric_loglevel, log_file, log_format, command) - s_handler = _stream_handler(numeric_loglevel, is_gui) - c_handler = _crash_handler(log_format) + + if command == "setup": + log_format = FaceswapFormatter("%(asctime)s %(module)-16s %(funcName)-30s %(levelname)-8s " + "%(message)s", datefmt="%m/%d/%Y %H:%M:%S") + s_handler = _stream_setup_handler(numeric_loglevel) + f_handler = _file_handler(root_loglevel, log_file, log_format, command) + else: + log_format = FaceswapFormatter("%(asctime)s %(processName)-15s %(threadName)-30s " + "%(module)-15s %(funcName)-30s %(levelname)-8s %(message)s", + datefmt="%m/%d/%Y %H:%M:%S") + s_handler = _stream_handler(numeric_loglevel, is_gui) + f_handler = _file_handler(numeric_loglevel, log_file, log_format, command) + rootlogger.addHandler(f_handler) rootlogger.addHandler(s_handler) - rootlogger.addHandler(c_handler) - logging.info("Log level set to: %s", loglevel.upper()) + + if command != "setup": + c_handler = _crash_handler(log_format) + rootlogger.addHandler(c_handler) + logging.info("Log level set to: %s", loglevel.upper()) -def _file_handler(loglevel, log_file, log_format, command): +def _file_handler(loglevel, + log_file: str, + log_format: FaceswapFormatter, + command: str) -> RotatingFileHandler: """ Add a rotating file handler for the current Faceswap session. 1 backup is always kept. Parameters @@ -270,21 +384,21 @@ def _file_handler(loglevel, log_file, log_format, command): filename += "_gui.log" if command == "gui" else ".log" should_rotate = os.path.isfile(filename) - log_file = RotatingFileHandler(filename, backupCount=1, encoding="utf-8") + handler = RotatingFileHandler(filename, backupCount=1, encoding="utf-8") if should_rotate: - log_file.doRollover() - log_file.setFormatter(log_format) - log_file.setLevel(loglevel) - return log_file + handler.doRollover() + handler.setFormatter(log_format) + handler.setLevel(loglevel) + return handler -def _stream_handler(loglevel, is_gui): +def _stream_handler(loglevel: int, is_gui: bool) -> Union[logging.StreamHandler, TqdmHandler]: """ Add a stream handler for the current Faceswap session. The stream handler will only ever output at a maximum of VERBOSE level to avoid spamming the console. Parameters ---------- - loglevel: str + loglevel: int The requested log level that messages should be logged at. is_gui: bool, optional Whether Faceswap is running in the GUI or not. Dictates where the stream handler should @@ -311,7 +425,30 @@ def _stream_handler(loglevel, is_gui): return log_console -def _crash_handler(log_format): +def _stream_setup_handler(loglevel: int) -> logging.StreamHandler: + """ Add a stream handler for faceswap's setup.py script + This stream handler outputs a limited set of easy to use information using colored labels + if available. It will only ever output at a minimum of INFO level + + Parameters + ---------- + loglevel: int + The requested log level that messages should be logged at. + + Returns + ------- + :class:`logging.StreamHandler` + The stream handler to use + """ + loglevel = max(loglevel, 15) + log_format = ColoredFormatter("%(levelname)-8s %(message)s", pad_newlines=True) + handler = logging.StreamHandler(sys.stdout) + handler.setFormatter(log_format) + handler.setLevel(loglevel) + return handler + + +def _crash_handler(log_format: FaceswapFormatter) -> logging.StreamHandler: """ Add a handler that stores the last 100 debug lines to :attr:'_DEBUG_BUFFER' for use in crash reports. @@ -331,7 +468,7 @@ def _crash_handler(log_format): return log_crash -def get_loglevel(loglevel): +def get_loglevel(loglevel: str) -> int: """ Check whether a valid log level has been supplied, and return the numeric log level that corresponds to the given string level. @@ -351,7 +488,7 @@ def get_loglevel(loglevel): return numeric_level -def crash_log(): +def crash_log() -> str: """ On a crash, write out the contents of :func:`_DEBUG_BUFFER` containing the last 100 lines of debug messages to a crash report in the root Faceswap folder. @@ -379,11 +516,11 @@ def crash_log(): _OLD_FACTORY = logging.getLogRecordFactory() -def _faceswap_logrecord(*args, **kwargs): +def _faceswap_logrecord(*args, **kwargs) -> logging.LogRecord: """ Add a flag to :class:`logging.LogRecord` to not strip formatting from particular records. """ record = _OLD_FACTORY(*args, **kwargs) - record.strip_spaces = True + record.strip_spaces = True # type:ignore return record diff --git a/requirements/_requirements_base.txt b/requirements/_requirements_base.txt index af6511fe..41d82871 100644 --- a/requirements/_requirements_base.txt +++ b/requirements/_requirements_base.txt @@ -13,6 +13,6 @@ ffmpy==0.2.3 #nvidia-ml-py>=11.510,<300 # Pin nvidida-ml-py to <11.515 until we know if bytes->str is an error or permanent change nvidia-ml-py<11.515 -tensorflow_probability<0.17 +tensorflow-probability<0.17 typing-extensions>=4.0.0 pywin32>=228 ; sys_platform == "win32" diff --git a/setup.cfg b/setup.cfg index 880f2f97..3822ce62 100644 --- a/setup.cfg +++ b/setup.cfg @@ -16,6 +16,8 @@ ignore_missing_imports = True ignore_missing_imports = True [mypy-matplotlib.*] ignore_missing_imports = True +[mypy-pexpect.*] +ignore_missing_imports = True [mypy-PIL.*] ignore_missing_imports = True [mypy-plaidml.*] diff --git a/setup.py b/setup.py index 1dc2cd5b..8d013afd 100755 --- a/setup.py +++ b/setup.py @@ -2,6 +2,7 @@ """ Install packages for faceswap.py """ # >>> Environment +import logging import ctypes import json import locale @@ -10,22 +11,24 @@ import operator import os import re import sys -from subprocess import CalledProcessError, run, PIPE, Popen -from typing import Dict, List, Optional, Tuple, TYPE_CHECKING, Union +from subprocess import run, PIPE, Popen, STDOUT +from typing import Dict, List, Optional, Tuple from pkg_resources import parse_requirements, Requirement -if TYPE_CHECKING: - from logging import Logger +from lib.logger import log_setup - -INSTALL_FAILED = False +logger = logging.getLogger(__name__) # pylint: disable=invalid-name +_INSTALL_FAILED = False # Revisions of tensorflow GPU and cuda/cudnn requirements. These relate specifically to the # Tensorflow builds available from pypi -TENSORFLOW_REQUIREMENTS = {">=2.4.0,<2.5.0": ["11.0", "8.0"], - ">=2.5.0,<2.9.0": ["11.2", "8.1"]} +_TENSORFLOW_REQUIREMENTS = {">=2.4.0,<2.5.0": ["11.0", "8.0"], + ">=2.5.0,<2.9.0": ["11.2", "8.1"]} +# Packages that are explicitly required for setup.py +_INSTALLER_REQUIREMENTS = ["pexpect>=4.8.0"] + # Mapping of Python packages to their conda names if different from pip or in non-default channel -CONDA_MAPPING = { +_CONDA_MAPPING: Dict[str, Tuple[str, str]] = { # "opencv-python": ("opencv", "conda-forge"), # Periodic issues with conda-forge opencv "fastcluster": ("fastcluster", "conda-forge"), "imageio-ffmpeg": ("imageio-ffmpeg", "conda-forge"), @@ -34,13 +37,16 @@ CONDA_MAPPING = { class Environment(): - """ The current install environment """ - def __init__(self, logger: Optional["Logger"] = None, updater: bool = False) -> None: - """ logger will override built in Output() function if passed in - updater indicates that this is being run from update_deps.py - so certain steps can be skipped/output limited """ + """ The current install environment + + Parameters + ---------- + updater: bool, Optional + ``True`` of the script is being called by Faceswap's internal updater. ``False`` if full + setup is running. Default: ``False`` + """ + def __init__(self, updater: bool = False) -> None: self.conda_required_packages: List[Tuple[str, ...]] = [("tk", )] - self.output: Union["Logger", "Output"] = logger if logger else Output() self.updater = updater # Flag that setup is being run by installer so steps can be skipped self.is_installer: bool = False @@ -50,18 +56,18 @@ class Environment(): self.enable_apple_silicon: bool = False self.enable_docker: bool = False self.enable_cuda: bool = False - self.required_packages: List[Tuple[str, Tuple[str, str]]] = [] - self.missing_packages: List[str] = [] - self.conda_missing_packages: List[str] = [] + self.required_packages: List[Tuple[str, List[Tuple[str, str]]]] = [] + self.missing_packages: List[Tuple[str, List[Tuple[str, str]]]] = [] + self.conda_missing_packages: List[Tuple[str, ...]] = [] - self.process_arguments() - self.check_permission() - self.check_system() - self.check_python() - self.output_runtime_info() - self.check_pip() - self.upgrade_pip() - self.set_ld_library_path() + self._process_arguments() + self._check_permission() + self._check_system() + self._check_python() + self._output_runtime_info() + self._check_pip() + self._upgrade_pip() + self._set_ld_library_path() self.installed_packages = self.get_installed_packages() self.installed_packages.update(self.get_installed_conda_packages()) @@ -107,13 +113,14 @@ class Environment(): retval = (os.path.basename(prefix) == "envs") return retval - def process_arguments(self) -> None: + def _process_arguments(self) -> None: """ Process any cli arguments and dummy in cli arguments if calling from updater. """ args = [arg for arg in sys.argv] # pylint:disable=unnecessary-comprehension if self.updater: from lib.utils import get_backend # pylint:disable=import-outside-toplevel args.append(f"--{get_backend()}") + logger.debug(args) for arg in args: if arg == "--installer": self.is_installer = True @@ -144,75 +151,82 @@ class Environment(): package = package.strip() if package and (not package.startswith(("#", "-r"))): requirements.append(package) - self.required_packages = [(pkg.name, pkg.specs) + + # Add required installer packages + if self.os_version[0] != "Windows": + for inst in _INSTALLER_REQUIREMENTS: + requirements.insert(0, inst) + + self.required_packages = [(pkg.unsafe_name, pkg.specs) for pkg in parse_requirements(requirements) if pkg.marker is None or pkg.marker.evaluate()] + logger.debug(self.required_packages) - def check_permission(self) -> None: + def _check_permission(self) -> None: """ Check for Admin permissions """ if self.updater: return if self.is_admin: - self.output.info("Running as Root/Admin") + logger.info("Running as Root/Admin") else: - self.output.info("Running without root/admin privileges") + logger.info("Running without root/admin privileges") - def check_system(self) -> None: + def _check_system(self) -> None: """ Check the system """ if not self.updater: - self.output.info("The tool provides tips for installation\n" - "and installs required python packages") - self.output.info(f"Setup in {self.os_version[0]} {self.os_version[1]}") + logger.info("The tool provides tips for installation and installs required python " + "packages") + logger.info("Setup in %s %s", self.os_version[0], self.os_version[1]) if not self.updater and not self.os_version[0] in ["Windows", "Linux", "Darwin"]: - self.output.error(f"Your system {self.os_version[0]} is not supported!") + logger.error("Your system %s is not supported!", self.os_version[0]) sys.exit(1) if self.os_version[0].lower() == "darwin" and platform.machine() == "arm64": self.enable_apple_silicon = True if not self.updater and not self.is_conda: - self.output.error("Setting up Faceswap for Apple Silicon outside of a Conda " - "environment is unsupported") + logger.error("Setting up Faceswap for Apple Silicon outside of a Conda " + "environment is unsupported") sys.exit(1) - def check_python(self) -> None: + def _check_python(self) -> None: """ Check python and virtual environment status """ - self.output.info(f"Installed Python: {self.py_version[0]} {self.py_version[1]}") + logger.info("Installed Python: %s %s", self.py_version[0], self.py_version[1]) if self.updater: return if not ((3, 7) <= sys.version_info < (3, 10) and self.py_version[1] == "64bit"): - self.output.error("Please run this script with Python version 3.7 to 3.9 " - "64bit and try again.") + logger.error("Please run this script with Python version 3.7 to 3.9 64bit and try " + "again.") sys.exit(1) if self.enable_amd and sys.version_info >= (3, 9): - self.output.error("The AMD version of Faceswap cannot be installed on versions of " - "Python higher than 3.8") + logger.error("The AMD version of Faceswap cannot be installed on versions of Python " + "higher than 3.8") sys.exit(1) - def output_runtime_info(self) -> None: + def _output_runtime_info(self) -> None: """ Output run time info """ if self.is_conda: - self.output.info("Running in Conda") + logger.info("Running in Conda") if self.is_virtualenv: - self.output.info("Running in a Virtual Environment") - self.output.info(f"Encoding: {self.encoding}") + logger.info("Running in a Virtual Environment") + logger.info("Encoding: %s", self.encoding) - def check_pip(self) -> None: + def _check_pip(self) -> None: """ Check installed pip version """ if self.updater: return try: import pip # noqa pylint:disable=unused-import,import-outside-toplevel except ImportError: - self.output.error("Import pip failed. Please Install python3-pip and try again") + logger.error("Import pip failed. Please Install python3-pip and try again") sys.exit(1) - def upgrade_pip(self) -> None: + def _upgrade_pip(self) -> None: """ Upgrade pip to latest version """ if not self.is_conda: # Don't do this with Conda, as we must use Conda version of pip - self.output.info("Upgrading pip...") + logger.info("Upgrading pip...") pipexe = [sys.executable, "-m", "pip"] pipexe.extend(["install", "--no-cache-dir", "-qq", "--upgrade"]) if not self.is_admin and not self.is_virtualenv: @@ -221,7 +235,7 @@ class Environment(): run(pipexe, check=True) import pip # pylint:disable=import-outside-toplevel pip_version = pip.__version__ - self.output.info(f"Installed pip: {pip_version}") + logger.info("Installed pip: %s", pip_version) def get_installed_packages(self) -> Dict[str, str]: """ Get currently installed packages """ @@ -234,6 +248,7 @@ class Environment(): continue item = pkg.split("==") installed_packages[item[0]] = item[1] + logger.debug(installed_packages) return installed_packages def get_installed_conda_packages(self) -> Dict[str, str]: @@ -247,6 +262,7 @@ class Environment(): for pkg in installed: item = pkg.split(" ") retval[item[0]] = item[1] + logger.debug(retval) return retval def update_tf_dep(self) -> None: @@ -257,7 +273,7 @@ class Environment(): tf_ver = None cudnn_inst = self.cudnn_version.split(".") - for key, val in TENSORFLOW_REQUIREMENTS.items(): + for key, val in _TENSORFLOW_REQUIREMENTS.items(): cuda_req = val[0] cudnn_req = val[1].split(".") if cuda_req == self.cuda_version and (cudnn_req[0] == cudnn_inst[0] and @@ -276,17 +292,18 @@ class Environment(): next(parse_requirements(tf_ver)).specs)) return - self.output.warning( + logger.warning( "The minimum Tensorflow requirement is 2.4 \n" - "Tensorflow currently has no official prebuild for your CUDA, cuDNN " - "combination.\nEither install a combination that Tensorflow supports or " - "build and install your own tensorflow-gpu.\r\n" - f"CUDA Version: {self.cuda_version}\r\n" - f"cuDNN Version: {self.cudnn_version}\r\n" + "Tensorflow currently has no official prebuild for your CUDA, cuDNN combination.\n" + "Either install a combination that Tensorflow supports or build and install your own " + "tensorflow-gpu.\r\n" + "CUDA Version: %s\r\n" + "cuDNN Version: %s\r\n" "Help:\n" "Building Tensorflow: https://www.tensorflow.org/install/install_sources\r\n" "Tensorflow supported versions: " - "https://www.tensorflow.org/install/source#tested_build_configurations") + "https://www.tensorflow.org/install/source#tested_build_configurations", + self.cuda_version, self.cudnn_version) custom_tf = input("Location of custom tensorflow-gpu wheel (leave " "blank to manually install): ") @@ -294,12 +311,15 @@ class Environment(): return custom_tf = os.path.realpath(os.path.expanduser(custom_tf)) + global _INSTALL_FAILED # pylint:disable=global-statement if not os.path.isfile(custom_tf): - self.output.error(f"{custom_tf} not found") + logger.error("%s not found", custom_tf) + _INSTALL_FAILED = True elif os.path.splitext(custom_tf)[1] != ".whl": - self.output.error(f"{custom_tf} is not a valid pip wheel") + logger.error("%s is not a valid pip wheel", custom_tf) + _INSTALL_FAILED = True elif custom_tf: - self.required_packages.append((custom_tf, (custom_tf, ""))) + self.required_packages.append((custom_tf, [(custom_tf, "")])) def set_config(self) -> None: """ Set the backend in the faceswap config file """ @@ -316,9 +336,9 @@ class Environment(): config_file = os.path.join(pypath, "config", ".faceswap") with open(config_file, "w", encoding="utf8") as cnf: json.dump(config, cnf) - self.output.info(f"Faceswap config written to: {config_file}") + logger.info("Faceswap config written to: %s", config_file) - def set_ld_library_path(self) -> None: + def _set_ld_library_path(self) -> None: """ Update the LD_LIBRARY_PATH environment variable when activating a conda environment and revert it when deactivating. Linux/conda only @@ -361,158 +381,132 @@ class Environment(): afile.write("export LD_LIBRARY_PATH=${OLD_LD_LIBRARY_PATH}\n") afile.write("unset OLD_LD_LIBRARY_PATH\n") - self.output.info(f"Cuda search path set to '{conda_libs}'") + logger.info("Cuda search path set to '%s'", conda_libs) -class Output(): - """ Format and display output """ - def __init__(self) -> None: - self.red: str = "\033[31m" - self.green: str = "\033[32m" - self.yellow: str = "\033[33m" - self.default_color: str = "\033[0m" - self.term_support_color: bool = platform.system().lower() in ("linux", "darwin") +class Checks(): # pylint:disable=too-few-public-methods + """ Pre-installation checks - @staticmethod - def __indent_text_block(text: str) -> str: - """ Indent a text block """ - lines = text.splitlines() - if len(lines) > 1: - out = lines[0] + "\r\n" - for i in range(1, len(lines)-1): - out = out + " " + lines[i] + "\r\n" - out = out + " " + lines[-1] - return out - return text - - def info(self, text: str) -> None: - """ Format INFO Text """ - trm = "INFO " - if self.term_support_color: - trm = f"{self.green}INFO {self.default_color} " - print(trm + self.__indent_text_block(text)) - - def warning(self, text: str) -> None: - """ Format WARNING Text """ - trm = "WARNING " - if self.term_support_color: - trm = f"{self.yellow}WARNING{self.default_color} " - print(trm + self.__indent_text_block(text)) - - def error(self, text: str) -> None: - """ Format ERROR Text """ - global INSTALL_FAILED # pylint:disable=global-statement - trm = "ERROR " - if self.term_support_color: - trm = f"{self.red}ERROR {self.default_color} " - print(trm + self.__indent_text_block(text)) - INSTALL_FAILED = True - - -class Checks(): - """ Pre-installation checks """ + Parameters + ---------- + environment: :class:`Environment` + Environment class holding information about the running system + """ def __init__(self, environment: Environment) -> None: - self.env: Environment = environment - self.output: Output = Output() - self.tips: Tips = Tips() + self._env: Environment = environment + self._tips: Tips = Tips() # Checks not required for installer - if self.env.is_installer: + if self._env.is_installer: return # Checks not required for Apple Silicon - if self.env.enable_apple_silicon: + if self._env.enable_apple_silicon: return + self._user_input() + self._check_cuda() + self._env.update_tf_dep() + if self._env.os_version[0] == "Windows": + self._tips.pip() - # Ask AMD/Docker/Cuda - self.amd_ask_enable() - if not self.env.enable_amd: - self.docker_ask_enable() - self.cuda_ask_enable() - if self.env.os_version[0] != "Linux" and self.env.enable_docker and self.env.enable_cuda: - self.docker_confirm() - if self.env.enable_docker: - self.docker_tips() - self.env.set_config() + def _user_input(self) -> None: + """ Get user input for AMD/Cuda/Docker """ + self._amd_ask_enable() + if not self._env.enable_amd: + self._docker_ask_enable() + self._cuda_ask_enable() + if self._env.os_version[0] != "Linux" and (self._env.enable_docker + and self._env.enable_cuda): + self._docker_confirm() + if self._env.enable_docker: + self._docker_tips() + self._env.set_config() sys.exit(0) - # Check for CUDA and cuDNN - if self.env.enable_cuda and self.env.is_conda: - self.output.info("Skipping Cuda/cuDNN checks for Conda install") - elif self.env.enable_cuda and self.env.os_version[0] in ("Linux", "Windows"): - check = CudaCheck() - if check.cuda_version: - self.env.cuda_version = check.cuda_version - self.output.info("CUDA version: " + self.env.cuda_version) - else: - self.output.error("CUDA not found. Install and try again.\n" - "Recommended version: CUDA 10.1 cuDNN 7.6\n" - "CUDA: https://developer.nvidia.com/cuda-downloads\n" - "cuDNN: https://developer.nvidia.com/rdp/cudnn-download") - return - - if check.cudnn_version: - self.env.cudnn_version = ".".join(check.cudnn_version.split(".")[:2]) - self.output.info(f"cuDNN version: {self.env.cudnn_version}") - else: - self.output.error("cuDNN not found. See " - "https://github.com/deepfakes/faceswap/blob/master/INSTALL.md#" - "cudnn for instructions") - return - elif self.env.enable_cuda and self.env.os_version[0] not in ("Linux", "Windows"): - self.tips.macos() - self.output.warning("Cannot find CUDA on macOS") - self.env.cuda_version = input("Manually specify CUDA version: ") - - self.env.update_tf_dep() - if self.env.os_version[0] == "Windows": - self.tips.pip() - - def amd_ask_enable(self) -> None: + def _amd_ask_enable(self) -> None: """ Enable or disable Plaidml for AMD""" - self.output.info("AMD Support: AMD GPU support is currently limited.\r\n" - "Nvidia Users MUST answer 'no' to this option.") + logger.info("AMD Support: AMD GPU support is currently limited.\r\n" + "Nvidia Users MUST answer 'no' to this option.") i = input("Enable AMD Support? [y/N] ") if i in ("Y", "y"): - self.output.info("AMD Support Enabled") - self.env.enable_amd = True + logger.info("AMD Support Enabled") + self._env.enable_amd = True else: - self.output.info("AMD Support Disabled") - self.env.enable_amd = False + logger.info("AMD Support Disabled") + self._env.enable_amd = False - def docker_ask_enable(self) -> None: + def _docker_ask_enable(self) -> None: """ Enable or disable Docker """ i = input("Enable Docker? [y/N] ") if i in ("Y", "y"): - self.output.info("Docker Enabled") - self.env.enable_docker = True + logger.info("Docker Enabled") + self._env.enable_docker = True else: - self.output.info("Docker Disabled") - self.env.enable_docker = False + logger.info("Docker Disabled") + self._env.enable_docker = False - def docker_confirm(self) -> None: + def _docker_confirm(self) -> None: """ Warn if nvidia-docker on non-Linux system """ - self.output.warning("Nvidia-Docker is only supported on Linux.\r\n" - "Only CPU is supported in Docker for your system") - self.docker_ask_enable() - if self.env.enable_docker: - self.output.warning("CUDA Disabled") - self.env.enable_cuda = False + logger.warning("Nvidia-Docker is only supported on Linux.\r\n" + "Only CPU is supported in Docker for your system") + self._docker_ask_enable() + if self._env.enable_docker: + logger.warning("CUDA Disabled") + self._env.enable_cuda = False - def docker_tips(self) -> None: + def _docker_tips(self) -> None: """ Provide tips for Docker use """ - if not self.env.enable_cuda: - self.tips.docker_no_cuda() + if not self._env.enable_cuda: + self._tips.docker_no_cuda() else: - self.tips.docker_cuda() + self._tips.docker_cuda() - def cuda_ask_enable(self) -> None: + def _cuda_ask_enable(self) -> None: """ Enable or disable CUDA """ i = input("Enable CUDA? [Y/n] ") if i in ("", "Y", "y"): - self.output.info("CUDA Enabled") - self.env.enable_cuda = True + logger.info("CUDA Enabled") + self._env.enable_cuda = True else: - self.output.info("CUDA Disabled") - self.env.enable_cuda = False + logger.info("CUDA Disabled") + self._env.enable_cuda = False + + def _check_cuda(self) -> None: + """ Check for Cuda and cuDNN Locations. """ + if not self._env.enable_cuda: + logger.debug("Skipping Cuda checks as not enabled") + return + + if self._env.is_conda: + logger.info("Skipping Cuda/cuDNN checks for Conda install") + return + + if self._env.os_version[0] in ("Linux", "Windows"): + global _INSTALL_FAILED # pylint:disable=global-statement + check = CudaCheck() + if check.cuda_version: + self._env.cuda_version = check.cuda_version + logger.info("CUDA version: %s", self._env.cuda_version) + else: + logger.error("CUDA not found. Install and try again.\n" + "Recommended version: CUDA 10.1 cuDNN 7.6\n" + "CUDA: https://developer.nvidia.com/cuda-downloads\n" + "cuDNN: https://developer.nvidia.com/rdp/cudnn-download") + _INSTALL_FAILED = True + return + + if check.cudnn_version: + self._env.cudnn_version = ".".join(check.cudnn_version.split(".")[:2]) + logger.info("cuDNN version: %s", self._env.cudnn_version) + else: + logger.error("cuDNN not found. See " + "https://github.com/deepfakes/faceswap/blob/master/INSTALL.md#" + "cudnn for instructions") + _INSTALL_FAILED = True + return + + # If we get here we're on MacOS + self._tips.macos() + logger.warning("Cannot find CUDA on macOS") + self._env.cuda_version = input("Manually specify CUDA version: ") class CudaCheck(): # pylint:disable=too-few-public-methods @@ -528,7 +522,8 @@ class CudaCheck(): # pylint:disable=too-few-public-methods for key in os.environ if key.lower().startswith("cuda_path_v")] self._cudnn_header_files: List[str] = ["cudnn_version.h", "cudnn.h"] - + logger.debug("cuda keys: %s, cudnn header files: %s", + self._cuda_keys, self._cudnn_header_files) if self._os in ("windows", "linux"): self._cuda_check() self._cudnn_check() @@ -560,6 +555,7 @@ class CudaCheck(): # pylint:disable=too-few-public-methods # Failed to load nvcc, manual check getattr(self, f"_cuda_check_{self._os}")() + logger.debug("Cuda Version: %s, Cuda Path: %s", self.cuda_version, self.cuda_path) def _cuda_check_linux(self) -> None: """ For Linux check the dynamic link loader for libcudart. If not found with ldconfig then @@ -589,6 +585,7 @@ class CudaCheck(): # pylint:disable=too-few-public-methods """ Check Linux or Windows cuDNN Version from cudnn.h and add to :attr:`cudnn_version`. """ cudnn_checkfiles = getattr(self, f"_get_checkfiles_{self._os}")() cudnn_checkfile = next((hdr for hdr in cudnn_checkfiles if os.path.isfile(hdr)), None) + logger.debug("cudnn checkfiles: %s", cudnn_checkfile) if not cudnn_checkfile: return found = 0 @@ -608,6 +605,7 @@ class CudaCheck(): # pylint:disable=too-few-public-methods if found != 3: # Full version could not be determined return self.cudnn_version = ".".join([str(major), str(minor), str(patchlevel)]) + logger.debug("cudnn version: %s", self.cudnn_version) def _get_checkfiles_linux(self) -> List[str]: """ Return the the files to check for cuDNN locations for Linux by querying @@ -648,92 +646,153 @@ class CudaCheck(): # pylint:disable=too-few-public-methods return cudnn_checkfiles -class Install(): - """ Install the requirements """ - def __init__(self, environment: Environment): +class Install(): # pylint:disable=too-few-public-methods + """ Handles installation of Faceswap requirements + + Parameters + ---------- + environment: :class:`Environment` + Environment class holding information about the running system + is_gui: bool, Optional + ``True`` if the caller is the Faceswap GUI. Used to prevent output of progress bars + which get scrambled in the GUI + """ + def __init__(self, environment: Environment, is_gui: bool = False) -> None: self._operators = {"==": operator.eq, ">=": operator.ge, "<=": operator.le, ">": operator.gt, "<": operator.lt} - self.output = environment.output - self.env = environment + self._env = environment + self._is_gui = is_gui - if not self.env.is_installer and not self.env.updater: - self.ask_continue() - self.env.get_required_packages() - self.check_missing_dep() - self.check_conda_missing_dep() - if (self.env.updater and - not self.env.missing_packages and not self.env.conda_missing_packages): - self.output.info("All Dependencies are up to date") + if not self._env.is_installer and not self._env.updater: + self._ask_continue() + self._env.get_required_packages() + self._check_missing_dep() + self._check_conda_missing_dep() + if (self._env.updater and + not self._env.missing_packages and not self._env.conda_missing_packages): + logger.info("All Dependencies are up to date") return - self.install_missing_dep() - if self.env.updater: + logger.info("Installing Required Python Packages. This may take some time...") + self._install_setup_packages() + self._install_missing_dep() + if self._env.updater: return - self.output.info("All python3 dependencies are met.\r\nYou are good to go.\r\n\r\n" - "Enter: 'python faceswap.py -h' to see the options\r\n" - " 'python faceswap.py gui' to launch the GUI") + logger.info("All python3 dependencies are met.\r\nYou are good to go.\r\n\r\n" + "Enter: 'python faceswap.py -h' to see the options\r\n" + " 'python faceswap.py gui' to launch the GUI") - def ask_continue(self): + @classmethod + def _ask_continue(cls) -> None: """ Ask Continue with Install """ inp = input("Please ensure your System Dependencies are met. Continue? [y/N] ") if inp in ("", "N", "n"): - self.output.error("Please install system dependencies to continue") + logger.error("Please install system dependencies to continue") sys.exit(1) - def check_missing_dep(self): + def _check_missing_dep(self) -> None: """ Check for missing dependencies """ - for key, specs in self.env.required_packages: + for key, specs in self._env.required_packages: - if self.env.is_conda: # Get Conda alias for Key - key = CONDA_MAPPING.get(key, (key, None))[0] + if self._env.is_conda: # Get Conda alias for Key + key = _CONDA_MAPPING.get(key, (key, None))[0] - if key not in self.env.installed_packages: + if key not in self._env.installed_packages: # Add not installed packages to missing packages list - self.env.missing_packages.append((key, specs)) + self._env.missing_packages.append((key, specs)) continue - installed_vers = self.env.installed_packages.get(key, "") + installed_vers = self._env.installed_packages.get(key, "") - if specs and not all(self._operators[spec[0]](installed_vers, spec[1]) + if specs and not all(self._operators[spec[0]]( + [int(s) for s in installed_vers.split(".")], + [int(s) for s in spec[1].split(".")]) for spec in specs): - self.env.missing_packages.append((key, specs)) + self._env.missing_packages.append((key, specs)) + logger.debug(self._env.missing_packages) - def check_conda_missing_dep(self): + def _check_conda_missing_dep(self) -> None: """ Check for conda missing dependencies """ - if not self.env.is_conda: + if not self._env.is_conda: return - for pkg in self.env.conda_required_packages: + installed_conda_packages = self._env.get_installed_conda_packages() + for pkg in self._env.conda_required_packages: key = pkg[0].split("==")[0] - if key not in self.env.installed_packages: - self.env.conda_missing_packages.append(pkg) + if key not in self._env.installed_packages: + self._env.conda_missing_packages.append(pkg) continue if len(pkg[0].split("==")) > 1: - if pkg[0].split("==")[1] != self.env.installed_conda_packages.get(key): - self.env.conda_missing_packages.append(pkg) + if pkg[0].split("==")[1] != installed_conda_packages.get(key): + self._env.conda_missing_packages.append(pkg) continue + logger.debug(self._env.conda_missing_packages) - def install_missing_dep(self): + @classmethod + def _format_package(cls, package: str, version: List[Tuple[str, str]]) -> str: + """ Format a parsed requirement package and version string to a format that can be used by + the installer. + + Parameters + ---------- + package: str + The package name + version: list + The parsed requirement version strings + + Returns + ------- + str + The formatted full package and version string + """ + return f"{package}{','.join(''.join(spec) for spec in version)}" + + def _install_setup_packages(self) -> None: + """ Install any packages that are required for the setup.py installer to work. This + includes the pexpect package if it is not already installed. + + Subprocess is used as we do not currently have pexpect + """ + setup_packages = [(pkg.unsafe_name, pkg.specs) + for pkg in parse_requirements(_INSTALLER_REQUIREMENTS)] + + for pkg in setup_packages: + if pkg not in self._env.missing_packages: + continue + self._env.missing_packages.pop(self._env.missing_packages.index(pkg)) + pkg_str = self._format_package(*pkg) + if self._env.is_conda: + cmd = ["conda", "install", "-y"] + else: + cmd = [sys.executable, "-m", "pip", "install", "--no-cache-dir"] + if self._env.is_admin: + cmd.append("--user") + cmd.append(pkg_str) + + clean_pkg = pkg_str.replace("\"", "") + if self._subproc_installer(cmd, clean_pkg) != 0: + logger.error("Unable to install package: %s. Process aborted", clean_pkg) + sys.exit(1) + + def _install_missing_dep(self) -> None: """ Install missing dependencies """ # Install conda packages first - if self.env.conda_missing_packages: - self.install_conda_packages() - if self.env.missing_packages: - self.install_python_packages() + if self._env.conda_missing_packages: + self._install_conda_packages() + if self._env.missing_packages: + self._install_python_packages() - def install_python_packages(self): + def _install_python_packages(self) -> None: """ Install required pip packages """ - self.output.info("Installing Required Python Packages. This may take some time...") conda_only = False - for pkg, version in self.env.missing_packages: - if self.env.is_conda: - pkg = CONDA_MAPPING.get(pkg, (pkg, None)) - channel = None if len(pkg) != 2 else pkg[1] - pkg = pkg[0] - if version: - pkg = f"{pkg}{','.join(''.join(spec) for spec in version)}" - if self.env.is_conda: + for pkg, version in self._env.missing_packages: + if self._env.is_conda: + mapping = _CONDA_MAPPING.get(pkg, (pkg, "")) + channel = None if mapping[1] == "" else mapping[1] + pkg = mapping[0] + pkg = self._format_package(pkg, version) if version else pkg + if self._env.is_conda: if pkg.startswith("tensorflow-gpu"): # From TF 2.4 onwards, Anaconda Tensorflow becomes a mess. The version of 2.5 # installed by Anaconda is compiled against an incorrect numpy version which @@ -744,32 +803,47 @@ class Install(): # TODO Revert to Conda if they get their act together # Rewrite tensorflow requirement to versions from highest available cuda/cudnn - highest_cuda = sorted(TENSORFLOW_REQUIREMENTS.values())[-1] - compat_tf = next(k for k, v in TENSORFLOW_REQUIREMENTS.items() + highest_cuda = sorted(_TENSORFLOW_REQUIREMENTS.values())[-1] + compat_tf = next(k for k, v in _TENSORFLOW_REQUIREMENTS.items() if v == highest_cuda) pkg = f"tensorflow-gpu{compat_tf}" conda_only = True - verbose = pkg.startswith("tensorflow") or self.env.updater - if self.conda_installer(pkg, - verbose=verbose, channel=channel, conda_only=conda_only): + if self._conda_installer(pkg, channel=channel, conda_only=conda_only): continue - self.pip_installer(pkg) + self._pip_installer(pkg) - def install_conda_packages(self): + def _install_conda_packages(self) -> None: """ Install required conda packages """ - self.output.info("Installing Required Conda Packages. This may take some time...") - for pkg in self.env.conda_missing_packages: + logger.info("Installing Required Conda Packages. This may take some time...") + for pkg in self._env.conda_missing_packages: channel = None if len(pkg) != 2 else pkg[1] - self.conda_installer(pkg[0], channel=channel, conda_only=True) + self._conda_installer(pkg[0], channel=channel, conda_only=True) - def conda_installer(self, package, channel=None, verbose=False, conda_only=False): - """ Install a conda package """ + def _conda_installer(self, + package: str, + channel: Optional[str] = None, + conda_only: bool = False) -> bool: + """ Install a conda package + + Parameters + ---------- + package: str + The full formatted package, with version, to be installed + channel: str, optional + The Conda channel to install from. Select ``None`` for default channel. + Default: ``None`` + conda_only: bool, optional + ``True`` if the package is only available in Conda. Default: ``False`` + + Returns + ------- + bool + ``True`` if the package was succesfully installed otherwise ``False`` + """ # Packages with special characters need to be enclosed in double quotes success = True condaexe = ["conda", "install", "-y"] - if not verbose or self.env.updater: - condaexe.append("-q") if channel: condaexe.extend(["-c", channel]) @@ -777,7 +851,7 @@ class Install(): # Here we will install the cuda/cudnn toolkits, currently only available from # conda-forge, but fail tensorflow itself so that it can be handled by pip. specs = Requirement.parse(package).specs - for key, val in TENSORFLOW_REQUIREMENTS.items(): + for key, val in _TENSORFLOW_REQUIREMENTS.items(): req_specs = Requirement.parse("foobar" + key).specs if all(item in req_specs for item in specs): cuda, cudnn = val @@ -792,53 +866,142 @@ class Install(): condaexe.append(package) clean_pkg = package.replace("\"", "") - self.output.info(f"Installing {clean_pkg}") - shell = self.env.os_version[0] == "Windows" - try: - if verbose: - run(condaexe, check=True, shell=shell) - else: - with open(os.devnull, "w", encoding="utf8") as devnull: - run(condaexe, stdout=devnull, stderr=devnull, check=True, shell=shell) - except CalledProcessError: - if not conda_only: - self.output.info(f"{package} not available in Conda. Installing with pip") - else: - self.output.warning(f"Couldn't install {package} with Conda. " - "Please install this package manually") - success = False + retcode = self._pexpect_installer(condaexe, clean_pkg) + + if retcode != 0 and not conda_only: + logger.info("%s not available in Conda. Installing with pip", package) + elif retcode != 0: + logger.warning("Couldn't install %s with Conda. Please install this package " + "manually", package) + success = retcode == 0 and success return success - def pip_installer(self, package): - """ Install a pip package """ - pipexe = [sys.executable, "-m", "pip"] - # hide info/warning and fix cache hang - pipexe.extend(["install", "--no-cache-dir"]) - if not self.env.updater and not package.startswith("tensorflow"): - pipexe.append("-qq") + def _pip_installer(self, package: str) -> None: + """ Install a pip package + + Parameters + ---------- + package: str + The full formatted package, with version, to be installed + """ + pipexe = [sys.executable, "-m", "pip", "install", "--no-cache-dir"] # install as user to solve perm restriction - if not self.env.is_admin and not self.env.is_virtualenv: + if not self._env.is_admin and not self._env.is_virtualenv: pipexe.append("--user") - msg = f"Installing {package}" - self.output.info(msg) pipexe.append(package) - try: - run(pipexe, check=True) - except CalledProcessError: - self.output.warning(f"Couldn't install {package} with pip. " - "Please install this package manually") + + if self._pexpect_installer(pipexe, package) != 0: + logger.warning("Couldn't install %s with pip. Please install this package manually", + package) + + def _pexpect_installer(self, command: List[str], package: str) -> int: + """ Run an install command using pexpect and log output. + + Pexpect is used so we can get unbuffered output to display updates + + Parameters + ---------- + command: list + The command to run + package: str + The package name that is being installed + + Returns + ------- + int + The return code from the subprocess + """ + import pexpect # pylint:disable=import-outside-toplevel + logger.info("Installing %s", package) + + proc = pexpect.spawn(" ".join(command), + encoding=self._env.encoding, + codec_errors="replace", + timeout=None) + last_line_cr = False + while True: + try: + idx = proc.expect(["\r\n", "\r"]) + line = proc.before.rstrip() + if line and idx == 0: + if last_line_cr: + last_line_cr = False + # Output last line of progress bar and go to next line + if not self._is_gui: + print(line) + logger.verbose(line) # type:ignore + elif line and idx == 1: + last_line_cr = True + logger.debug(line) + if not self._is_gui: + print(line, end="\r") + except pexpect.EOF: + break + proc.close() + returncode = proc.exitstatus + logger.debug("Package: %s, returncode: %s", package, returncode) + return returncode + + def _subproc_installer(self, command: List[str], package: str) -> int: + """ Run an install command using subprocess Popen. + + pexpect uses pty which is not useable in Windows. The pexpect popen_spawn module does not + give easy access to the return code, and also dumps stdout to console so we use subprocess + for Windows. The downside of this is that we cannot do unbuffered reads, so the process can + look like it hangs. + + #TODO Implement real time read functionality for windows + + Parameters + ---------- + command: list + The command to run + package: str + The package name that is being installed + + Returns + ------- + int + The return code from the subprocess + """ + logger.info("Installing %s", package) + shell = self._env.os_version[0] == "Windows" + + with Popen(command, bufsize=0, stdout=PIPE, stderr=STDOUT, shell=shell) as proc: + last_line_cr = False + while True: + if proc.stdout is not None: + line = proc.stdout.readline().decode(self._env.encoding, errors="replace") + if line == "" and proc.poll is not None: + break + + is_cr = line.startswith("\r") + line = line.rstrip() + + if line and not is_cr: + if last_line_cr: + last_line_cr = False + # Go to next line + if not self._is_gui: + print("") + logger.verbose(line) # type:ignore + elif line: + last_line_cr = True + logger.debug(line) + if not self._is_gui: + print(line, end="\r") + returncode = proc.wait() + logger.debug("Package: %s, returncode: %s", package, returncode) + return returncode class Tips(): """ Display installation Tips """ - def __init__(self): - self.output = Output() - - def docker_no_cuda(self): + @classmethod + def docker_no_cuda(cls) -> None: """ Output Tips for Docker without Cuda """ - path = os.path.dirname(os.path.realpath(__file__)) - self.output.info( + logger.info( "1. Install Docker\n" "https://www.docker.com/community-edition\n\n" "2. Build Docker Image For Faceswap\n" @@ -847,7 +1010,7 @@ class Tips(): "# without GUI\n" "docker run -tid -p 8888:8888 \\ \n" "\t--hostname deepfakes-cpu --name deepfakes-cpu \\ \n" - f"\t-v {path}:/srv \\ \n" + "\t-v %s:/srv \\ \n" "\tdeepfakes-cpu\n\n" "# with gui. tools.py gui working.\n" "## enable local access to X11 server\n" @@ -855,7 +1018,7 @@ class Tips(): "## create container\n" "nvidia-docker run -tid -p 8888:8888 \\ \n" "\t--hostname deepfakes-cpu --name deepfakes-cpu \\ \n" - f"\t-v {path}:/srv \\ \n" + "\t-v %s:/srv \\ \n" "\t-v /tmp/.X11-unix:/tmp/.X11-unix \\ \n" "\t-e DISPLAY=unix$DISPLAY \\ \n" "\t-e AUDIO_GID=`getent group audio | cut -d: -f3` \\ \n" @@ -864,14 +1027,14 @@ class Tips(): "\t-e UID=`id -u` \\ \n" "\tdeepfakes-cpu \n\n" "4. Open a new terminal to run faceswap.py in /srv\n" - "docker exec -it deepfakes-cpu bash") - self.output.info("That's all you need to do with a docker. Have fun.") - - def docker_cuda(self): - """ Output Tips for Docker wit Cuda""" + "docker exec -it deepfakes-cpu bash", path, path) + logger.info("That's all you need to do with a docker. Have fun.") + @classmethod + def docker_cuda(cls) -> None: + """ Output Tips for Docker with Cuda""" path = os.path.dirname(os.path.realpath(__file__)) - self.output.info( + logger.info( "1. Install Docker\n" "https://www.docker.com/community-edition\n\n" "2. Install latest CUDA\n" @@ -884,7 +1047,7 @@ class Tips(): "# without gui \n" "docker run -tid -p 8888:8888 \\ \n" "\t--hostname deepfakes-gpu --name deepfakes-gpu \\ \n" - f"\t-v {path}:/srv \\ \n" + "\t-v %s:/srv \\ \n" "\tdeepfakes-gpu\n\n" "# with gui.\n" "## enable local access to X11 server\n" @@ -894,7 +1057,7 @@ class Tips(): "## create container\n" "nvidia-docker run -tid -p 8888:8888 \\ \n" "\t--hostname deepfakes-gpu --name deepfakes-gpu \\ \n" - f"\t-v {path}:/srv \\ \n" + "\t-v %s:/srv \\ \n" "\t-v /tmp/.X11-unix:/tmp/.X11-unix \\ \n" "\t-e DISPLAY=unix$DISPLAY \\ \n" "\t-e AUDIO_GID=`getent group audio | cut -d: -f3` \\ \n" @@ -903,11 +1066,13 @@ class Tips(): "\t-e UID=`id -u` \\ \n" "\tdeepfakes-gpu\n\n" "6. Open a new terminal to interact with the project\n" - "docker exec deepfakes-gpu python /srv/faceswap.py gui\n") + "docker exec deepfakes-gpu python /srv/faceswap.py gui\n", + path, path) - def macos(self): + @classmethod + def macos(cls) -> None: """ Output Tips for macOS""" - self.output.info( + logger.info( "setup.py does not directly support macOS. The following tips should help:\n\n" "1. Install system dependencies:\n" "XCode from the Apple Store\n" @@ -922,17 +1087,21 @@ class Tips(): "CUDA: https://developer.nvidia.com/cuda-downloads" "cuDNN: https://developer.nvidia.com/rdp/cudnn-download\n\n") - def pip(self): + @classmethod + def pip(cls) -> None: """ Pip Tips """ - self.output.info("1. Install PIP requirements\n" - "You may want to execute `chcp 65001` in cmd line\n" - "to fix Unicode issues on Windows when installing dependencies") + logger.info("1. Install PIP requirements\n" + "You may want to execute `chcp 65001` in cmd line\n" + "to fix Unicode issues on Windows when installing dependencies") if __name__ == "__main__": + logfile = os.path.join(os.path.dirname(os.path.realpath(sys.argv[0])), "faceswap_setup.log") + log_setup("INFO", logfile, "setup") + logger.debug("Setup called with args: %s", sys.argv) ENV = Environment() Checks(ENV) ENV.set_config() - if INSTALL_FAILED: + if _INSTALL_FAILED: sys.exit(1) Install(ENV) diff --git a/update_deps.py b/update_deps.py index b4a49452..8065de56 100644 --- a/update_deps.py +++ b/update_deps.py @@ -3,30 +3,32 @@ Checks for installed Conda / Pip packages and updates accordingly """ +import logging +import os +import sys -from setup import Environment, Install, Output +from lib.logger import log_setup +from setup import Environment, Install -_LOGGER = None +logger = logging.getLogger(__name__) -def output(msg): - """ Output to print or logger """ - if _LOGGER is not None: - _LOGGER.info(msg) - else: - Output().info(msg) +def main(is_gui=False) -> None: + """ Check for and update dependencies - -def main(logger=None): - """ Check for and update dependencies """ - if logger is not None: - global _LOGGER # pylint:disable=global-statement - _LOGGER = logger - output("Updating dependencies...") - update = Environment(logger=logger, updater=True) - Install(update) - output("Dependencies updated") + Parameters + ---------- + is_gui: bool, optional + ``True`` if being called by the GUI. Prevents the updater from outputting progress bars + which get scrambled in the GUI + """ + logger.info("Updating dependencies...") + update = Environment(updater=True) + Install(update, is_gui=is_gui) + logger.info("Dependencies updated") if __name__ == "__main__": + logfile = os.path.join(os.path.dirname(os.path.realpath(sys.argv[0])), "faceswap_update.log") + log_setup("INFO", logfile, "setup") main()