mirror of
https://github.com/saphid/frame-control.git
synced 2026-10-23 10:01:38 +02:00
Reports: connection summary in fixed words only; scrub log lines at capture
Independent review (pr79-review-r1) found leaks in the first version: a failure's raw text was hidden with the current headset's hosts (so switching headsets let the old one's name through), unknown hosts and other cases survived, Windows user names with spaces partly survived, the PATH scan ran on every preview, and the log throttle only caught consecutive repeats. - The always-on summary has no free text: the current error and last failure are a stage plus the telemetry error category (decided when the failure happens) and how long ago. ssh -V is reduced to its version words. - The opt-in server log line is scrubbed when written, with that attempt's hosts (case-insensitive), any name ssh gives after hostname/host/to, and then the shared scrubber. - frame_telemetry.scrub: a Windows home folder's whole name (spaces too) and the whole user part of ssh's user@host (spaces, DOMAIN\user) become <user>. - The ssh discovery runs once in the background from server start; a report waits at most 0.3 s for it. - The log throttle keeps per-failure timestamps and counts, bounded to 32. - Regression tests for each case; privacy.md says exactly what's sent. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
This commit is contained in:
1 parent
6f5aa33197
commit
70309d3cec
7 files changed
+267
-95
No files matched your search
+30
-15
@@ -123,26 +123,34 @@ With **Include diagnostics** ticked (the default), the report adds:
|
||||
- the Frame's SteamOS build, if it has connected since the app started
|
||||
- which analytics levels are on
|
||||
- a short connection summary, so "the app can't find the headset" can be
|
||||
diagnosed:
|
||||
diagnosed. It is made of fixed words, counts and the alias name only; no
|
||||
text from an error message or from ssh goes in it:
|
||||
- the connector's state (idle, connecting, connected or failed), the stage
|
||||
it failed at (network, find, ssh, identity or login), the attempt number
|
||||
and why it started
|
||||
- how many headsets are saved, and the active one's ssh alias name (such as
|
||||
`frame`) and number of addresses
|
||||
- the current error and the last failure (with how long ago), as shown on
|
||||
the connection pill, plus ssh's last line about it. The headset's
|
||||
addresses and host names, and the user name in `user@host`, are replaced
|
||||
with `<host>` and `<user>@`
|
||||
and why it started (such as "Starting up" or "Trying again")
|
||||
- how many headsets are saved, the active one's ssh alias name (such as
|
||||
`frame`; it's whatever name the headset was set up under), whether it's
|
||||
saved or a bare ssh alias, and its number of addresses
|
||||
- for the current error and the last failure: the stage and an error
|
||||
category (the same fixed names as error details, such as
|
||||
`frame_unreachable`, `frame_not_set_up`, `frame_auth` or `other`), and
|
||||
how long ago the last failure was. The category is decided when the
|
||||
failure happens
|
||||
- for each address tried, only its kind (`.local`, `ipv4`, `ipv6`,
|
||||
`ipv6 link-local`, `tailscale`, `hostname`, `alias` for one read from
|
||||
`~/.ssh/config`, and what a name resolved to, such as
|
||||
`.local->ipv6 link-local`) and how the try went (answered, unresolved,
|
||||
timeout, refused, unreachable, SSH failed). Never the address itself
|
||||
timeout, refused, unreachable, sshfailed). Never the address itself
|
||||
- when connected, the kind of address used and its round trip in ms
|
||||
- whether this computer has a network gateway, and whether Tailscale is on,
|
||||
off or not installed
|
||||
- which kind of `ssh` the app runs (such as Windows OpenSSH in System32,
|
||||
Git for Windows, Homebrew, or the system one), never its path, with the
|
||||
first line of `ssh -V`, and the kinds of any other `ssh` on the PATH
|
||||
- which kind of `ssh` the app runs (Windows OpenSSH in System32, OpenSSH in
|
||||
Program Files, Git for Windows, MSYS2/Cygwin, Homebrew or /usr/local,
|
||||
Nix, the system one, or "other"), never its path; its version words from
|
||||
`ssh -V` (such as `OpenSSH_for_Windows_9.5p1, LibreSSL 3.8.2`, and
|
||||
nothing else it prints); and the kinds of any other `ssh` on the PATH.
|
||||
This is looked up once in the background after the app starts, so a
|
||||
report sent straight away may say "still being checked"
|
||||
- whether `~/.ssh/config` exists, whether it has Set Up Connection's
|
||||
managed block for the active alias, how many managed blocks it has, and
|
||||
whether a hand-written `Host` line also names the alias
|
||||
@@ -150,9 +158,16 @@ With **Include diagnostics** ticked (the default), the report adds:
|
||||
**Also include recent activity and the server log** is off by default,
|
||||
because those lines can name files and apps. When ticked, it adds the newest
|
||||
Activity lines and server log lines, without the request lines. The server
|
||||
log has a line for each failed connection attempt (the same stage, message
|
||||
and address kinds as above, scrubbed the same way when written; a failure
|
||||
that repeats on every retry is written at most once every 5 minutes).
|
||||
log has a line for each failed connection attempt: its stage, the message
|
||||
shown on the connection pill, ssh's last line about it, and the address kinds
|
||||
above. That free text is scrubbed when the line is written: the addresses and
|
||||
names of the headset being tried (whatever their case), and any name ssh gives
|
||||
after "hostname", "host" or "to", become `<host>`; a Windows home folder's
|
||||
whole name and the whole user part of `user@host` (spaces and `DOMAIN\user`
|
||||
included) become `<user>`; then the scrubbing below. A host name ssh mentions
|
||||
in some other wording can still get through, so check the log lines in **Show
|
||||
exactly what's included** before sending. A failure that repeats on every
|
||||
retry is written at most once every 5 minutes.
|
||||
|
||||
Everything is scrubbed like error details and limited to what fits in the
|
||||
report. Environment details are kept first, then the newest lines. **Show
|
||||
|
||||
+123
-27
@@ -602,12 +602,16 @@ class Connecting(unittest.TestCase):
|
||||
|
||||
# ---- what a failure leaves for a problem report ----
|
||||
def stderr(self):
|
||||
fl._logged.update(line=None, at=0.0, repeats=0)
|
||||
err = io.StringIO()
|
||||
p = mock.patch.object(sys, "stderr", err)
|
||||
p.start()
|
||||
self.addCleanup(p.stop)
|
||||
return err
|
||||
return quiet_log(self)
|
||||
|
||||
def report(self):
|
||||
import frame_report as fr
|
||||
done = threading.Thread(target=lambda: None)
|
||||
done.start()
|
||||
done.join()
|
||||
with mock.patch.object(fr, "link", self.link), \
|
||||
mock.patch.dict(fr._ssh, {"thread": done, "line": "SSH: system OpenSSH, OpenSSH_9.9p1, LibreSSL 3.3.6"}):
|
||||
return fr.diagnostics()
|
||||
|
||||
def test_each_failure_goes_to_the_server_log_scrubbed(self):
|
||||
err = self.stderr()
|
||||
@@ -621,38 +625,101 @@ class Connecting(unittest.TestCase):
|
||||
self.assertNotIn(leaked, line)
|
||||
self.assertEqual(self.link.last_failure["stage"], "login")
|
||||
|
||||
def test_the_same_failure_isnt_logged_every_retry(self):
|
||||
err = self.stderr()
|
||||
for _ in range(3):
|
||||
fl.log_failure("find", "The Frame isn't answering.", "", [{"host": "frame.local", "state": "timeout"}])
|
||||
self.assertEqual(err.getvalue().count("frame_link:"), 1)
|
||||
fl._logged["at"] -= fl.LOG_REPEAT_EVERY + 1
|
||||
fl.log_failure("find", "The Frame isn't answering.", "", [{"host": "frame.local", "state": "timeout"}])
|
||||
self.assertIn("(and 2 more times)", err.getvalue())
|
||||
self.assertNotIn("frame.local", err.getvalue())
|
||||
|
||||
def test_reports_carry_a_connection_summary_without_addresses(self):
|
||||
import frame_report as fr
|
||||
def test_reports_carry_a_connection_summary_in_fixed_words(self):
|
||||
self.stderr()
|
||||
self.device("steamdeck-jane.invalid", "frame-t.invalid")
|
||||
(self.dir / "ssh" / "config").write_text(
|
||||
f"{fd.begin_mark('frame-t')}\nHost frame-t\n HostName 192.168.1.50\n User steamos\n{fd.end_mark('frame-t')}\n"
|
||||
"Host frame-t\n HostName 10.0.0.7\n")
|
||||
self.link.connect(["start"])
|
||||
fake = subprocess.CompletedProcess(["ssh", "-V"], 0, "", "OpenSSH_9.9p1, LibreSSL 3.3.6\n")
|
||||
with mock.patch.object(fr, "link", self.link), mock.patch.dict(fr._ssh_versions, clear=True), \
|
||||
mock.patch.object(fr.frame_host, "run_ssh", return_value=fake):
|
||||
text = fr.diagnostics()
|
||||
text = self.report()
|
||||
self.assertIn("Connection: failed at find, attempt 1 (Starting up)", text)
|
||||
self.assertIn('Headsets: 1 saved; active "frame-t" (saved, 2 address(es))', text)
|
||||
self.assertIn("Error: Can't find the Frame on the network. | ssh said: ssh: Could not resolve hostname <host>", text)
|
||||
self.assertIn("Error: find, frame_not_set_up", text)
|
||||
self.assertRegex(text, r"Last failure: find, frame_not_set_up, 0 min \d+ s ago")
|
||||
self.assertIn("Addresses tried: hostname unresolved; hostname unresolved", text)
|
||||
self.assertIn("Network: gateway yes, Tailscale not installed", text)
|
||||
self.assertIn("OpenSSH_9.9p1", text)
|
||||
self.assertIn("SSH: system OpenSSH, OpenSSH_9.9p1", text)
|
||||
self.assertIn('~/.ssh/config: managed "frame-t" block yes (1 managed in all); hand-written "Host frame-t" yes', text)
|
||||
for leaked in ("steamdeck-jane", "192.168", "10.0.0.7", "steamos", str(self.dir)):
|
||||
# No free text from the error or ssh at all.
|
||||
for leaked in ("steamdeck-jane", "Could not resolve", "Can't find", "192.168", "10.0.0.7", "steamos", str(self.dir)):
|
||||
self.assertNotIn(leaked, text)
|
||||
|
||||
def test_a_failure_on_the_last_headset_leaves_nothing_of_it_after_switching(self):
|
||||
self.stderr()
|
||||
a = self.device("steamdeck-jane.invalid")
|
||||
self.link.connect(["start"])
|
||||
b = self.reg.add_device("frame-2", port=self.port, hosts=[])
|
||||
self.reg.add_address(b["id"], "localhost", kind="lan")
|
||||
self.hosts({"localhost": "ok"})
|
||||
self.reg.set_active(b["id"])
|
||||
self.link.connect(["switch"])
|
||||
self.assertEqual(self.link.snapshot()["phase"], "connected")
|
||||
text = self.report()
|
||||
self.assertIn("Connection: connected via hostname->ipv4", text)
|
||||
self.assertRegex(text, r"Last failure: find, frame_not_set_up, ")
|
||||
self.assertNotIn("steamdeck-jane", text)
|
||||
self.assertNotEqual(a["id"], b["id"])
|
||||
|
||||
|
||||
def quiet_log(test):
|
||||
"""Catch frame_link's log lines, starting with nothing remembered."""
|
||||
fl._logged.clear()
|
||||
err = io.StringIO()
|
||||
p = mock.patch.object(sys, "stderr", err)
|
||||
p.start()
|
||||
test.addCleanup(p.stop)
|
||||
return err
|
||||
|
||||
|
||||
class FailureLog(unittest.TestCase):
|
||||
def test_the_same_failure_isnt_logged_every_retry(self):
|
||||
err = quiet_log(self)
|
||||
for _ in range(3):
|
||||
fl.log_failure("find", "The Frame isn't answering.", "", [{"host": "frame.local", "state": "timeout"}])
|
||||
self.assertEqual(err.getvalue().count("frame_link:"), 1)
|
||||
for v in fl._logged.values():
|
||||
v["at"] -= fl.LOG_REPEAT_EVERY + 1
|
||||
fl.log_failure("find", "The Frame isn't answering.", "", [{"host": "frame.local", "state": "timeout"}])
|
||||
self.assertIn("(and 2 more times)", err.getvalue())
|
||||
self.assertNotIn("frame.local", err.getvalue())
|
||||
|
||||
def test_interleaved_failures_are_throttled_too(self):
|
||||
err = quiet_log(self)
|
||||
for _ in range(4):
|
||||
fl.log_failure("find", "The Frame isn't answering.")
|
||||
fl.log_failure("login", "The Frame didn't accept this computer's SSH key.")
|
||||
self.assertEqual(err.getvalue().count("frame_link:"), 2)
|
||||
for i in range(fl.LOG_REMEMBER + 10): # many different failures: memory stays bounded
|
||||
fl.log_failure("ssh", f"failure number {i}")
|
||||
self.assertLessEqual(len(fl._logged), fl.LOG_REMEMBER)
|
||||
|
||||
def test_hosts_ssh_names_go_known_or_not_and_whatever_the_case(self):
|
||||
err = quiet_log(self)
|
||||
fl.log_failure("ssh", "ssh stopped", "ssh: Could not resolve hostname bastion-jane: Name or service not known")
|
||||
fl.log_failure("ssh", "ssh stopped", "channel 0: open failed: connect to host jane-office.example.com port 22")
|
||||
fl.log_failure("ssh", "ssh stopped", "kex_exchange_identification: Connection reset by steamdeck-jane",
|
||||
hosts=["STEAMDECK-JANE"])
|
||||
fl.log_failure("ssh", "Timed out talking to frame-jane", "")
|
||||
out = err.getvalue()
|
||||
self.assertIn("hostname <host>", out)
|
||||
self.assertIn("connect to host <host> port 22", out)
|
||||
for leaked in ("bastion-jane", "jane-office", "steamdeck-jane", "frame-jane"):
|
||||
self.assertNotIn(leaked, out)
|
||||
|
||||
def test_windows_user_names_with_spaces_go_whole(self):
|
||||
err = quiet_log(self)
|
||||
with mock.patch.object(fl.frame_telemetry, "_user_names", return_value=set()):
|
||||
fl.log_failure("ssh", r"Bad owner or permissions on C:\Users\Jane Doe/.ssh/config", "")
|
||||
fl.log_failure("login", "The Frame didn't accept this computer's SSH key.",
|
||||
"Jane Doe@frame: Permission denied (publickey).")
|
||||
fl.log_failure("login", "refused", r"debug | ssh said: CORP\jane@frame's password: denied")
|
||||
out = err.getvalue()
|
||||
self.assertIn(r"C:\Users\<user>/.ssh/config", out)
|
||||
self.assertIn("<user>@frame: Permission denied", out)
|
||||
for leaked in ("Jane", "Doe", "jane", "CORP"):
|
||||
self.assertNotIn(leaked, out)
|
||||
|
||||
|
||||
class ConnectionDiagnostics(unittest.TestCase):
|
||||
def test_address_kinds_never_the_address(self):
|
||||
@@ -673,8 +740,37 @@ class ConnectionDiagnostics(unittest.TestCase):
|
||||
"frame_link: Could not resolve hostname <host>")
|
||||
self.assertEqual(fl.hide_hosts("ssh frame to frame.local", ["frame.local", "frame"], keep=("frame",)),
|
||||
"ssh frame to <host>")
|
||||
self.assertEqual(fl.hide_hosts("steamos@frame: Permission denied (publickey).", []),
|
||||
"<user>@frame: Permission denied (publickey).")
|
||||
self.assertEqual(fl.hide_hosts("reset by SteamDeck", ["steamdeck"]), "reset by <host>")
|
||||
self.assertEqual(fl.hide_operands("The headset took too long to answer."), "The headset took too long to answer.")
|
||||
|
||||
def test_ssh_version_is_only_its_version_words(self):
|
||||
import frame_report as fr
|
||||
for said, want in (("OpenSSH_for_Windows_9.5p1, LibreSSL 3.8.2\n", "OpenSSH_for_Windows_9.5p1, LibreSSL 3.8.2"),
|
||||
("OpenSSH_9.9p1, LibreSSL 3.3.6\n", "OpenSSH_9.9p1, LibreSSL 3.3.6"),
|
||||
(r"C:\Users\Jane Doe\ssh.exe: something odd", "unrecognised version (exit 0)")):
|
||||
with mock.patch.object(fr.frame_host, "run_ssh", return_value=subprocess.CompletedProcess([], 0, "", said)):
|
||||
self.assertEqual(fr.ssh_version("ssh"), want)
|
||||
|
||||
def test_a_slow_path_never_holds_up_a_report(self):
|
||||
import frame_report as fr
|
||||
release = threading.Event()
|
||||
|
||||
def slow():
|
||||
release.wait(5)
|
||||
return []
|
||||
with mock.patch.dict(fr._ssh, {"thread": None, "line": None}), mock.patch.object(fr, "_ssh_on_path", slow), \
|
||||
mock.patch.object(fr, "link", None), mock.patch.object(fr.shutil, "which", return_value="/usr/bin/ssh"), \
|
||||
mock.patch.object(fr.frame_host, "run_ssh",
|
||||
return_value=subprocess.CompletedProcess([], 0, "", "OpenSSH_9.9p1, LibreSSL 3.3.6\n")):
|
||||
t0 = time.monotonic()
|
||||
self.assertIn("Connection: no connector", fr.diagnostics())
|
||||
self.assertIn("SSH: still being checked", fr.ssh_line())
|
||||
self.assertLess(time.monotonic() - t0, 2)
|
||||
thread = fr._ssh["thread"]
|
||||
release.set()
|
||||
thread.join(5)
|
||||
self.assertTrue(fr._ssh["line"].startswith("SSH: "))
|
||||
self.assertNotEqual(fr.ssh_line(), "SSH: still being checked")
|
||||
|
||||
def test_ssh_kinds(self):
|
||||
import frame_report as fr
|
||||
|
||||
+61
-23
@@ -171,34 +171,67 @@ def probes_summary(probes):
|
||||
|
||||
def hide_hosts(text, hosts, keep=()):
|
||||
"""text with each of `hosts` (the headset's own addresses and names) replaced by <host>,
|
||||
longest first, so a bare name like "steamdeck" that the scrubber can't recognise goes too;
|
||||
and ssh's "user@host" loses the user."""
|
||||
for h in sorted({h for h in hosts if h and h not in keep}, key=len, reverse=True):
|
||||
text = re.sub(r"(?<![\w.:-])%s(?![\w-]|[:.%%]\w)" % re.escape(h), "<host>", text)
|
||||
return re.sub(r"[\w.+-]+@(?=[\w\[<])", "<user>@", text)
|
||||
longest first and whatever the case, so a bare name like "steamdeck" that the scrubber
|
||||
can't recognise goes too."""
|
||||
keep = {k.lower() for k in keep if k}
|
||||
for h in sorted({h for h in hosts if h and h.lower() not in keep}, key=len, reverse=True):
|
||||
text = re.sub(r"(?<![\w.:-])%s(?![\w-]|[:.%%]\w)" % re.escape(h), "<host>", text, flags=re.I)
|
||||
return text
|
||||
|
||||
|
||||
_logged = {"line": None, "at": 0.0, "repeats": 0}
|
||||
# ssh names the host it was going to after these words ("Could not resolve hostname X",
|
||||
# "connect to host X port 22", "Timed out talking to X"): whatever follows goes, known or not.
|
||||
OPERAND = re.compile(r"(?i)\b(hostname|host|to(?:\s+host)?)\s+(?!<)([^\s:,;'\"()|]+)")
|
||||
PLAIN_WORDS = {"answer", "the", "a", "an", "this", "it", "its", "be", "connect", "find", "work", "try"}
|
||||
|
||||
|
||||
def hide_operands(text):
|
||||
def one(m):
|
||||
word = m.group(2).rstrip(".")
|
||||
dots = m.group(2)[len(word):]
|
||||
return m.group(0) if word.lower() in PLAIN_WORDS else f"{m.group(1)} <host>{dots}"
|
||||
return OPERAND.sub(one, text)
|
||||
|
||||
|
||||
def scrub_failure(text, hosts=()):
|
||||
"""Free text about a failed attempt, for the log: the attempt's own hosts and anything ssh
|
||||
names as a host replaced, then the shared scrubber (addresses, paths, user names)."""
|
||||
return frame_telemetry.scrub(hide_operands(hide_hosts(str(text or ""), hosts)), 600)
|
||||
|
||||
|
||||
def failure_category(message, raw=""):
|
||||
"""The telemetry error category (frame_unreachable, frame_auth, ...) for a failure: a fixed
|
||||
word, never its text."""
|
||||
return frame_telemetry.categorize(f"{message or ''}\n{raw or ''}")[0]
|
||||
|
||||
|
||||
_logged = {} # failure line -> {"at": when last written, "repeats": since then}
|
||||
LOG_REPEAT_EVERY = 300 # the same failure, retried every 30 s, goes in the log at most this often
|
||||
LOG_REMEMBER = 32 # different failures remembered for that
|
||||
|
||||
|
||||
def log_failure(stage, message, raw="", probes=()):
|
||||
"""One failed connection attempt to stderr (the app's server.log), scrubbed like a report."""
|
||||
bits = [f"frame_link: {stage} failed: {message}"]
|
||||
def log_failure(stage, message, raw="", probes=(), hosts=()):
|
||||
"""One failed connection attempt to stderr (the app's server.log), scrubbed when written,
|
||||
with the hosts of that attempt (so a later switch of headset can't let them through)."""
|
||||
hosts = list(hosts) + [r.get(k) for r in probes or () for k in ("host", "ip")]
|
||||
bits = [f"frame_link: {stage} failed: {scrub_failure(message, hosts)}"]
|
||||
last = [ln.strip() for ln in (raw or "").splitlines() if ln.strip()][-1:]
|
||||
if last and last[0] != message:
|
||||
bits.append(f"ssh said: {last[0][:300]}")
|
||||
bits.append(f"ssh said: {scrub_failure(last[0][:300], hosts)}")
|
||||
tried = probes_summary(probes)
|
||||
if tried:
|
||||
bits.append(f"addresses: {tried}")
|
||||
hosts = [r.get("host") for r in probes or ()] + [r.get("ip") for r in probes or ()]
|
||||
line = frame_telemetry.scrub(hide_hosts(" | ".join(bits), hosts), 800)
|
||||
line = " | ".join(bits)[:900]
|
||||
t = time.monotonic()
|
||||
if line == _logged["line"] and t - _logged["at"] < LOG_REPEAT_EVERY:
|
||||
_logged["repeats"] += 1
|
||||
seen = _logged.get(line)
|
||||
if seen and t - seen["at"] < LOG_REPEAT_EVERY:
|
||||
seen["repeats"] += 1
|
||||
return
|
||||
more = f" (and {_logged['repeats']} more times)" if line == _logged["line"] and _logged["repeats"] else ""
|
||||
_logged.update(line=line, at=t, repeats=0)
|
||||
more = f" (and {seen['repeats']} more times)" if seen and seen["repeats"] else ""
|
||||
_logged.pop(line, None)
|
||||
_logged[line] = {"at": t, "repeats": 0}
|
||||
while len(_logged) > LOG_REMEMBER:
|
||||
_logged.pop(next(iter(_logged))) # the least recently written
|
||||
try:
|
||||
print(line + more, file=sys.stderr, flush=True)
|
||||
except (OSError, ValueError, AttributeError):
|
||||
@@ -257,7 +290,7 @@ class Link:
|
||||
self.route_lock = threading.Lock()
|
||||
self.routed = None # the device id every ssh command points at
|
||||
self.routed_device = None
|
||||
self.last_failure = None # {"stage", "message", "raw", "at"}: for report diagnostics
|
||||
self.last_failure = None # {"stage", "category", "at"}: for report diagnostics, no free text
|
||||
|
||||
# ---- publishing ----
|
||||
def publish(self, **fields):
|
||||
@@ -507,8 +540,7 @@ class Link:
|
||||
self.connect(reasons)
|
||||
except Exception as e: # keep the loop alive whatever happens; say what went wrong
|
||||
message = f"{type(e).__name__}: {e}"
|
||||
self.last_failure = {"stage": "network", "message": message, "raw": str(e), "at": now()}
|
||||
log_failure("network", message)
|
||||
self.note_failure("network", message, str(e))
|
||||
self.publish(phase="failed", error={"stage": "network", "message": message,
|
||||
"raw": str(e)}, retry_at=now() + RETRY[-1])
|
||||
finally:
|
||||
@@ -613,8 +645,7 @@ class Link:
|
||||
now() + RETRY[min(self.fails, len(RETRY)) - 1])
|
||||
if not self.state["error"]:
|
||||
self.state["error"] = {"stage": "find", "message": "Couldn't connect", "raw": ""}
|
||||
self.last_failure = dict(self.state["error"], at=now())
|
||||
log_failure("find", "Couldn't connect", "", self.state["probes"])
|
||||
self.note_failure("find", "Couldn't connect", "", self.state["probes"])
|
||||
self.version += 1
|
||||
self.cond.notify_all()
|
||||
|
||||
@@ -638,8 +669,15 @@ class Link:
|
||||
with self.cond:
|
||||
self.state["error"] = {"stage": sid, "message": message, "raw": raw}
|
||||
probes = copy.deepcopy(self.state["probes"])
|
||||
self.last_failure = {"stage": sid, "message": message, "raw": raw, "at": now()}
|
||||
log_failure(sid, message, raw, probes)
|
||||
self.note_failure(sid, message, raw, probes)
|
||||
|
||||
def note_failure(self, stage, message, raw="", probes=()):
|
||||
"""Keep a failure for report diagnostics as fixed values only (its stage and error
|
||||
category, decided now), and write it to the log scrubbed with this attempt's hosts."""
|
||||
self.last_failure = {"stage": stage, "category": failure_category(message, raw), "at": now()}
|
||||
d = self.routed_device or {}
|
||||
hosts = [a.get("host") for a in d.get("addresses") or ()] + [d.get("frozen_host")]
|
||||
log_failure(stage, message, raw, probes, hosts)
|
||||
|
||||
def attempt(self, device):
|
||||
if device.get("none"):
|
||||
|
||||
+44
-28
@@ -17,6 +17,7 @@ import re
|
||||
import shutil
|
||||
import subprocess
|
||||
import sys
|
||||
import threading
|
||||
import time
|
||||
import uuid
|
||||
|
||||
@@ -34,7 +35,6 @@ ACTIVITY_LINES = 25
|
||||
|
||||
frame = {} # the Frame's last known SteamOS build, set by server.status()
|
||||
link = None # the connector (frame_link.Link), set by server.main; None on the Frame itself
|
||||
_ssh_versions = {} # ssh path -> `ssh -V`, asked once per run
|
||||
|
||||
|
||||
def u16(s):
|
||||
@@ -98,20 +98,21 @@ def _ssh_on_path():
|
||||
return found
|
||||
|
||||
|
||||
VERSION_RE = re.compile(r"\b((?:OpenSSH|Sun_SSH|dropbear)[\w.\-]*)(?:[, ]+((?:LibreSSL|OpenSSL) [\w.\-]+))?", re.I)
|
||||
|
||||
|
||||
def ssh_version(path):
|
||||
"""`ssh -V`'s first line (it prints to stderr), asked once per run."""
|
||||
if path not in _ssh_versions:
|
||||
try:
|
||||
r = frame_host.run_ssh([path, "-V"], capture_output=True, stdin=subprocess.DEVNULL, text=True,
|
||||
errors="replace", timeout=5)
|
||||
lines = ((r.stderr or "") + (r.stdout or "")).strip().splitlines()
|
||||
_ssh_versions[path] = lines[0][:120] if lines else f"no version (exit {r.returncode})"
|
||||
except (OSError, subprocess.SubprocessError) as e:
|
||||
_ssh_versions[path] = f"couldn't run it ({type(e).__name__})"
|
||||
return _ssh_versions[path]
|
||||
"""The version words of `ssh -V` (it prints to stderr), nothing else it says."""
|
||||
try:
|
||||
r = frame_host.run_ssh([path, "-V"], capture_output=True, stdin=subprocess.DEVNULL, text=True,
|
||||
errors="replace", timeout=5)
|
||||
except (OSError, subprocess.SubprocessError) as e:
|
||||
return f"couldn't run it ({type(e).__name__})"
|
||||
m = VERSION_RE.search((r.stderr or "") + " " + (r.stdout or ""))
|
||||
return ", ".join(g for g in m.groups() if g) if m else f"unrecognised version (exit {r.returncode})"
|
||||
|
||||
|
||||
def ssh_line():
|
||||
def _ssh_check():
|
||||
path = shutil.which("ssh")
|
||||
if not path:
|
||||
return "SSH: no ssh on PATH"
|
||||
@@ -121,6 +122,32 @@ def ssh_line():
|
||||
return f"SSH: {ssh_path_kind(path)}, {ssh_version(path)}" + (f"; also on PATH: {', '.join(others)}" if others else "")
|
||||
|
||||
|
||||
_ssh = {"thread": None, "line": None}
|
||||
_ssh_lock = threading.Lock()
|
||||
SSH_WAIT = 0.3 # how long a report preview waits for the ssh check (PATH can hold slow network drives)
|
||||
|
||||
|
||||
def start_ssh_check():
|
||||
"""Look for ssh once, in the background (server.main starts it), so a report never waits
|
||||
on PATH folders on slow or mapped drives."""
|
||||
def run():
|
||||
try:
|
||||
line = _ssh_check()
|
||||
except Exception as e: # a report must still go out
|
||||
line = f"SSH: couldn't check ({type(e).__name__})"
|
||||
_ssh["line"] = line
|
||||
with _ssh_lock:
|
||||
if _ssh["thread"] is None:
|
||||
_ssh["thread"] = threading.Thread(target=run, name="report-ssh-check", daemon=True)
|
||||
_ssh["thread"].start()
|
||||
return _ssh["thread"]
|
||||
|
||||
|
||||
def ssh_line():
|
||||
start_ssh_check().join(SSH_WAIT)
|
||||
return _ssh["line"] or "SSH: still being checked"
|
||||
|
||||
|
||||
def config_line(alias):
|
||||
"""Whether ~/.ssh/config has the managed block for the alias, and a hand-written Host for it."""
|
||||
try:
|
||||
@@ -146,23 +173,13 @@ def config_line(alias):
|
||||
|
||||
|
||||
def connection_lines():
|
||||
"""A short summary of the connector: kinds of addresses and states, never the addresses."""
|
||||
"""A short summary of the connector in fixed words only: states, stages, error categories,
|
||||
kinds of address, counts. No text from errors or ssh, and never an address."""
|
||||
if link is None:
|
||||
return ["Connection: no connector (this server doesn't reach a headset over SSH)"]
|
||||
snap = link.snapshot()
|
||||
active = link.active_device()
|
||||
alias = active.get("alias") or "?"
|
||||
hosts = [a.get("host") for a in active.get("addresses") or ()] + [active.get("frozen_host")]
|
||||
hosts += [r.get(k) for r in snap.get("probes") or () for k in ("host", "ip")]
|
||||
hosts += [(snap.get("via") or {}).get(k) for k in ("host", "ip")]
|
||||
|
||||
def hide(text):
|
||||
return frame_link.hide_hosts(str(text or ""), hosts, keep=(alias,))
|
||||
|
||||
def ssh_said(raw, message):
|
||||
last = [ln.strip() for ln in (raw or "").splitlines() if ln.strip()][-1:]
|
||||
return f" | ssh said: {hide(last[0])[:300]}" if last and last[0] != message else ""
|
||||
|
||||
phase, err, via = snap.get("phase") or "idle", snap.get("error"), snap.get("via")
|
||||
head = f"Connection: {phase}"
|
||||
if phase == "connected" and via:
|
||||
@@ -176,12 +193,11 @@ def connection_lines():
|
||||
else f"saved, {len(active.get('addresses') or [])} address(es)")
|
||||
lines.append(f"Headsets: {len(link.reg.devices())} saved; active \"{alias}\" ({kind})")
|
||||
if err:
|
||||
lines.append(f"Error: {hide(err.get('message'))}{ssh_said(err.get('raw'), err.get('message'))}")
|
||||
lines.append(f"Error: {err.get('stage')}, {frame_link.failure_category(err.get('message'), err.get('raw'))}")
|
||||
last = link.last_failure
|
||||
if last and (not err or last.get("message") != err.get("message")):
|
||||
if last:
|
||||
ago = max(0, int(frame_link.now() - last.get("at", 0)))
|
||||
lines.append(f"Last failure ({last.get('stage')}, {ago // 60} min {ago % 60} s ago): "
|
||||
f"{hide(last.get('message'))}{ssh_said(last.get('raw'), last.get('message'))}")
|
||||
lines.append(f"Last failure: {last.get('stage')}, {last.get('category')}, {ago // 60} min {ago % 60} s ago")
|
||||
lines.append(f"Addresses tried: {frame_link.probes_summary(snap.get('probes')) or 'none yet'}")
|
||||
net = snap.get("network")
|
||||
if net:
|
||||
|
||||
@@ -229,9 +229,15 @@ def scrub(text, limit=2000):
|
||||
home = str(Path.home())
|
||||
if len(home) > 3:
|
||||
t = t.replace(home, '~')
|
||||
t = re.sub(r'(/Users/|/home/|[A-Za-z]:\\Users\\)[^/\\\s]+', r'\1<user>', t)
|
||||
t = re.sub(r'(/Users/|/home/)[^/\\\s]+', r'\1<user>', t)
|
||||
# A Windows home folder's whole name, spaces and all ("C:\Users\Jane Doe\..."), up to the next separator.
|
||||
t = re.sub(r'''([A-Za-z]:[\\/]+Users[\\/]+)[^\\/\n'"]+''', r'\1<user>', t)
|
||||
for pattern, repl in SCRUBS:
|
||||
t = pattern.sub(repl, t)
|
||||
# ssh's "user@host: ..." and "user@host's password": the whole user part, even "Jane Doe" or
|
||||
# DOMAIN\user, when it starts a line or follows ": " or "| "; then any other word@host.
|
||||
t = re.sub(r'''(?m)(?:^|(?<=: )|(?<=\| ))[^@\n:|'"<]{1,64}@(?=[\w.\[\]%<>-]+(?::|'s\s))''', '<user>@', t)
|
||||
t = re.sub(r'(?<![\w.+\\<-])[\w.+\\-]+@(?=[A-Za-z\[<])', '<user>@', t)
|
||||
t = IPV6_RE.sub(_ipv6, t)
|
||||
for name in _user_names():
|
||||
t = re.sub(r'\b%s\b' % re.escape(name), '<user>', t)
|
||||
|
||||
+1
-1
@@ -1272,7 +1272,7 @@
|
||||
<label class="field">Your email address<input type="email" id="bugContact" maxlength="254" placeholder="you@example.com" disabled></label>
|
||||
<p class="hint" id="bugReplaces" role="status" hidden></p>
|
||||
<label class="popt"><input type="checkbox" id="bugDiag" checked><b>Include diagnostics</b>
|
||||
<span class="sub">Frame Control's version, your OS, the Frame's SteamOS build, and a connection summary: how connecting went, the kinds of address tried, your ssh version and whether ~/.ssh/config has the headset's entry. Never the addresses themselves.</span></label>
|
||||
<span class="sub">Frame Control's version, your OS, the Frame's SteamOS build, and a connection summary in fixed words: how connecting went, the kinds of address tried, your ssh version and whether ~/.ssh/config has the headset's entry. No error text, and never the addresses themselves.</span></label>
|
||||
<label class="popt"><input type="checkbox" id="bugLogs"><b>Also include recent activity and the server log</b>
|
||||
<span class="sub">Often shows what went wrong, but can contain file and app names. Check it below before sending.</span></label>
|
||||
<details id="bugDiagBox"><summary>Show exactly what's included</summary><div class="sentlog" id="bugDiagText">Loading…</div></details>
|
||||
|
||||
@@ -2711,6 +2711,7 @@ def main():
|
||||
mux_base=MUX_BASE, control=CONTROL, apply=route, explain=unreachable)
|
||||
LINK.work_lock, LINK.work = _work_lock, lambda: _work[0]
|
||||
frame_report.link = LINK # its connection summary goes in every report's diagnostics
|
||||
frame_report.start_ssh_check() # ...with which ssh this is, found once in the background
|
||||
LINK.start()
|
||||
if not frame_host.WINDOWS:
|
||||
signal.signal(signal.SIGTERM, lambda *_: (_ for _ in ()).throw(KeyboardInterrupt))
|
||||
|
||||
Reference in new issue
Block a user