diff --git a/bin/validate-against-mpbiopath.py b/bin/validate-against-mpbiopath.py index f3c0498..9b2d207 100644 --- a/bin/validate-against-mpbiopath.py +++ b/bin/validate-against-mpbiopath.py @@ -37,6 +37,7 @@ sys.path.insert(0, os.path.abspath(os.path.join(os.path.dirname(__file__), ".."))) +from src.credential_redaction import install as _install_credential_redaction from src.argument_parser import logger # noqa: E402 from src.neo4j_connector import get_graph # noqa: E402 @@ -405,6 +406,9 @@ def validate_one_pathway( } +_install_credential_redaction() + + def main(): ap = argparse.ArgumentParser() ap.add_argument("--output-dir", default="output", help="Where regenerated pathway dirs live") diff --git a/scripts/validate_logic_network.py b/scripts/validate_logic_network.py index 286fc50..46938e3 100755 --- a/scripts/validate_logic_network.py +++ b/scripts/validate_logic_network.py @@ -21,6 +21,11 @@ from py2neo import Graph import os +sys.path.insert(0, str(Path(__file__).resolve().parents[1])) +from src.credential_redaction import install as _install_credential_redaction + +_install_credential_redaction() + # Depth limit when resolving an EntitySet to its leaf members. Sets nest a few # levels at most; an unbounded traversal is slow and can revisit cycles. MAX_SET_NESTING = 5 diff --git a/src/argument_parser.py b/src/argument_parser.py index 777e736..f1695fc 100644 --- a/src/argument_parser.py +++ b/src/argument_parser.py @@ -3,6 +3,8 @@ import sys from argparse import Namespace +from src import credential_redaction + def parse_args() -> Namespace: parser: argparse.ArgumentParser = argparse.ArgumentParser( @@ -50,5 +52,11 @@ def configure_logging(debug_flag: bool, verbose_flag: bool) -> None: console_handler.setFormatter(formatter) logging.getLogger().addHandler(console_handler) + # Credentials must not reach debug_log.txt (mode 0664), stdout or stderr. + # Applied here, at the output boundary, because per-call-site redaction + # demonstrably misses ungated exc_info in other modules, chained + # __cause__, and entrypoints with no handler at all. + credential_redaction.install() + logger: logging.Logger = logging.getLogger(__name__) diff --git a/src/credential_redaction.py b/src/credential_redaction.py new file mode 100644 index 0000000..44bbeac --- /dev/null +++ b/src/credential_redaction.py @@ -0,0 +1,126 @@ +"""Redact credential material at the output boundary. + +Both Reactome repositories are public, and the realistic disclosure path is +someone pasting a log line or a stack trace into an issue. Neo4j credentials +can be embedded in ``NEO4J_URL``, and py2neo re-emits them in its own +exception text via ``ConnectionProfile`` and ``IPv4Address`` reprs. + +Redacting at each call site does not work, and an adversarial review proved +it: gating the fourteen ``exc_info=True`` calls inside ``neo4j_connector`` +left the same secret reaching ``debug_log.txt`` through an ungated +``exc_info=True`` two frames up in ``reaction_generator``, and reaching stderr +entirely unhandled from ``scripts/validate_logic_network.py``. Chained +exceptions leak it again through ``__cause__`` even when ``str()`` is clean. + +So redaction belongs where the text is emitted — a logging filter on every +handler, plus an excepthook for anything uncaught — which covers paths nobody +enumerated. + +Scrubbing is structural rather than value-based wherever possible. Replacing +occurrences of the password itself is a poor primary defence here because the +documented dev passwords are ordinary words ("reactome", "test") that appear +in paths, keys and prose; value replacement is applied, but it substitutes the +token rather than discarding the whole message. +""" + +from __future__ import annotations + +import logging +import os +import re +import sys +import traceback +from typing import Any + +REDACTED = "" + +# scheme://userinfo@host — the userinfo is credential material by definition. +_URL_USERINFO = re.compile(r"(?P[A-Za-z][A-Za-z0-9+.\-]*://)[^\s/@]*@") + +# py2neo's own reprs, which are how a password fragment escapes even when our +# own message is already redacted. +_PROFILE_REPR = re.compile(r"ConnectionProfile\((['\"]).*?\1\)") +_ADDRESS_REPR = re.compile(r"IPv4Address\(\(.*?\)\)") +_ADDRESS6_REPR = re.compile(r"IPv6Address\(\(.*?\)\)") + + +def scrub(text: str) -> str: + """Remove credential material from arbitrary text. + + Structural first (URL userinfo, py2neo reprs), then the literal password + as a backstop for paths that format it directly. + """ + if not text: + return text + text = _URL_USERINFO.sub(lambda m: f"{m.group('scheme')}{REDACTED}@", text) + text = _PROFILE_REPR.sub(f"ConnectionProfile({REDACTED})", text) + text = _ADDRESS_REPR.sub(f"IPv4Address({REDACTED})", text) + text = _ADDRESS6_REPR.sub(f"IPv6Address({REDACTED})", text) + + password = os.getenv("NEO4J_PASSWORD") or "" + # Substituting a 1-3 character password would corrupt almost every line + # for no security benefit; such a value is not a secret worth protecting. + if len(password) >= 4 and password in text: + text = text.replace(password, REDACTED) + return text + + +class CredentialRedactingFilter(logging.Filter): + """Scrub every log record, including its traceback, before it is emitted. + + Attached to handlers rather than loggers so it applies to records + propagated from any module, including third-party ones. + """ + + def filter(self, record: logging.LogRecord) -> bool: + try: + message = record.getMessage() + except Exception: # pragma: no cover - a broken record must still emit + return True + + scrubbed = scrub(message) + if scrubbed != message: + record.msg = scrubbed + record.args = () + + if record.exc_info: + # Render the traceback now and scrub it; leaving exc_info set + # would let the handler re-render the unredacted original. + rendered = "".join(traceback.format_exception(*record.exc_info)) + record.exc_text = scrub(rendered) + record.exc_info = None + elif record.exc_text: + record.exc_text = scrub(record.exc_text) + return True + + +def install_log_redaction(logger: logging.Logger | None = None) -> None: + """Attach the filter to every handler on the root (or given) logger.""" + target = logger if logger is not None else logging.getLogger() + for handler in target.handlers: + if not any(isinstance(f, CredentialRedactingFilter) for f in handler.filters): + handler.addFilter(CredentialRedactingFilter()) + + +def install_excepthook() -> None: + """Scrub uncaught tracebacks. + + `scripts/validate_logic_network.py` and `bin/validate-against-mpbiopath.py` + construct a Graph with no handler at all, so a first-connection failure — + the most likely failure — printed the full chain to stderr. + """ + previous = sys.excepthook + + def _hook(exc_type: type, exc: BaseException, tb: Any) -> None: + if previous is not sys.__excepthook__: + previous(exc_type, exc, tb) + return + sys.stderr.write(scrub("".join(traceback.format_exception(exc_type, exc, tb)))) + + sys.excepthook = _hook + + +def install() -> None: + """Install both guards. Safe to call more than once.""" + install_log_redaction() + install_excepthook() diff --git a/src/neo4j_connector.py b/src/neo4j_connector.py index a0009dc..637366a 100755 --- a/src/neo4j_connector.py +++ b/src/neo4j_connector.py @@ -1,4 +1,6 @@ import os + +from src.credential_redaction import scrub from typing import Any, Dict, List, Optional, Set, Union import pandas as pd @@ -51,11 +53,61 @@ def _safe_neo4j_url() -> str: authority = hostpart else: authority = rest - # Drop any path/query, leaving host[:port]. - authority = authority.split("/", 1)[0].split("?", 1)[0] + # Drop any path/query/fragment, leaving host[:port]. "#" matters because + # bolt://neo4j:pw@host:7687#SECRET previously kept the fragment. + authority = authority.split("/", 1)[0].split("?", 1)[0].split("#", 1)[0] return f"{scheme}://{authority}" if authority else "" +def _safe_exception(exc: BaseException) -> str: + """An exception rendered without the credentials py2neo puts in its text. + + `_safe_neo4j_url()` above redacts OUR message, but every caller then + appended `Original error: {str(e)}` — and py2neo's own text embeds the + ConnectionProfile, which is exactly the mis-parse that redactor exists to + avoid. With NEO4J_URL=bolt://neo4j:p@ssSECRET@host the appended text read: + + Cannot open connection to ConnectionProfile('bolt://ssSECRET@host') + + so the password fragment survived, in the same log line as the redaction. + Both repositories are public, and the realistic disclosure path is someone + pasting a stack trace into an issue. + + The exception TYPE is the part with diagnostic value; the message body is + py2neo boilerplate plus the profile. Return the type, and the message only + when it is demonstrably free of credential material. + """ + detail = str(exc) + # Anything resembling embedded credentials, an authority with userinfo, or + # py2neo's profile repr means the text cannot be shown. + unsafe = ( + "://" in detail + or "ConnectionProfile" in detail + or "IPv4Address" in detail + or "@" in detail + ) + if unsafe: + return f"{type(exc).__name__} (message withheld: may contain credentials)" + # A message merely CONTAINING the password is scrubbed, not withheld. The + # documented dev passwords here are ordinary words ("test" in README.md, + # "reactome" in practice), so withholding on a substring match discarded + # real diagnostics: "Cannot find /opt/reactome/data/graph.db" and + # "KeyError: 'reactome_release'" both vanished entirely. + return f"{type(exc).__name__}: {scrub(detail)}" + + +def _traceback_kwargs() -> Dict[str, Any]: + """Logger kwargs for an exception on a Neo4j path. + + A traceback through py2neo carries the same ConnectionProfile the message + does, so `**_traceback_kwargs()` reintroduces the disclosure the message fix just + closed. Tracebacks are opt-in via LNG_DEBUG_TRACEBACKS=1 for local + debugging, off by default so nothing credential-bearing reaches + debug_log.txt (mode 0664) or stdout. + """ + return {"exc_info": os.getenv("LNG_DEBUG_TRACEBACKS") == "1"} + + # Module-level caches for bulk pre-fetched data _labels_cache: Dict[str, List[str]] = {} _components_cache: Dict[str, Dict[str, int]] = {} @@ -326,11 +378,11 @@ def get_reaction_connections(pathway_id: str) -> pd.DataFrame: except ValueError: raise except Exception as e: - logger.error(f"Error querying Neo4j for pathway {pathway_id}", exc_info=True) + logger.error(f"Error querying Neo4j for pathway {pathway_id}", **_traceback_kwargs()) raise ConnectionError( f"Failed to connect to Neo4j database at " f"{_safe_neo4j_url()}. " - f"Ensure Neo4j is running and accessible. Original error: {str(e)}" + f"Ensure Neo4j is running and accessible. Original error: {_safe_exception(e)}" ) from e @@ -358,11 +410,11 @@ def get_top_level_pathways() -> List[Dict[str, Any]]: logger.info(f"Found {len(result)} top-level pathways") return result except Exception as e: - logger.error("Error in get_top_level_pathways", exc_info=True) + logger.error("Error in get_top_level_pathways", **_traceback_kwargs()) raise ConnectionError( f"Failed to query top-level pathways from Neo4j at " f"{_safe_neo4j_url()}. " - f"Ensure Neo4j is running and accessible. Original error: {str(e)}" + f"Ensure Neo4j is running and accessible. Original error: {_safe_exception(e)}" ) from e @@ -406,12 +458,12 @@ def get_pathway_participating_entities(pathway_id: str) -> Set[str]: except Exception as e: logger.error( f"Error in get_pathway_participating_entities for {pathway_id}", - exc_info=True, + **_traceback_kwargs(), ) raise ConnectionError( f"Failed to query participating entities from Neo4j at " f"{_safe_neo4j_url()}. " - f"Original error: {str(e)}" + f"Original error: {_safe_exception(e)}" ) from e @@ -453,12 +505,12 @@ def get_pathway_entity_reactions( return out except Exception as e: logger.error( - f"Error in get_pathway_entity_reactions for {pathway_id}", exc_info=True + f"Error in get_pathway_entity_reactions for {pathway_id}", **_traceback_kwargs() ) raise ConnectionError( f"Failed to query entity reactions from Neo4j at " f"{_safe_neo4j_url()}. " - f"Original error: {str(e)}" + f"Original error: {_safe_exception(e)}" ) from e @@ -489,11 +541,11 @@ def get_pathway_name(pathway_id: str) -> str: except ValueError: raise except Exception as e: - logger.error(f"Error in get_pathway_name for {pathway_id}", exc_info=True) + logger.error(f"Error in get_pathway_name for {pathway_id}", **_traceback_kwargs()) raise ConnectionError( f"Failed to query pathway name from Neo4j at " f"{_safe_neo4j_url()}. " - f"Original error: {str(e)}" + f"Original error: {_safe_exception(e)}" ) from e @@ -509,7 +561,7 @@ def get_labels(entity_id: str) -> List[str]: _labels_cache[entity_id] = result return result except Exception: - logger.error("Error in get_labels", exc_info=True) + logger.error("Error in get_labels", **_traceback_kwargs()) raise @@ -532,7 +584,7 @@ def get_complex_components(entity_id: str) -> Dict[str, int]: _components_cache[entity_id] = result return result except Exception: - logger.error("Error in get_complex_components", exc_info=True) + logger.error("Error in get_complex_components", **_traceback_kwargs()) raise @@ -555,7 +607,7 @@ def get_set_members(entity_id: str) -> Set[str]: _members_cache[entity_id] = result return result except Exception: - logger.error("Error in get_set_members", exc_info=True) + logger.error("Error in get_set_members", **_traceback_kwargs()) raise @@ -579,7 +631,7 @@ def get_reaction_input_output_ids(reaction_id: str, input_or_output: str) -> Set try: return set(get_graph().run(query, reaction_id=reaction_id).data()[0]["io_ids"]) except Exception: - logger.error("Error in get_reaction_input_output_ids", exc_info=True) + logger.error("Error in get_reaction_input_output_ids", **_traceback_kwargs()) raise @@ -607,7 +659,7 @@ def get_reaction_io_stoichiometry(reaction_id: str, input_or_output: str) -> Dic try: data = get_graph().run(query, reaction_id=reaction_id).data() except Exception: - logger.error("Error in get_reaction_io_stoichiometry", exc_info=True) + logger.error("Error in get_reaction_io_stoichiometry", **_traceback_kwargs()) raise result: Dict[str, int] = {} @@ -662,7 +714,7 @@ def get_modifier_isoform_entity_set_ids() -> Set[str]: try: data = get_graph().run(query, genes=list(_MODIFIER_GENE_NAMES)).data() except Exception: - logger.error("Error in get_modifier_isoform_entity_set_ids", exc_info=True) + logger.error("Error in get_modifier_isoform_entity_set_ids", **_traceback_kwargs()) raise _modifier_isoform_set_cache = set(data[0]["stids"]) if data else set() return _modifier_isoform_set_cache @@ -692,7 +744,7 @@ def get_reference_entity_id(entity_id: str) -> Union[str, None]: _reference_entity_cache[entity_id] = result return result except Exception: - logger.error("Error in get_reference_entity_id", exc_info=True) + logger.error("Error in get_reference_entity_id", **_traceback_kwargs()) raise @@ -721,6 +773,6 @@ def get_reactome_release() -> Optional[int]: logger.warning( "Could not read the Reactome release from DBInfo; cache fingerprints " "will not include it.", - exc_info=True, + **_traceback_kwargs(), ) return None diff --git a/tests/test_neo4j_connector_safety.py b/tests/test_neo4j_connector_safety.py new file mode 100644 index 0000000..d7ba4ef --- /dev/null +++ b/tests/test_neo4j_connector_safety.py @@ -0,0 +1,141 @@ +"""Credential material must never reach a log, an error, or an artifact. + +Both repositories are public. `_safe_neo4j_url()` redacts our own message, but +every caller used to append py2neo's raw exception text, whose ConnectionProfile +repr re-emits the password fragment the redactor exists to avoid. See issue #62. +""" + +import os +import sys + +import pytest + +import src.neo4j_connector as nc + + +@pytest.mark.parametrize( + "url,expected", + [ + ("bolt://neo4j:hunter2@localhost:7687", "bolt://localhost:7687"), + # An unencoded "@" in the password: ConnectionProfile.uri emitted the + # tail of the password as if it were the host. + ("bolt://neo4j:p@ssSECRET@localhost:7687", "bolt://localhost:7687"), + # An unencoded "/" makes the authority boundary undecidable, so we + # disclose nothing rather than risk a fragment. + ("bolt://neo4j:pw/slashSECRET@localhost:7687", "bolt://"), + ("bolt://neo4j:hunter2@localhost:7687#TOPSECRET", "bolt://localhost:7687"), + ("bolt://localhost:7687?password=hunter2", "bolt://localhost:7687"), + ("bolt://[::1]:7687", "bolt://[::1]:7687"), + ("not-a-url", ""), + ], +) +def test_safe_url_never_emits_credential_material(url, expected, monkeypatch): + monkeypatch.setenv("NEO4J_URL", url) + got = nc._safe_neo4j_url() + assert got == expected + assert "SECRET" not in got + assert "hunter2" not in got + + +@pytest.mark.parametrize( + "text", + [ + "Cannot open connection to ConnectionProfile('bolt://ssSECRET@host')", + "Cannot connect to IPv4Address(('ssSECRET@localhost', 9999))", + "auth failure for bolt://neo4j:SECRET@host", + ], +) +def test_credential_bearing_exception_text_is_withheld(text): + rendered = nc._safe_exception(Exception(text)) + assert "SECRET" not in rendered + assert "withheld" in rendered + + +def test_exception_text_matching_the_password_is_withheld(monkeypatch): + monkeypatch.setenv("NEO4J_PASSWORD", "hunter2") + assert "hunter2" not in nc._safe_exception(Exception("auth failed for hunter2")) + + +def test_benign_exception_keeps_its_message(): + """Over-redaction would make every failure undiagnosable.""" + rendered = nc._safe_exception(ValueError("column 'foo' not found in results")) + assert rendered == "ValueError: column 'foo' not found in results" + + +def test_tracebacks_are_off_by_default(monkeypatch): + """A py2neo traceback carries the same ConnectionProfile the message did.""" + monkeypatch.delenv("LNG_DEBUG_TRACEBACKS", raising=False) + assert nc._traceback_kwargs() == {"exc_info": False} + monkeypatch.setenv("LNG_DEBUG_TRACEBACKS", "1") + assert nc._traceback_kwargs() == {"exc_info": True} + + +# --- Boundary redaction ----------------------------------------------------- +# +# An adversarial review showed that per-call-site gating is not enough: an +# ungated exc_info=True in reaction_generator, a chained __cause__, and two +# entrypoints with no handler at all each still emitted +# ConnectionProfile('bolt://ssSECRET@host') into debug_log.txt or stderr. +# Redaction now happens where text is emitted, so these test that boundary. + +import logging + +from src.credential_redaction import CredentialRedactingFilter, scrub + + +@pytest.mark.parametrize( + "text", + [ + "Cannot open connection to ConnectionProfile('bolt://ssSECRET@localhost:7687')", + "Cannot connect to IPv4Address(('ssSECRET@localhost', 7687))", + "connecting to bolt://neo4j:SECRET@localhost:7687", + "profile ConnectionProfile(\"bolt://neo4j:SECRET@h\") failed", + ], +) +def test_scrub_removes_credential_material(text): + assert "SECRET" not in scrub(text) + + +def test_scrub_leaves_ordinary_text_alone(): + msg = "Reaction R-HSA-69620 has empty outputs, skipping" + assert scrub(msg) == msg + + +def test_scrub_replaces_the_password_without_discarding_the_message(monkeypatch): + """A common-word password must not blank out the whole line.""" + monkeypatch.setenv("NEO4J_PASSWORD", "reactome") + out = scrub("Cannot find /opt/reactome/data/graph.db") + assert "reactome" not in out + assert "Cannot find" in out and "graph.db" in out + + +def test_scrub_ignores_trivially_short_passwords(monkeypatch): + """Substituting a 1-3 char value would corrupt every line for no benefit.""" + monkeypatch.setenv("NEO4J_PASSWORD", "ab") + assert scrub("a table of abbreviations") == "a table of abbreviations" + + +def test_logging_filter_scrubs_message_and_traceback(caplog): + """The path that defeated per-call-site gating: an ungated exc_info.""" + record_filter = CredentialRedactingFilter() + try: + raise RuntimeError( + "Cannot open connection to ConnectionProfile('bolt://ssSECRET@h')" + ) + except RuntimeError: + record = logging.LogRecord( + "t", logging.ERROR, __file__, 1, + "failed talking to bolt://neo4j:ssSECRET@h", (), sys.exc_info(), + ) + assert record_filter.filter(record) is True + assert "SECRET" not in record.getMessage() + assert "SECRET" not in (record.exc_text or "") + # exc_info must be cleared, or the handler re-renders the original. + assert record.exc_info is None + + +def test_safe_exception_scrubs_rather_than_withholds_a_password_substring(monkeypatch): + monkeypatch.setenv("NEO4J_PASSWORD", "reactome") + rendered = nc._safe_exception(RuntimeError("KeyError: 'reactome_release'")) + assert "reactome" not in rendered + assert "withheld" not in rendered