diff --git a/README.md b/README.md index 0448bad..a60ebf0 100644 --- a/README.md +++ b/README.md @@ -636,3 +636,56 @@ ist die massgebliche, aktuelle Fassung dieser Liste. Kurzfassung: sollten das Problem loesen, sollten aber nach dem Deployment einmal manuell im Browser bestaetigt werden. + +## Phase 14: `get_server_host_key()` kennt kein `connect_timeout` + +**Meldung:** `Host-Key konnte nicht ermittelt werden -- Ziel nicht erreichbar: +get_server_host_key() got an unexpected keyword argument 'connect_timeout'`, +und zwar in **unter einer Sekunde** nach dem Klick auf "Host-Key ermitteln". + +**Ursache:** `asyncssh.get_server_host_key()` nimmt -- anders als +`asyncssh.connect()` -- **kein `**kwargs`** entgegen. Seine Parameterliste ist +in asyncssh 2.18.0 abschliessend (`host, port, tunnel, proxy_command, family, +flags, local_addr, sock, client_version, kex_algs, server_host_key_algs, +config, options`); `connect_timeout` gehoert **nicht** dazu. Nur +`asyncssh.connect()` reicht unbekannte Argumente ueber `**kwargs` an +`SSHClientConnectionOptions` weiter -- deshalb war `connect_timeout=10` dort +korrekt und hier ein sofortiger `TypeError`, noch bevor ein Socket geoeffnet +wurde. Daher die Reaktionszeit von unter einer Sekunde: es gab nie einen +Verbindungsversuch. + +Der Fehler stammt aus Phase 12 und betraf **beide** Aufrufstellen in +`app/ssh_proxy/proxy.py`: `discover_and_store_host_key()` (Knopf "Host-Key +ermitteln") und `_verified_host_key()` -- letzteres liegt im regulaeren +Verbindungspfad, es war also **jede** SSH-Sitzung betroffen, nicht nur die +Ermittlung. + +**Warum es dreimal falsch diagnostiziert wurde:** anfangs lief der `TypeError` +unbehandelt bis FastAPI -> nackter HTTP 500 ohne Wortlaut. Der Nachtrag zu +Phase 12 deutete diesen 500er als zu enges `except (asyncssh.Error, OSError)` +und verbreiterte auf `except Exception`. Damit wurde der `TypeError` zwar +gefangen -- aber als `HostKeyDiscoveryError` und damit als "Ziel nicht +erreichbar" **verkleidet**. Die Tests aus Phase 12 konnten es nicht sehen, +weil ihre asyncssh-Attrappen als `(host, port=22, **kw)` definiert waren und +jedes beliebige Argument klaglos schluckten. + +**Loesung** +* Neuer Helfer `_fetch_server_host_key(address, port)` in `proxy.py`: ruft + `asyncssh.get_server_host_key(address, port=port)` auf und setzt das + Zeitlimit von aussen ueber `asyncio.wait_for()` + (`HOST_KEY_CONNECT_TIMEOUT = 10`). Damit ist der Aufruf unabhaengig davon, + wie einzelne asyncssh-Versionen ihre Optionen benennen. +* Beide Aufrufstellen benutzen den Helfer. Ein `asyncio.TimeoutError` wird als + `HostKeyDiscoveryError` mit Klartext "Zeitlimit von 10s ueberschritten" + gemeldet. +* **Ein `TypeError` wird ausdruecklich NICHT mehr maskiert**, sondern + durchgereicht (und mit vollem Traceback geloggt): ein Aufruffehler im + eigenen Code darf nicht als Netzwerkproblem erscheinen. Genau diese + Maskierung hat die Fehlersuche zweimal in die falsche Richtung geschickt. + Alle uebrigen Fehler dieses einen externen Aufrufs bleiben wie bisher breit + gefangen. +* `tests/test_phase12.py`: die Attrappen haben jetzt **kein** `**kw` mehr. +* `tests/test_phase14.py` (8 Faelle), u.a. ein Test, der per + `inspect.signature(asyncssh.get_server_host_key).bind(...)` gegen das + **tatsaechlich installierte** asyncssh prueft -- der haette den Bug im + Produktivsystem gefunden. diff --git a/app/ssh_proxy/proxy.py b/app/ssh_proxy/proxy.py index a96e195..a613d50 100644 --- a/app/ssh_proxy/proxy.py +++ b/app/ssh_proxy/proxy.py @@ -9,6 +9,7 @@ Pflicht: ohne gepinnten Fingerprint wird die Verbindung abgelehnt. """ from __future__ import annotations +import asyncio import logging import asyncssh @@ -380,6 +381,35 @@ def resolve_ssh_username(host: dict, credential_username: str | None) -> str: return username +HOST_KEY_CONNECT_TIMEOUT = 10 + + +async def _fetch_server_host_key(address: str, port: int) -> asyncssh.SSHKey | None: + """Reiner SSH-Key-Exchange ohne Anmeldung, mit Zeitlimit. + + ACHTUNG, das war der Bug hinter drei Fehlersuchen (Phase 12 + Nachtraege): + asyncssh.get_server_host_key() nimmt -- ANDERS als asyncssh.connect() -- + KEIN **kwargs entgegen. Seine Parameterliste ist in asyncssh 2.18.0 + abschliessend: + + get_server_host_key(host='', port=(), *, tunnel=(), proxy_command=(), + family=(), flags=0, local_addr=(), sock=None, + client_version=(), kex_algs=(), + server_host_key_algs=(), config=(), options=None) + + 'connect_timeout' ist NICHT dabei (nur asyncssh.connect() reicht unbekannte + Argumente ueber **kwargs an SSHClientConnectionOptions weiter). Ein Aufruf + mit connect_timeout=... endete deshalb SOFORT -- vor jedem Socket, daher + "in unter einer Sekunde" -- in einem TypeError. Das Zeitlimit wird hier + darum von aussen per asyncio.wait_for() gesetzt; das ist zugleich + unabhaengig davon, wie einzelne asyncssh-Versionen ihre Optionen benennen. + """ + return await asyncio.wait_for( + asyncssh.get_server_host_key(address, port=port), + timeout=HOST_KEY_CONNECT_TIMEOUT, + ) + + async def _verified_host_key( conn: aiosqlite.Connection, host: dict ) -> asyncssh.SSHKey: @@ -401,17 +431,25 @@ async def _verified_host_key( raise HostKeyNotPinnedError(host["id"]) try: - observed_key = await asyncssh.get_server_host_key( - host["address"], port=host["port"], connect_timeout=10 - ) + observed_key = await _fetch_server_host_key(host["address"], host["port"]) + except asyncio.TimeoutError as exc: + raise HostKeyDiscoveryError( + host["id"], f"Zeitlimit von {HOST_KEY_CONNECT_TIMEOUT}s ueberschritten" + ) from exc + except TypeError: + # NICHT maskieren: ein TypeError aus diesem Aufruf ist kein + # Netzwerkproblem, sondern ein Aufruffehler im eigenen Code. Genau so + # wurde der connect_timeout-Bug oben mehrfach als "Ziel nicht + # erreichbar" fehlgedeutet, nachdem das except hier auf Exception + # verbreitert worden war. + raise except Exception as exc: - # Bewusst dieselbe Verbreiterung wie in discover_and_store_host_key(): - # (asyncssh.Error, OSError) allein fing nicht jede Art von Fehlschlag - # dieses externen Aufrufs ab (z.B. asyncio.TimeoutError vor Python - # 3.11, kein OSError). Ein hier unbehandelter Fehler wuerde ungefiltert - # bis in terminal_ws.py/sftp.py durchreichen -- SSH_SETUP_ERRORS - # erkennt HostKeyDiscoveryError dort explizit und zeigt eine saubere - # deutsche Meldung statt eines generischen Sitzungsabbruchs. + # Bewusst breit: (asyncssh.Error, OSError) allein fing nicht jede Art + # von Fehlschlag dieses externen Aufrufs ab. Ein hier unbehandelter + # Fehler wuerde ungefiltert bis in terminal_ws.py/sftp.py + # durchreichen -- SSH_SETUP_ERRORS erkennt HostKeyDiscoveryError dort + # explizit und zeigt eine saubere deutsche Meldung statt eines + # generischen Sitzungsabbruchs. raise HostKeyDiscoveryError(host["id"], str(exc)) from exc if observed_key is None: raise HostKeyDiscoveryError(host["id"], "Das Ziel hat keinen Host-Key gesendet") @@ -554,9 +592,17 @@ async def discover_and_store_host_key( raise HostNotConfiguredError("Host-Key-Ermittlung ist nur fuer SSH-Ziele moeglich") try: - key = await asyncssh.get_server_host_key( - host["address"], port=host["port"], connect_timeout=10 - ) + key = await _fetch_server_host_key(host["address"], host["port"]) + except asyncio.TimeoutError as exc: + logger.warning("Host-Key-Ermittlung fuer Host %s: Zeitlimit ueberschritten", host_id) + raise HostKeyDiscoveryError( + host_id, f"Zeitlimit von {HOST_KEY_CONNECT_TIMEOUT}s ueberschritten" + ) from exc + except TypeError: + # Siehe _fetch_server_host_key(): Aufruffehler im eigenen Code duerfen + # NICHT als "Ziel nicht erreichbar" verkleidet werden. + logger.exception("Host-Key-Ermittlung fuer Host %s: fehlerhafter asyncssh-Aufruf", host_id) + raise except Exception as exc: logger.warning("Host-Key-Ermittlung fuer Host %s fehlgeschlagen: %s", host_id, exc) raise HostKeyDiscoveryError(host_id, str(exc)) from exc diff --git a/tests/test_phase12.py b/tests/test_phase12.py index c9bb69e..83d452b 100644 --- a/tests/test_phase12.py +++ b/tests/test_phase12.py @@ -161,7 +161,7 @@ async def test_discovery_braucht_keine_anmeldung(tmp_path, monkeypatch): async def _fake_connect(*a, **kw): # pragma: no cover - darf nicht laufen raise AssertionError("Die Ermittlung darf keine Anmeldung mehr versuchen") - async def _fake_get_host_key(host, port=22, **kw): + async def _fake_get_host_key(host, port=22): # bewusst OHNE **kw -- siehe test_phase14.py assert (host, port) == ("185.228.139.3", 22) return FakeHostKey() @@ -183,7 +183,7 @@ async def test_discovery_braucht_keine_anmeldung(tmp_path, monkeypatch): async def test_discovery_meldet_echte_unerreichbarkeit(tmp_path, monkeypatch): import asyncssh - async def _fake_get_host_key(host, port=22, **kw): + async def _fake_get_host_key(host, port=22): # bewusst OHNE **kw -- siehe test_phase14.py raise OSError("Connection refused") monkeypatch.setattr(asyncssh, "get_server_host_key", _fake_get_host_key, raising=False) @@ -219,7 +219,7 @@ async def test_abweichender_hostkey_bricht_vor_der_anmeldung_ab(tmp_path, monkey versuche.append(kw) raise AssertionError("Bei abweichendem Host-Key darf keine Anmeldung erfolgen") - async def _fake_get_host_key(host, port=22, **kw): + async def _fake_get_host_key(host, port=22): # bewusst OHNE **kw -- siehe test_phase14.py return FakeHostKey(fingerprint="SHA256:einVoelligAndererSchluessel", public="ssh-ed25519 AAAAfremd x") monkeypatch.setattr(asyncssh, "connect", _fake_connect) @@ -242,7 +242,7 @@ async def test_verbindung_nutzt_benutzernamen_der_zugangsdaten(tmp_path, monkeyp aufrufe.update(kw) return FakeConnectionResult() - async def _fake_get_host_key(host, port=22, **kw): + async def _fake_get_host_key(host, port=22): # bewusst OHNE **kw -- siehe test_phase14.py return FakeHostKey() monkeypatch.setattr(asyncssh, "connect", _fake_connect) @@ -262,7 +262,7 @@ async def test_hostkey_wechsel_nach_der_pruefung_beendet_die_sitzung(tmp_path, m async def _fake_connect(address, **kw): return verbindung - async def _fake_get_host_key(host, port=22, **kw): + async def _fake_get_host_key(host, port=22): # bewusst OHNE **kw -- siehe test_phase14.py return FakeHostKey() monkeypatch.setattr(asyncssh, "connect", _fake_connect) @@ -283,7 +283,7 @@ async def test_altbestand_ohne_gespeicherten_hostkey_wird_nachgetragen(tmp_path, async def _fake_connect(address, **kw): return FakeConnectionResult() - async def _fake_get_host_key(host, port=22, **kw): + async def _fake_get_host_key(host, port=22): # bewusst OHNE **kw -- siehe test_phase14.py return FakeHostKey() monkeypatch.setattr(asyncssh, "connect", _fake_connect) diff --git a/tests/test_phase14.py b/tests/test_phase14.py new file mode 100644 index 0000000..065bdd7 --- /dev/null +++ b/tests/test_phase14.py @@ -0,0 +1,179 @@ +""" +Tests fuer Phase 14 -- die eigentliche Ursache des "Host-Key konnte nicht +ermittelt werden -- Ziel nicht erreichbar"-Dauerbrenners. + +Gemeldet wurde zuletzt: + + Host-Key konnte nicht ermittelt werden -- Ziel nicht erreichbar: + get_server_host_key() got an unexpected keyword argument 'connect_timeout' + +...und zwar in unter einer Sekunde nach dem Klick. Genau das ist der Beweis: +es wurde nie ein Socket geoeffnet. asyncssh.get_server_host_key() nimmt -- +anders als asyncssh.connect() -- KEIN **kwargs entgegen, 'connect_timeout' +gehoert nicht zu seinen Parametern. Der Aufruf endete also schon beim +Argument-Binding in einem TypeError. + +Warum das dreimal falsch diagnostiziert wurde: + * Phase 12 fuehrte get_server_host_key(..., connect_timeout=10) ein. Der + TypeError lief unbehandelt bis FastAPI -> nackter HTTP 500. + * Der Phase-12-Nachtrag deutete diesen 500er als "except (asyncssh.Error, + OSError) ist zu eng" und verbreiterte auf except Exception. Damit wurde + der TypeError zwar gefangen -- aber als HostKeyDiscoveryError, also als + "Ziel nicht erreichbar" VERKLEIDET. Erst dadurch wurde der Wortlaut + ueberhaupt sichtbar. + * Die Tests aus Phase 12 konnten es nicht sehen: ihre asyncssh-Attrappen + waren als (host, port=22, **kw) definiert und schluckten jedes beliebige + Argument klaglos. + +Diese Datei sichert genau diese drei Punkte ab. +""" +from __future__ import annotations + +import asyncio +import inspect + +import asyncssh +import pytest + +from app.ssh_proxy import proxy as proxy_module +from app.ssh_proxy.proxy import ( + HostKeyDiscoveryError, + _verified_host_key, + discover_and_store_host_key, + load_host, +) + +try: # je nach sys.path-Modus von pytest + from tests.test_phase12 import FINGERPRINT, PUBLIC_KEY, FakeConnection, FakeHostKey, _make_db +except ImportError: # pragma: no cover + from test_phase12 import FINGERPRINT, PUBLIC_KEY, FakeConnection, FakeHostKey, _make_db + + +# -------------------------------------------------------------------------- +# Attrappe mit der ECHTEN Signatur von asyncssh 2.18.0. Bewusst kein **kwargs: +# jedes zusaetzliche Argument aus dem Produktivcode schlaegt hier genauso fehl +# wie beim echten asyncssh. +# -------------------------------------------------------------------------- + +def _strict_get_server_host_key(result=None, *, calls=None): + async def _fake( + host="", port=(), *, tunnel=(), proxy_command=(), family=(), flags=0, + local_addr=(), sock=None, client_version=(), kex_algs=(), + server_host_key_algs=(), config=(), options=None, + ): + if calls is not None: + calls.append((host, port)) + if isinstance(result, BaseException): + raise result + return result if result is not None else FakeHostKey() + + return _fake + + +# -------------------------------------------------------------------------- +# 1) Die Signatur selbst -- der Test, der den Bug im Produktivsystem gefunden +# haette. Laeuft gegen das TATSAECHLICH installierte asyncssh. +# -------------------------------------------------------------------------- + +def test_aufruf_passt_zur_echten_signatur_von_get_server_host_key(): + sig = inspect.signature(asyncssh.get_server_host_key) + # So ruft proxy.py auf -- muss sich binden lassen: + sig.bind("10.0.0.1", port=22) + + +def test_connect_timeout_ist_kein_parameter_von_get_server_host_key(): + """Dokumentiert die Falle: connect_timeout ist bei asyncssh.connect() + erlaubt (das reicht **kwargs an SSHClientConnectionOptions weiter), bei + get_server_host_key() aber NICHT -- dessen Parameterliste ist + abschliessend.""" + sig = inspect.signature(asyncssh.get_server_host_key) + hat_var_keyword = any( + p.kind is inspect.Parameter.VAR_KEYWORD for p in sig.parameters.values() + ) + if hat_var_keyword: + pytest.skip("Diese asyncssh-Version nimmt **kwargs entgegen") + assert "connect_timeout" not in sig.parameters + with pytest.raises(TypeError): + sig.bind("10.0.0.1", port=22, connect_timeout=10) + + +async def test_fetch_server_host_key_uebergibt_nur_host_und_port(monkeypatch): + calls: list = [] + monkeypatch.setattr( + asyncssh, "get_server_host_key", _strict_get_server_host_key(calls=calls), raising=False + ) + key = await proxy_module._fetch_server_host_key("10.0.0.1", 2222) + assert calls == [("10.0.0.1", 2222)] + assert key.get_fingerprint("sha256") == FINGERPRINT + + +# -------------------------------------------------------------------------- +# 2) Beide betroffenen Pfade end-to-end -- mit der strengen Attrappe. +# Wichtig: _verified_host_key() liegt im REGULAEREN Verbindungspfad +# (connect_to_host), der connect_timeout-Bug hat also nicht nur den Knopf +# "Host-Key ermitteln", sondern JEDE SSH-Sitzung lahmgelegt. +# -------------------------------------------------------------------------- + +async def test_discovery_laeuft_mit_echter_signatur_durch(tmp_path, monkeypatch): + monkeypatch.setattr( + asyncssh, "get_server_host_key", _strict_get_server_host_key(), raising=False + ) + conn = FakeConnection(_make_db(tmp_path, fingerprint=None, host_key=None)) + assert await discover_and_store_host_key(conn, 1, admin_user_id=1) == FINGERPRINT + + +async def test_pinning_laeuft_mit_echter_signatur_durch(tmp_path, monkeypatch): + monkeypatch.setattr( + asyncssh, "get_server_host_key", _strict_get_server_host_key(), raising=False + ) + conn = FakeConnection(_make_db(tmp_path)) + host = await load_host(conn, 1) + key = await _verified_host_key(conn, host) + assert key.get_fingerprint("sha256") == FINGERPRINT + + +# -------------------------------------------------------------------------- +# 3) Fehlerbehandlung: echte Netzwerkfehler bleiben "Ziel nicht erreichbar", +# ein Aufruffehler im eigenen Code aber NICHT. +# -------------------------------------------------------------------------- + +async def test_netzwerkfehler_bleibt_hostkeydiscoveryerror(tmp_path, monkeypatch): + monkeypatch.setattr( + asyncssh, "get_server_host_key", + _strict_get_server_host_key(OSError("Connection refused")), raising=False, + ) + conn = FakeConnection(_make_db(tmp_path)) + with pytest.raises(HostKeyDiscoveryError) as excinfo: + await discover_and_store_host_key(conn, 1, admin_user_id=1) + assert "Connection refused" in excinfo.value.reason + + +async def test_typeerror_wird_nicht_als_unerreichbar_verkleidet(tmp_path, monkeypatch): + """Der Kern der Lehre aus dieser Phase: haette der Catch-all den TypeError + nicht als HostKeyDiscoveryError ausgegeben, waere die Meldung von Anfang + an als Programmierfehler erkennbar gewesen.""" + async def _kaputt(*a, **kw): + raise TypeError("get_server_host_key() got an unexpected keyword argument 'irgendwas'") + + monkeypatch.setattr(asyncssh, "get_server_host_key", _kaputt, raising=False) + conn = FakeConnection(_make_db(tmp_path)) + with pytest.raises(TypeError): + await discover_and_store_host_key(conn, 1, admin_user_id=1) + host = await load_host(conn, 1) + with pytest.raises(TypeError): + await _verified_host_key(conn, host) + + +async def test_zeitlimit_wird_von_aussen_gesetzt(tmp_path, monkeypatch): + """Das Zeitlimit ist nicht ersatzlos entfallen, sondern liegt jetzt in + asyncio.wait_for() -- unabhaengig davon, wie asyncssh seine Optionen + benennt.""" + async def _haengt(*a, **kw): + await asyncio.sleep(5) + + monkeypatch.setattr(asyncssh, "get_server_host_key", _haengt, raising=False) + monkeypatch.setattr(proxy_module, "HOST_KEY_CONNECT_TIMEOUT", 0.05) + conn = FakeConnection(_make_db(tmp_path)) + with pytest.raises(HostKeyDiscoveryError) as excinfo: + await discover_and_store_host_key(conn, 1, admin_user_id=1) + assert "Zeitlimit" in excinfo.value.reason