diff --git a/tools/test_webui.py b/tools/test_webui.py index 23ac1a1..e531584 100644 --- a/tools/test_webui.py +++ b/tools/test_webui.py @@ -607,5 +607,73 @@ class TestIdleKeepalive(unittest.TestCase): self.assertGreater(webui.IDLE_FRAME_INTERVAL_S, 1.0 / webui.TARGET_FPS) +class TestClientIpInLogs(unittest.TestCase): + """Entries carry the client IP, so a shared log says who did what.""" + + def test_key_entry_records_the_client_ip(self): + client, sup, http = make_supervised() + log = http.application.config["LOG"] + http.post("/api/key", json={"key": "MENU", "hold_ms": 60}, + environ_overrides={"REMOTE_ADDR": "172.21.91.137"}) + entries = [e for e in log.entries() if e["source"] == "key"] + self.assertTrue(entries) + self.assertEqual(entries[-1]["ip"], "172.21.91.137") + + def test_power_entry_records_the_client_ip(self): + client, sup, http = make_supervised() + log = http.application.config["LOG"] + http.post("/api/power/reset", + environ_overrides={"REMOTE_ADDR": "172.21.91.137"}) + entries = [e for e in log.entries() if e["source"] == "power"] + self.assertTrue(entries) + self.assertEqual(entries[-1]["ip"], "172.21.91.137") + + def test_ipv6_is_recorded(self): + client, sup, http = make_supervised() + log = http.application.config["LOG"] + http.post("/api/key", json={"key": "UP", "hold_ms": 60}, + environ_overrides={"REMOTE_ADDR": "fd3c:3f9b:6424:2::99"}) + entries = [e for e in log.entries() if e["source"] == "key"] + self.assertEqual(entries[-1]["ip"], "fd3c:3f9b:6424:2::99") + + def test_x_forwarded_for_is_preferred_behind_a_proxy(self): + """nginx reverse-proxies this, so REMOTE_ADDR is always 127.0.0.1.""" + client, sup, http = make_supervised() + log = http.application.config["LOG"] + http.post("/api/key", json={"key": "UP", "hold_ms": 60}, + environ_overrides={"REMOTE_ADDR": "127.0.0.1", + "HTTP_X_FORWARDED_FOR": "172.21.91.137"}) + entries = [e for e in log.entries() if e["source"] == "key"] + self.assertEqual(entries[-1]["ip"], "172.21.91.137") + + def test_only_the_first_hop_of_x_forwarded_for_is_used(self): + """The rest of the chain is attacker-controlled and must be ignored.""" + client, sup, http = make_supervised() + log = http.application.config["LOG"] + http.post("/api/key", json={"key": "UP", "hold_ms": 60}, + environ_overrides={ + "REMOTE_ADDR": "127.0.0.1", + "HTTP_X_FORWARDED_FOR": "172.21.91.137, 10.0.0.1"}) + entries = [e for e in log.entries() if e["source"] == "key"] + self.assertEqual(entries[-1]["ip"], "172.21.91.137") + + def test_entries_without_a_request_have_no_ip(self): + """Firmware serial and qemu output come from no client at all.""" + from uvk5_logs import LogBuffer + log = LogBuffer() + log.add("serial", "boot banner") + self.assertIsNone(log.entries()[-1]["ip"]) + + def test_page_renders_the_ip_between_time_and_source(self): + _, http = make_app() + body = http.get("/").get_data(as_text=True) + # e.time + ip + source, in that order + line = [l for l in body.splitlines() if "e.source" in l and "e.time" in l] + self.assertTrue(line, "log line template not found") + tmpl = line[0] + self.assertLess(tmpl.index("e.time"), tmpl.index("ip")) + self.assertLess(tmpl.index("ip"), tmpl.index("e.source")) + + if __name__ == "__main__": unittest.main() diff --git a/tools/uvk5_logs.py b/tools/uvk5_logs.py index 1e24ffd..320a491 100644 --- a/tools/uvk5_logs.py +++ b/tools/uvk5_logs.py @@ -22,12 +22,19 @@ class LogBuffer: self._lock = threading.Lock() self._seq = 0 - def add(self, source: str, text: str): + def add(self, source: str, text: str, ip: str = None): + """Record one line. `ip` identifies the client that caused it. + + The buffer is shared by every viewer, so without an attributed IP a log of + keypresses from two people is unreadable. Entries with no client behind + them -- firmware serial, QEMU stderr -- carry None. + """ with self._lock: self._seq += 1 self._entries.append({ "seq": self._seq, "time": time.strftime("%H:%M:%S"), + "ip": ip, "source": source, "text": text, }) diff --git a/tools/webui.py b/tools/webui.py index 925d26b..0654ff2 100644 --- a/tools/webui.py +++ b/tools/webui.py @@ -124,6 +124,20 @@ def create_app(client, frame_addr: int, status_addr: int, scale: int = 4, app.config["PUMP"] = pump app.config["SUPERVISOR"] = supervisor + def client_ip(): + """The address of whoever made this request. + + Behind the nginx reverse proxy REMOTE_ADDR is always 127.0.0.1, so the + first hop of X-Forwarded-For is what identifies the real client. Only the + first entry is trusted: the rest of the chain can be set by the caller. + """ + forwarded = request.headers.get("X-Forwarded-For", "") + if forwarded: + first = forwarded.split(",")[0].strip() + if first: + return first + return request.remote_addr + def active_client(): """The live QMP client, or None when the emulator is off. @@ -179,6 +193,10 @@ def create_app(client, frame_addr: int, status_addr: int, scale: int = 4, "so it will not stop it. Restart without --attach to " "manage the process here."), 409 + # Attribute the action here: the supervisor has no request context, and on + # a shared log "who powered it off" is the useful part. + log.add("power", f"{action} requested", ip=client_ip()) + {"on": supervisor.power_on, "off": supervisor.power_off, "reset": supervisor.reset, @@ -200,7 +218,8 @@ def create_app(client, frame_addr: int, status_addr: int, scale: int = 4, if not is_valid(key): # Log refusals too: a silently dropped key is indistinguishable from # a dead button in the browser. - log.add("key", f"{body.get('key')!r} rejected: not a key on this model") + log.add("key", f"{body.get('key')!r} rejected: not a key on this model", + ip=client_ip()) return jsonify(error=f"unknown key {body.get('key')!r}", valid=list(KEYS)), 400 if action not in ("down", "up", "tap"): @@ -222,10 +241,10 @@ def create_app(client, frame_addr: int, status_addr: int, scale: int = 4, try: if action == "down": - log.add("key", f"{key} down") + log.add("key", f"{key} down", ip=client_ip()) set_press(key) elif action == "up": - log.add("key", f"{key} up") + log.add("key", f"{key} up", ip=client_ip()) set_press("") else: # Label by what the FIRMWARE will conclude, so the log says what @@ -233,14 +252,14 @@ def create_app(client, frame_addr: int, status_addr: int, scale: int = 4, # not the UI's hold threshold -- conflating the two is what caused # the tap+held double send in the first place. kind = "held" if hold_ms >= FIRMWARE_HELD_MS else "tap" - log.add("key", f"{key} {kind} {hold_ms}ms") + log.add("key", f"{key} {kind} {hold_ms}ms", ip=client_ip()) # Hold here, locally. See the note on TAP_MS: doing this as two # requests puts the network round trip inside the press duration. set_press(key) time.sleep(hold_ms / 1000) set_press("") except LookupError: - log.add("key", f"{key} ignored: emulator is off") + log.add("key", f"{key} ignored: emulator is off", ip=client_ip()) return jsonify(error="emulator is off; press On first"), 409 return jsonify(ok=True, key=key, action=action, hold_ms=hold_ms) @@ -548,7 +567,13 @@ async function pollLogs() {{ pre.scrollHeight - pre.scrollTop - pre.clientHeight < 24; for (const e of j.entries) {{ - pre.textContent += e.time + ' [' + e.source + '] ' + e.text + '\\n'; + // IP sits between the time and the source. The log is shared by everyone + // who opens the page, so attribution is what makes it readable when two + // people are pressing keys. Entries with no client behind them -- firmware + // serial, qemu output -- show a dash. + const ip = e.ip ? e.ip : '-'; + pre.textContent += e.time + ' ' + ip + ' [' + e.source + '] ' + + e.text + '\\n'; }} const lines = pre.textContent.split('\\n'); if (lines.length > MAX_LOG_LINES) {{