A read_log tool and six MCP resources over the log and the catalogue
read_log fetches the live log over FTP and filters by tag, severity and message before it returns anything, because half an hour of uptime is five thousand entries. It excludes shp_usbmode by default, a five-second USB poll that can be a third of the log, and says in the result that it did so. Only the current file is reachable: the archives the drone rotates into are a previous owner's sessions and carry network and location data, which is a decision for a person, not a tool. bebop://commands is the resource worth having, because it needs no drone: the whole catalogue is readable with the aircraft switched off. The ones that do need a link return an explanation rather than raising, since a resource that errors looks broken while one that explains itself is empty for a reason. bebop://state also reports telemetry age, because the aircraft accepts a second controller and silently redirects telemetry to it, so a connected flag proves nothing. The log says nothing resolvable about ARSDK, measured rather than assumed: no command ids appear anywhere in it, and the COMMANDS function names match arsdk-xml for 4 of 11 symbols, 3.5% of the tag. So nothing here resolves them, and read_log says where to look instead. _host moves into tools/_common as drone_host now that three tool modules need it, and head/tail in the shell allow-list gains the reason they must take a file argument: ld.so.preload makes SIGPIPE fatal, so a pipe into head writes a crash report to the aircraft's flash.
This commit is contained in:
@@ -0,0 +1,159 @@
|
||||
"""`read_log`: the filters, the defaults, and what it says about a live log.
|
||||
|
||||
The log is built here from the ulogcat format rather than fetched, so none of
|
||||
this touches the aircraft or the captured file.
|
||||
"""
|
||||
|
||||
import pytest
|
||||
from fastmcp import Client
|
||||
from test_ulog import entry
|
||||
|
||||
from mcbebop.config import Settings
|
||||
from mcbebop.server import build_server
|
||||
from mcbebop.tools import _common, logs
|
||||
|
||||
|
||||
def synthetic_log() -> bytes:
|
||||
return b"".join(
|
||||
[
|
||||
entry("Booting Linux on physical CPU 0", tag="KERNEL", uptime_us=0),
|
||||
entry("AM I HOST mode for 5 s", tag="shp_usbmode", uptime_us=1_000_000),
|
||||
entry("AM I HOST mode for 5 s", tag="shp_usbmode", uptime_us=6_000_000),
|
||||
entry("Cmd Tx : battery level <62%>", tag="COMMANDS", uptime_us=10_000_000),
|
||||
entry("Magneto calibration state (1-required) : 0", tag="COMMANDS", uptime_us=11_000_000),
|
||||
entry("eth0: no IPv6 routers present", tag="KERNEL", priority="W", uptime_us=12_000_000),
|
||||
entry("fileOpen: error: cannot open file", tag="colibry", priority="E", uptime_us=13_000_000),
|
||||
]
|
||||
)
|
||||
|
||||
|
||||
def records():
|
||||
from mcbebop.files import ulog
|
||||
|
||||
return list(ulog.parse(synthetic_log()))
|
||||
|
||||
|
||||
# --- the filters, without a server ------------------------------------------
|
||||
|
||||
|
||||
def test_a_tag_filter_is_exact_and_case_insensitive():
|
||||
kept, matched = logs.select(records(), tag="kernel")
|
||||
assert matched == 2
|
||||
assert {r.tag for r in kept} == {"KERNEL"}
|
||||
|
||||
|
||||
def test_a_substring_is_a_valid_regex_and_behaves_like_one():
|
||||
kept, _ = logs.select(records(), match="battery")
|
||||
assert [r.tag for r in kept] == ["COMMANDS"]
|
||||
|
||||
|
||||
def test_a_broken_regex_says_it_was_read_as_a_regex():
|
||||
from fastmcp.exceptions import ToolError
|
||||
|
||||
with pytest.raises(ToolError, match="regular expression"):
|
||||
logs.select(records(), match="unclosed (")
|
||||
|
||||
|
||||
def test_a_severity_filter_keeps_that_level_and_worse():
|
||||
kept, _ = logs.select(records(), min_level="warning")
|
||||
assert [r.level for r in kept] == ["warning", "error"]
|
||||
kept, _ = logs.select(records(), min_level="error")
|
||||
assert [r.level for r in kept] == ["error"]
|
||||
|
||||
|
||||
def test_the_limit_takes_the_newest_matches_not_the_first():
|
||||
kept, matched = logs.select(records(), limit=2)
|
||||
assert matched == 7
|
||||
assert [r.uptime_us for r in kept] == [12_000_000, 13_000_000]
|
||||
|
||||
|
||||
def test_the_noisy_poll_is_excluded_by_default_and_can_be_asked_for():
|
||||
assert "shp_usbmode" in logs.NOISY_TAGS
|
||||
kept, _ = logs.select(records(), exclude_tags=logs.NOISY_TAGS)
|
||||
assert "shp_usbmode" not in {r.tag for r in kept}
|
||||
kept, _ = logs.select(records(), exclude_tags=[])
|
||||
assert "shp_usbmode" in {r.tag for r in kept}
|
||||
|
||||
|
||||
def test_naming_a_tag_explicitly_beats_the_default_exclusion():
|
||||
# Asking for a tag by name and getting nothing because a default hid it
|
||||
# would be the worst kind of helpful.
|
||||
kept, matched = logs.select(records(), tag="shp_usbmode", exclude_tags=logs.NOISY_TAGS)
|
||||
assert matched == 2
|
||||
assert {r.tag for r in kept} == {"shp_usbmode"}
|
||||
|
||||
|
||||
# --- through the server -----------------------------------------------------
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
def served(monkeypatch, tmp_path):
|
||||
"""A server whose FTP fetch hands back a synthetic log."""
|
||||
log = tmp_path / "ckcm.bin"
|
||||
log.write_bytes(synthetic_log())
|
||||
asked: dict = {}
|
||||
|
||||
def fake_fetch(area, path, *, host, capture_dir, max_bytes=0, timeout=0.0):
|
||||
asked.update(area=area, path=path, host=host)
|
||||
return log
|
||||
|
||||
monkeypatch.setattr("mcbebop.files.ftp.fetch", fake_fetch)
|
||||
return build_server(Settings(capture_dir=tmp_path)), asked
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
async def client(served):
|
||||
server, asked = served
|
||||
async with Client(server) as c:
|
||||
# No connect(): the log comes off the aircraft's FTP server, which
|
||||
# answers whether or not a command session is open.
|
||||
_common.app().target = "192.0.2.1"
|
||||
yield c, asked
|
||||
|
||||
|
||||
async def test_read_log_fetches_from_the_log_area_and_returns_parsed_entries(client):
|
||||
c, asked = client
|
||||
result = await c.call_tool("read_log", {})
|
||||
body = result.structured_content
|
||||
assert asked == {"area": logs.LOG_AREA, "path": logs.LOG_PATH, "host": "192.0.2.1"}
|
||||
assert body["parsed"] == 7
|
||||
assert body["returned"] == 5, "the usb poll should be excluded by default"
|
||||
assert body["entries"][0]["message"].startswith("fileOpen"), "newest first by default"
|
||||
assert body["tags"]["KERNEL"] == 2
|
||||
|
||||
|
||||
async def test_read_log_reports_which_tags_it_hid(client):
|
||||
c, _ = client
|
||||
body = (await c.call_tool("read_log", {})).structured_content
|
||||
assert "shp_usbmode" in body["note"]
|
||||
assert "exclude_tags=[]" in body["note"]
|
||||
|
||||
|
||||
async def test_read_log_can_order_oldest_first_while_still_taking_the_newest(client):
|
||||
c, _ = client
|
||||
body = (await c.call_tool("read_log", {"limit": 2, "newest_first": False})).structured_content
|
||||
assert [e["uptime"] for e in body["entries"]] == [12.0, 13.0]
|
||||
|
||||
|
||||
async def test_the_whole_file_tag_census_survives_the_filters(client):
|
||||
c, _ = client
|
||||
body = (await c.call_tool("read_log", {"tag": "colibry"})).structured_content
|
||||
assert body["matched"] == 1
|
||||
assert body["parsed"] == 7, "parsed counts the file, not the filter"
|
||||
assert set(body["tags"]) == {"KERNEL", "shp_usbmode", "COMMANDS", "colibry"}
|
||||
|
||||
|
||||
async def test_an_absent_tag_says_which_tags_are_present(client):
|
||||
c, _ = client
|
||||
body = (await c.call_tool("read_log", {"tag": "NETMON"})).structured_content
|
||||
assert body["returned"] == 0
|
||||
assert "NETMON" in body["note"] and "KERNEL" in body["note"]
|
||||
|
||||
|
||||
async def test_the_log_is_not_reachable_on_the_simulator(client):
|
||||
from fastmcp.exceptions import ToolError
|
||||
|
||||
c, _ = client
|
||||
_common.app().target = "sim"
|
||||
with pytest.raises(ToolError, match="simulator"):
|
||||
await c.call_tool("read_log", {})
|
||||
@@ -0,0 +1,198 @@
|
||||
"""The MCP resources, driven through a real client.
|
||||
|
||||
The point of the split under test here is that the command catalogue needs no
|
||||
aircraft while everything else does, and that the ones that do degrade into an
|
||||
explanation rather than an exception.
|
||||
"""
|
||||
|
||||
import json
|
||||
|
||||
import pytest
|
||||
from fastmcp import Client
|
||||
from test_ulog import entry
|
||||
|
||||
from mcbebop.config import Settings
|
||||
from mcbebop.protocol import xml_index
|
||||
from mcbebop.server import build_server
|
||||
from mcbebop.tools import _common, logs
|
||||
|
||||
|
||||
def body(result) -> dict:
|
||||
return json.loads(result[0].text)
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
async def client():
|
||||
async with Client(build_server()) as c:
|
||||
yield c
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
async def connected(client):
|
||||
await client.call_tool("connect", {"target": "sim"})
|
||||
yield client
|
||||
await client.call_tool("disconnect", {})
|
||||
|
||||
|
||||
# --- what is registered ------------------------------------------------------
|
||||
|
||||
|
||||
async def test_the_static_resources_are_registered(client):
|
||||
uris = {str(r.uri) for r in await client.list_resources()}
|
||||
assert uris == {"bebop://commands", "bebop://state"}
|
||||
|
||||
|
||||
async def test_the_templated_resources_are_registered(client):
|
||||
uris = {t.uri_template for t in await client.list_resource_templates()}
|
||||
assert uris == {
|
||||
"bebop://commands/{name}",
|
||||
"bebop://state/{key}",
|
||||
"bebop://files/{area}",
|
||||
"bebop://log/{tag}",
|
||||
}
|
||||
|
||||
|
||||
# --- the catalogue, which needs no drone -------------------------------------
|
||||
|
||||
|
||||
async def test_the_whole_catalogue_reads_without_a_drone(client):
|
||||
data = body(await client.read_resource("bebop://commands"))
|
||||
assert data["count"] == len(xml_index.all_commands())
|
||||
names = {c["name"] for c in data["commands"]}
|
||||
assert "ardrone3.Piloting.TakeOff" in names
|
||||
assert all({"tier", "direction", "bebop2"} <= set(c) for c in data["commands"])
|
||||
|
||||
|
||||
async def test_one_command_reads_in_full_with_its_dotted_name(client):
|
||||
data = body(await client.read_resource("bebop://commands/ardrone3.Camera.OrientationV2"))
|
||||
assert data["name"] == "ardrone3.Camera.OrientationV2"
|
||||
assert [a["name"] for a in data["args"]] == ["tilt", "pan"]
|
||||
assert data["ids"] and data["buffer"]
|
||||
|
||||
|
||||
async def test_an_enum_argument_arrives_with_its_allowed_names(client):
|
||||
# Without these a caller has to guess at the string an argument accepts,
|
||||
# which is the main reason to read a command rather than send and see.
|
||||
data = body(await client.read_resource("bebop://commands/common.Mavlink.Start"))
|
||||
(arg,) = [a for a in data["args"] if a["name"] == "type"]
|
||||
assert arg["enum_values"] == ["flightPlan", "mapMyHouse"]
|
||||
|
||||
|
||||
async def test_an_unknown_command_suggests_rather_than_failing(client):
|
||||
data = body(await client.read_resource("bebop://commands/ardrone3.Piloting.Takeof"))
|
||||
assert data["available"] is False
|
||||
assert "ardrone3.Piloting.TakeOff" in data["did_you_mean"]
|
||||
|
||||
|
||||
# --- the ones that need a drone ----------------------------------------------
|
||||
|
||||
|
||||
async def test_state_explains_itself_when_nothing_is_connected(client):
|
||||
data = body(await client.read_resource("bebop://state"))
|
||||
assert data["available"] is False
|
||||
assert "connect" in data["reason"].lower()
|
||||
|
||||
|
||||
async def test_one_state_key_explains_itself_when_nothing_is_connected(client):
|
||||
data = body(await client.read_resource("bebop://state/BatteryStateChanged_percent"))
|
||||
assert data["available"] is False
|
||||
|
||||
|
||||
async def test_state_carries_every_reported_value_with_its_age(connected):
|
||||
data = body(await connected.read_resource("bebop://state"))
|
||||
assert data["available"] is True
|
||||
assert data["keys"] > 20
|
||||
battery = data["values"]["BatteryStateChanged_percent"]
|
||||
assert isinstance(battery["value"], int) and battery["age"] >= 0
|
||||
|
||||
|
||||
async def test_state_reports_link_freshness_because_connected_is_not_evidence(connected):
|
||||
# The aircraft accepts a second controller and silently redirects
|
||||
# telemetry to it, leaving this session reporting connected with nothing
|
||||
# arriving. The age of the newest event is the only tell.
|
||||
data = body(await connected.read_resource("bebop://state"))
|
||||
assert data["last_event_age"] is not None and data["last_event_age"] < 10
|
||||
|
||||
|
||||
async def test_a_state_key_matches_on_a_prefix(connected):
|
||||
data = body(await connected.read_resource("bebop://state/BatteryStateChanged"))
|
||||
assert data["available"] is True
|
||||
assert "BatteryStateChanged_percent" in data["values"]
|
||||
|
||||
|
||||
async def test_a_state_key_the_drone_never_sent_says_so(connected):
|
||||
data = body(await connected.read_resource("bebop://state/NoSuchThing"))
|
||||
assert data["available"] is False
|
||||
assert "bebop://state" in data["reason"]
|
||||
|
||||
|
||||
async def test_a_file_listing_on_the_simulator_explains_itself(connected):
|
||||
data = body(await connected.read_resource("bebop://files/media"))
|
||||
assert data["available"] is False
|
||||
assert "simulator" in data["reason"]
|
||||
|
||||
|
||||
async def test_an_unknown_file_area_lists_the_real_ones(client):
|
||||
data = body(await client.read_resource("bebop://files/update"))
|
||||
assert data["available"] is False
|
||||
assert "flightplans" in data["reason"]
|
||||
|
||||
|
||||
async def test_the_log_resource_explains_itself_with_no_aircraft(connected):
|
||||
data = body(await connected.read_resource("bebop://log/KERNEL"))
|
||||
assert data["available"] is False
|
||||
assert "simulator" in data["reason"]
|
||||
|
||||
|
||||
# --- the log resource against a synthetic log --------------------------------
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
async def with_log(monkeypatch, tmp_path):
|
||||
log = tmp_path / "ckcm.bin"
|
||||
log.write_bytes(
|
||||
entry("Machine: Milos board", tag="KERNEL", uptime_us=0)
|
||||
+ entry("Cmd Tx : battery level <62%>", tag="COMMANDS", uptime_us=9_000_000)
|
||||
+ entry("eth0: no IPv6 routers present", tag="KERNEL", priority="W", uptime_us=12_000_000)
|
||||
)
|
||||
monkeypatch.setattr("mcbebop.files.ftp.fetch", lambda *a, **k: log)
|
||||
async with Client(build_server(Settings(capture_dir=tmp_path))) as c:
|
||||
_common.app().target = "192.0.2.1"
|
||||
yield c
|
||||
|
||||
|
||||
async def test_the_log_resource_returns_recent_entries_for_one_tag(with_log):
|
||||
data = body(await with_log.read_resource("bebop://log/KERNEL"))
|
||||
assert data["available"] is True
|
||||
assert data["matched"] == 2
|
||||
assert data["parsed"] == 3
|
||||
assert data["entries"][0]["message"].startswith("eth0"), "newest first"
|
||||
|
||||
|
||||
async def test_the_log_resource_shows_the_whole_tag_census(with_log):
|
||||
data = body(await with_log.read_resource("bebop://log/COMMANDS"))
|
||||
assert data["tags"] == {"KERNEL": 2, "COMMANDS": 1}
|
||||
|
||||
|
||||
async def test_the_log_resource_caps_what_it_returns(with_log):
|
||||
from mcbebop import resources
|
||||
|
||||
assert resources.LOG_RESOURCE_LIMIT <= 100, "a resource read must not flood a context"
|
||||
data = body(await with_log.read_resource("bebop://log/KERNEL"))
|
||||
assert len(data["entries"]) <= resources.LOG_RESOURCE_LIMIT
|
||||
|
||||
|
||||
async def test_a_tag_the_log_does_not_carry_is_empty_not_an_error(with_log):
|
||||
data = body(await with_log.read_resource("bebop://log/NETMON"))
|
||||
assert data["available"] is True
|
||||
assert data["matched"] == 0
|
||||
assert data["entries"] == []
|
||||
|
||||
|
||||
async def test_the_log_resource_does_not_apply_the_tools_default_exclusions(with_log):
|
||||
# It addresses one tag by name, so there is nothing to protect the caller
|
||||
# from; a resource that silently returned nothing for a tag it was asked
|
||||
# for would be worse than a long answer.
|
||||
assert logs.NOISY_TAGS, "the tool excludes something by default"
|
||||
data = body(await with_log.read_resource("bebop://log/KERNEL"))
|
||||
assert data["matched"] == 2
|
||||
+1
-1
@@ -32,7 +32,7 @@ async def test_every_tool_is_registered(client):
|
||||
assert names == {
|
||||
"connect", "disconnect", "connection_status", "list_commands", "command_info",
|
||||
"send_command", "get_state", "watch_state", "preflight_check", "camera_snapshot",
|
||||
"camera_record", "list_files", "fetch_file", "shell_read", "arm", "disarm",
|
||||
"camera_record", "list_files", "fetch_file", "shell_read", "read_log", "arm", "disarm",
|
||||
} # fmt: skip
|
||||
|
||||
|
||||
|
||||
Reference in New Issue
Block a user