Files
lemana-vpn/tests/logging.py
T

177 lines
8.9 KiB
Python

#!/usr/bin/env python3
"""Filesystem and closed-input regressions; no VPN, Keychain, or GUI."""
import json
import os
from pathlib import Path
import subprocess
import tempfile
ROOT = Path(__file__).resolve().parents[1]
RUNTIME = Path(os.environ.get("LEMANA_TEST_RUNTIME", ROOT / "bin/vpn-lemanapro.sh"))
SOURCE = RUNTIME.read_text()
def function(name):
start = SOURCE.index(name + "() {")
return SOURCE[start:SOURCE.index("\n}\n", start) + 3]
def shell(code, env, stdin="", timeout=5):
return subprocess.run(["/bin/bash", "-c", code], input=stdin, text=True,
capture_output=True, env=env, timeout=timeout)
with tempfile.TemporaryDirectory(prefix="lemana-logging-") as tmp:
home = Path(tmp)
env = {k: v for k, v in os.environ.items()
if not k.startswith(("LEMANA_VPN_", "OPENCONNECT_LITE_"))}
env.update(HOME=tmp, LEMANA_VPN_CONFIG_DIR=str(home / "config"),
LEMANA_VPN_STATUS_DIR=str(home / "state"))
# EOF must differ from an intentional empty Enter, even in a conditional caller.
prompts = "\n".join(function(n) for n in (
"_emit", "_prompt_read", "_ensure_username", "_configure_login", "_configure_keychain", "_bw_unlock"))
setup = '''
set -eu
JSON_MODE=true
KC_USERNAME=''
CACHE_BW_SESSION=0
USE_TOUCHID=0
LOCAL_OTP=0
USE_BITWARDEN=1
_can_prompt() { return 0; }
_tty_available() { return 1; }
_keychain_has() { return 0; }
_persist_username() { echo unexpected-write; }
_store_keychain() { echo unexpected-write; }
_bw_cache_session() { :; }
bw() { case "$1" in status) echo '{"status":"locked"}';; unlock) echo fake-session;; esac; }
'''
for call in ("_ensure_username", "_configure_login", "_configure_keychain", "_bw_unlock"):
result = shell(prompts + setup + f"\nif {call}; then exit 99; else exit 7; fi", env)
assert result.returncode == 7, (call, result.stdout, result.stderr)
assert "unexpected-write" not in result.stdout
assert len(result.stderr) < 500, (call, result.stderr)
result = shell(prompts + setup + '\nif _configure_keychain; then exit 99; else exit 7; fi', env, "fake-password\n")
assert result.returncode == 7 and "unexpected-write" not in result.stdout, result.stderr
result = shell(prompts + setup + '\nvalue_out=x; _prompt_read value_out ""; test -z "$value_out"', env, "\n")
assert result.returncode == 0, result.stderr
helper = home / "fingerprint"
helper.write_text('#!/bin/sh\n[ "$1" != set ] || echo unexpected-write >> "$HOME/secret-write"\n')
helper.chmod(0o755)
result = shell(prompts + setup + f'\nUSE_TOUCHID=1; KC_FP="{helper}"; BW_KC_SERVICE=fake; BW_KC_ACCOUNT_MASTER=fake\n'
'if _bw_unlock; then exit 99; else exit 7; fi', env, "fake-password\n")
assert result.returncode == 7, result.stderr
assert not (home / "secret-write").exists(), "EOF consent must not save a password"
print("closed input: username/password/2FA/Bitwarden/save consent exit without persistence; empty Enter unchanged")
log = home / "nested" / "client.log"
log.parent.mkdir()
log.write_bytes(b"legacy" * 10000)
log.chmod(0o644)
log_functions = "\n".join(function(n) for n in (
"_append_connection_log", "_log_connection_line", "_prepare_connection_log", "_parse_expiry", "_valid_ipv4", "_publish_connection", "_filter_output"))
log_setup = f'\nCONNECT_LOG_FILE="{log}"; LOG_MAX_BYTES=256; _connection_log_failed=false; OC_BIN=fake\n'
result = shell(log_functions + log_setup + '''
_prepare_connection_log
for ((i=0; i<80; i++)); do _log_connection_line "record-$i: Привет"; done
_log_connection_line "$(printf '%02000d' 1)"
_log_connection_line newest
''', env)
assert result.returncode == 0, result.stderr
for p in (log, Path(str(log) + ".1")):
assert p.stat().st_size <= 256, (p, p.stat().st_size)
assert p.stat().st_mode & 0o777 == 0o600, p
assert log.read_bytes().endswith(b"newest\n")
assert len(list(log.parent.iterdir())) == 2
# A new process with a lower setting also bounds the previous archive.
result = shell(log_functions + log_setup + 'LOG_MAX_BYTES=64; _log_connection_line reduced', env)
assert result.returncode == 0, result.stderr
assert all(p.stat().st_size <= 64 for p in log.parent.iterdir())
# Logging failure cannot stop the output consumer, and warns only once.
result = shell(log_functions + log_setup + f'CONNECT_LOG_FILE="{log}/invalid"\n' + '''
DEBUG=true; JSON_MODE=false
printf 'first\nsecond\n' | _filter_output
''', env)
assert result.returncode == 0, result.stderr
assert result.stdout == "first\nsecond\n", result.stdout
assert result.stderr.count("Cannot write VPN log") == 1, result.stderr
result = shell(function("_emit") + log_functions + log_setup + f'CONNECT_LOG_FILE="{log}/invalid"\n' + '''
set -euo pipefail
DEBUG=false; JSON_MODE=true
scutil() { :; }
_write_status() { :; }
_stop_connect_progress() { :; }
printf 'Configured as 10.2.3.4\nSession authentication will expire at invalid-date\n' | _filter_output
''', env)
assert result.returncode == 0, result.stderr
connected = json.loads(result.stdout)
assert connected.pop("started_at")
assert connected == {"event": "connected", "ip": "10.2.3.4", "expires": "", "remaining_sec": 0, "attempt_id": ""}
print("CLI log: legacy + repeated + oversized writes <= 256 bytes per file; newest kept; I/O failure preserves output")
config = home / "config"
config.mkdir()
config.joinpath("env").write_text('LEMANA_VPN_LOG_MAX_BYTES="384"\nLEMANA_VPN_BW_ITEM=\'Corporate "VPN" & / office\'\n')
status = subprocess.run(["bash", str(RUNTIME), "--status", "--json"], env=env,
text=True, capture_output=True, check=True)
modules = json.loads(status.stdout)["modules"]
assert modules["logging"]["max_bytes"] == 384
assert modules["bitwarden"]["item"] == 'Corporate "VPN" & / office'
home.joinpath("status.json").write_text(status.stdout)
for limit in ("", "0", "-1", "abc", "1000000000"):
result = subprocess.run(["bash", str(RUNTIME), "--status"], env=dict(env, LEMANA_VPN_LOG_MAX_BYTES=limit),
text=True, capture_output=True)
assert result.returncode == 2, (limit, result.stdout, result.stderr)
result = subprocess.run(["bash", str(RUNTIME), "--statuz", "--status"], env=env,
text=True, capture_output=True)
assert result.returncode == 2 and "Unknown argument" in result.stderr
assert not (home / "state").exists()
print("CLI settings: saved limit and quoted item round-trip; malformed limits and unknown flags rejected")
# Compile the actual Foundation logger and actual status types, without starting the app.
manager_source = (ROOT / "app/Sources/LemanaVPN/VPNManager.swift").read_text()
types = manager_source.split("enum VPNState:")[0]
types += manager_source[manager_source.index("enum VPNLaunchMode:"):manager_source.index("struct VPNLineBuffer")]
home.joinpath("Status.swift").write_text(types)
home.joinpath("main.swift").write_text(r'''
import Foundation
let dir = URL(fileURLWithPath: CommandLine.arguments[1])
let response = try JSONDecoder().decode(VPNStatusResponse.self, from: Data(contentsOf: dir.appendingPathComponent("status.json")))
let url = dir.appendingPathComponent("swift/app.log")
var log = BoundedLog(url: url)
precondition(log.maxBytes == 5242880)
log.maxBytes = response.modules!.logging!.max_bytes
precondition(log.maxBytes == 384)
try FileManager.default.createDirectory(at: url.deletingLastPathComponent(), withIntermediateDirectories: true)
try Data(repeating: 65, count: 100_000).write(to: url)
for i in 0..<80 { try log.append("record-\(i): Привет\n") }
try log.append(String(repeating: "Ж", count: 2000) + "\n")
try log.append("newest\n")
for path in [url, url.appendingPathExtension("1")] {
let attrs = try FileManager.default.attributesOfItem(atPath: path.path)
precondition((attrs[.size] as! NSNumber).intValue <= 384)
precondition((attrs[.posixPermissions] as! NSNumber).intValue == 0o600)
}
let latest = try String(contentsOf: url, encoding: .utf8)
precondition(latest.hasSuffix("newest\n"))
log.maxBytes = 64
try log.append("reduced\n")
for path in [url, url.appendingPathExtension("1")] {
let bytes = try Data(contentsOf: path)
precondition(bytes.count <= 64)
}
do {
try BoundedLog(url: url.appendingPathComponent("invalid")).append("failed\n")
fatalError("Expected I/O failure")
} catch {}
print("Swift log: decoded CLI limit; legacy/repeated/oversized writes bounded; newest retained; I/O errors throwable")
''')
binary = home / "log-check"
subprocess.run(["swiftc", "-module-cache-path", str(ROOT / "app/.build/log-test-module-cache"),
str(ROOT / "app/Sources/LemanaVPN/BoundedLog.swift"),
str(home / "Status.swift"), str(home / "main.swift"), "-o", str(binary)], check=True)
subprocess.run([str(binary), tmp], check=True)
print("logging checks ok")