diff --git a/CHANGELOG.md b/CHANGELOG.md index 46ceb48..9c20ce2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,14 @@ ## Unreleased +### Added + +- You can now configure VS code internal log level using [`blender.addon.logLevel`](vscode://settings/blender.addon.logLevel) and [`blender.addon.logLevelGlobal`](vscode://settings/blender.addon.logLevelGlobal) (#198) + - to mute logs set log level to critical + - to enable more logs set log level to debug + - changing log level required blender restart + - logs now have colors + ## [0.0.23] - 2024-09-06 ### Added diff --git a/README.md b/README.md index c2dce75..ff17ffe 100644 --- a/README.md +++ b/README.md @@ -156,6 +156,8 @@ This addon has some ability to help with [Blender source code development](https - Use the latest Blender version from https://www.blender.org/download/. - Check [CHANGELOG](./CHANGELOG.md) for breaking changes. - Search Issues for similar problems. + - when reporting issue please enable debug logs using [`blender.addon.logLevel`](vscode://settings/blender.addon.logLevel) + and [`blender.addon.logLevelGlobal`](vscode://settings/blender.addon.logLevelGlobal) - Look in VS Code output window. ## Status diff --git a/package.json b/package.json index f6602c1..abe2a8a 100644 --- a/package.json +++ b/package.json @@ -258,6 +258,20 @@ "--factory-startup" ] ] + }, + "blender.addon.logLevel": { + "type": "string", + "scope": "resource", + "description": "Log level for blender_vscode extension inside Blender. Debug is most verbose.", + "default": "info", + "enum": ["debug", "info", "warning", "error", "critical"] + }, + "blender.addon.logLevelGlobal": { + "type": "string", + "scope": "resource", + "description": "Log level for 3rd party modules in blender_vscode extension. Debug is most verbose.", + "default": "warning", + "enum": ["debug", "info", "warning", "error", "critical"] } } } diff --git a/pythonFiles/include/blender_vscode/__init__.py b/pythonFiles/include/blender_vscode/__init__.py index 9f264ec..a78eea3 100644 --- a/pythonFiles/include/blender_vscode/__init__.py +++ b/pythonFiles/include/blender_vscode/__init__.py @@ -5,6 +5,10 @@ import bpy +from . import log + +LOG = log.getLogger() + @dataclass class AddonInfo: diff --git a/pythonFiles/include/blender_vscode/communication.py b/pythonFiles/include/blender_vscode/communication.py index 2501fd8..c4087e7 100644 --- a/pythonFiles/include/blender_vscode/communication.py +++ b/pythonFiles/include/blender_vscode/communication.py @@ -1,21 +1,26 @@ +import random +import threading import time +from functools import partial from typing import Callable, Dict -import flask import debugpy -import random +import flask import requests -import threading -from functools import partial -from .utils import run_in_main_thread + from .environment import blender_path, scripts_folder, python_path +from .utils import run_in_main_thread +from . import log + +LOG = log.getLogger() EDITOR_ADDRESS = None OWN_SERVER_PORT = None DEBUGPY_PORT = None -server = flask.Flask("Blender Server") -post_handlers = {} +SERVER = flask.Flask("Blender Server") +log.configure_flask_log(SERVER) +POST_HANDLERS = {} def setup(address: str, path_mappings): @@ -27,9 +32,9 @@ def setup(address: str, path_mappings): send_connection_information(path_mappings) - print("Waiting for debug client.") + LOG.info("Waiting for debug client.") debugpy.wait_for_client() - print("Debug client attached.") + LOG.info("Debug client attached.") def start_own_server(): @@ -39,7 +44,7 @@ def server_thread_function(): while True: try: port[0] = get_random_port() - server.run(debug=True, port=port[0], use_reloader=False) + SERVER.run(debug=True, port=port[0], use_reloader=False) except OSError: pass @@ -71,30 +76,38 @@ def start_debug_server(): ######################################### -@server.route("/", methods=["POST"]) +@SERVER.route("/", methods=["POST"]) def handle_post(): data = flask.request.get_json() - print("Got POST:", data) + LOG.debug(f"Got POST: {data}") - if data["type"] in post_handlers: - return post_handlers[data["type"]](data) + if data["type"] in POST_HANDLERS: + return POST_HANDLERS[data["type"]](data) + else: + LOG.warning(f"Unhandled POST: {data}") return "OK" -@server.route("/", methods=["GET"]) +@SERVER.route("/", methods=["GET"]) def handle_get(): data = flask.request.get_json() - print("Got GET:", data) + LOG.debug(f"Got GET: {str(data)}") if data["type"] == "ping": pass + elif data["type"] == "complete": + from .blender_complete import complete + + return {"items": complete(data)} + else: + LOG.warning(f"Unhandled GET: {data}") return "OK" def register_post_handler(type: str, handler: Callable): - assert type not in post_handlers, post_handlers - post_handlers[type] = handler + assert type not in POST_HANDLERS, POST_HANDLERS + POST_HANDLERS[type] = handler def register_post_action(type: str, handler: Callable): @@ -123,7 +136,7 @@ def send_connection_information(path_mappings: Dict): def send_dict_as_json(data): - print("Sending:", data) + LOG.debug(f"Sending: {data}") requests.post(EDITOR_ADDRESS, json=data) diff --git a/pythonFiles/include/blender_vscode/environment.py b/pythonFiles/include/blender_vscode/environment.py index 744ff2b..02e016e 100644 --- a/pythonFiles/include/blender_vscode/environment.py +++ b/pythonFiles/include/blender_vscode/environment.py @@ -1,11 +1,30 @@ +import logging +import os +import sys +from pathlib import Path from typing import Optional -import bpy -import sys import addon_utils -from pathlib import Path -import platform -import os +import bpy + +_str_to_log_level = { + "debug-with-flask": logging.DEBUG, + "debug": logging.DEBUG, + "info": logging.INFO, + "warning": logging.WARNING, + "error": logging.ERROR, + "critical": logging.CRITICAL, +} + + +def _parse_log(env_var_name: str) -> int: + log_env_global = os.environ.get(env_var_name, "info") or "info" + try: + return _str_to_log_level[log_env_global] + except KeyError as e: + logging.warning(f"Log level for {env_var_name} not set: {e}") + return logging.WARNING + # binary_path_python was removed in blender 2.92 # but it is the most reliable way of getting python path for older versions @@ -19,3 +38,5 @@ addon_directories = tuple(map(Path, addon_utils.paths())) EXTENSIONS_REPOSITORY: Optional[str] = os.environ.get("VSCODE_EXTENSIONS_REPOSITORY", "user_default") or "user_default" +LOG_LEVEL_GLOBAL = _parse_log("VSCODE_GLOBAL_LOG_LEVEL") +LOG_LEVEL = _parse_log("VSCODE_LOG_LEVEL") diff --git a/pythonFiles/include/blender_vscode/installation.py b/pythonFiles/include/blender_vscode/installation.py index 217c77b..b1e84d4 100644 --- a/pythonFiles/include/blender_vscode/installation.py +++ b/pythonFiles/include/blender_vscode/installation.py @@ -6,8 +6,10 @@ from pathlib import Path from . import handle_fatal_error +from . import log from .environment import python_path +LOG = log.getLogger() _CWD_FOR_SUBPROCESSES = python_path.parent @@ -40,7 +42,7 @@ def ensure_package_is_installed(name: str): def install_package(name: str): target = get_package_install_directory() command = [str(python_path), "-m", "pip", "install", name, "--target", target] - print("Execute: ", " ".join(command)) + LOG.info("Execute: ", " ".join(command)) subprocess.run(command, cwd=_CWD_FOR_SUBPROCESSES) if not module_can_be_imported(name): @@ -51,7 +53,7 @@ def install_pip(): # try ensurepip before get-pip.py if module_can_be_imported("ensurepip"): command = [str(python_path), "-m", "ensurepip", "--upgrade"] - print("Execute: ", " ".join(command)) + LOG.info("Execute: ", " ".join(command)) subprocess.run(command, cwd=_CWD_FOR_SUBPROCESSES) return # pip can not necessarily be imported into Blender after this diff --git a/pythonFiles/include/blender_vscode/load_addons.py b/pythonFiles/include/blender_vscode/load_addons.py index a92360e..7210cdd 100644 --- a/pythonFiles/include/blender_vscode/load_addons.py +++ b/pythonFiles/include/blender_vscode/load_addons.py @@ -7,11 +7,13 @@ import bpy -from . import AddonInfo +from . import AddonInfo, log from .communication import send_dict_as_json from .environment import addon_directories, EXTENSIONS_REPOSITORY from .utils import is_addon_legacy, addon_has_bl_info +LOG = log.getLogger() + if bpy.app.version >= (4, 2, 0): _EXTENSIONS_DEFAULT_DIR = Path(bpy.utils.user_resource("EXTENSIONS", path=EXTENSIONS_REPOSITORY)) else: @@ -37,7 +39,7 @@ def setup_addon_links(addons_to_load: List[AddonInfo]) -> List[Dict]: try: load_path = _link_addon_or_extension(addon_info) except PermissionError as e: - print( + LOG.error( f"""ERROR: {e} Path "{e.filename}" can not be removed. **Please remove it manually!** Most likely causes: - Path requires admin permissions to remove @@ -81,7 +83,7 @@ def _remove_duplicate_addon_links(addon_info: AddonInfo): existing_addon_with_the_same_target = does_addon_link_exist(addon_info.load_dir) while existing_addon_with_the_same_target: if existing_addon_with_the_same_target: - print("INFO: Removing old link:", existing_addon_with_the_same_target) + LOG.info(f"Removing old link: {existing_addon_with_the_same_target}") os.remove(existing_addon_with_the_same_target) existing_addon_with_the_same_target = does_addon_link_exist(addon_info.load_dir) @@ -90,7 +92,7 @@ def _remove_duplicate_extension_links(addon_info: AddonInfo): existing_extension_with_the_same_target = does_extension_link_exist(addon_info.load_dir) while existing_extension_with_the_same_target: if existing_extension_with_the_same_target: - print("INFO: Removing old link:", existing_extension_with_the_same_target) + LOG.info(f"Removing old link: {existing_extension_with_the_same_target}") os.remove(existing_extension_with_the_same_target) existing_extension_with_the_same_target = does_extension_link_exist(addon_info.load_dir) @@ -126,14 +128,14 @@ def _resolve_link(path: Path) -> Optional[str]: # OSError: [Errno 22] Invalid argument: '/snap/blender/5088/4.2/extensions/system/readme.txt' if e.errno == 22: return None - print("Warning: can not resolve link target", e) + LOG.warning("can not resolve link target", e) return None except ValueError as e: # there are major differences in python windows junction support (3.7.0 and 3.7.9 give different errors) if sys.platform == "win32": return _resolve_link_windows_cmd(path) else: - print("Warning: can not resolve link target", e) + LOG.warning("can not resolve link target", e) return None @@ -172,7 +174,7 @@ def ensure_extension_repo_exists(extensions_repository: str): repo: bpy.types.UserExtensionRepo if repo.module == extensions_repository: return repo - print(f'DEBUG: new extensions repository "{extensions_repository}" created') + LOG.debug(f'New extensions repository "{extensions_repository}" created') return bpy.context.preferences.extensions.repos.new(name=extensions_repository, module=extensions_repository) @@ -183,7 +185,7 @@ def remove_broken_addon_links(): continue target = _resolve_link(addon_dir) if target and not os.path.exists(target): - print("INFO: Removing invalid link:", addon_dir, "->", target) + LOG.info(f"Removing invalid link: {addon_dir} -> {target}") os.remove(addon_dir) @@ -199,7 +201,7 @@ def remove_broken_extension_links(): existing_extension_dir = repo_dir / file target = _resolve_link(existing_extension_dir) if target and not os.path.exists(target): - print("INFO: Removing invalid link:", existing_extension_dir, "->", target) + LOG.info(f"Removing invalid link: {existing_extension_dir} -> {target}") os.remove(existing_extension_dir) diff --git a/pythonFiles/include/blender_vscode/log.py b/pythonFiles/include/blender_vscode/log.py new file mode 100644 index 0000000..7cb737b --- /dev/null +++ b/pythonFiles/include/blender_vscode/log.py @@ -0,0 +1,56 @@ +import logging + +import flask.app + +from .environment import LOG_LEVEL, LOG_LEVEL_GLOBAL + + +class ColoredFormatter(logging.Formatter): + white = "\x1b[1;37;20m" + grey = "\x1b[1;38;20m" + yellow = "\x1b[1;33;20m" + red = "\x1b[1;31;20m" + bold_red = "\x1b[1;31;1m" + reset = "\x1b[1;0m" + format = "%(levelname)s: %(message)s (%(filename)s:%(lineno)d)" + + FORMATS = { + logging.DEBUG: grey + format + reset, + logging.INFO: white + format + reset, + logging.WARNING: yellow + format + reset, + logging.ERROR: red + format + reset, + logging.CRITICAL: bold_red + format + reset, + } + + def format(self, record): + log_fmt = self.FORMATS.get(record.levelno) + formatter = logging.Formatter(log_fmt) + return formatter.format(record) + + +def configure_flask_log(app: flask.app.Flask): + if LOG_LEVEL_GLOBAL <= logging.DEBUG: + return + logging.getLogger("werkzeug").disabled = True + app.logger.disabled = True + + +def getLogger(name: str = "blender_vs"): + logging.getLogger().setLevel(LOG_LEVEL_GLOBAL) + + log = logging.getLogger(name) + if log.handlers: + # log is already configured + return log + log.propagate = False + log.setLevel(LOG_LEVEL) + + # create console handler with a higher log level + ch = logging.StreamHandler() + ch.setLevel(logging.DEBUG) + + ch.setFormatter(ColoredFormatter()) + + log.addHandler(ch) + + return log diff --git a/pythonFiles/include/blender_vscode/operators/script_runner.py b/pythonFiles/include/blender_vscode/operators/script_runner.py index 755e36c..8b31e4c 100644 --- a/pythonFiles/include/blender_vscode/operators/script_runner.py +++ b/pythonFiles/include/blender_vscode/operators/script_runner.py @@ -4,6 +4,9 @@ from bpy.props import * from ..utils import redraw_all from ..communication import register_post_action +from .. import log + +LOG = log.getLogger() class RunScriptOperator(bpy.types.Operator): @@ -14,6 +17,8 @@ class RunScriptOperator(bpy.types.Operator): def execute(self, context): ctx = prepare_script_context(self.filepath) + LOG.info(f'Run script: "{self.filepath}"') + LOG.debug(f"Run script context override: {ctx}") runpy.run_path(self.filepath, init_globals={"CTX": ctx}) redraw_all() return {"FINISHED"} diff --git a/pythonFiles/launch.py b/pythonFiles/launch.py index e75f431..dc7b6fa 100644 --- a/pythonFiles/launch.py +++ b/pythonFiles/launch.py @@ -1,3 +1,4 @@ +import logging import os import sys import json @@ -14,7 +15,8 @@ else: import blender_vscode -print("ADDONS_TO_LOAD", json.loads(os.environ["ADDONS_TO_LOAD"])) +LOG = blender_vscode.log.getLogger() +LOG.info(f"ADDONS_TO_LOAD {json.loads(os.environ['ADDONS_TO_LOAD'])}") try: addons_to_load = [] diff --git a/src/blender_executable.ts b/src/blender_executable.ts index 8be249d..4dd6603 100644 --- a/src/blender_executable.ts +++ b/src/blender_executable.ts @@ -272,6 +272,8 @@ async function getBlenderLaunchEnv() { return { ADDONS_TO_LOAD: JSON.stringify(loadDirsWithNames), VSCODE_EXTENSIONS_REPOSITORY: config.get("addon.extensionsRepository"), + VSCODE_GLOBAL_LOG_LEVEL: config.get("addon.logLevelGlobal"), + VSCODE_LOG_LEVEL: config.get("addon.logLevel"), EDITOR_PORT: getServerPort().toString(), ...config.get("environmentVariables", {}), };