diff --git a/docs/development.md b/docs/development.md index 8cde546..53a8f61 100644 --- a/docs/development.md +++ b/docs/development.md @@ -126,7 +126,7 @@ the package's `pyproject.toml`: ```toml [project.entry-points."mvt.modules"] -my-mvt-modules = "my_mvt_modules:get_modules" +mvt-plugin-amnesty-custom = "mvt_plugin_amnesty_custom:get_modules" ``` The entry point must resolve to an iterable of `MVTModule` subclasses, or to @@ -157,9 +157,39 @@ from sources you trust. For a `pipx` installation of MVT, inject the package into MVT's environment: ```bash -pipx inject mvt my-mvt-modules +pipx inject mvt mvt-plugin-amnesty-custom ``` +### Naming module packages + +Name module packages `mvt-plugin-` (import package `mvt_plugin_`), +and include the name of the publishing organization or author so packages from +different groups do not collide: for example, Amnesty International's custom +modules would be distributed as `mvt-plugin-amnesty-custom` with the import +package `mvt_plugin_amnesty_custom`. + +The prefix makes module packages easy to find on PyPI and keeps their import +names from clashing with unrelated Python packages. It is a convention, not a +technical requirement: modules load through the `mvt.modules` entry point +regardless of what the package is called, and existing packages with other +names keep working. Note that the prefix is also not a mark of authenticity — +anyone can publish a package with any available name, so vet a module package +and its publisher before installing it, whatever it is called. + +### Module logging + +Modules log through `self.log`, and MVT names the logger for where the module +came from. MVT's own modules log under their dotted path (for example +`mvt.ios.modules.mixed.whatsapp`). Everything external is namespaced under +`mvt.ext` to keep it visually distinct from built-in modules and isolated from +MVT's internal logger tree: + +- Installed packages log under `mvt.ext.`, with the `mvt_plugin_` + prefix stripped: modules in `mvt_plugin_amnesty_custom` log as + `mvt.ext.amnesty_custom.*`. +- Files loaded with `--load-module` or `MVT_CUSTOM_MODULES` log as + `mvt.ext.`. + ## Auditing loaded modules Because installed module packages load automatically, MVT records where every diff --git a/src/mvt/common/cmd_check_iocs.py b/src/mvt/common/cmd_check_iocs.py index c227659..c2dbdcd 100644 --- a/src/mvt/common/cmd_check_iocs.py +++ b/src/mvt/common/cmd_check_iocs.py @@ -9,6 +9,7 @@ from typing import Optional from mvt.common.command import Command from mvt.common.module import MVTModule +from mvt.common.module_loader import get_module_logger from mvt.common.utils import exec_or_profile log = logging.getLogger(__name__) @@ -76,7 +77,7 @@ class CmdCheckIOCS(Command): ) m = iocs_module.from_json( - file_path, log=logging.getLogger(iocs_module.__module__) + file_path, log=get_module_logger(iocs_module) ) if not m: log.warning("No result from this module, skipping it") diff --git a/src/mvt/common/command.py b/src/mvt/common/command.py index 54a59e2..6111dc7 100644 --- a/src/mvt/common/command.py +++ b/src/mvt/common/command.py @@ -19,7 +19,12 @@ from .alerts import AlertLevel, AlertStore from .config import settings from .indicators import Indicators from .module import EncryptedBackupError, MVTModule, run_module, save_timeline -from .module_loader import ModuleOrigin, get_module_origin, module_supports_command +from .module_loader import ( + ModuleOrigin, + get_module_logger, + get_module_origin, + module_supports_command, +) from .module_types import ModuleTimeline, URLResult from .utils import ( CustomJSONEncoder, @@ -394,7 +399,7 @@ class Command: executed_by_type: dict[type[MVTModule], MVTModule] = {} for module in ordered_modules: - module_logger = logging.getLogger(module.__module__) + module_logger = get_module_logger(module) m = module( target_path=self.target_path, diff --git a/src/mvt/common/module_loader.py b/src/mvt/common/module_loader.py index 893e9b8..956da4c 100644 --- a/src/mvt/common/module_loader.py +++ b/src/mvt/common/module_loader.py @@ -22,7 +22,10 @@ from .version import MVT_VERSION MVT_CUSTOM_MODULES_ENV = "MVT_CUSTOM_MODULES" MODULES_ENTRY_POINT_GROUP = "mvt.modules" +EXTERNAL_LOGGER_NAMESPACE = "mvt.ext" +PLUGIN_PACKAGE_PREFIX = "mvt_plugin_" _ORIGIN_ATTRIBUTE = "_mvt_module_origin" +_PATH_MODULE_PREFIX = "_mvt_custom_module_" log = logging.getLogger(__name__) @@ -60,7 +63,36 @@ class ModuleOrigin: def _module_name_for_path(path: Path) -> str: digest = hashlib.sha256(str(path).encode("utf-8")).hexdigest()[:16] - return f"_mvt_custom_module_{path.stem}_{digest}" + return f"{_PATH_MODULE_PREFIX}{path.stem}_{digest}" + + +def get_module_logger(module_class: type[MVTModule]) -> logging.Logger: + """Return the logger a module's records should be emitted through. + + Modules loaded from installed packages or file paths live outside the + "mvt" logger hierarchy, so their records would never reach the handlers + attached to the "mvt" logger and instead fall through to + logging.lastResort (which prints bare messages and drops anything below + WARNING). Their loggers are parented under the "mvt.ext" namespace, + keeping external module names from colliding with MVT's own logger + tree. File-path modules are named after their file instead of the + mangled internal import name, and packages following the recommended + "mvt_plugin_" naming convention log under "mvt.ext.". + """ + name = module_class.__module__ + if name == "mvt" or name.startswith("mvt."): + return logging.getLogger(name) + + if name.startswith(_PATH_MODULE_PREFIX): + name = Path(get_module_origin(module_class).name).stem + else: + top_level, separator, rest = name.partition(".") + if top_level.startswith(PLUGIN_PACKAGE_PREFIX) and len(top_level) > len( + PLUGIN_PACKAGE_PREFIX + ): + name = top_level[len(PLUGIN_PACKAGE_PREFIX) :] + separator + rest + + return logging.getLogger(f"{EXTERNAL_LOGGER_NAMESPACE}.{name}") def _iter_module_files(path: Path) -> Iterable[Path]: diff --git a/tests/common/test_module_loader.py b/tests/common/test_module_loader.py index 15b6052..dec636e 100644 --- a/tests/common/test_module_loader.py +++ b/tests/common/test_module_loader.py @@ -3,10 +3,12 @@ import pytest from mvt.common.module import MVTModule from mvt.common.module_loader import ( CustomModuleLoadError, + get_module_logger, load_custom_modules, load_custom_modules_from_path, module_supports_command, ) +from mvt.ios.modules.mixed.whatsapp import Whatsapp MODULE_TEMPLATE = """ @@ -144,3 +146,44 @@ def test_module_supports_command_honors_supported_commands(tmp_path): assert module_supports_command(module, "ios", "check-backup") assert not module_supports_command(module, "ios", "check-fs") + + +def test_get_module_logger_keeps_builtin_names(): + assert get_module_logger(Whatsapp).name == "mvt.ios.modules.mixed.whatsapp" + + +def test_get_module_logger_parents_package_modules_under_mvt_ext(): + class PackageModule(MVTModule): + pass + + PackageModule.__module__ = "some_plugin_package.ios.custom" + + assert ( + get_module_logger(PackageModule).name + == "mvt.ext.some_plugin_package.ios.custom" + ) + + +def test_get_module_logger_strips_the_plugin_package_prefix(): + class PluginModule(MVTModule): + pass + + PluginModule.__module__ = "mvt_plugin_amnesty_custom.ios.custom" + + assert get_module_logger(PluginModule).name == "mvt.ext.amnesty_custom.ios.custom" + + +def test_get_module_logger_only_strips_the_prefix_from_the_top_level(): + class NestedModule(MVTModule): + pass + + NestedModule.__module__ = "other_package.mvt_plugin_sub" + + assert get_module_logger(NestedModule).name == "mvt.ext.other_package.mvt_plugin_sub" + + +def test_get_module_logger_names_path_modules_after_their_file(tmp_path): + module_path = _write_module(tmp_path / "my_custom_module.py", "PathModule") + module = load_custom_modules_from_path(str(module_path))[0] + + assert get_module_logger(module).name == "mvt.ext.my_custom_module"