diff --git a/digsigserver/logredaction.py b/digsigserver/logredaction.py new file mode 100644 index 0000000..9f235af --- /dev/null +++ b/digsigserver/logredaction.py @@ -0,0 +1,81 @@ +import hashlib +import logging +import subprocess +from typing import Any + + +class SecretRedactionFilter(logging.Filter): + def __init__(self) -> None: + super().__init__() + self._secrets: list[str] = [] + + def set_secrets(self, secrets: list[str]) -> None: + self._secrets = [secret for secret in secrets if secret] + + @staticmethod + def _redaction_token(secret: str) -> str: + return f"sha256:{hashlib.sha256(secret.encode('utf-8')).digest()[:16].hex()}" + + def _redact(self, value: Any) -> Any: + if isinstance(value, str): + for secret in self._secrets: + value = value.replace(secret, self._redaction_token(secret)) + return value + if isinstance(value, tuple): + return tuple(self._redact(item) for item in value) + if isinstance(value, list): + return [self._redact(item) for item in value] + if isinstance(value, dict): + return {key: self._redact(item) for key, item in value.items()} + return value + + def _redact_exception(self, exc: BaseException) -> BaseException: + if isinstance(exc, subprocess.CalledProcessError): + return subprocess.CalledProcessError( + exc.returncode, + self._redact(exc.cmd), + output=self._redact(exc.output), + stderr=self._redact(exc.stderr), + ) + + redacted_args = self._redact(exc.args) + try: + return type(exc)(*redacted_args) + except Exception: + return RuntimeError(self._redact(str(exc))) + + def _redact_record_fields(self, record: logging.LogRecord) -> None: + for key, value in tuple(record.__dict__.items()): + if key in {'msg', 'args', 'exc_info', 'exc_text', 'message'}: + continue + record.__dict__[key] = self._redact(value) + + def filter(self, record: logging.LogRecord) -> bool: + record.msg = self._redact(record.msg) + record.args = self._redact(record.args) + if isinstance(record.msg, str): + record.msg = self._redact(record.getMessage()) + record.args = () + if record.exc_info: + exc_type, exc_value, exc_traceback = record.exc_info + if exc_value is not None: + record.exc_info = (exc_type, self._redact_exception(exc_value), exc_traceback) + self._redact_record_fields(record) + if hasattr(record, 'exc_text'): + record.exc_text = None + return True + + +def install_log_redaction_filter(secrets: list[str]) -> SecretRedactionFilter: + for logger_name in ('', 'sanic.root', 'sanic.error', 'sanic.access'): + target_logger = logging.getLogger(logger_name) + for existing_filter in target_logger.filters: + if isinstance(existing_filter, SecretRedactionFilter): + existing_filter.set_secrets(secrets) + return existing_filter + redaction_filter = SecretRedactionFilter() + redaction_filter.set_secrets(secrets) + for logger_name in ('', 'sanic.root', 'sanic.error', 'sanic.access'): + target_logger = logging.getLogger(logger_name) + target_logger.addFilter(redaction_filter) + return redaction_filter diff --git a/digsigserver/server.py b/digsigserver/server.py index 5a48c20..38d1add 100644 --- a/digsigserver/server.py +++ b/digsigserver/server.py @@ -1,10 +1,15 @@ import asyncio +import logging import tempfile from typing import Optional import re import os +import uuid +import ipaddress +from contextvars import ContextVar from sanic import Sanic, request +from sanic.exceptions import SanicException from sanic.log import logger from sanic.response import text @@ -20,6 +25,7 @@ from digsigserver.signers.ueficapsulesign import UefiCapsuleSigner from digsigserver.signers.ekbsign import EKBSigner from digsigserver.signers.fitimagesign import FitImageSigner +from digsigserver.logredaction import install_log_redaction_filter from . import utils # Signing can take a loooong time, so set a more reasonable @@ -30,7 +36,8 @@ 'L4T_TOOLS_BASE': '/opt/nvidia', 'IMX_CST_BASE': '/opt/NXP', 'KEYFILE_URI': 'file:///please/configure/this/path', - 'LOG_LEVEL': 'DEBUG' + 'LOG_LEVEL': 'DEBUG', + 'SOURCE_IP_WHITELIST': '', } """ @@ -38,15 +45,270 @@ """ +request_source_ip: ContextVar[str | None] = ContextVar('request_source_ip', default=None) +request_ssl_client_s_dn: ContextVar[str | None] = ContextVar('request_ssl_client_s_dn', default=None) +request_ssl_client_verify: ContextVar[str | None] = ContextVar('request_ssl_client_verify', default=None) +TRUSTED_PROXY_IPS = {'172.30.0.11'} +AUDIT_LOG_DUMP_EXCLUDED_PATHS = {'/health'} + + +def load_dotenv(path: str = '.env') -> None: + if not os.path.exists(path): + return + with open(path, mode='r', encoding='utf-8') as f: + for raw_line in f: + line = raw_line.strip() + if not line or line.startswith('#'): + continue + if line.startswith('export '): + line = line[7:].lstrip() + key, sep, value = line.partition('=') + if not sep: + continue + key = key.strip() + value = value.strip() + if len(value) >= 2 and value[0] == value[-1] and value[0] in ("'", '"'): + value = value[1:-1] + os.environ.setdefault(key, value) + + def create_app() -> Sanic: - app = Sanic(name='digsigserver', env_prefix='DIGSIGSERVER_') + load_dotenv(os.environ.get('DIGSIGSERVER_DOTENV', '.env')) + resolved_level = resolve_log_level(os.environ.get('DIGSIGSERVER_LOG_LEVEL', CodesignSanicDefaults['LOG_LEVEL'])) + app = Sanic(name='digsigserver', env_prefix='DIGSIGSERVER_', log_config=build_sanic_log_config(resolved_level)) app.config.update_config(CodesignSanicDefaults) app.config.load_environment_vars(prefix='DIGSIGSERVER_') - logger.setLevel(app.config.get("LOG_LEVEL")) + file_backed_password = utils.read_secret_file(app.config.get('YUBIHSM_PASSWORD_FILE')) + if file_backed_password is not None: + app.config['YUBIHSM_PASSWORD'] = file_backed_password + install_log_redaction_filter(utils.get_yubihsm_redaction_secrets()) + install_request_logging_filter() + attach_request_context_handlers(app) + attach_exception_handlers(app) attach_endpoints(app) return app +def resolve_log_level(log_level: int | str | None) -> int: + if isinstance(log_level, int): + return log_level + if isinstance(log_level, str): + resolved_level = logging.getLevelNamesMapping().get(log_level.upper()) + if resolved_level is not None: + return resolved_level + raise ValueError(f'Invalid LOG_LEVEL: {log_level}') + return logging.INFO + + +def build_sanic_log_config(log_level: int) -> dict: + return { + 'version': 1, + 'disable_existing_loggers': False, + 'formatters': { + 'logfmt': { + '()': 'digsigserver.setup_logfmt.LogfmtFormatter', + }, + }, + 'handlers': { + 'stderr': { + 'class': 'logging.StreamHandler', + 'formatter': 'logfmt', + 'level': log_level, + 'stream': 'ext://sys.stderr', + }, + 'stdout': { + 'class': 'logging.StreamHandler', + 'formatter': 'logfmt', + 'level': log_level, + 'stream': 'ext://sys.stdout', + }, + }, + 'loggers': { + 'sanic.root': {'handlers': ['stderr'], 'level': log_level, 'propagate': False}, + 'sanic.error': {'handlers': ['stderr'], 'level': log_level, 'propagate': False}, + 'sanic.server': {'handlers': ['stderr'], 'level': log_level, 'propagate': False}, + 'sanic.websockets': {'handlers': ['stderr'], 'level': log_level, 'propagate': False}, + 'sanic.access': {'handlers': ['stdout'], 'level': log_level, 'propagate': False}, + }, + 'root': { + 'handlers': ['stderr'], + 'level': log_level, + }, + } + + +class RequestContextFilter(logging.Filter): + def filter(self, record: logging.LogRecord) -> bool: + source_ip = request_source_ip.get() + if source_ip: + record.source_ip = source_ip + ssl_client_s_dn = request_ssl_client_s_dn.get() + if ssl_client_s_dn: + record.ssl_client_s_dn = ssl_client_s_dn + ssl_client_verify = request_ssl_client_verify.get() + if ssl_client_verify: + record.ssl_client_verify = ssl_client_verify + return True + + +def install_request_logging_filter() -> None: + request_filter = RequestContextFilter() + for logger_name in ('', 'sanic.root', 'sanic.error', 'sanic.server', 'sanic.websockets', 'sanic.access'): + target_logger = logging.getLogger(logger_name) + if any(isinstance(existing_filter, RequestContextFilter) for existing_filter in target_logger.filters): + continue + target_logger.addFilter(request_filter) + + +class LogAuditCategory: + ACCESS_CONTROL = 'accessControl' + REQUEST_ERRORS = 'requestErrors' + CONTROL_SYSTEM_EVENTS = 'controlSystemEvents' + BACKUP_AND_RESTORE_EVENTS = 'backupAndRestoreEvents' + CONFIGURATION_CHANGES = 'configurationChanges' + AUDIT_LOG_EVENTS = 'auditLogEvents' + PKI_SIGNING = 'pkiSigning' + + +def build_audit_payload(category: str, event_type: str, event_result: object, **fields) -> dict: + payload = { + 'audit': True, + 'category': category, + 'type': event_type, + 'event_id': str(uuid.uuid4()), + 'event_result': event_result, + } + for key, value in fields.items(): + if value is not None: + payload[key] = value + return payload + + +def log_audit( + category: str, + event_type: str, + event_result: object, + *, + level: int = logging.INFO, + exc: Exception | None = None, + **fields, +) -> None: + payload = build_audit_payload(category, event_type, event_result, **fields) + logger.log(level, payload, exc_info=exc) + + +def log_signing_audit(event_type: str, event_result: str, **fields) -> None: + log_audit(LogAuditCategory.PKI_SIGNING, event_type, event_result, **fields) + + +def parse_csv_config(value: str | None) -> list[str]: + if not value: + return [] + return [item.strip() for item in str(value).split(',') if item.strip()] + + +def get_peer_ip(req: request) -> str | None: + remote_addr = getattr(req, 'remote_addr', None) + if isinstance(remote_addr, tuple): + return remote_addr[0] + return remote_addr + + +def get_source_ip(req: request) -> str | None: + peer_ip = get_peer_ip(req) + if peer_ip not in TRUSTED_PROXY_IPS: + return peer_ip + + forwarded_for = req.headers.get('x-forwarded-for') + if not forwarded_for: + return peer_ip + + forwarded_ips = parse_csv_config(forwarded_for) + return forwarded_ips[0] if forwarded_ips else peer_ip + + +def is_ip_allowed(req: request, source_ip: str | None) -> bool: + whitelist = parse_csv_config(req.app.config.get('SOURCE_IP_WHITELIST')) + if not whitelist or not source_ip: + return True + + source_address = ipaddress.ip_address(source_ip) + for entry in whitelist: + try: + if '/' in entry: + if source_address in ipaddress.ip_network(entry, strict=False): + return True + elif source_address == ipaddress.ip_address(entry): + return True + except ValueError: + logger.warning('Invalid SOURCE_IP_WHITELIST entry: %s', entry) + return False + + +def attach_request_context_handlers(app: Sanic): + @app.on_request + async def bind_request_source_ip(req: request): + source_ip = get_source_ip(req) + ssl_client_s_dn = req.headers.get('x-ssl-client-s-dn') + ssl_client_verify = req.headers.get('x-ssl-client-verify') + req.ctx.source_ip = source_ip + req.ctx.ssl_client_s_dn = ssl_client_s_dn + req.ctx.ssl_client_verify = ssl_client_verify + request_source_ip.set(source_ip) + request_ssl_client_s_dn.set(ssl_client_s_dn) + request_ssl_client_verify.set(ssl_client_verify) + if not is_ip_allowed(req, source_ip): + log_audit(LogAuditCategory.ACCESS_CONTROL, 'source_ip_denied', 'failure', + source_ip=source_ip, request_path=req.path, request_method=req.method) + return text('Forbidden', status=403) + + @app.on_response + async def clear_request_source_ip(req: request, res): + del res + should_dump_audit_logs = req.path not in AUDIT_LOG_DUMP_EXCLUDED_PATHS + del req + request_source_ip.set(None) + request_ssl_client_s_dn.set(None) + request_ssl_client_verify.set(None) + if should_dump_audit_logs: + await utils.dump_upload_and_reset_logs() + + +def attach_exception_handlers(app: Sanic): + @app.exception(SanicException) + async def handle_sanic_exception(req: request, exc: SanicException): + log_audit( + LogAuditCategory.REQUEST_ERRORS, + 'http_exception', + 'failure', + level=logging.ERROR, + exc=exc, + request_path=req.path, + request_method=req.method, + source_ip=getattr(req.ctx, 'source_ip', None), + ssl_client_s_dn=getattr(req.ctx, 'ssl_client_s_dn', None), + ssl_client_verify=getattr(req.ctx, 'ssl_client_verify', None), + status_code=getattr(exc, 'status_code', 500), + ) + return text(str(exc), status=getattr(exc, 'status_code', 500)) + + @app.exception(Exception) + async def handle_unexpected_error(req: request, exc: Exception): + log_audit( + LogAuditCategory.REQUEST_ERRORS, + 'unhandled_exception', + 'failure', + level=logging.ERROR, + exc=exc, + request_path=req.path, + request_method=req.method, + source_ip=getattr(req.ctx, 'source_ip', None), + ssl_client_s_dn=getattr(req.ctx, 'ssl_client_s_dn', None), + ssl_client_verify=getattr(req.ctx, 'ssl_client_verify', None), + ) + return text('Signing error', status=500) + + def config_get(item: str, default_value=None) -> str: return Sanic.get_app('digsigserver').config.get(item, default_value) @@ -98,6 +360,10 @@ async def return_tarball(req: request, workdir: str, return_filename: str = "sig def attach_endpoints(app: Sanic): + @app.get("/health") + async def health_handler(req: request): + return text("OK") + @app.post("/sign/tegra") async def sign_handler_tegra(req: request): f = validate_upload(req, "artifact") @@ -122,7 +388,11 @@ async def sign_handler_tegra(req: request): else: result = await asyncio.get_running_loop().run_in_executor(None, s.sign, envvars) if result: + log_signing_audit('tegra_sign', 'success', machine=req.form.get('machine'), + soctype=req.form.get('soctype'), bsp_version=req.form.get('bspversion')) return await return_tarball(req, workdir) + log_signing_audit('tegra_sign', 'failure', machine=req.form.get('machine'), + soctype=req.form.get('soctype'), bsp_version=req.form.get('bspversion')) return text("Signing error", status=500) @app.post("/sign/rk") @@ -146,9 +416,13 @@ async def sign_handler_rk_kernel_fit(req: request): workdir, f): if await asyncio.get_running_loop().run_in_executor(None, s.sign, artifact_type, burn_key_hash, None, None, external_data_offset): + log_signing_audit('rockchip_sign', 'success', artifact_type=artifact_type, + machine=req.form.get('machine'), soctype=req.form.get('soctype')) await return_tarball(req, workdir, s.fit_image_output_files) response = None else: + log_signing_audit('rockchip_sign', 'failure', artifact_type=artifact_type, + machine=req.form.get('machine'), soctype=req.form.get('soctype')) response = text("Signing error", status=500) else: with open(os.path.join(workdir, "artifact"), "wb") as artifact: @@ -157,9 +431,13 @@ async def sign_handler_rk_kernel_fit(req: request): outfile.close() if await asyncio.get_running_loop().run_in_executor(None, s.sign, artifact_type, burn_key_hash, artifact.name, outfile.name, None): + log_signing_audit('rockchip_sign', 'success', artifact_type=artifact_type, + machine=req.form.get('machine'), soctype=req.form.get('soctype')) await return_file(req, outfile.name, "artifact.signed") response = None else: + log_signing_audit('rockchip_sign', 'failure', artifact_type=artifact_type, + machine=req.form.get('machine'), soctype=req.form.get('soctype')) response = text("Signing error", status=500) return response @@ -187,9 +465,15 @@ async def sign_handler_imx(req: request): outfile.close() if await asyncio.get_running_loop().run_in_executor(None, s.sign, outfile.name): + log_signing_audit('imx_sign', 'success', machine=req.form.get('machine'), + soctype=req.form.get('soctype'), cst_version=req.form.get('cstversion'), + backend=req.form.get('backend')) await return_file(req, outfile.name, "artifact.signed") response = None else: + log_signing_audit('imx_sign', 'failure', machine=req.form.get('machine'), + soctype=req.form.get('soctype'), cst_version=req.form.get('cstversion'), + backend=req.form.get('backend')) response = text("Signing error", status=500) return response @@ -198,9 +482,15 @@ async def sign_handler_fitimage(req: request): f = validate_upload(req, "artifact") if not f: return text("Invalid artifact", status=400) + backend = req.form.get("backend") + keyname = req.form.get("keyname") + if backend == "pkcs11" and not keyname: + return text("Key URI missing for PKCS#11 backend", status=400) + if not keyname: + keyname = "dev" with tempfile.TemporaryDirectory() as workdir: try: - s = FitImageSigner(app, workdir) + s = FitImageSigner(app, workdir, backend) except ValueError: return text("Invalid parameters", status=400) @@ -214,11 +504,20 @@ async def sign_handler_fitimage(req: request): None, req.form.get("external_data_offset"), req.form.get("mark_required"), - req.form.get("algo"), - req.form.get("keyname")): + req.form.get("algo"), + keyname, + req.form.get("comment")): + log_signing_audit('fitimage_sign', 'success', backend=backend, + mark_required=bool(req.form.get('mark_required')), + algo=req.form.get('algo'), + has_comment=bool(req.form.get('comment'))) await return_file(req, artifact.name, "artifact.signed") response = None else: + log_signing_audit('fitimage_sign', 'failure', backend=backend, + mark_required=bool(req.form.get('mark_required')), + algo=req.form.get('algo'), + has_comment=bool(req.form.get('comment'))) response = text("Signing error", status=500) return response @@ -236,7 +535,11 @@ async def sign_handler_modules(req: request): if await asyncio.get_running_loop().run_in_executor(None, utils.extract_files, workdir, f): result = await asyncio.get_running_loop().run_in_executor(None, s.sign) if result: + log_signing_audit('module_sign', 'success', machine=req.form.get('machine'), + hash_alg=req.form.get('hashalg', 'sha512')) return await return_tarball(req, workdir) + log_signing_audit('module_sign', 'failure', machine=req.form.get('machine'), + hash_alg=req.form.get('hashalg', 'sha512')) return text("Signing error", status=500) @app.post("/sign/tegra/uefi") @@ -264,9 +567,13 @@ async def sign_handler_uefi(req: request): s.sign, artifact.name, outfile.name): + log_signing_audit('uefi_sign', 'success', machine=req.form.get('machine'), + signing_type=req.form.get('signing_type')) await return_file(req, outfile.name, "artifact.signed") response = None else: + log_signing_audit('uefi_sign', 'failure', machine=req.form.get('machine'), + signing_type=req.form.get('signing_type')) response = text("Signing error", status=500) os.unlink(outfile.name) return response @@ -296,9 +603,13 @@ async def sign_handler_uefi_capsule(req: request): s.generate_signed_capsule, artifact.name, outfile.name): + log_signing_audit('uefi_capsule_sign', 'success', machine=req.form.get('machine'), + soctype=req.form.get('soctype'), bsp_version=req.form.get('bspversion')) await return_file(req, outfile.name, "artifact.cap") response = None else: + log_signing_audit('uefi_capsule_sign', 'failure', machine=req.form.get('machine'), + soctype=req.form.get('soctype'), bsp_version=req.form.get('bspversion')) response = text("Signing error", status=500) os.unlink(outfile.name) return response @@ -317,7 +628,9 @@ async def sign_handler_optee(req: request): if await asyncio.get_running_loop().run_in_executor(None, utils.extract_files, workdir, f): result = await asyncio.get_running_loop().run_in_executor(None, s.sign) if result: + log_signing_audit('optee_sign', 'success', machine=req.form.get('machine')) return await return_tarball(req, workdir) + log_signing_audit('optee_sign', 'failure', machine=req.form.get('machine')) return text("Signing error", status=500) @app.post("/sign/rkoptee-tee") @@ -337,9 +650,11 @@ async def sign_handler_rk_optee_tee(req: request): if await asyncio.get_running_loop().run_in_executor(None, s.resign_tee, os.path.join(workdir, "tee.bin"), outfile.name): + log_signing_audit('rockchip_optee_tee_sign', 'success', machine=req.form.get('machine')) await return_file(req, outfile.name, "tee.bin.signed") response = None else: + log_signing_audit('rockchip_optee_tee_sign', 'failure', machine=req.form.get('machine')) response = text("Signing error", status=500) os.unlink(outfile.name) return response @@ -358,7 +673,9 @@ async def sign_handler_rk_optee_ta(req: request): if await asyncio.get_running_loop().run_in_executor(None, utils.extract_files, workdir, f): result = await asyncio.get_running_loop().run_in_executor(None, s.resign_tas) if result: + log_signing_audit('rockchip_optee_ta_sign', 'success', machine=req.form.get('machine')) return await return_tarball(req, workdir) + log_signing_audit('rockchip_optee_ta_sign', 'failure', machine=req.form.get('machine')) return text("Signing error", status=500) @app.post("/sign/swupdate") @@ -366,15 +683,19 @@ async def sign_handler_swupdate(req: request): distro = req.form.get("distro") if not distro: return text("Distro name missing", status=400) + backend = req.form.get("backend") method = req.form.get("method") if not method: method = "RSA" + key_uri = req.form.get("key-uri") + if backend == "pkcs11" and not key_uri: + return text("Key URI missing for PKCS#11 backend", status=400) f = validate_upload(req, "sw-description") if not f: return text("Invalid sw-description", status=400) with tempfile.TemporaryDirectory() as workdir: try: - s = SwupdateSigner(app, workdir, distro) + s = SwupdateSigner(app, workdir, distro, backend) except ValueError: logger.info("could not init signer") return text("Invalid parameters", status=400) @@ -384,10 +705,12 @@ async def sign_handler_swupdate(req: request): infile.write(f.body.decode('UTF-8')) if await asyncio.get_running_loop().run_in_executor(None, s.sign, method, "sw-description", - outfile.name): + outfile.name, key_uri): + log_signing_audit('swupdate_sign', 'success', distro=distro, backend=backend, method=method) await return_file(req, outfile.name, "sw-description.sig") response = None else: + log_signing_audit('swupdate_sign', 'failure', distro=distro, backend=backend, method=method) response = text("Signing error", status=500) os.unlink(outfile.name) return response @@ -406,7 +729,9 @@ async def sign_handler_mender(req: request): except ValueError: return text("Invalid parameters", status=400) if await asyncio.get_running_loop().run_in_executor(None, s.sign): + log_signing_audit('mender_sign', 'success', distro=distro) return text("Signing successful") + log_signing_audit('mender_sign', 'failure', distro=distro) return text("Signing error", status=500) @@ -428,9 +753,13 @@ async def get_handler_ekb(req: request): if await asyncio.get_running_loop().run_in_executor(None, s.generate_ekb, outfile.name): + log_signing_audit('ekb_sign', 'success', machine=req.form.get('machine'), + soctype=req.form.get('soctype'), bsp_version=req.form.get('bspversion')) await return_file(req, outfile.name, "ekb.img") response = None else: + log_signing_audit('ekb_sign', 'failure', machine=req.form.get('machine'), + soctype=req.form.get('soctype'), bsp_version=req.form.get('bspversion')) response = text("Signing error", status=500) os.unlink(outfile.name) return response diff --git a/digsigserver/setup_logfmt.py b/digsigserver/setup_logfmt.py new file mode 100644 index 0000000..be304c8 --- /dev/null +++ b/digsigserver/setup_logfmt.py @@ -0,0 +1,96 @@ +import logging +import sys +from datetime import datetime, UTC + +STANDARD_LOG_RECORD_KEYS = frozenset(logging.makeLogRecord({}).__dict__) + + +class LogfmtFormatter(logging.Formatter): + source = 'secure-boot-signer-digsigserver' + + def __init__(self) -> None: + super().__init__() + + @staticmethod + def _quote(text: str) -> str: + if not text or any(ch.isspace() for ch in text) or any(ch in text for ch in '"='): + text = ( + text.replace('\\', '\\\\') + .replace('\n', '\\n') + .replace('\r', '\\r') + .replace('\t', '\\t') + .replace('"', '\\"') + ) + return f'"{text}"' + return text + + @classmethod + def _format_value(cls, value: object) -> str: + if isinstance(value, bool): + return 'true' if value else 'false' + if value is None: + return 'null' + if isinstance(value, str): + return cls._quote(value.strip()) + return cls._quote(str(value)) + + def format(self, record: logging.LogRecord) -> str: + timestamp = datetime.fromtimestamp(record.created, UTC).strftime('%Y-%m-%dT%H:%M:%SZ') + parts = [ + f'ts={timestamp}', + f'level={record.levelname}', + f'source={self._format_value(self.source)}', + f'name={self._format_value(record.name)}', + ] + source_ip = getattr(record, 'source_ip', None) + if source_ip: + parts.append(f'source_ip={self._format_value(source_ip)}') + ssl_client_s_dn = getattr(record, 'ssl_client_s_dn', None) + if ssl_client_s_dn: + parts.append(f'ssl_client_s_dn={self._format_value(ssl_client_s_dn)}') + ssl_client_verify = getattr(record, 'ssl_client_verify', None) + if ssl_client_verify: + parts.append(f'ssl_client_verify={self._format_value(ssl_client_verify)}') + + extra_fields = { + key: value + for key, value in record.__dict__.items() + if key not in STANDARD_LOG_RECORD_KEYS + and key not in {'source_ip', 'ssl_client_s_dn', 'ssl_client_verify'} + } + + if isinstance(record.msg, dict): + for key, value in record.msg.items(): + parts.append(f'{key}={self._format_value(value)}') + else: + message = record.getMessage() + if message: + parts.append(f'msg={self._format_value(message)}') + for key, value in extra_fields.items(): + parts.append(f'{key}={self._format_value(value)}') + if record.exc_info: + parts.append(f'exc_info={self._format_value(self.formatException(record.exc_info))}') + return ' '.join(parts) + + +def setup_logfmt( + logger_level: int | None = None, + handler: logging.Handler | None = None, + should_update_root_log_level: bool = True, + should_include_thread_name: bool = False, +) -> None: + del should_include_thread_name + + if logger_level is None: + logger_level = logging.INFO + + root_logger = logging.getLogger() + if should_update_root_log_level: + root_logger.setLevel(logger_level) + + if handler is None: + handler = logging.StreamHandler(stream=sys.stderr) + + handler.setLevel(logger_level) + handler.setFormatter(LogfmtFormatter()) + root_logger.addHandler(handler) diff --git a/digsigserver/signers/fitimagesign.py b/digsigserver/signers/fitimagesign.py index 75c9692..16958e1 100644 --- a/digsigserver/signers/fitimagesign.py +++ b/digsigserver/signers/fitimagesign.py @@ -10,8 +10,8 @@ class FitImageSigner (Signer): keytag = 'fitimagesign' - def __init__(self, app: Sanic, workdir: str): - super().__init__(app, workdir, "imx") + def __init__(self, app: Sanic, workdir: str, backend: str): + super().__init__(app, workdir, 'imx', backend, load_keys=backend != 'pkcs11') def _prepare_path(self) -> dict: env = dict(copy.deepcopy(os.environ)) @@ -25,20 +25,27 @@ def sign(self, fitimage: str, external_data_offset: Optional[str], mark_required: Optional[bool], algo: Optional[str], - keyname: str = "dev.key") -> bool: - private_key = self.keys.get("{}.key".format(keyname)) + keyname: str = "dev", + comment: Optional[str] = None) -> bool: env = self._prepare_path() - cmd = [ 'mkimage', '-F', '-k', os.path.dirname(private_key) ] + if self.backend == "pkcs11": + keyname = keyname.replace('pin-value=password', 'pin-value=' + self.app.config.get('YUBIHSM_PASSWORD')) + cmd = ['mkimage', '-E', '-F', '-N', 'pkcs11', '-k', keyname, '-v'] + else: + private_key = self.keys.get("{}.key".format(keyname)) + cmd = ['mkimage', '-F', '-k', os.path.dirname(private_key)] + + if comment: + cmd += ['-c', comment] if external_data_offset: - cmd += [ '-p', external_data_offset ] + cmd += ['-p', external_data_offset] if mark_required: - cmd += [ '-r' ] + cmd += ['-r'] if dtb: - cmd += [ '-K', dtb ] + cmd += ['-K', dtb] if algo: - cmd +=[ '-o', algo ] + cmd += ['-o', algo] - cmd += [ fitimage ] + cmd += [fitimage] result = self.run_command(cmd, env=env) - self.keys.cleanup() return result diff --git a/digsigserver/signers/imxsign.py b/digsigserver/signers/imxsign.py index aa8c771..16e19df 100644 --- a/digsigserver/signers/imxsign.py +++ b/digsigserver/signers/imxsign.py @@ -22,8 +22,7 @@ def __init__(self, app: Sanic, workdir: str, machine: str, soctype: str, cstvers raise ValueError("no tools available for cstversion={}".format(cstversion)) self.soctype = soctype self.machine = machine - self.backend = backend - super().__init__(app, workdir, machine) + super().__init__(app, workdir, machine, backend) def _prepare_path(self) -> dict: env = dict(copy.deepcopy(os.environ)) @@ -47,7 +46,7 @@ def sign(self, outfile: str) -> bool: with open(cst_path, "r") as f: content = f.read() with open(cst_path, "w") as f: - new_content = content.replace("pin-value=password", "pin-value=" + os.environ.get('YUBIHSM_PASSWORD')) + new_content = content.replace("pin-value=password", "pin-value=" + self.app.config.get('YUBIHSM_PASSWORD')) f.write(new_content) if self.run_command(command, env=env): self.keys.cleanup() diff --git a/digsigserver/signers/signer.py b/digsigserver/signers/signer.py index 51220ad..5cc4d78 100644 --- a/digsigserver/signers/signer.py +++ b/digsigserver/signers/signer.py @@ -10,10 +10,14 @@ class Signer: keytag = 'Unknown' - def __init__(self, app: Sanic, workdir: str, key_selector: str): + def __init__(self, app: Sanic, workdir: str, key_selector: Optional[str] = None, + backend: Optional[str] = None, load_keys: bool = True): self.app = app self.workdir = workdir - self.keys = KeyFiles(app, self.keytag, key_selector) + self.backend = backend or 'ssl' + self.keys = None + if load_keys: + self.keys = KeyFiles(app, self.keytag, key_selector) def sign(self, *args) -> bool: raise RuntimeError("unimplemented sign method") @@ -30,11 +34,12 @@ def run_command(self, cmd: list, cleanup: bool = True, env: Optional[dict] = Non logger.debug("stdout: {}".format(proc.stdout)) logger.debug("stderr: {}".format(proc.stderr)) except subprocess.CalledProcessError as e: - if cleanup: + if cleanup and self.keys: self.keys.cleanup() logger.warning("signing error: {}".format(e.stderr)) logger.warning("stdout: {}".format(e.stdout)) + logger.warning("return code: {}".format(e.returncode)) return False - if cleanup: + if cleanup and self.keys: self.keys.cleanup() return True diff --git a/digsigserver/signers/swupdsign.py b/digsigserver/signers/swupdsign.py index 17f4d79..a571ea5 100644 --- a/digsigserver/signers/swupdsign.py +++ b/digsigserver/signers/swupdsign.py @@ -6,28 +6,44 @@ class SwupdateSigner(Signer): keytag = 'swupdate' - def __init__(self, app: Sanic, workdir: str, distro: str): + def __init__(self, app: Sanic, workdir: str, distro: str, backend: str): signcmd = shutil.which('openssl') if not signcmd: raise RuntimeError('no openssl command') self.signcmd = signcmd - super().__init__(app, workdir, distro) + super().__init__(app, workdir, distro, backend) - def sign(self, method: str, sw_description: str, outfile: str) -> bool: - if method == "RSA": - privkey = self.keys.get('rsa-private.key') - if not privkey: - raise RuntimeError('RSA private key missing for swupdate signing') - cmd = [self.signcmd, 'dgst', '-sha256', '-sign', privkey, '-out', outfile, sw_description] - elif method == "CMS": - cms_cert = self.keys.get('cms.cert') - cms_key = self.keys.get('cms-private.key') - if not cms_cert or not cms_key: - raise RuntimeError('CMS cert or private key missing for swupdate signing') - cmd = [self.signcmd, 'cms', '-sign', '-in', sw_description, '-out', outfile, - '-signer', cms_cert, '-inkey', cms_key, '-outform', 'DER', - '-nosmimecap', '-binary'] - else: - raise RuntimeError('Unrecognized signing method {} - must be RSA or CMS'.format(method)) + def sign(self, method: str, sw_description: str, outfile: str, key_uri: str = None) -> bool: + match (method, self.backend): + case ("RSA", "ssl"): + privkey = self.keys.get('rsa-private.key') + if not privkey: + raise RuntimeError('RSA private key missing for swupdate signing') + cmd = [self.signcmd, 'dgst', '-sha256', '-sign', privkey, '-out', outfile, sw_description] + case ("CMS", "ssl"): + cms_cert = self.keys.get('cms.cert') + cms_key = self.keys.get('cms-private.key') + if not cms_cert or not cms_key: + raise RuntimeError('CMS cert or private key missing for swupdate signing') + cmd = [self.signcmd, 'cms', '-sign', '-in', sw_description, '-out', outfile, + '-signer', cms_cert, '-inkey', cms_key, '-outform', 'DER', + '-nosmimecap', '-binary'] + case ("RSA", "pkcs11"): + if not key_uri: + raise RuntimeError('Key URI missing for RSA signing with PKCS#11 backend') + key_uri = key_uri.replace('pin-value=password', 'pin-value=' + self.app.config.get('YUBIHSM_PASSWORD')) + cmd = [self.signcmd, 'dgst', '-sha256', '-engine', 'pkcs11', + '-keyform', 'ENGINE', '-sign', key_uri, '-out', outfile, sw_description] + case ("CMS", "pkcs11"): + if not key_uri: + raise RuntimeError('Key URI missing for CMS signing with PKCS#11 backend') + key_uri = key_uri.replace('pin-value=password', 'pin-value=' + self.app.config.get('YUBIHSM_PASSWORD')) + cert_uri = self.keys.get("cms.cert") + cmd = [self.signcmd, 'cms', '-sign', '-engine', 'pkcs11', + '-keyform', 'engine', '-in', sw_description, '-out', outfile, + '-signer', cert_uri, '-inkey', key_uri, '-outform', 'DER', + '-nosmimecap', '-binary'] + case _: + raise RuntimeError('Unrecognized signing method {} or backend {} allowed: RSA, CMS with ssl or pkcs11'.format(method, self.backend)) return self.run_command(cmd) diff --git a/digsigserver/utils.py b/digsigserver/utils.py index ee9ed11..5607812 100644 --- a/digsigserver/utils.py +++ b/digsigserver/utils.py @@ -1,4 +1,6 @@ +from datetime import datetime import os +import re import shutil import subprocess from urllib.parse import urlparse @@ -6,6 +8,8 @@ from sanic.log import logger from typing import Optional +from digsigserver.logredaction import install_log_redaction_filter + def extract_files(workdir: str, f: request.File) -> bool: try: @@ -96,3 +100,184 @@ def to_boolean(boolstr: Optional[str]) -> bool: if not boolstr: return False return boolstr.upper() in ["Y", "YES", "1", "T", "TRUE", "ON"] + + +def _extract_last_log_item_index(log_content: str) -> Optional[int]: + for line in reversed(log_content.splitlines()): + match = re.match(r'\s*item:\s*(\d+)\s+--', line) + if match: + return int(match.group(1)) + return None + + +def _build_yubihsm_redaction_secrets(password: str) -> list[str]: + pass_value = password[4:] + return [password, pass_value] + + +def _split_yubihsm_password(password: str) -> tuple[str, str]: + return f"0x{password[0:4]}", password[4:] + + +def read_secret_file(path: Optional[str]) -> Optional[str]: + if not path: + return None + + try: + with open(path, 'r', encoding='utf-8') as secret_file: + secret_value = secret_file.read().strip() + except OSError: + logger.warning('Unable to read secret file: %s', path) + return None + + return secret_value or None + + +def get_digsigserver_yubihsm_password() -> Optional[str]: + password = read_secret_file(os.environ.get('DIGSIGSERVER_YUBIHSM_PASSWORD_FILE')) + if password is not None: + return password + return os.environ.get('DIGSIGSERVER_YUBIHSM_PASSWORD') + + +def get_digsigserver_yubihsm_password_logs() -> Optional[str]: + password = read_secret_file(os.environ.get('DIGSIGSERVER_YUBIHSM_PASSWORD_LOGS_FILE')) + if password is not None: + return password + + password = os.environ.get('DIGSIGSERVER_YUBIHSM_PASSWORD_LOGS') + if password is not None: + return password + + return get_digsigserver_yubihsm_password() + + +def get_yubihsm_redaction_secrets() -> list[str]: + secrets: list[str] = [] + + for password in (get_digsigserver_yubihsm_password(), get_digsigserver_yubihsm_password_logs()): + if password and len(password) > 4: + for secret in _build_yubihsm_redaction_secrets(password): + if secret not in secrets: + secrets.append(secret) + + return secrets + + +def get_hsm_audit_log_target() -> str: + target = os.environ.get('HSM_AUDIT_LOG_TARGET', 'hsm-main') + if target in {'hsm-main', 'hsm-backup'}: + return target + + logger.warning('Invalid HSM_AUDIT_LOG_TARGET=%s, defaulting to hsm-main', target) + return 'hsm-main' + + +def get_hsm_audit_log_bucket() -> str: + bucket = os.environ.get('HSM_AUDIT_LOG_BUCKET', 'td-yubihsm-backup').strip() + if bucket: + return bucket + + logger.warning('Invalid HSM_AUDIT_LOG_BUCKET=%s, defaulting to td-yubihsm-backup', bucket) + return 'td-yubihsm-backup' + + +def get_digsigserver_yubihsm_connector() -> str: + connector = os.environ.get('DIGSIGSERVER_YUBIHSM_CONNECTOR', 'http://host.docker.internal:12345').strip() + if connector: + return connector + + logger.warning( + 'Invalid DIGSIGSERVER_YUBIHSM_CONNECTOR=%s, defaulting to http://host.docker.internal:12345', + connector, + ) + return 'http://host.docker.internal:12345' + + +def build_yubihsm_shell_command(action: str, *args: str) -> list[str]: + return [ + 'yubihsm-shell', + '--connector', + get_digsigserver_yubihsm_connector(), + '-a', + action, + *args, + ] + + +async def dump_upload_and_reset_logs() -> None: + from digsigserver.server import LogAuditCategory, log_audit + + password = get_digsigserver_yubihsm_password_logs() + if not password or len(password) <= 4: + logger.warning('Skipping YubiHSM audit log dump: YubiHSM password is not configured correctly') + return + + auth_key, pass_value = _split_yubihsm_password(password) + + timestamp_str = datetime.now().strftime('%Y%m%d_%H%M%S') + temp_log_file = f'audit-{timestamp_str}.log' + upload_uri = f's3://{get_hsm_audit_log_bucket()}/logs/{get_hsm_audit_log_target()}/{temp_log_file}' + upload_succeeded = False + + try: + subprocess.run( + build_yubihsm_shell_command('get-logs', '--out', temp_log_file, '--authkey', auth_key, '-p', pass_value), + check=True, + stdin=subprocess.DEVNULL, + capture_output=True, + encoding='utf-8', + ) + + with open(temp_log_file, 'r', encoding='utf-8') as f: + log_content = f.read() + + last_item_index = _extract_last_log_item_index(log_content) + if last_item_index is None: + logger.warning('Skipping YubiHSM audit log index update: no log items found in %s', temp_log_file) + return + + upload_file(temp_log_file, upload_uri) + upload_succeeded = True + + set_log_index = last_item_index - 1 + if upload_succeeded: + subprocess.run( + build_yubihsm_shell_command( + 'set-log-index', + '--log-index', + str(set_log_index), + '--authkey', + auth_key, + '-p', + pass_value, + ), + check=True, + stdin=subprocess.DEVNULL, + capture_output=True, + encoding='utf-8', + ) + + log_audit( + LogAuditCategory.AUDIT_LOG_EVENTS, + 'yubihsm_audit_logs_archived', + 'success', + upload_uri=upload_uri, + upload_succeeded=upload_succeeded, + log_item_index=last_item_index, + set_log_index=set_log_index, + log_line_count=len(log_content.splitlines()), + ) + except (OSError, RuntimeError, subprocess.CalledProcessError) as exc: + logger.exception('Failed to dump and archive YubiHSM audit logs') + log_audit( + LogAuditCategory.AUDIT_LOG_EVENTS, + 'yubihsm_audit_logs_archived', + 'failure', + level=40, + exc=exc, + upload_uri=upload_uri, + ) + finally: + if os.path.exists(temp_log_file): + os.remove(temp_log_file) \ No newline at end of file diff --git a/doc/fitimage.md b/doc/fitimage.md index 2a1db01..3edbff2 100644 --- a/doc/fitimage.md +++ b/doc/fitimage.md @@ -23,7 +23,9 @@ Optional parameters: * `external_data_offset=` - external data offset to be used during FIT signing * `mark_required=` - if this parameter exists the key will be marked as required * `algo=` - customize the signing algorithm -* `keyname=` - specify a keyname other than `dev` +* `comment=` - add a comment to the FIT signature node +* `keyname=` - specify a keyname other than `dev`; required for `backend=pkcs11` +* `backend=` - backend can be `pkcs11` or `ssl`, defaults to `ssl` if omitted Response: signed binary @@ -37,4 +39,3 @@ Example usage: ## Future improvements * Enable including a device tree blob in which the public key is injected. * Change the `imx` "machine" to something more logical, this is not machine dependent - diff --git a/doc/swupdsign.md b/doc/swupdsign.md index 9beaf4f..65a4f8a 100644 --- a/doc/swupdsign.md +++ b/doc/swupdsign.md @@ -30,6 +30,11 @@ Expected parameters: * `distro=` - a name for the "distro", used to locate the signing keys * `sw-description=` - the contents of the `sw-description` file to have signatures included +Optional parameters: +* `method=` - may be `RSA` or `CMS`, defaults to `RSA` if omitted +* `backend=` - backend can be `pkcs11` or `ssl`, defaults to `ssl` if omitted +* `key-uri=` - key URI required for `backend=pkcs11` + Response: a `sw-description` file with signatures inserted Example client: [swupdatesign.bbclass](https://github.com/madisongh/tegra-test-distro/blob/master/layers/meta-testdistro/classes/swupdatesign.bbclass) diff --git a/docker/Dockerfile b/docker/Dockerfile index 7cfa942..7eff733 100644 --- a/docker/Dockerfile +++ b/docker/Dockerfile @@ -5,7 +5,8 @@ FROM l4t-release:35.5.0 AS l4t-35.5.0 FROM l4t-release:35.6.0 AS l4t-35.6.0 FROM l4t-release:36.4.0 AS l4t-36.4.0 FROM l4t-release:36.4.3 AS l4t-36.4.3 -FROM ubuntu:18.04 as mkimage +FROM l4t-release:36.4.4 AS l4t-36.4.4 +FROM ubuntu:22.04 as mkimage # Dependencies for building u-boot tools RUN apt-get update && apt-get install -y \ @@ -23,21 +24,21 @@ RUN make rk3568_defconfig && \ make olddefconfig && \ make CROSS_COMPILE=aarch64-linux-gnu- tools -FROM ubuntu:18.04 +FROM ubuntu:22.04 RUN apt-get update && apt-get install -y \ device-tree-compiler \ liblz4-tool \ python2.7 \ - python3.7 \ - python3.7-dev \ + python3.10 \ + python3.10-dev \ python3-pip \ sbsigntool \ && rm -rf /var/lib/apt/lists/* RUN update-alternatives --install /usr/bin/python python /usr/bin/python2.7 1 RUN update-alternatives --install /usr/bin/python2 python2 /usr/bin/python2.7 1 -RUN update-alternatives --install /usr/bin/python3 python3 /usr/bin/python3.7 1 +RUN update-alternatives --install /usr/bin/python3 python3 /usr/bin/python3.10 1 RUN pip3 install --upgrade pip @@ -58,6 +59,7 @@ COPY --from=l4t-35.5.0 /opt/nvidia /opt/nvidia COPY --from=l4t-35.6.0 /opt/nvidia /opt/nvidia COPY --from=l4t-36.4.0 /opt/nvidia /opt/nvidia COPY --from=l4t-36.4.3 /opt/nvidia /opt/nvidia +COPY --from=l4t-36.4.4 /opt/nvidia /opt/nvidia # Rockchip ARG ROCKCHIP_TOOLS_REPO_URL=https://github.com/rockchip-linux/rkbin/raw/829d7a6a2272938aac67dfe9f807277fa617809b/ ENV DIGSIGSERVER_RK_TOOLS_PATH=/opt diff --git a/docker/Dockerfile.l4t-36.4.3 b/docker/Dockerfile.l4t-36.4.3 index c1c540f..8dac791 100644 --- a/docker/Dockerfile.l4t-36.4.3 +++ b/docker/Dockerfile.l4t-36.4.3 @@ -6,7 +6,7 @@ RUN apt-get update && apt-get install -y \ wget \ && rm -rf /var/lib/apt/lists/* -RUN git clone --branch scarthgap https://github.com/OE4T/meta-tegra.git meta-tegra-scarthgap +RUN git clone --branch scarthgap https://github.com/OE4T/meta-tegra.git meta-tegra-scarthgap && cd meta-tegra-scarthgap && git checkout 5bd3a1c9f2dd523351ae1ad32e46b98db4a6d4d2 RUN mkdir -p /opt/nvidia/L4T-36.4.3-tegra234 diff --git a/docker/Dockerfile.l4t-36.4.4 b/docker/Dockerfile.l4t-36.4.4 new file mode 100644 index 0000000..ab48e85 --- /dev/null +++ b/docker/Dockerfile.l4t-36.4.4 @@ -0,0 +1,35 @@ +FROM ubuntu:18.04 + +RUN apt-get update && apt-get install -y \ + git \ + python3-cryptography \ + wget \ + && rm -rf /var/lib/apt/lists/* + +RUN git clone --branch scarthgap https://github.com/OE4T/meta-tegra.git meta-tegra-scarthgap + +RUN mkdir -p /opt/nvidia/L4T-36.4.4-tegra234 + +RUN wget -q -O /opt/nvidia/l4t-release.tbz2 https://developer.nvidia.com/downloads/embedded/l4t/r36_release_v4.4/release/Jetson_Linux_R36.4.4_aarch64.tbz2 + +RUN tar -xjf /opt/nvidia/l4t-release.tbz2 -C /opt/nvidia/L4T-36.4.4-tegra234 + +RUN rm /opt/nvidia/l4t-release.tbz2 + +RUN wget -q -O /opt/nvidia/public_sources.tbz2 https://developer.nvidia.com/downloads/embedded/l4t/r36_release_v4.4/sources/public_sources.tbz2 + +RUN tar -xjf /opt/nvidia/public_sources.tbz2 -C /opt/nvidia/L4T-36.4.4-tegra234 Linux_for_Tegra/source/nvidia-jetson-optee-source.tbz2 && \ + mkdir /opt/nvidia/L4T-36.4.4-tegra234/Linux_for_Tegra/source/public && \ + tar -xjf /opt/nvidia/L4T-36.4.4-tegra234/Linux_for_Tegra/source/nvidia-jetson-optee-source.tbz2 -C /opt/nvidia/L4T-36.4.4-tegra234/Linux_for_Tegra/source/public + +RUN rm /opt/nvidia/public_sources.tbz2 && \ + rm /opt/nvidia/L4T-36.4.4-tegra234/Linux_for_Tegra/source/nvidia-jetson-optee-source.tbz2 + +ARG TEGRA234_36_4_4_DIR=/opt/nvidia/L4T-36.4.4-tegra234/Linux_for_Tegra + +RUN cd meta-tegra-scarthgap/recipes-bsp/tegra-binaries/tegra-helper-scripts && \ + install -m 0755 tegra-flash-helper.sh ${TEGRA234_36_4_4_DIR}/bootloader/tegra234-flash-helper && \ + install -m 0755 tegra-signimage-helper.sh ${TEGRA234_36_4_4_DIR}/tegra-signimage-helper && \ + install -m 0755 nvflashxmlparse.py ${TEGRA234_36_4_4_DIR}/bootloader/nvflashxmlparse + +RUN patch -p1 --directory=${TEGRA234_36_4_4_DIR} < meta-tegra-scarthgap/recipes-bsp/tegra-binaries/files/0013-Fix-location-of-bsp_version-file-in-l4t_bup_gen.func.patch diff --git a/tests/test_yubihsm_log_redaction.py b/tests/test_yubihsm_log_redaction.py new file mode 100644 index 0000000..a487668 --- /dev/null +++ b/tests/test_yubihsm_log_redaction.py @@ -0,0 +1,171 @@ +import logging +import subprocess + +from digsigserver.logredaction import SecretRedactionFilter +from digsigserver.setup_logfmt import LogfmtFormatter +from digsigserver.utils import ( + _build_yubihsm_redaction_secrets, + build_yubihsm_shell_command, + get_digsigserver_yubihsm_connector, + get_digsigserver_yubihsm_password_logs, + get_hsm_audit_log_bucket, + get_yubihsm_redaction_secrets, + read_secret_file, +) + + +def _hash16(secret: str) -> str: + return SecretRedactionFilter._redaction_token(secret) + + +def test_build_yubihsm_redaction_secrets_includes_split_fragments() -> None: + assert _build_yubihsm_redaction_secrets('1234supersecret') == [ + '1234supersecret', + 'supersecret', + ] + + +def test_redaction_filter_masks_split_yubihsm_password_fragments() -> None: + redaction_filter = SecretRedactionFilter() + redaction_filter.set_secrets(_build_yubihsm_redaction_secrets('1234supersecret')) + + record = logging.LogRecord( + name='test', + level=logging.ERROR, + pathname=__file__, + lineno=1, + msg='Command failed: %s', + args=(['yubihsm-shell', '--authkey', '0x1234', '-p', 'supersecret'],), + exc_info=None, + ) + + assert redaction_filter.filter(record) is True + assert record.args == () + assert '0x1234' in record.msg + assert 'supersecret' not in record.msg + assert _hash16('supersecret') in record.msg + + +def test_redaction_filter_masks_called_process_error_command() -> None: + redaction_filter = SecretRedactionFilter() + redaction_filter.set_secrets(_build_yubihsm_redaction_secrets('0031password')) + + exc = subprocess.CalledProcessError( + 1, + ['yubihsm-shell', '-a', 'get-logs', '--authkey', '0x0031', '-p', 'password'], + ) + record = logging.LogRecord( + name='test', + level=logging.ERROR, + pathname=__file__, + lineno=1, + msg='audit log dump failed', + args=(), + exc_info=(type(exc), exc, None), + ) + + assert redaction_filter.filter(record) is True + redacted_exc = record.exc_info[1] + assert isinstance(redacted_exc, subprocess.CalledProcessError) + assert redacted_exc.cmd == [ + 'yubihsm-shell', + '-a', + 'get-logs', + '--authkey', + '0x0031', + '-p', + _hash16('password'), + ] + + +def test_redaction_filter_masks_final_formatted_string_and_extra_fields() -> None: + redaction_filter = SecretRedactionFilter() + redaction_filter.set_secrets(_build_yubihsm_redaction_secrets('0031password')) + + exc = subprocess.CalledProcessError( + 1, + ['yubihsm-shell', '-a', 'get-logs', '--authkey', '0x0031', '-p', 'password'], + ) + record = logging.LogRecord( + name='test', + level=logging.ERROR, + pathname=__file__, + lineno=1, + msg='audit command failed: %s', + args=("Command '['yubihsm-shell', '--authkey', '0x0031', '-p', 'password']' returned status 1",), + exc_info=(type(exc), exc, None), + ) + record.audit_detail = "Command '['yubihsm-shell', '--authkey', '0x0031', '-p', 'password']' returned status 1" + + assert redaction_filter.filter(record) is True + + formatted = LogfmtFormatter().format(record) + assert '0x0031' in formatted + assert 'password' not in formatted + assert _hash16('password') in formatted + + +def test_read_secret_file_strips_trailing_newline(tmp_path) -> None: + secret_file = tmp_path / 'yubihsm-password' + secret_file.write_text('0031supersecret\n', encoding='utf-8') + + assert read_secret_file(str(secret_file)) == '0031supersecret' + + +def test_get_hsm_audit_log_bucket_uses_env_override(monkeypatch) -> None: + monkeypatch.setenv('HSM_AUDIT_LOG_BUCKET', 'td-yubihsm-backup-test') + + assert get_hsm_audit_log_bucket() == 'td-yubihsm-backup-test' + + +def test_get_hsm_audit_log_bucket_defaults_when_unset(monkeypatch) -> None: + monkeypatch.delenv('HSM_AUDIT_LOG_BUCKET', raising=False) + + assert get_hsm_audit_log_bucket() == 'td-yubihsm-backup' + + +def test_get_digsigserver_yubihsm_password_logs_uses_logs_env_override(monkeypatch) -> None: + monkeypatch.setenv('DIGSIGSERVER_YUBIHSM_PASSWORD', '0031signing-secret') + monkeypatch.setenv('DIGSIGSERVER_YUBIHSM_PASSWORD_LOGS', '0022logs-secret') + + assert get_digsigserver_yubihsm_password_logs() == '0022logs-secret' + + +def test_get_digsigserver_yubihsm_password_logs_falls_back_to_signing_password(monkeypatch) -> None: + monkeypatch.setenv('DIGSIGSERVER_YUBIHSM_PASSWORD', '0031signing-secret') + monkeypatch.delenv('DIGSIGSERVER_YUBIHSM_PASSWORD_LOGS', raising=False) + monkeypatch.delenv('DIGSIGSERVER_YUBIHSM_PASSWORD_LOGS_FILE', raising=False) + + assert get_digsigserver_yubihsm_password_logs() == '0031signing-secret' + + +def test_get_yubihsm_redaction_secrets_combines_signing_and_logs_passwords(monkeypatch) -> None: + monkeypatch.setenv('DIGSIGSERVER_YUBIHSM_PASSWORD', '0031signing-secret') + monkeypatch.setenv('DIGSIGSERVER_YUBIHSM_PASSWORD_LOGS', '0022logs-secret') + + assert get_yubihsm_redaction_secrets() == [ + '0031signing-secret', + 'signing-secret', + '0022logs-secret', + 'logs-secret', + ] + + +def test_get_digsigserver_yubihsm_connector_defaults_when_unset(monkeypatch) -> None: + monkeypatch.delenv('DIGSIGSERVER_YUBIHSM_CONNECTOR', raising=False) + + assert get_digsigserver_yubihsm_connector() == 'http://host.docker.internal:12345' + + +def test_build_yubihsm_shell_command_includes_connector(monkeypatch) -> None: + monkeypatch.setenv('DIGSIGSERVER_YUBIHSM_CONNECTOR', 'http://host.docker.internal:12345') + + assert build_yubihsm_shell_command('get-logs', '--out', 'audit.log') == [ + 'yubihsm-shell', + '--connector', + 'http://host.docker.internal:12345', + '-a', + 'get-logs', + '--out', + 'audit.log', + ] \ No newline at end of file