feat(ipc)!: remove the cache-key mailboxes (control socket stage 5)

The control socket is now the only way the web interface sends the display a
command. The display stops reading display_on_demand_request and
plugin_error_clear_request, and the web interface stops writing them.

- Display: no mailbox poll (MailboxWatch, the 1 s / 0.25 s cadence,
  _consume_on_demand_request, the deprecation log) and no persisted
  display_on_demand_processed_id guard; the error publisher reads no clear
  request. CacheManager.file_signature and MailboxWatch are removed.
- A write to either retired key is dropped by CacheManager.save_cache and
  logged once per writer, naming the plugin from the call stack (or the
  request's plugin_id), with the API to move to.
- Web: on-demand start with no display listening starts the service (when
  start_service) and sends the request again once the socket answers (45 s,
  10 s for a running service without a socket yet); every other failure is
  a 503 (400 for invalid_args). Stop answers 503 when no display listens,
  unless stop_service. errors/clear answers 503 with a reason-specific
  message instead of writing a request; clear_pending is always false.
  src.ipc.client.should_fall_back is replaced by display_not_listening.
- Kept: display_current_state, display_on_demand_state,
  plugin_runtime_snapshot and the heartbeat (read whenever the socket cannot
  answer), and display_on_demand_config (the display's resume record).

Tests: mailbox-only tests removed (test_on_demand_mailbox.py, the mailbox
cadence, file_signature and MailboxWatch tests); tests that injected
requests through the mailbox now use the socket queue or a plugin's
in-process request. The run-loop harness sends on-demand requests over its
fake control socket, so four golden traces change: on-demand starts and
stops land at the request instant instead of the next 0.25 s mailbox look
(one frame fewer on the screen they end), and in vegas.json within one
frame instead of 263 ms, which shifts the later 1 s-throttled WiFi-notice
check by under a second.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
Chuck
2026-10-05 09:32:22 -04:00
co-authored by Claude Opus 5.5
parent bb475a79ea
commit c461f4efdb
33 changed files with 1307 additions and 1756 deletions
+48
View File
@@ -19,6 +19,54 @@ accepts both, but the store flags the old spelling as deprecated
## Unreleased ## Unreleased
### Removed: the cache-key mailboxes (control socket stage 5) -- breaking
The control socket (`docs/IPC_CONTROL_SOCKET.md`) is now the only way the
web interface sends the display a command. The file mailboxes it fell back
to for one release are gone.
- **`display_on_demand_request` and `plugin_error_clear_request` are no
longer written or read.** The display stops polling the on-demand mailbox
(`MailboxWatch`, `MAILBOX_POLL_INTERVAL_WITH_SOCKET`,
`_consume_on_demand_request` and the persisted
`display_on_demand_processed_id` guard are removed), and the error
publisher stops reading the clear request. `CacheManager.file_signature`,
`src.cache_manager.MailboxWatch`, `src.ipc.client.should_fall_back` and
`src.error_aggregator.ERROR_CLEAR_REQUEST_KEY` are removed.
- **A write to either key is dropped, with one warning per writer.**
`CacheManager.save_cache` (and so `set`) refuses `RETIRED_MAILBOX_KEYS`
and logs `Ignored a write to the retired '<key>' cache key by plugin
'<id>'`, naming the plugin from the call stack or the request. Plugins
must use `BasePlugin.request_on_demand()` / `end_on_demand()` (3.8.1).
In the official monorepo, birdnet-go, mqtt-notifications, on-air and
pomodoro-timer still write the mailbox, but only as their fallback when
those methods are missing or answer `None`.
- **On-demand routes without a listening display.** `POST
/api/v3/display/on-demand/start` with the service stopped starts it (when
`start_service`, the default) and sends the request once the display's
socket answers, waiting up to 45 s (10 s for a service that is running but
has no socket yet); otherwise it answers `400` (`start_service` false) or
`503` with `socket_error`. Every other socket failure (`unknown_command`
from an older display, `disabled`/`unsupported`, `busy`, a timeout) is a
`503`. `/stop` answers `503` when no display is listening, unless
`stop_service` stops the service. `transport` is always `"socket"`; the
`"mailbox"` value is gone.
- **`POST /api/v3/errors/clear` without the socket answers `503`** (with
`context.socket_error` and a message saying why) instead of recording a
request. `clear_pending` in the error routes is now always `false`;
`src.error_aggregator.read_error_report()` returns only the snapshot, and
`error_summary_from_report()` / `plugin_health_from_report()` /
`request_error_clear()` lose their clear-request arguments.
- **Kept:** the display still writes `display_current_state`,
`display_on_demand_state`, `plugin_runtime_snapshot` and the heartbeat
file, because the web interface reads them whenever the socket cannot
answer (a stopped or starting display, a web user not yet in the socket's
group, Windows), and `display_on_demand_config`, its own record for
resuming a session after a restart.
- **Windows and `LEDMATRIX_CONTROL_SOCKET=off`:** with no socket, the web
interface can no longer start or stop on-demand sessions or clear errors
on a running display (the mailbox used to carry them).
### Plugins ask for the screen in-process: `request_on_demand()` / `end_on_demand()` ### Plugins ask for the screen in-process: `request_on_demand()` / `end_on_demand()`
The in-process way in that stage 5 of the control socket needed The in-process way in that stage 5 of the control socket needed
+16 -43
View File
@@ -650,11 +650,10 @@ When nothing is running on demand, `data.state` is
> above (or the web UI buttons). The API handlers > above (or the web UI buttons). The API handlers
> (`start_on_demand_display()` / `stop_on_demand_display()` in > (`start_on_demand_display()` / `stop_on_demand_display()` in
> `web_interface/blueprints/api_v3/display.py`) send the request over the > `web_interface/blueprints/api_v3/display.py`) send the request over the
> display's control socket ([IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md)). > display's control socket ([IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md)),
> Only when the socket cannot carry it do they write it into the cache > the only way in (the `display_on_demand_request` cache-key mailbox is
> manager under the `display_on_demand_request` key, which > gone). A plugin asks for the screen with `BasePlugin.request_on_demand()`
> `DisplayController._poll_on_demand_requests()` > (see [PLUGIN_API_REFERENCE.md](PLUGIN_API_REFERENCE.md)). A separate
> (`src/display_controller.py`) picks up. A separate
> `display_on_demand_config` key is used by the controller itself > `display_on_demand_config` key is used by the controller itself
> during activation (`_activate_on_demand()`) to track what's > during activation (`_activate_on_demand()`) to track what's
> currently running, and is cleared by `_clear_on_demand()`. > currently running, and is cleared by `_clear_on_demand()`.
@@ -737,29 +736,12 @@ keys helps troubleshoot stuck states.
### Cache Keys ### Cache Keys
**1. display_on_demand_request** (TTL: 1 hour) Requests are not cache keys: they go over the control socket. The
```json `display_on_demand_request` and `display_on_demand_processed_id` keys of
{ earlier releases are no longer written or read; a leftover file is
"request_id": "uuid-string", harmless and can be deleted.
"action": "start|stop",
"plugin_id": "plugin-name",
"mode": "mode-name",
"duration": 30.0,
"pinned": true,
"timestamp": 1234567890.123
}
```
**Purpose:** Communication from web interface to display controller, as the
fallback when the control socket cannot carry the request (deprecated; it
will be removed in a later release)
**When Set:** API endpoint receives a request and the display's control
socket is unavailable (display stopped, or older than the socket or the
command); some plugins also write it directly
**Read:** once a second while the display serves the control socket (0.25 s
without it), and only when the file changed since the last look
**Auto-Cleared:** After processing or 1 hour TTL
**2. display_on_demand_config** (No TTL) **1. display_on_demand_config** (No TTL)
```json ```json
{ {
"mode": "mode-name", "mode": "mode-name",
@@ -771,7 +753,7 @@ without it), and only when the file changed since the last look
**When Set:** Controller processes start request **When Set:** Controller processes start request
**Auto-Cleared:** When on-demand stops **Auto-Cleared:** When on-demand stops
**3. display_on_demand_state** (Continuously updated) **2. display_on_demand_state** (Continuously updated)
```json ```json
{ {
"active": true, "active": true,
@@ -785,31 +767,24 @@ without it), and only when the file changed since the last look
**When Set:** Every display loop iteration **When Set:** Every display loop iteration
**Auto-Cleared:** Never (continuously updated) **Auto-Cleared:** Never (continuously updated)
**4. display_on_demand_processed_id** (TTL: 1 hour)
```text
"uuid-string-of-last-processed-request"
```
**Purpose:** Prevents duplicate request processing
**When Set:** After processing request
**Auto-Cleared:** After 1 hour TTL
### When Manual Clearing is Needed ### When Manual Clearing is Needed
**Scenario 1: Stuck in On-Demand State** **Scenario 1: Stuck in On-Demand State**
- Symptom: Display stays on one plugin, won't return to rotation - Symptom: Display stays on one plugin, won't return to rotation
- Clear: `config`, `state`, `request` - Clear: `config`, `state`
**Scenario 2: Mode Switching Issues** **Scenario 2: Mode Switching Issues**
- Symptom: Can't change to different plugin - Symptom: Can't change to different plugin
- Clear: `request`, `processed_id`, `state` - Clear: `state`, then restart the display
**Scenario 3: On-Demand Not Activating** **Scenario 3: On-Demand Not Activating**
- Symptom: Button click does nothing - Symptom: Button click does nothing, or answers an error
- Clear: `processed_id`, `request` - Check the error's `socket_error` (see [IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md),
"Checking it on a device"); no cache key is involved
**Scenario 4: After Service Crash** **Scenario 4: After Service Crash**
- Symptom: Strange behavior after crash/restart - Symptom: Strange behavior after crash/restart
- Clear: All four keys - Clear: both keys
### Manual Recovery Procedures ### Manual Recovery Procedures
@@ -846,8 +821,6 @@ from src.cache_manager import CacheManager
cache = CacheManager() cache = CacheManager()
cache.clear_cache('display_on_demand_config') cache.clear_cache('display_on_demand_config')
cache.clear_cache('display_on_demand_state') cache.clear_cache('display_on_demand_state')
cache.clear_cache('display_on_demand_request')
cache.clear_cache('display_on_demand_processed_id')
``` ```
> `CacheManager` also has a `delete(key)` method — a thin wrapper over > `CacheManager` also has a `delete(key)` method — a thin wrapper over
+12 -15
View File
@@ -42,11 +42,11 @@ each other. They share three things:
| State | Where | Written by | Read by | | State | Where | Written by | Read by |
|---|---|---|---| |---|---|---|---|
| On-demand command | control socket `/run/ledmatrix/control.sock` ([IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md)) | web: `start_on_demand_display()` / `stop_on_demand_display()` in [`api_v3/display.py`](../web_interface/blueprints/api_v3/display.py), via [`src/ipc/client.py`](../src/ipc/client.py) | display: [`src/ipc/server.py`](../src/ipc/server.py) acks; the render thread applies it in `_poll_on_demand_requests()` | | On-demand command | control socket `/run/ledmatrix/control.sock` ([IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md)) | web: `start_on_demand_display()` / `stop_on_demand_display()` in [`api_v3/display.py`](../web_interface/blueprints/api_v3/display.py), via [`src/ipc/client.py`](../src/ipc/client.py) | display: [`src/ipc/server.py`](../src/ipc/server.py) acks; the render thread applies it in `_poll_on_demand_requests()` |
| On-demand request (fallback) | cache `display_on_demand_request` | web, only when the socket could not carry the request (`should_fall_back`); four plugins write it directly | display: `_poll_on_demand_requests()`, a `stat()` every 1 s while the socket is up (0.25 s without), read only when the file changed | | On-demand request from a plugin | in memory: `BasePlugin.request_on_demand()` / `end_on_demand()` | a plugin in the display process | display: `submit_plugin_on_demand()` queues it; the render thread applies it in `_poll_on_demand_requests()` |
| On-demand state | cache `display_on_demand_state` | display: `_publish_on_demand_state()` | web: `/api/v3/display/on-demand/status` | | On-demand state | cache `display_on_demand_state` | display: `_publish_on_demand_state()` | web: `/api/v3/display/on-demand/status` |
| Current screen | cache `display_current_state` | display | web: `/api/v3/display/current-status` | | Current screen | cache `display_current_state` | display | web: `/api/v3/display/current-status` |
| Plugin errors | cache `plugin_error_snapshot` | display: `ErrorSnapshotPublisher` ([`src/error_aggregator.py`](../src/error_aggregator.py)) | web: `read_error_report()` for `/api/v3/errors/*` | | Plugin errors | cache `plugin_error_snapshot` | display: `ErrorSnapshotPublisher` ([`src/error_aggregator.py`](../src/error_aggregator.py)) | web: `read_error_report()` for `/api/v3/errors/*` |
| Error clear | control socket `errors.clear`; cache `plugin_error_clear_request` as the fallback | web: `POST /api/v3/errors/clear` | display: applied before the socket answers; the mailbox on the error publisher's 5 s tick, read only when the file changed | | Error clear | control socket `errors.clear` | web: `POST /api/v3/errors/clear` | display: applied before the socket answers |
| Font usage | cache `font_usage_snapshot` | display: `FontUsagePublisher` ([`src/font_usage.py`](../src/font_usage.py)) | web: Fonts tab | | Font usage | cache `font_usage_snapshot` | display: `FontUsagePublisher` ([`src/font_usage.py`](../src/font_usage.py)) | web: Fonts tab |
| Fetch statistics (requests per plugin and host) | cache `fetch_stats_snapshot` | display: `FetchStatsPublisher` ([`src/common/fetch_service.py`](../src/common/fetch_service.py)), at most once a minute on change | web: `read_fetch_stats()` for `/api/v3/plugins/fetch-stats` | | Fetch statistics (requests per plugin and host) | cache `fetch_stats_snapshot` | display: `FetchStatsPublisher` ([`src/common/fetch_service.py`](../src/common/fetch_service.py)), at most once a minute on change | web: `read_fetch_stats()` for `/api/v3/plugins/fetch-stats` |
| Plugin health | cache `plugin_health:<id>` | display (web writes on reset) | web: `/api/v3/plugins/health` | | Plugin health | cache `plugin_health:<id>` | display (web writes on reset) | web: `/api/v3/plugins/health` |
@@ -58,18 +58,15 @@ each other. They share three things:
The on-demand start route starts `ledmatrix.service` when it is not running The on-demand start route starts `ledmatrix.service` when it is not running
(`start_service`, on by default) but never restarts a running one. The routes (`start_service`, on by default) but never restarts a running one. The routes
send the command over the display's control socket and get an ack; only when send the command over the display's control socket and get an ack. That is
the socket could not carry it (a stopped display, one older than the socket the only way in: the cache-key mailboxes (`display_on_demand_request`,
or the command) do they write the mailbox instead. A display that had the `plugin_error_clear_request`) are gone, and a write to either is dropped
request and refused it is answered with the error, not posted a mailbox with a warning. When no display is listening yet, the start route starts the
copy. The display looks at the mailbox every service (if asked) and sends the request again once the socket is up; any
`MAILBOX_POLL_INTERVAL_WITH_SOCKET` (1 s) while it serves the socket, and other failure is answered as an error. Socket commands and plugins'
every `ON_DEMAND_POLL_INTERVAL` (0.25 s) without one, from its dwell sleep, in-process requests end in the same handler, `_handle_on_demand_request()`.
its render loops and Vegas's interrupt check as well as the main loop; a
look is one `stat()` unless the file changed. Both ways end in the same
handler, `_handle_on_demand_request()`.
The socket's handlers only queue; see [IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md) The socket's handlers only queue; see [IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md)
for the protocol, the permission model and the plan to retire the mailboxes. for the protocol and the permission model.
### Web and display processes: who runs plugins ### Web and display processes: who runs plugins
@@ -118,8 +115,8 @@ other web-UI action runs its script as a subprocess. A later, explicit
The **control socket** from the web process to the display The **control socket** from the web process to the display
([IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md)) carries on-demand ([IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md)) carries on-demand
commands and reloads an updated plugin; its next stages stream the commands, reloads an updated plugin and streams the display's state; it
display's state and retire the cache-key mailboxes. The plugin web-entry replaced the cache-key mailboxes. The plugin web-entry
contract above is still to come. contract above is still to come.
### Plugin state: desired, observed, and who owns it ### Plugin state: desired, observed, and who owns it
+90 -89
View File
@@ -1,18 +1,18 @@
# Control socket (web → display) # Control socket (web → display)
The display process serves a Unix socket that the web interface uses to send The display process serves a Unix socket that the web interface uses to send
it commands and get an answer back. It replaces the cache-file "mailboxes" on it commands and get an answer back. It replaced the cache-file "mailboxes" on
the SD card one command at a time. Stage 1 carries on-demand start, stop and the SD card one command at a time. Stage 1 carries on-demand start, stop and
status. Stage 2 makes those commands land within a frame on every kind of status. Stage 2 makes those commands land within a frame on every kind of
screen, and adds `brightness.set` and `plugin.reload`. Stage 3 adds a state screen, and adds `brightness.set` and `plugin.reload`. Stage 3 adds a state
stream (`state.get`, `state.subscribe`), so the web interface reads what the stream (`state.get`, `state.subscribe`), so the web interface reads what the
display is doing from the socket instead of from cache files the display display is doing from the socket instead of from cache files the display
wrote to the SD card. Stage 4 makes the socket the only way a command goes display wrote to the SD card. Stage 4 makes the socket the only way a command goes
while it works: the web interface writes a mailbox only when the socket while it works, and `errors.clear` replaces the last command that always
cannot carry the request, `errors.clear` replaces the last command that went through a mailbox. Stage 5 removes the mailboxes: the web interface no
always went through a mailbox, and the display looks at the mailboxes once longer writes them and the display no longer reads them, so the socket is
a second, with a `stat()`. The file mailboxes and the cache keys stay as a the only way a command reaches the display (see "Without the socket"). The
fallback for one release. cache keys the display writes for readers stay as their fallback.
| | | | | |
|---|---| |---|---|
@@ -145,14 +145,17 @@ than the display's wait, so `pending` arrives before the client gives up.
`v` the display does not speak gets `unsupported_version`. `hello` is checked `v` the display does not speak gets `unsupported_version`. `hello` is checked
by its `versions` list instead, and its result names the highest version both by its `versions` list instead, and its result names the highest version both
sides share, so a client can find out what a display supports before it sides share, so a client can find out what a display supports before it
relies on anything newer. The client sends `v: 1` and falls back to the relies on anything newer. The client sends `v: 1`, and a route answers an
mailbox when the display refuses it. It does not send `hello` first, which error when the display refuses it. It does not send `hello` first, which
saves a round trip. saves a round trip.
New commands are added within a version, so stage 2 is still version 1. A New commands are added within a version, so stage 2 is still version 1. A
display that does not know a command answers `unknown_command`, which the display that does not know a command answers `unknown_command`, which the
web interface treats like any other socket failure and falls back from, and web interface treats like any other socket failure and falls back from, and
`hello` lists the commands a display knows. The version changes only when the `hello` lists the commands a display knows.
(Since stage 5, a command the display does not know is an error the route
reports, telling the user to restart the display; there is no mailbox left
to fall back to.) The version changes only when the
envelope or the meaning of an existing command changes. envelope or the meaning of an existing command changes.
**Events.** `state.subscribe` is the one command with more than one message **Events.** `state.subscribe` is the one command with more than one message
@@ -368,13 +371,12 @@ request, validates it against the contract, and then does one of two things:
- For a query, it answers from a status snapshot the display provides - For a query, it answers from a status snapshot the display provides
(`DisplayController._control_status`). The snapshot only reads attributes. (`DisplayController._control_status`). The snapshot only reads attributes.
The render thread drains the queue in `_poll_on_demand_requests()`, the same The render thread drains the queue in `_poll_on_demand_requests()`:
place it reads the mailbox:
- An on-demand command goes to `_handle_on_demand_request()`, which is the - An on-demand command goes to `_handle_on_demand_request()`, which also
mailbox's own handler. The two paths share all of their code: activation, handles plugins' own requests. The two paths share all of their code:
the processed-id guard, error publishing, and resuming the rotation activation, the request-id guard, error publishing, and resuming the
afterwards. rotation afterwards.
- `brightness.set` is applied there and then (`_apply_control_brightness`), - `brightness.set` is applied there and then (`_apply_control_brightness`),
and the current frame is pushed again so the panel shows it. and the current frame is pushed again so the panel shows it.
- `plugin.reload` starts at the top of the next loop pass, the place where - `plugin.reload` starts at the top of the next loop pass, the place where
@@ -407,14 +409,13 @@ place it reads the mailbox:
unloads it mid-load; a disable saved meanwhile is applied once the unloads it mid-load; a disable saved meanwhile is applied once the
reload is done. A second reload of the same plugin runs after the first. reload is done. A second reload of the same plugin runs after the first.
The floor on the mailbox read (0.25 s, 1 s since stage 4) does not apply to the queue, because Draining the queue costs no disk read, so it has no floor. A queued command
draining it costs no disk read. A queued command also lets also lets `_service_pending_changes()` skip its own 0.25 s floor.
`_service_pending_changes()` skip its own floor.
### Waking the render thread (stage 2) ### Waking the render thread (stage 2)
Stage 1 made the socket answer, but not land sooner: a queued command waited Stage 1 made the socket answer, but not land sooner: a queued command waited
for the same polls the mailbox does. Measured on ledpi (Pi 4, 24 fps Vegas), for the same polls the mailbox did. Measured on ledpi (Pi 4, 24 fps Vegas),
a start took 1.02 s on a static screen and about 0.4 s in Vegas either way. a start took 1.02 s on a static screen and about 0.4 s in Vegas either way.
Now the queue wakes the render thread: Now the queue wakes the render thread:
@@ -434,8 +435,7 @@ Now the queue wakes the render thread:
- **Scrolling screens** already service pending changes every frame. - **Scrolling screens** already service pending changes every frame.
So a command lands within a millisecond or so on a static screen and in a So a command lands within a millisecond or so on a static screen and in a
dwell, and within one frame in Vegas and on a scrolling screen. The mailbox dwell, and within one frame in Vegas and on a scrolling screen. Commands still run only on the render thread: the
is slower on purpose (see "The mailboxes now"). Commands still run only on the render thread: the
connection threads only queue them and set the event. The one exception is connection threads only queue them and set the event. The one exception is
the slow half of `plugin.reload` (tearing down and loading the plugin), the slow half of `plugin.reload` (tearing down and loading the plugin),
which runs on its own thread. Every change to the display's state still which runs on its own thread. Every change to the display's state still
@@ -453,74 +453,75 @@ bookkeeping. A client's send to the render thread waking took 0.72 ms median
Without a socket (Windows, `LEDMATRIX_CONTROL_SOCKET=off`) the waits are the Without a socket (Windows, `LEDMATRIX_CONTROL_SOCKET=off`) the waits are the
plain sleeps they were. plain sleeps they were.
**Exactly once.** Since stage 4 the web interface writes the mailbox only **Exactly once.** A request goes over the socket once. The web route sends
when the display never had the request (see "When the web interface falls it again only while no display is listening (see "Without the socket"), so
back"), so a request goes one way or the other, never both. A command and a a display gets it at most once; a start with a request id the display has
mailbox write for the same request still share one `request_id`, and the just processed is dropped anyway (`on_demand_request_id`). The persisted
`on_demand_request_id` and processed-id checks still drop a second copy: an `display_on_demand_processed_id` guard against a mailbox replayed after a
older web interface (before stage 4) wrote the mailbox after a reply timed restart went with the mailbox.
out, too. The display takes such a copy out of the mailbox when it drops it.
## When the web interface falls back (stage 4) ## Without the socket (stage 5)
The client tells a request the display never had from one it had and then The client tells a request the display never had from one it had and then
failed. `ControlError.sent` is True once the whole request was written to a failed. `ControlError.sent` is True once the whole request was written to a
connected display; a refusal the display sends before reading anything connected display; a refusal the display sends before reading anything
(`forbidden`, too many connections) carries no request id, and leaves it (`forbidden`, too many connections) carries no request id, and leaves it
False. `src.ipc.client.should_fall_back()` is the one rule every route uses: False. `src.ipc.client.display_not_listening()` picks out the one case a
later retry can fix: nothing is listening (`no_socket`, `refused`) and the
request was never sent.
| What happened | Example reasons | Mailbox? | The route answers | | What happened | Example reasons | On-demand start | On-demand stop | `errors.clear` |
|---|---|---|---| |---|---|---|---|---|
| The display never had it | `no_socket`, `refused`, `disabled`, `unsupported`, a connect or send that timed out, `forbidden` / `busy` at the door, `invalid_request` (refused by the client itself) | yes | success, `transport: "mailbox"`, `socket_error` | | No display listening | `no_socket`, `refused` | service stopped: `400` without `start_service`; with it, start the service and send again once the socket answers (up to 45 s), else `503`. Service running (still starting): send again for up to 10 s, else `503` | `503` ("not running" / "may still be starting"); with `stop_service` the service is stopped and the route succeeds | `503` ("not running"; its errors are the last run's, and the next run starts with none) |
| A display too old to know it (the upgrade case) | `unknown_command`, `unsupported_version` | yes | as above | | A display too old to know the command | `unknown_command`, `unsupported_version` | `503` | `503` | `503`, "restart it" |
| The display had it and failed | `busy` (queue full), `invalid_args`, `internal`, a timeout or hang-up after the send, `bad_response` | no | `503` (`400` for `invalid_args`), `socket_error` | | No socket in this process | `disabled`, `unsupported` (Windows, `LEDMATRIX_CONTROL_SOCKET=off`) | `503` | `503` | `503` |
| The display had it and failed, turned it away, or never answered | `busy`, `invalid_args`, `internal`, a timeout, a hang-up, `bad_response`, `forbidden` | `503` (`400` for `invalid_args`) | `503` (with `stop_service`: stopped anyway) | `503` |
A display that had the request may have applied it (a reply that timed out), Every error answer carries `socket_error` (a reason code, or `other`).
or would refuse the mailbox copy as well (bad arguments), or is stuck and Nothing is written to the cache in any of these cases. The start route's
would not read the mailbox either (a full queue). Writing the copy anyway waits are bounded (`ON_DEMAND_SOCKET_WAIT_SECONDS`,
only turned that into a "success". An on-demand stop with `stop_service` `ON_DEMAND_SOCKET_WAIT_RUNNING_SECONDS` in
still stops the service, which ends on-demand whatever happened. `web_interface/blueprints/api_v3/display.py`): the socket comes up when the
display's run loop starts, after every plugin has loaded. A client with a
shorter HTTP timeout (the MQTT bridge's is 15 s) can give up first while
the route still delivers the request.
Brightness and plugin reload never had a mailbox: without the socket, the Brightness and plugin reload never had a mailbox: without the socket, the
config watcher applies the saved brightness and a reload becomes the config watcher applies the saved brightness and a reload becomes the
restart banner, as before. restart banner, as before.
### The mailboxes now ### The mailboxes are gone
| Mailbox | Written by | Read by the display | While the socket is up | | Former mailbox | Last written by | Now |
|---|---|---|---| |---|---|---|
| `display_on_demand_request` | the web interface, only on fallback; plugins that predate `BasePlugin.request_on_demand()`, or run on a core without it | the render thread, `_poll_on_demand_requests()` | looked at every 1 s (`MAILBOX_POLL_INTERVAL_WITH_SOCKET`), 0.25 s without a socket | | `display_on_demand_request` | the web interface on fallback (stage 4); plugins that predate `BasePlugin.request_on_demand()` | not read. A write is dropped by `CacheManager.save_cache` (`RETIRED_MAILBOX_KEYS`) and logged once per writer as a warning that names the plugin when it can be told (the plugin instance on the call stack, else the `plugin_id` in the request) |
| `plugin_error_clear_request` | the web interface, only on fallback | the error publisher's thread, every 5 s tick | unchanged rate | | `plugin_error_clear_request` | the web interface on fallback (stage 4) | not read; a write is dropped and logged the same way |
A look is one `stat()` of the mailbox file (`CacheManager.file_signature`): A file left on the SD card by an older version is never read again, so it
`(inode, mtime, size)`, and every write renames a new file into place, so a is harmless. `MailboxWatch` and
new write always looks different. `MailboxWatch` reads the file only when `CacheManager.file_signature`, which made a look at a mailbox one `stat()`,
that changed since the last look, so a mailbox that holds nothing new, or went with them.
nothing at all, costs no open and no parse. A socket command never reads or
deletes the on-demand mailbox. A start already processed is taken out of
the mailbox instead of being re-read until it expires.
A request that comes through the on-demand mailbox while the socket is up The four plugins that wrote `display_on_demand_request` (birdnet-go,
is logged once per writer (`came through the file mailbox although the mqtt-notifications, on-air, pomodoro-timer) use `request_on_demand()` on a
control socket is up`), which names the plugins that still write it. core that has it, and fall back to the mailbox only when that method is
missing or answers `None` (no display in the process, or a full queue).
On a stage-5 core such a fallback write is dropped with the warning above.
### Plugins in the display process ### Plugins in the display process
A plugin asks for the screen with `BasePlugin.request_on_demand()` and gives A plugin asks for the screen with `BasePlugin.request_on_demand()` and gives
it back with `end_on_demand()` (see "On-demand display" in it back with `end_on_demand()` (see "On-demand display" in
[PLUGIN_API_REFERENCE.md](PLUGIN_API_REFERENCE.md)). Neither goes through [PLUGIN_API_REFERENCE.md](PLUGIN_API_REFERENCE.md)). Neither goes through
the socket or a file: `PluginManager` hands the mailbox-shaped request, the socket or a file: `PluginManager` hands the on-demand request,
marked `source: 'plugin'`, to `DisplayController.submit_plugin_on_demand`, marked `source: 'plugin'`, to `DisplayController.submit_plugin_on_demand`,
which queues it in memory (at most `PLUGIN_ON_DEMAND_QUEUE_SIZE`, 32) from which queues it in memory (at most `PLUGIN_ON_DEMAND_QUEUE_SIZE`, 32) from
whatever thread the plugin called on, and wakes the render thread through whatever thread the plugin called on, and wakes the render thread through
the socket's queue flag (`ControlServer.wake()`). The render thread applies the socket's queue flag (`ControlServer.wake()`). The render thread applies
it in `_drain_control_commands`, after the socket's commands, through the it in `_drain_control_commands`, after the socket's commands, through the
same `_handle_on_demand_request`, so it lands within a frame like a socket same `_handle_on_demand_request`, so it lands within a frame like a socket
command. Without a socket it lands on the next pending-changes pass (typically command. Without a socket it lands on the next pending-changes pass. A
within 0.25 s). A plugin's stop ends only a session that plugin owns. The four plugin's stop ends only a session that plugin owns.
plugins that wrote the mailbox (birdnet-go, mqtt-notifications, on-air,
pomodoro-timer) use it where the core has it and write the mailbox
otherwise.
## Robustness ## Robustness
@@ -538,8 +539,7 @@ block the render loop or crash it:
found. A client that disconnects mid-message is dropped silently. No found. A client that disconnects mid-message is dropped silently. No
exception from a handler leaves the connection thread. exception from a handler leaves the connection thread.
- **Full queue.** When the queue is full, the client gets `busy`, and the web - **Full queue.** When the queue is full, the client gets `busy`, and the web
interface answers `503` rather than write the mailbox, which the stuck interface answers `503`. A full queue means the render thread
render thread would not read either. A full queue means the render thread
is stuck, and the systemd watchdog deals with that. is stuck, and the systemd watchdog deals with that.
- **Awaited commands.** The wait for an awaited command's outcome happens on - **Awaited commands.** The wait for an awaited command's outcome happens on
its connection thread and is bounded (`AWAIT_SECONDS`), so a stuck render its connection thread and is bounded (`AWAIT_SECONDS`), so a stuck render
@@ -554,8 +554,8 @@ block the render loop or crash it:
process created. process created.
- **Never fatal.** If the server cannot start (Windows, no `AF_UNIX`, a bind - **Never fatal.** If the server cannot start (Windows, no `AF_UNIX`, a bind
failure, `LEDMATRIX_CONTROL_SOCKET=off`), it logs that and the display runs failure, `LEDMATRIX_CONTROL_SOCKET=off`), it logs that and the display runs
as before. The web interface then uses the mailbox, and reads the cache as before. The web interface then cannot send it commands (the routes
keys and the heartbeat file. answer `503`), and reads the cache keys and the heartbeat file.
- **Subscribers (stage 3).** A `state.subscribe` connection gives its request - **Subscribers (stage 3).** A `state.subscribe` connection gives its request
slot back and takes one of 4 subscriber slots (`MAX_SUBSCRIBERS`). A fifth slot back and takes one of 4 subscriber slots (`MAX_SUBSCRIBERS`). A fifth
gets `busy`. So a few browsers' web processes holding streams can never gets `busy`. So a few browsers' web processes holding streams can never
@@ -613,11 +613,9 @@ device never touches the live display.
## Stage plan ## Stage plan
1. **On-demand, with acks (done, #706).** Contract, server, client. 1. **On-demand, with acks (done, #706).** Contract, server, client.
`on_demand.start`/`stop`/`status`, `hello`, `ping`. The REST routes try the `on_demand.start`/`stop`/`status`, `hello`, `ping`. The REST routes tried
socket first and report `transport: "socket" | "mailbox"` (plus the socket first and reported `transport: "socket" | "mailbox"` (plus
`socket_error` on fallback). The mailbox is unchanged, and the plugins that `socket_error` on fallback).
write it directly (birdnet-go, mqtt-notifications, on-air, pomodoro-timer)
keep working.
2. **Commands that were restarts or polls (done).** 2. **Commands that were restarts or polls (done).**
- The render thread waits on the queue instead of sleeping, and Vegas - The render thread waits on the queue instead of sleeping, and Vegas
checks it every frame, so a command lands within a frame on every kind checks it every frame, so a command lands within a frame on every kind
@@ -660,12 +658,12 @@ device never touches the live display.
4. **The mailboxes become a fallback (done).** 4. **The mailboxes become a fallback (done).**
- The web interface writes a mailbox only when the socket could not carry - The web interface writes a mailbox only when the socket could not carry
the request (`should_fall_back`); a display that had it and failed is the request (`should_fall_back`); a display that had it and failed is
answered as that (see "When the web interface falls back"). answered as that.
- `errors.clear` replaces `plugin_error_clear_request` as the way a clear - `errors.clear` replaces `plugin_error_clear_request` as the way a clear
reaches the display. reaches the display.
- The display looks at the on-demand mailbox once a second while the - The display looks at the on-demand mailbox once a second while the
socket is up, reads either mailbox only when its file changed, and logs socket is up, reads either mailbox only when its file changed, and logs
who still writes the on-demand one (see "The mailboxes now"). who still writes the on-demand one.
- Not changed, deliberately: config saves (the schedule, the dim - Not changed, deliberately: config saves (the schedule, the dim
schedule, plugin settings) still reach the display through schedule, plugin settings) still reach the display through
`config.json` and its watcher, which is the setting itself rather than `config.json` and its watcher, which is the setting itself rather than
@@ -674,15 +672,19 @@ device never touches the live display.
already stats at most once a second. Plugin health and metrics resets already stats at most once a second. Plugin health and metrics resets
write the persisted record the display publishes and do not reach the write the persisted record the display publishes and do not reach the
running display (their routes say so); they are not mailboxes. running display (their routes say so); they are not mailboxes.
5. **Remove the mailboxes (next release).** Once every device has run a 5. **Remove the mailboxes (done, the release after 3.8.1).** The web
display with stage 4, the web interface stops writing both mailboxes and interface no longer writes `display_on_demand_request` or
the display stops reading them. The four plugins that wrote `plugin_error_clear_request`, and the display no longer reads them (see
`display_on_demand_request` now have an in-process way to ask for the "Without the socket"). When no display is listening, the start route
screen (`BasePlugin.request_on_demand()` / `end_on_demand()`, see starts the service if asked and sends the request again once its socket
"Plugins in the display process"); they keep the mailbox write only as is up; every other failure is an error the route reports. A write to
their fallback on older cores. The display also stops writing `display_current_state`, either key is dropped with a one-time warning naming the writer. The
`display_on_demand_state` and `plugin_runtime_snapshot` once the web display still writes `display_current_state`, `display_on_demand_state`
interface no longer falls back to them. and `plugin_runtime_snapshot`: the web interface reads them whenever the
socket cannot answer (a stopped or starting display, a web user not yet
in the socket's group, a platform without Unix sockets), and
`display_on_demand_config` is the display's own record for resuming a
session after a restart. Retiring those keys is left for later.
## Checking it on a device ## Checking it on a device
@@ -694,12 +696,11 @@ curl -s -X POST localhost:5000/api/v3/display/on-demand/start \
# ... "transport": "socket" # ... "transport": "socket"
``` ```
If the response says `"transport": "mailbox"`, `socket_error` gives the On an error, `socket_error` gives the reason. `no_socket` means the display
reason. `no_socket` means the display is stopped or predates the socket. is stopped or still starting. `refused` usually means the web user is not in
`refused` usually means the web user is not in the socket's group, which the socket's group, which takes effect when the web service restarts after
takes effect when the web service restarts after the user is added. A `503` the user is added. `busy`, `timeout` and the like mean the display had the
with `"transport": "socket"` means the display had the request and did not request and did not take it. Nothing is ever written to a mailbox.
take it (`busy`, `timeout`, ...): nothing was written to the mailbox.
An error clear: An error clear:
@@ -707,7 +708,7 @@ An error clear:
curl -s -X POST localhost:5000/api/v3/errors/clear \ curl -s -X POST localhost:5000/api/v3/errors/clear \
-H 'Content-Type: application/json' -d '{"all":true}' -H 'Content-Type: application/json' -d '{"all":true}'
# ... "applied": true, "transport": "socket" # ... "applied": true, "transport": "socket"
sudo journalctl -u ledmatrix | grep -E "Cleared .* plugin error|file mailbox" sudo journalctl -u ledmatrix | grep -E "Cleared .* plugin error|retired"
``` ```
Brightness and a plugin reload: Brightness and a plugin reload:
+30 -20
View File
@@ -522,42 +522,52 @@ Returns the request id once queued, or `None` as above.
These methods are new after core 3.8.0 (see `CHANGELOG.md`). Before them, These methods are new after core 3.8.0 (see `CHANGELOG.md`). Before them,
plugins wrote the `display_on_demand_request` cache key (the "mailbox") plugins wrote the `display_on_demand_request` cache key (the "mailbox")
themselves. The display reads it only once a second while the control themselves. **The mailbox is gone** (see
socket is up, and it will be removed in a future release (see [IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md), stage 5): the display no
[IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md), stage 5). A plugin that longer reads it, and a write to it is dropped with a warning in the log,
must keep working on older cores checks for the method, and writes the once per plugin:
mailbox only when the method is missing or answers `None`:
```
Ignored a write to the retired 'display_on_demand_request' cache key by plugin 'my-plugin': ...
```
A plugin that only needs to run on cores with these methods calls them and
treats `None` as "no display took it":
```python
def _show_alert(self):
if self.request_on_demand(mode="my_alert", duration=15) is None:
self.logger.info("No display to show the alert on")
```
A plugin that must also work on cores before them can keep the mailbox
write as its fallback, guarded by `hasattr`: on those cores the display
still reads it, and on a current core the write is only dropped and logged
(when the method is missing it never runs at all). Raise
`ledmatrix_min_version` to the release that added the methods once you no
longer need it.
```python ```python
import time, uuid import time, uuid
def _show_alert(self): def _show_alert(self):
if hasattr(self, "request_on_demand") and self.request_on_demand( if hasattr(self, "request_on_demand"):
mode="my_alert", duration=15): self.request_on_demand(mode="my_alert", duration=15)
return return
# Older core, or no display in this process: the mailbox, as before. # A core older than request_on_demand(): the mailbox it still reads.
self.cache_manager.set("display_on_demand_request", { self.cache_manager.set("display_on_demand_request", {
"request_id": str(uuid.uuid4()), "action": "start", "request_id": str(uuid.uuid4()), "action": "start",
"plugin_id": self.plugin_id, "mode": "my_alert", "plugin_id": self.plugin_id, "mode": "my_alert",
"duration": 15, "pinned": False, "timestamp": time.time(), "duration": 15, "pinned": False, "timestamp": time.time(),
}) })
def _release(self):
if hasattr(self, "end_on_demand") and self.end_on_demand():
return
self.cache_manager.set("display_on_demand_request", {
"request_id": str(uuid.uuid4()), "action": "stop",
"plugin_id": self.plugin_id, "timestamp": time.time(),
})
``` ```
Keep `ledmatrix_min_version` where it is: the fallback is what keeps the `end_on_demand()` ends only the plugin's own session; a stop written to the
plugin working on older cores. A mailbox stop ends any on-demand session, mailbox on an older core ends any session, whoever started it.
whoever started it; `end_on_demand()` ends only the plugin's own.
Both methods answer a request id only when the plugin manager returned a Both methods answer a request id only when the plugin manager returned a
string, so a test that gives the plugin a `MagicMock()` plugin manager gets string, so a test that gives the plugin a `MagicMock()` plugin manager gets
`None` and exercises the mailbox path. To test the new path, set `None`. To test the path where the display takes the request, set
`plugin_manager.request_on_demand.return_value = "some-id"`. `plugin_manager.request_on_demand.return_value = "some-id"`.
> The full source for `BasePlugin` lives in > The full source for `BasePlugin` lives in
+36 -34
View File
@@ -464,7 +464,7 @@ Request a specific plugin to display on-demand.
- `mode` (string, optional): Display mode name (plugin_id inferred if not provided) - `mode` (string, optional): Display mode name (plugin_id inferred if not provided)
- `duration` (number, optional): Duration in seconds (0 = until stopped) - `duration` (number, optional): Duration in seconds (0 = until stopped)
- `pinned` (boolean, optional): Pin display (pause rotation) - `pinned` (boolean, optional): Pin display (pause rotation)
- `start_service` (boolean, optional): Start the display service if it is not running (default: true). A running service is never restarted: it picks the request up within a frame over its control socket (within about a second through the mailbox fallback). When false and the service is stopped, the route returns 400. - `start_service` (boolean, optional): Start the display service if it is not running (default: true). A running service is never restarted: it picks the request up within a frame over its control socket. A stopped one is started and sent the request once its socket is up, which can take as long as the display takes to load its plugins (the route waits up to 45 s). When false and the service is stopped, the route returns 400.
**Response**: **Response**:
```json ```json
@@ -484,24 +484,30 @@ Request a specific plugin to display on-demand.
`service` is `null` when `start_service` is false. `service` is `null` when `start_service` is false.
`transport` says how the request reached the display: `"socket"` means the `transport` is always `"socket"`: the display's control socket acknowledged
display's control socket acknowledged it (it is queued for the render thread, the request (it is queued for the render thread, which wakes for it and
which wakes for it and applies it within a frame; see applies it within a frame; see [IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md)).
[IPC_CONTROL_SOCKET.md](IPC_CONTROL_SOCKET.md)), `"mailbox"` means it was The `"mailbox"` value earlier releases could answer is gone with the
written to the cache mailbox the display polls, as before the socket existed. mailbox: nothing is written to the cache.
The mailbox is used only when the socket could not carry the request. With
`"mailbox"`, `socket_error` gives the reason (`no_socket` when the display is
stopped or predates the socket, `refused`, a connect `timeout`,
`unknown_command` from a display too old for the command, ...). Either way
the request is applied the same way; `request_id` is the same id in both.
When the display had the request and did not take it -- a full queue When the display did not take the request, the route answers an error with
(`busy`), bad arguments (`invalid_args`), no answer after the request was `status: "error"` and `data: {request_id, transport: "socket",
sent (`timeout`, `closed`) -- the route answers `503` (`400` for socket_error}` (plus `service` when it started or checked the service):
`invalid_args`) with `status: "error"` and `data: {request_id, transport:
"socket", socket_error}`, and writes nothing to the mailbox. The stop route - no display listening (`no_socket`, `refused`): with the service stopped
does the same, except that with `stop_service: true` it still stops the and `start_service` false, `400`; otherwise the route waits for the
service and answers success. display's socket (45 s after starting the service, 10 s when it was
already running and may still be starting) and answers `503` if it never
answers;
- a full queue (`busy`), no answer after the request was sent (`timeout`,
`closed`), a display older than the command (`unknown_command`), no
socket in the web process (`disabled`, `unsupported`): `503` at once;
- bad arguments (`invalid_args`): `400`.
The stop route answers the same errors (`503` when no display is
listening, with a message saying whether the service is stopped), except
that with `stop_service: true` it still stops the service and answers
success, with `socket_error` set.
### Stop On-Demand Display ### Stop On-Demand Display
@@ -531,7 +537,7 @@ Stop the current on-demand display.
} }
``` ```
`transport` and `socket_error` are as for start. `transport` and the errors are as for start; a stop is never retried.
--- ---
@@ -2197,7 +2203,7 @@ Every response below adds three fields to the shape it always had:
|---|---| |---|---|
| `snapshot_available` | `false` until the display service has reported (for example, it is not running). Counts are then zero. | | `snapshot_available` | `false` until the display service has reported (for example, it is not running). Counts are then zero. |
| `generated_at` | When the display service produced the snapshot (ISO, the Pi's local time), or `null`. | | `generated_at` | When the display service produced the snapshot (ISO, the Pi's local time), or `null`. |
| `clear_pending` | A clear has been requested and the display service has not applied it yet. | | `clear_pending` | Always `false`: a clear is applied before its route answers. Kept for compatibility. |
### Get Error Summary ### Get Error Summary
@@ -2278,21 +2284,17 @@ before it answers: `applied` is `true`, `transport` is `"socket"`, and
} }
``` ```
When the socket cannot carry it (the display is stopped, or older than `clear_requested`, `applied` and `transport` are always `true`, `true` and
`errors.clear`) the clear is asynchronous, as before: the web interface `"socket"`, and are kept for compatibility.
records a request (`plugin_error_clear_request` in the shared cache),
`applied` is `false` and `transport` is `"mailbox"`, and the display service
applies it within about 5 seconds. Reads hide the cleared errors from the
moment the request is recorded. Until the display service applies an
age-based clear, `recent_errors` and `active_patterns` are already filtered
but the counts are the old ones, and `clear_pending` is `true`. Then
`cleared_count` is how many of the reported errors the clear hides, and
`null` when that cannot be known before the display service applies it (an
age-based clear over more errors than the report lists).
A request that could not be written to the shared cache answers `500`. A When the socket cannot carry the clear, the route answers `503` with
display that had the request and failed it (`internal`, a timeout after the `context.socket_error`, and nothing is cleared or recorded: the
request was sent) answers `503`, with `context.socket_error`. `plugin_error_clear_request` mailbox earlier releases fell back to is gone.
The message says why: the display service is not running (its errors are
then the last run's, and its next run starts with none), it is too old for
`errors.clear` (restart it), the web process has no socket, or the display
had the request and failed it (`internal`, a timeout after the request was
sent).
--- ---
+54 -48
View File
@@ -25,10 +25,11 @@ Typical plugin usage::
import json import json
import os import os
import sys
import time import time
from datetime import datetime from datetime import datetime
import pytz import pytz
from typing import Any, Dict, List, Optional, Tuple from typing import Any, Dict, List, Optional
import logging import logging
import threading import threading
import tempfile import tempfile
@@ -72,41 +73,60 @@ def _outlived(record: Any, max_age: Optional[float], now: float) -> bool:
return False return False
_NOT_SEEN: Any = object() #: Cache keys that were file "mailboxes" from the web interface (and some
#: plugins) to the display. The control socket replaced them, and nothing
#: reads them any more, so a write is refused rather than left on the SD card
#: for nobody: see :func:`_refuse_retired_mailbox_write`.
RETIRED_MAILBOX_KEYS = frozenset({'display_on_demand_request', 'plugin_error_clear_request'})
#: (key, writer) pairs already warned about, so a plugin that writes on every
#: event logs once per process, not once per write.
_retired_writers_warned: set = set()
_retired_writers_lock = threading.Lock()
class MailboxWatch: def _retired_mailbox_writer(data: Any) -> str:
"""Tells the poller of a mailbox key whether its file changed since the """Name whoever is writing a retired mailbox key, as well as can be told.
last look, from one stat() (:meth:`CacheManager.file_signature`).
The display polls the mailboxes the web interface falls back to. Reading The plugin instance on the call stack when there is one (a ``self`` with
one is an open and a JSON parse; with this a poll that finds the same file a string ``plugin_id`` and a ``cache_manager``: what BasePlugin gives
(or none) costs a stat, and the file is read only after a new write. A every plugin), else the ``plugin_id`` the request itself names, else
cache without ``file_signature`` (a test double) is read every time. ``'unknown'``.
""" """
frame = sys._getframe(2) # pylint: disable=protected-access
depth = 0
while frame is not None and depth < 25:
owner = frame.f_locals.get('self')
plugin_id = getattr(owner, 'plugin_id', None) if owner is not None else None
if isinstance(plugin_id, str) and plugin_id and hasattr(owner, 'cache_manager'):
return f"plugin '{plugin_id}'"
frame = frame.f_back
depth += 1
payload = data.get('data', data) if isinstance(data, dict) else None
named = payload.get('plugin_id') if isinstance(payload, dict) else None
if isinstance(named, str) and named:
return f"plugin '{named}' (named in the request)"
return 'unknown'
def __init__(self, key: str):
self.key = key
self._seen: Any = _NOT_SEEN
def changed(self, cache_manager: Any) -> bool: def _refuse_retired_mailbox_write(logger: logging.Logger, key: str, data: Any) -> None:
"""True when the poller should read the key now.""" """Warn, once per writer, that a write to a retired mailbox key was dropped."""
signature = getattr(cache_manager, 'file_signature', None) try:
sig = signature(self.key) if callable(signature) else _NOT_SEEN writer = _retired_mailbox_writer(data)
if sig is not None and not isinstance(sig, tuple): except Exception: # pylint: disable=broad-except
return True # cannot tell: read it writer = 'unknown'
if sig is None: with _retired_writers_lock:
self._seen = None if (key, writer) in _retired_writers_warned:
return False # no file, nothing to read return
if sig == self._seen: _retired_writers_warned.add((key, writer))
return False if key == 'display_on_demand_request':
self._seen = sig hint = ("call self.request_on_demand() / self.end_on_demand() instead "
return True "(BasePlugin, LEDMatrix 3.8.1 and later)")
else:
def forget(self) -> None: hint = "clear errors through POST /api/v3/errors/clear instead"
"""Read the key on the next poll even if its file has not changed logger.warning("Ignored a write to the retired '%s' cache key by %s: the display no "
(the last read failed).""" "longer reads this file mailbox. Update it to %s. (Logged once per writer.)",
self._seen = _NOT_SEEN key, writer, hint)
class CacheManager: class CacheManager:
@@ -333,24 +353,6 @@ class CacheManager:
"""Get the path for a cache file.""" """Get the path for a cache file."""
return self._disk_cache_component.get_cache_path(key) return self._disk_cache_component.get_cache_path(key)
def file_signature(self, key: str) -> Optional[Tuple[int, int, int]]:
"""``(st_ino, st_mtime_ns, st_size)`` of ``key``'s file, or None when
there is no file (the key is absent, or this cache has no disk tier).
One stat(), no read: a poller of a mailbox another process writes
compares it with the last one it saw and reads the file only when it
changed. Every write replaces the file (a temp file renamed into
place), so a new write always has a new inode, however fast it came.
"""
path = self._get_cache_path(key)
if not path:
return None
try:
st = os.stat(path)
except OSError:
return None
return (st.st_ino, st.st_mtime_ns, st.st_size)
def get_cached_data(self, key: str, max_age: int = 300, memory_ttl: Optional[int] = None) -> Optional[Dict[str, Any]]: def get_cached_data(self, key: str, max_age: int = 300, memory_ttl: Optional[int] = None) -> Optional[Dict[str, Any]]:
"""Get data from cache (memory first, then disk) honoring TTLs. """Get data from cache (memory first, then disk) honoring TTLs.
@@ -388,6 +390,10 @@ class CacheManager:
key: Cache key key: Cache key
data: Data to cache data: Data to cache
""" """
if key in RETIRED_MAILBOX_KEYS:
_refuse_retired_mailbox_write(self.logger, key, data)
return
# Periodic cleanup before adding new entries # Periodic cleanup before adding new entries
self._cleanup_memory_cache() self._cleanup_memory_cache()
+30 -182
View File
@@ -48,7 +48,7 @@ from src.screen_runner import (
from src.display_manager import DisplayManager from src.display_manager import DisplayManager
from src.config_manager import ConfigManager from src.config_manager import ConfigManager
from src.config_service import ConfigService from src.config_service import ConfigService
from src.cache_manager import CacheManager, MailboxWatch from src.cache_manager import CacheManager
from src.font_manager import FontManager from src.font_manager import FontManager
from src.logging_config import get_logger from src.logging_config import get_logger
from src.exceptions import PluginError from src.exceptions import PluginError
@@ -68,10 +68,6 @@ from src.vegas_mode.render_pipeline import SYNC_SEND_INTERVAL
# Get logger with consistent configuration # Get logger with consistent configuration
logger = get_logger(__name__) logger = get_logger(__name__)
# The on-demand file mailbox: the fallback for a web interface that cannot
# reach the control socket, and how some plugins still ask for the screen.
ON_DEMAND_MAILBOX_KEY = 'display_on_demand_request'
# How often the unchanged current mode is republished for the web UI, which # How often the unchanged current mode is republished for the web UI, which
# treats display_current_state older than 120 s as unknown. # treats display_current_state older than 120 s as unknown.
CURRENT_STATE_REFRESH_SECONDS = 30 CURRENT_STATE_REFRESH_SECONDS = 30
@@ -424,19 +420,15 @@ class DisplayController:
# coordinator exists (Vegas was off at startup). The render thread # coordinator exists (Vegas was off at startup). The render thread
# creates it in _is_vegas_mode_active(), never the watcher thread. # creates it in _is_vegas_mode_active(), never the watcher thread.
self._pending_vegas_init = False self._pending_vegas_init = False
# Monotonic stamp of the last mailbox disk read; see # Monotonic stamp of the last _service_pending_changes pass. None
# _poll_on_demand_requests. None means "never polled", so the first # means "never", so the first call always goes through.
# call always goes through.
self._last_on_demand_poll: Optional[float] = None
# Monotonic stamp of the last _service_pending_changes pass; same
# "None means never" convention as _last_on_demand_poll.
self._last_pending_service: Optional[float] = None self._last_pending_service: Optional[float] = None
# Monotonic stamp of the last scheduled-update pass; see # Monotonic stamp of the last scheduled-update pass; see
# _tick_plugin_updates_if_due. Same "None means never" convention. # _tick_plugin_updates_if_due. Same "None means never" convention.
self._last_plugin_update_tick: Optional[float] = None self._last_plugin_update_tick: Optional[float] = None
# The control socket (src/ipc), started by run(). None when it is not # The control socket (src/ipc), started by run(). None when it is not
# served (Windows, LEDMATRIX_CONTROL_SOCKET=off, a bind failure); # served (Windows, LEDMATRIX_CONTROL_SOCKET=off, a bind failure);
# the file mailbox works either way. # then only plugins in this process can start on-demand sessions.
self._control_server = None self._control_server = None
# A brightness set_brightness() refused, so the periodic service pass # A brightness set_brightness() refused, so the periodic service pass
# doesn't retry (and log) the same failure several times a second. # doesn't retry (and log) the same failure several times a second.
@@ -1866,34 +1858,14 @@ class DisplayController:
self.force_change = True self.force_change = True
self._publish_on_demand_state() self._publish_on_demand_state()
#: Shortest gap between mailbox disk reads. This is called after every #: Shortest gap between _service_pending_changes passes. The schedule
#: frame -- about 125 times a second on a scrolling mode -- and the read #: checks are gated to once per clock minute and the rest is attribute
#: below is deliberately uncached, so without a floor it was 125 disk reads #: compares. Callers run at frame rate,
#: per second to find nothing. An on-demand request comes from a person
#: clicking in the web UI, so a quarter second of latency is not
#: perceptible, and it cuts the read rate by 30x.
ON_DEMAND_POLL_INTERVAL = 0.25
#: The mailbox poll while the control socket is up. The web interface then
#: writes the mailbox only when it could not reach the socket (a display
#: being restarted, a web user not yet in the socket's group), and the
#: plugins that still write it get the screen within this long. A look is
#: one stat() of the mailbox file (MailboxWatch).
MAILBOX_POLL_INTERVAL_WITH_SOCKET = 1.0
#: Shortest gap between _service_pending_changes passes. The same floor
#: the mailbox poll had before the socket, since that read was the only
#: real cost in the pass: the schedule checks are gated to once per clock
#: minute and the rest is attribute compares. Callers run at frame rate,
#: so between passes the whole cost is one monotonic-clock compare. #: so between passes the whole cost is one monotonic-clock compare.
PENDING_CHANGES_INTERVAL = 0.25 PENDING_CHANGES_INTERVAL = 0.25
#: Class-level defaults for controllers built without __init__ (tests). #: Class-level defaults for controllers built without __init__ (tests).
_control_server: Optional[ControlServer] = None _control_server: Optional[ControlServer] = None
#: Created on the first poll; see _poll_on_demand_requests.
_on_demand_mailbox: Optional[MailboxWatch] = None
#: Writers whose mailbox requests have been logged (_note_mailbox_request).
_mailbox_writers_logged: FrozenSet[str] = frozenset()
#: Most plugin on-demand requests waiting for the render thread at once. #: Most plugin on-demand requests waiting for the render thread at once.
#: A plugin that asks faster than the display drains (four times a #: A plugin that asks faster than the display drains (four times a
#: second at worst) is refused, not queued without end. #: second at worst) is refused, not queued without end.
@@ -2036,44 +2008,11 @@ class DisplayController:
on_demand_plugin_id, len(enabled_plugins)) on_demand_plugin_id, len(enabled_plugins))
return enabled_plugins return enabled_plugins
def _consume_on_demand_request(self, request_id: str) -> None:
"""Remove the request we just handled from the mailbox.
Leaving it on disk meant a restart replayed the previous request: the
fresh controller read it, activated it and cached it, so the request
the caller had just made was ignored and the panel silently showed the
earlier plugin.
Compare before deleting. The web process can post a newer request
between the read and this delete; an unconditional delete threw that
one away and it was never processed -- the user's second click did
nothing. Re-reading uncached and only deleting our own request_id
leaves a newer request in the mailbox for the next poll instead.
This narrows the window rather than closing it: a request landing
between the re-read and the delete is still lost. Closing it properly
needs an atomic claim (a rename, or a compare-and-delete primitive)
that the cache layer does not currently offer, so the honest fix is a
smaller window plus this note, not a bigger lock. For start requests
processed_id still guards against reprocessing if the delete fails.
"""
try:
current = self.cache_manager.get(ON_DEMAND_MAILBOX_KEY,
max_age=3600, memory_ttl=0)
if not current or current.get('request_id') == request_id:
self.cache_manager.delete(ON_DEMAND_MAILBOX_KEY)
else:
logger.debug("Newer on-demand request %s arrived while processing "
"%s; leaving it in the mailbox",
current.get('request_id'), request_id)
except (OSError, AttributeError, KeyError) as err:
logger.debug("Could not clear the on-demand request mailbox: %s", err)
def _start_control_server(self) -> None: def _start_control_server(self) -> None:
"""Serve the control socket (src/ipc/server.py). Never raises. """Serve the control socket (src/ipc/server.py). Never raises.
Its handlers only queue commands; _drain_control_commands applies Its handlers only queue commands; _drain_control_commands applies
them on the render thread, where the mailbox is read. them on the render thread.
""" """
if self._control_server is not None: if self._control_server is not None:
return return
@@ -2086,7 +2025,8 @@ class DisplayController:
state_hub=hub, state_hub=hub,
handlers={ControlCommand.ERRORS_CLEAR: apply_error_clear}) handlers={ControlCommand.ERRORS_CLEAR: apply_error_clear})
except Exception: # pylint: disable=broad-except except Exception: # pylint: disable=broad-except
logger.exception("Control socket not started; using the file mailbox only") logger.exception("Control socket not started; the web interface cannot "
"send this display commands")
if self._control_server is not None: if self._control_server is not None:
self._start_state_stream(hub) self._start_state_stream(hub)
@@ -2114,10 +2054,8 @@ class DisplayController:
def _drain_control_commands(self) -> None: def _drain_control_commands(self) -> None:
"""Apply the commands that arrived over the control socket. """Apply the commands that arrived over the control socket.
On-demand commands go through _handle_on_demand_request, the On-demand commands go through _handle_on_demand_request, as plugins'
mailbox's own handler, so both ways in behave the same, and a own requests do, so both ways in behave the same. A brightness is applied
request that came both ways (a client that timed out and fell back)
has one request id and is processed once. A brightness is applied
here. A plugin reload waits for the top of the next loop pass, where here. A plugin reload waits for the top of the next loop pass, where
no plugin is on the stack (_apply_pending_plugin_reloads); until no plugin is on the stack (_apply_pending_plugin_reloads); until
then the current screen ends early (_plugin_reload_pending). then the current screen ends early (_plugin_reload_pending).
@@ -2150,7 +2088,7 @@ class DisplayController:
``PluginManager.request_on_demand`` / ``end_on_demand`` (which ``PluginManager.request_on_demand`` / ``end_on_demand`` (which
BasePlugin's methods of the same names call) build ``request``: the BasePlugin's methods of the same names call) build ``request``: the
mailbox's shape, with ``source: 'plugin'`` and the asking plugin's on-demand request shape, with ``source: 'plugin'`` and the asking plugin's
id. Nothing here touches the panel or the on-demand state; the render id. Nothing here touches the panel or the on-demand state; the render
thread applies the request where it applies a socket command thread applies the request where it applies a socket command
(_drain_control_commands), through _handle_on_demand_request, and is (_drain_control_commands), through _handle_on_demand_request, and is
@@ -2445,105 +2383,35 @@ class DisplayController:
} }
command.succeed(dict(result)) command.succeed(dict(result))
def _mailbox_poll_interval(self) -> float:
"""How often the on-demand mailbox is looked at: its old 0.25 s when
it is the only way in, MAILBOX_POLL_INTERVAL_WITH_SOCKET while the
control socket carries the web interface's commands."""
if self._control_server is not None:
return self.MAILBOX_POLL_INTERVAL_WITH_SOCKET
return self.ON_DEMAND_POLL_INTERVAL
def _poll_on_demand_requests(self) -> None: def _poll_on_demand_requests(self) -> None:
"""Apply on-demand requests: the control socket's, then the mailbox's. """Apply on-demand requests: the control socket's, then plugins' own.
Socket commands are in memory and are applied at once. The file Both are in memory (no disk read), so this has no floor and is
mailbox (``display_on_demand_request``) is the fallback for a web cheap to call every frame. The file mailbox
interface that could not reach the socket, and the way four plugins (``display_on_demand_request``) is gone: nothing reads it, and a
still ask for the screen. It is looked at once per poll interval write to it is dropped with a warning (CacheManager).
(_mailbox_poll_interval), and read only when its file changed
(MailboxWatch): a look that finds nothing new is one stat().
""" """
# Socket commands are already in memory: no disk read, so no floor.
self._drain_control_commands() self._drain_control_commands()
now = time.monotonic()
if (self._last_on_demand_poll is not None
and now - self._last_on_demand_poll < self._mailbox_poll_interval()):
return
self._last_on_demand_poll = now
watch = self._on_demand_mailbox
if watch is None:
watch = self._on_demand_mailbox = MailboxWatch(ON_DEMAND_MAILBOX_KEY)
if not watch.changed(self.cache_manager):
return
try:
# Use a long max_age (1 hour) to ensure requests aren't expired before processing
# The request_id check prevents duplicate processing.
#
# memory_ttl=0 is required, not optional: this key is a mailbox the
# web process writes and this process reads. get() defaults the
# in-memory TTL to max_age, so without it the first request read was
# pinned in memory for the full hour and every later poll returned
# that stale copy -- meaning no second on-demand request was honoured
# for an hour, while the API still reported success.
request = self.cache_manager.get(ON_DEMAND_MAILBOX_KEY,
max_age=3600, memory_ttl=0)
except (OSError, RuntimeError, ValueError, TypeError) as err:
watch.forget() # read it again next time
logger.error("Failed to read on-demand request: %s", err, exc_info=True)
return
if not isinstance(request, dict):
return
self._note_mailbox_request(request)
self._handle_on_demand_request(request)
def _note_mailbox_request(self, request: Dict[str, Any]) -> None:
"""Log, once per writer, an on-demand request that came through the
mailbox while the control socket is up.
The web interface writes the mailbox only when the socket fails, so
this is mostly a plugin that writes ``display_on_demand_request``
itself. The mailbox is going away; the log says who still uses it.
"""
if self._control_server is None:
return
writer = request.get('plugin_id') or request.get('mode') or 'unknown'
if not isinstance(writer, str):
writer = 'unknown'
if writer in self._mailbox_writers_logged:
return
self._mailbox_writers_logged = self._mailbox_writers_logged | {writer}
logger.info("On-demand %s request %s (for %s) came through the file mailbox "
"although the control socket is up. The mailbox is deprecated: it "
"is read every %.1fs and will be removed in a future release.",
request.get('action'), request.get('request_id'), writer,
self.MAILBOX_POLL_INTERVAL_WITH_SOCKET)
def _handle_on_demand_request(self, request: Dict[str, Any]) -> None: def _handle_on_demand_request(self, request: Dict[str, Any]) -> None:
"""Process one on-demand request, from the mailbox or the control socket. """Process one on-demand request, from the control socket or a plugin.
A socket command carries ``source: 'socket'``, and a plugin's own A socket command carries ``source: 'socket'``, and a plugin's own
request (submit_plugin_on_demand) ``source: 'plugin'``. Only a request (submit_plugin_on_demand) ``source: 'plugin'``.
mailbox request is removed from the mailbox afterwards: the others
never put anything there, so that would be a disk read and maybe a
delete for nothing.
A plugin's stop ends only that plugin's own session: a plugin A plugin's stop ends only that plugin's own session: a plugin
releasing the screen must not end one the user started for releasing the screen must not end one the user started for
another plugin. (A stop through the mailbox ends any session, as it another plugin. A stop from the socket (the web interface) ends any
always has.) session.
""" """
request_id = request.get('request_id') request_id = request.get('request_id')
if not request_id: if not request_id:
return return
source = request.get('source') source = request.get('source')
from_mailbox = source not in ('socket', 'plugin')
action = request.get('action') action = request.get('action')
# For stop requests, always process them (don't check processed_id) # For stop requests, always process them (no request-id guard)
# This allows stopping even if the same stop request was sent before # This allows stopping even if the same stop request was sent before
if action == 'stop': if action == 'stop':
if source == 'plugin' and not ( if source == 'plugin' and not (
@@ -2569,42 +2437,22 @@ class DisplayController:
# without this the status route kept reporting it until # without this the status route kept reporting it until
# the state aged out (120s) or another request came in. # the state aged out (120s) or another request came in.
self._clear_on_demand(reason='requested-stop') self._clear_on_demand(reason='requested-stop')
# Stop requests are deliberately exempt from the request_id/ # Stop requests are deliberately exempt from the request_id
# processed_id guards above, so that a second click stops a mode # guard below, so that a second click stops a mode that a race
# that a race left running. Consuming the mailbox is therefore the # left running.
# only thing that ends the request: without it the same stop was
# re-read and re-processed on every poll, forever, logging at
# ON_DEMAND_POLL_INTERVAL for the life of the process.
if from_mailbox:
self._consume_on_demand_request(request_id)
return return
# For start requests, check if already processed. A duplicate in the # A start already processed (a client that sent the same request
# mailbox (a copy of a socket command, or one read before a restart) # id twice) is not applied a second time.
# is taken out of it too, so it is not read again.
if request_id == self.on_demand_request_id: if request_id == self.on_demand_request_id:
logger.debug("On-demand start request %s already processed (instance check)", request_id) logger.debug("On-demand start request %s already processed", request_id)
if from_mailbox:
self._consume_on_demand_request(request_id)
return
# Also check persistent processed_id (for restart scenarios)
processed_request_id = self.cache_manager.get('display_on_demand_processed_id', max_age=3600)
if request_id == processed_request_id:
logger.debug("On-demand start request %s already processed (persisted check)", request_id)
if from_mailbox:
self._consume_on_demand_request(request_id)
return return
logger.info("Received on-demand request %s: %s (plugin_id=%s, mode=%s, via %s)", logger.info("Received on-demand request %s: %s (plugin_id=%s, mode=%s, via %s)",
request_id, action, request.get('plugin_id'), request.get('mode'), request_id, action, request.get('plugin_id'), request.get('mode'),
'mailbox' if from_mailbox else source) source or 'unknown')
# Mark as processed BEFORE processing (to prevent duplicate processing)
self.cache_manager.set('display_on_demand_processed_id', request_id, ttl=3600)
self.on_demand_request_id = request_id self.on_demand_request_id = request_id
if from_mailbox:
self._consume_on_demand_request(request_id)
if action == 'start': if action == 'start':
logger.info("Processing on-demand start request for plugin: %s", request.get('plugin_id')) logger.info("Processing on-demand start request for plugin: %s", request.get('plugin_id'))
+54 -175
View File
@@ -19,7 +19,7 @@ import uuid
from collections import defaultdict from collections import defaultdict
from dataclasses import dataclass, field from dataclasses import dataclass, field
from datetime import datetime, timedelta from datetime import datetime, timedelta
from typing import Dict, List, Optional, Any, Callable, Tuple from typing import Dict, List, Optional, Any, Callable
import logging import logging
from src.exceptions import LEDMatrixError from src.exceptions import LEDMatrixError
@@ -487,33 +487,28 @@ def record_error(
# service publishes to the shared cache directory -- the same channel, and the # service publishes to the shared cache directory -- the same channel, and the
# same file permissions, as display_current_state and plugin_metrics_snapshot: files # same file permissions, as display_current_state and plugin_metrics_snapshot: files
# are 0660 and carry the cache directory's group, so root writes and the web # are 0660 and carry the cache directory's group, so root writes and the web
# user reads, and the other way round for the clear request. # user reads.
# #
# ERROR_SNAPSHOT_KEY written by the display service only # ERROR_SNAPSHOT_KEY written by the display service only
# ERROR_CLEAR_REQUEST_KEY written by the web interface only, as a fallback
# #
# A clear goes over the control socket (``errors.clear``): the display applies # A clear goes over the control socket (``errors.clear``): the display applies
# it (clear_before) and republishes the snapshot before it answers. Only when # it (clear_before) and republishes the snapshot before it answers. When the
# the socket cannot carry it (no socket, or a display older than the command) # socket cannot carry it, the clear fails and the route says so: the
# does the web interface record a request in the mailbox, which the display # ``plugin_error_clear_request`` file mailbox it used to fall back to is gone.
# applies on its next tick; its tick reads that file only when it changed. # A stopped display's errors go anyway: its next run publishes an empty
# Until it has, the web interface hides whatever the snapshot shows from # snapshot over the old one. The web interface never writes the snapshot
# before the cutoff, so a clear takes effect for readers immediately and a # itself: two writers would race, and a snapshot owned by the web user is one
# snapshot published just before the request cannot bring old errors back. # more file root's write has to replace.
# The web interface never writes the snapshot itself: two writers would race,
# and a snapshot owned by the web user is one more file root's write has to
# replace.
ERROR_SNAPSHOT_KEY = "plugin_error_snapshot" ERROR_SNAPSHOT_KEY = "plugin_error_snapshot"
ERROR_CLEAR_REQUEST_KEY = "plugin_error_clear_request"
#: Shortest gap between two snapshot writes, in seconds. A plugin failing in #: Shortest gap between two snapshot writes, in seconds. A plugin failing in
#: a tight loop changes the aggregator many times a second; the snapshot is #: a tight loop changes the aggregator many times a second; the snapshot is
#: rewritten at most this often, and only when something changed. #: rewritten at most this often, and only when something changed.
SNAPSHOT_MIN_INTERVAL = 10.0 SNAPSHOT_MIN_INTERVAL = 10.0
#: How often the display service checks for changes and clear requests. A #: How often the display service checks for changes. A check is an
#: check is an in-memory comparison plus reading one small file. #: in-memory comparison.
SNAPSHOT_TICK_INTERVAL = 5.0 SNAPSHOT_TICK_INTERVAL = 5.0
_SNAPSHOT_RECENT_ERRORS = 20 _SNAPSHOT_RECENT_ERRORS = 20
@@ -582,8 +577,8 @@ class ErrorSnapshotPublisher:
Runs in the display service only. tick() is the whole job; start() just Runs in the display service only. tick() is the whole job; start() just
calls it from a daemon thread every SNAPSHOT_TICK_INTERVAL seconds, which calls it from a daemon thread every SNAPSHOT_TICK_INTERVAL seconds, which
also means errors recorded while a write was being throttled still reach also means errors recorded while a write was being throttled still reach
the cache once the interval has passed, and a clear request is applied the cache once the interval has passed. A clear (``errors.clear`` over
even when no new error arrives to trigger a publish. the control socket) is applied by :meth:`clear_now`.
Nothing here raises: a failure to read or write the cache is logged at Nothing here raises: a failure to read or write the cache is logged at
debug and retried on a later tick. debug and retried on a later tick.
@@ -601,11 +596,6 @@ class ErrorSnapshotPublisher:
self._published_version: Optional[int] = None self._published_version: Optional[int] = None
self._last_attempt: Optional[float] = None self._last_attempt: Optional[float] = None
self._applied_clear_id: Optional[str] = None self._applied_clear_id: Optional[str] = None
# The widest cutoff applied in this process: a clear request at or
# before it has nothing left to clear (see _pending_cutoff).
self._applied_clear_cutoff: Optional[float] = None
from src.cache_manager import MailboxWatch # the display's cache, loaded already
self._mailbox = MailboxWatch(ERROR_CLEAR_REQUEST_KEY)
self._tick_lock = threading.Lock() self._tick_lock = threading.Lock()
self._stop = threading.Event() self._stop = threading.Event()
self._thread: Optional[threading.Thread] = None self._thread: Optional[threading.Thread] = None
@@ -617,39 +607,9 @@ class ErrorSnapshotPublisher:
cleared = self.aggregator.clear_before(datetime.fromtimestamp(cutoff)) cleared = self.aggregator.clear_before(datetime.fromtimestamp(cutoff))
_snapshot_logger.info("Cleared %d plugin error record(s) as requested (%s)", _snapshot_logger.info("Cleared %d plugin error record(s) as requested (%s)",
cleared, request_id) cleared, request_id)
if self._applied_clear_cutoff is None or cutoff > self._applied_clear_cutoff:
self._applied_clear_cutoff = cutoff
# A malformed request is acknowledged too, so it is not retried forever.
self._applied_clear_id = request_id self._applied_clear_id = request_id
return cleared return cleared
def _apply_clear_request(self) -> bool:
"""Honour a mailbox clear request we have not applied yet. True if one was.
The mailbox is the fallback for a web interface that could not use
the control socket (``errors.clear``, :meth:`clear_now`). It is read
only when its file changed since the last tick; otherwise a tick
costs one stat().
"""
if not self._mailbox.changed(self.cache_manager):
return False
try:
request = self.cache_manager.get(ERROR_CLEAR_REQUEST_KEY, max_age=None, memory_ttl=0)
except Exception:
self._mailbox.forget()
raise
if not isinstance(request, dict):
return False
request_id = request.get("request_id")
if not isinstance(request_id, str) or not request_id or request_id == self._applied_clear_id:
return False
try:
cutoff = float(request.get("cutoff"))
except (TypeError, ValueError):
cutoff = float("nan")
self._clear(request_id, cutoff)
return True
def clear_now(self, request_id: str, cutoff: float) -> int: def clear_now(self, request_id: str, cutoff: float) -> int:
"""``errors.clear`` over the control socket: apply a clear at once and """``errors.clear`` over the control socket: apply a clear at once and
republish the snapshot, so the web interface's next read has it. republish the snapshot, so the web interface's next read has it.
@@ -667,23 +627,20 @@ class ErrorSnapshotPublisher:
self._last_attempt = now self._last_attempt = now
snapshot = self.aggregator.build_snapshot() snapshot = self.aggregator.build_snapshot()
snapshot["applied_clear_id"] = self._applied_clear_id snapshot["applied_clear_id"] = self._applied_clear_id
snapshot["applied_clear_cutoff"] = self._applied_clear_cutoff
self.cache_manager.set(ERROR_SNAPSHOT_KEY, snapshot) self.cache_manager.set(ERROR_SNAPSHOT_KEY, snapshot)
self._published_version = version self._published_version = version
def tick(self) -> bool: def tick(self) -> bool:
"""Apply a pending clear and publish if due. True if a snapshot was written.""" """Publish if due. True if a snapshot was written."""
with self._tick_lock: with self._tick_lock:
try: try:
cleared = self._apply_clear_request()
version = self.aggregator.version version = self.aggregator.version
now = self._clock() now = self._clock()
if not cleared: if version == self._published_version:
if version == self._published_version: return False
return False if (self._last_attempt is not None
if (self._last_attempt is not None and now - self._last_attempt < self.min_interval):
and now - self._last_attempt < self.min_interval): return False
return False
self._publish(version, now) self._publish(version, now)
return True return True
except Exception as err: # never let reporting break the display except Exception as err: # never let reporting break the display
@@ -754,16 +711,13 @@ def apply_error_clear(request_id: str, args: Any) -> Dict[str, Any]:
# --- Reading side (web interface) ------------------------------------------- # --- Reading side (web interface) -------------------------------------------
def read_error_report(cache_manager: Any) -> Tuple[Optional[Dict[str, Any]], Optional[Dict[str, Any]]]: def read_error_report(cache_manager: Any) -> Optional[Dict[str, Any]]:
"""The display service's latest snapshot and the latest clear request. """The display service's latest snapshot, or None before it has published.
memory_ttl=0: both keys are written by the other process, so only the memory_ttl=0: the display writes the key, so only the file is current.
file is current.
""" """
snapshot = cache_manager.get(ERROR_SNAPSHOT_KEY, max_age=None, memory_ttl=0) snapshot = cache_manager.get(ERROR_SNAPSHOT_KEY, max_age=None, memory_ttl=0)
clear_request = cache_manager.get(ERROR_CLEAR_REQUEST_KEY, max_age=None, memory_ttl=0) return snapshot if isinstance(snapshot, dict) else None
return (snapshot if isinstance(snapshot, dict) else None,
clear_request if isinstance(clear_request, dict) else None)
def _epoch(iso: Any) -> Optional[float]: def _epoch(iso: Any) -> Optional[float]:
@@ -776,36 +730,6 @@ def _epoch(iso: Any) -> Optional[float]:
return None return None
def _pending_cutoff(snapshot: Optional[Dict[str, Any]],
clear_request: Optional[Dict[str, Any]]) -> Optional[float]:
"""The cutoff of a clear the snapshot has not applied yet, if any."""
if not clear_request:
return None
request_id = clear_request.get("request_id")
if not request_id:
return None
if snapshot is not None and snapshot.get("applied_clear_id") == request_id:
return None
try:
cutoff = float(clear_request.get("cutoff"))
except (TypeError, ValueError):
return None
if not math.isfinite(cutoff):
return None
# A wider clear has been applied since (over the control socket): this
# older request has nothing left to hide.
applied = snapshot.get("applied_clear_cutoff") if snapshot is not None else None
if (isinstance(applied, (int, float)) and not isinstance(applied, bool)
and applied >= cutoff):
return None
return cutoff
def _is_after(item: Any, field_name: str, cutoff: float) -> bool:
when = _epoch(item.get(field_name)) if isinstance(item, dict) else None
return when is not None and when > cutoff
def _empty_summary(snapshot: Optional[Dict[str, Any]]) -> Dict[str, Any]: def _empty_summary(snapshot: Optional[Dict[str, Any]]) -> Dict[str, Any]:
return { return {
"session_start": snapshot.get("session_start") if snapshot else None, "session_start": snapshot.get("session_start") if snapshot else None,
@@ -818,11 +742,11 @@ def _empty_summary(snapshot: Optional[Dict[str, Any]]) -> Dict[str, Any]:
} }
def error_summary_from_report(snapshot: Optional[Dict[str, Any]], def error_summary_from_report(snapshot: Optional[Dict[str, Any]]) -> Dict[str, Any]:
clear_request: Optional[Dict[str, Any]]) -> Dict[str, Any]:
"""The /errors/summary payload: get_error_summary()'s shape plus """The /errors/summary payload: get_error_summary()'s shape plus
``generated_at``, ``snapshot_available`` and ``clear_pending``.""" ``generated_at``, ``snapshot_available`` and ``clear_pending`` (always
cutoff = _pending_cutoff(snapshot, clear_request) False now: a clear is applied before its route answers; kept for API
compatibility)."""
summary = _empty_summary(snapshot) summary = _empty_summary(snapshot)
if snapshot is not None: if snapshot is not None:
for name, default in summary.items(): for name, default in summary.items():
@@ -831,32 +755,17 @@ def error_summary_from_report(snapshot: Optional[Dict[str, Any]],
isinstance(default, float) and isinstance(value, int)) or ( isinstance(default, float) and isinstance(value, int)) or (
name == "session_start" and isinstance(value, str)): name == "session_start" and isinstance(value, str)):
summary[name] = value summary[name] = value
if cutoff is not None:
recent = summary["recent_errors"]
newest = _epoch(recent[-1].get("timestamp")) if recent and isinstance(recent[-1], dict) else None
if newest is None or newest <= cutoff:
# Everything the display has reported predates the clear.
summary = _empty_summary(snapshot)
else:
# Only part of it does. The lists can be filtered exactly; the
# counts cannot, and stay as reported until the display
# applies the clear (clear_pending says so).
summary["recent_errors"] = [r for r in recent if _is_after(r, "timestamp", cutoff)]
summary["active_patterns"] = {
k: p for k, p in summary["active_patterns"].items()
if _is_after(p, "last_seen", cutoff)
}
summary["generated_at"] = snapshot.get("generated_at") if snapshot else None summary["generated_at"] = snapshot.get("generated_at") if snapshot else None
summary["snapshot_available"] = snapshot is not None summary["snapshot_available"] = snapshot is not None
summary["clear_pending"] = cutoff is not None summary["clear_pending"] = False
return summary return summary
def plugin_health_from_report(snapshot: Optional[Dict[str, Any]], def plugin_health_from_report(snapshot: Optional[Dict[str, Any]],
clear_request: Optional[Dict[str, Any]],
plugin_id: str) -> Dict[str, Any]: plugin_id: str) -> Dict[str, Any]:
"""The /errors/plugin/<id> payload: get_plugin_health()'s shape plus """The /errors/plugin/<id> payload: get_plugin_health()'s shape plus
``generated_at``, ``snapshot_available`` and ``clear_pending``.""" ``generated_at``, ``snapshot_available`` and ``clear_pending`` (always
False, as in error_summary_from_report)."""
health: Dict[str, Any] = { health: Dict[str, Any] = {
"plugin_id": plugin_id, "plugin_id": plugin_id,
"status": "healthy", "status": "healthy",
@@ -865,19 +774,15 @@ def plugin_health_from_report(snapshot: Optional[Dict[str, Any]],
"recent_error_count": 0, "recent_error_count": 0,
"last_error": None, "last_error": None,
} }
cutoff = _pending_cutoff(snapshot, clear_request)
table = snapshot.get("plugin_health") if snapshot else None table = snapshot.get("plugin_health") if snapshot else None
entry = table.get(plugin_id) if isinstance(table, dict) else None entry = table.get(plugin_id) if isinstance(table, dict) else None
if isinstance(entry, dict): if isinstance(entry, dict):
# last_error is the plugin's newest error: if even that predates a for name in ("status", "total_errors", "error_types", "recent_error_count", "last_error"):
# pending clear, so does everything else the display reported for it. if name in entry:
if cutoff is None or _is_after(entry.get("last_error"), "timestamp", cutoff): health[name] = entry[name]
for name in ("status", "total_errors", "error_types", "recent_error_count", "last_error"):
if name in entry:
health[name] = entry[name]
health["generated_at"] = snapshot.get("generated_at") if snapshot else None health["generated_at"] = snapshot.get("generated_at") if snapshot else None
health["snapshot_available"] = snapshot is not None health["snapshot_available"] = snapshot is not None
health["clear_pending"] = cutoff is not None health["clear_pending"] = False
return health return health
@@ -899,61 +804,35 @@ def _count_cleared(summary: Dict[str, Any], cutoff: float) -> Optional[int]:
#: ``send(request_id, cutoff)`` hands a clear to the display over the control #: ``send(request_id, cutoff)`` hands a clear to the display over the control
#: socket and returns its ErrorsClearResult, or None when the socket could #: socket and returns its ErrorsClearResult. It raises when the socket could
#: not carry it and the mailbox should be written instead. Any exception it #: not carry it or the display failed it (``src.ipc.client.ControlError``).
#: raises reaches the caller: the display had the request and failed it. ClearSender = Callable[[str, float], Dict[str, Any]]
ClearSender = Callable[[str, float], Optional[Dict[str, Any]]]
def request_error_clear(cache_manager: Any, cutoff: float, def request_error_clear(cache_manager: Any, cutoff: float,
send: Optional[ClearSender] = None) -> Dict[str, Any]: send: ClearSender) -> Dict[str, Any]:
"""Ask the display service to forget errors recorded at or before ``cutoff``. """Ask the display service to forget errors recorded at or before ``cutoff``.
Over the control socket when ``send`` is given and carries it: the Over the control socket: the display applies the clear and republishes
display applies the clear and republishes its snapshot before it its snapshot before it answers, so nothing is written here. Whatever
answers, so nothing is written here. Otherwise (no socket, or a display ``send`` raises reaches the caller.
older than ``errors.clear``) a request is written to the
``plugin_error_clear_request`` mailbox, which the display applies on
its next tick, and readers hide the cleared errors until then.
Returns ``request_id``, ``cutoff`` (ISO, local time), ``cleared_count``, Returns ``request_id``, ``cutoff`` (ISO, local time), ``cleared_count``
``clear_requested``, ``applied`` (the display has already cleared them) (the display's own count, else an estimate from the snapshot; see
and ``transport`` (``socket`` or ``mailbox``). ``cleared_count`` is the _count_cleared), and ``clear_requested``, ``applied`` and ``transport``,
display's own count over the socket, else an estimate from the snapshot which are always True, True and ``"socket"`` now and are kept for API
(see _count_cleared). Raises OSError when a mailbox request did not reach compatibility.
the shared cache, since a cache without a usable directory accepts set()
and keeps nothing.
A request the display has not applied yet is only ever widened: a later,
narrower one ("older than 24 hours" after "everything") overwriting it
would otherwise bring back the errors the first one hid.
""" """
snapshot, clear_request = read_error_report(cache_manager) before = error_summary_from_report(read_error_report(cache_manager))
pending = _pending_cutoff(snapshot, clear_request)
if pending is not None:
cutoff = max(cutoff, pending)
before = error_summary_from_report(snapshot, clear_request)
request_id = uuid.uuid4().hex request_id = uuid.uuid4().hex
answer = { result = send(request_id, cutoff)
count = result.get("cleared") if isinstance(result, dict) else None
return {
"clear_requested": True, "clear_requested": True,
"request_id": request_id, "request_id": request_id,
"cutoff": datetime.fromtimestamp(cutoff).isoformat(), "cutoff": datetime.fromtimestamp(cutoff).isoformat(),
"applied": True,
"transport": "socket",
"cleared_count": (count if isinstance(count, int) and not isinstance(count, bool)
else _count_cleared(before, cutoff)),
} }
if send is not None:
result = send(request_id, cutoff)
if result is not None:
count = result.get("cleared")
return dict(answer, applied=True, transport="socket",
cleared_count=count if isinstance(count, int) and not isinstance(count, bool)
else _count_cleared(before, cutoff))
request = {
"request_id": request_id,
"cutoff": cutoff,
"requested_at": time.time(),
}
cache_manager.set(ERROR_CLEAR_REQUEST_KEY, request)
stored = cache_manager.get(ERROR_CLEAR_REQUEST_KEY, max_age=None, memory_ttl=0)
if not isinstance(stored, dict) or stored.get("request_id") != request["request_id"]:
raise OSError("the clear request was not stored in the shared cache")
return dict(answer, applied=False, transport="mailbox",
cleared_count=_count_cleared(before, cutoff))
+23 -28
View File
@@ -5,11 +5,11 @@ a refused or timed-out connection, a reply that breaks the contract, or an
error the display returned -- raises :class:`ControlError` with a short error the display returned -- raises :class:`ControlError` with a short
``reason``. Nothing here blocks for longer than ``timeout`` in total. ``reason``. Nothing here blocks for longer than ``timeout`` in total.
Whether the caller may then write the file mailbox instead is There is no other way to reach the display: the file mailboxes the web
:func:`should_fall_back`: only when the display never took the request (it interface used to fall back to are gone. :func:`display_not_listening` tells
could not be reached, or it is too old to know the command). A display that a caller when no display is listening yet (it is stopped, or still
took the request and then failed, refused or went quiet is answered as starting), the one case where sending the same request again later, once a
that, not posted a second time through the mailbox. display is up, can work.
""" """
from __future__ import annotations from __future__ import annotations
@@ -43,8 +43,7 @@ from src.ipc.contract import (
#: Total budget for one request: connect, send and the reply. The display #: Total budget for one request: connect, send and the reply. The display
#: answers from a thread that does no rendering, normally within a few #: answers from a thread that does no rendering, normally within a few
#: milliseconds; this only bounds a wedged one. The web route then falls back #: milliseconds; this only bounds a wedged one.
#: to the mailbox, so a timeout costs this much latency and nothing else.
DEFAULT_TIMEOUT_SECONDS = 1.0 DEFAULT_TIMEOUT_SECONDS = 1.0
@@ -74,28 +73,25 @@ class ControlError(Exception):
#: Answers from a display that read the request but does not speak it: one #: Answers from a display that read the request but does not speak it: one
#: older than the command (an upgrade in progress) or the protocol version. #: older than the command (an upgrade in progress) or the protocol version.
#: It did nothing, so the mailbox is the way to reach it.
UPGRADE_REASONS = frozenset({ErrorCode.UNKNOWN_COMMAND, ErrorCode.UNSUPPORTED_VERSION}) UPGRADE_REASONS = frozenset({ErrorCode.UNKNOWN_COMMAND, ErrorCode.UNSUPPORTED_VERSION})
#: Transport reasons that mean nothing is listening at the socket: no socket
#: file (the display is stopped, or has not reached its run loop), or a file
#: nobody accepts on (a stale socket) or that this user may not open.
NOT_LISTENING_REASONS = frozenset({'no_socket', 'refused'})
def should_fall_back(error: BaseException) -> bool:
"""May the caller write the file mailbox after ``error``?
Yes when the display never took the request: there is no socket (the def display_not_listening(error: BaseException) -> bool:
display is stopped, predates the socket, or it is switched off), the """True when ``error`` says no display took the request because none is
connection was refused or timed out, the display turned the connection listening: it never reached one (``sent`` is False) and the reason is in
away before reading it, or it is too old to know the command :data:`NOT_LISTENING_REASONS`. A display that is started, or finishes
(:data:`UPGRADE_REASONS`). Also for an error that is not a starting, may take the same request later. False for everything else:
:class:`ControlError` (a bug in the client), as before. a display that had the request and failed it, one too old to know the
command, a client that cannot use the socket at all (``disabled``,
No once the display had the request: a ``busy`` queue, ``invalid_args``, ``unsupported``), and an exception that is not a :class:`ControlError`.
an ``internal`` error, or a timeout or hang-up after the request was
sent. The display may have applied it, or would refuse it from the
mailbox too, so a second copy there only hides the failure.
""" """
if not isinstance(error, ControlError): return (isinstance(error, ControlError) and not error.sent
return True and error.reason in NOT_LISTENING_REASONS)
return not error.sent or error.reason in UPGRADE_REASONS
def request(cmd: str, args: Optional[Mapping[str, Any]] = None, *, def request(cmd: str, args: Optional[Mapping[str, Any]] = None, *,
@@ -218,8 +214,8 @@ def on_demand_start(request_id: str, plugin_id: Optional[str], mode: Optional[st
paths: Optional[Sequence[str]] = None) -> Dict[str, Any]: paths: Optional[Sequence[str]] = None) -> Dict[str, Any]:
"""Ask the display to show a plugin now. Returns the ack; raises :class:`ControlError`. """Ask the display to show a plugin now. Returns the ack; raises :class:`ControlError`.
``request_id`` doubles as the on-demand request id, so a request that a ``request_id`` doubles as the on-demand request id, so a request sent
timed-out caller then also writes to the mailbox is processed only once. twice with the same id is processed only once.
""" """
args = {'plugin_id': plugin_id, 'mode': mode, 'duration': duration, 'pinned': pinned} args = {'plugin_id': plugin_id, 'mode': mode, 'duration': duration, 'pinned': pinned}
return request(Command.ON_DEMAND_START, args, request_id=request_id, return request(Command.ON_DEMAND_START, args, request_id=request_id,
@@ -281,8 +277,7 @@ def errors_clear(request_id: str, cutoff: float, *,
Returns :class:`~src.ipc.contract.ErrorsClearResult` once it is done. Returns :class:`~src.ipc.contract.ErrorsClearResult` once it is done.
Raises :class:`ControlError`: ``unknown_command`` from a display older Raises :class:`ControlError`: ``unknown_command`` from a display older
than the command, which still reads the ``plugin_error_clear_request`` than the command.
mailbox.
""" """
return request(Command.ERRORS_CLEAR, {'cutoff': cutoff}, request_id=request_id, return request(Command.ERRORS_CLEAR, {'cutoff': cutoff}, request_id=request_id,
timeout=timeout, paths=paths) timeout=timeout, paths=paths)
+10 -11
View File
@@ -85,8 +85,8 @@ DEFAULT_SOCKET_PATH = DEFAULT_SOCKET_DIR + '/' + SOCKET_NAME
#: Overrides the socket path for both processes (a dev checkout, a second #: Overrides the socket path for both processes (a dev checkout, a second
#: instance, tests). One of :data:`DISABLED_VALUES` turns the socket off: the #: instance, tests). One of :data:`DISABLED_VALUES` turns the socket off: the
#: display does not serve it and the web interface goes straight to the #: display does not serve it, and the web interface cannot send it commands
#: file mailbox. #: (it still reads the state the display writes to the cache).
SOCKET_PATH_ENV = 'LEDMATRIX_CONTROL_SOCKET' SOCKET_PATH_ENV = 'LEDMATRIX_CONTROL_SOCKET'
DISABLED_VALUES = frozenset({'off', '0', 'false', 'no', 'none', 'disabled'}) DISABLED_VALUES = frozenset({'off', '0', 'false', 'no', 'none', 'disabled'})
@@ -375,8 +375,8 @@ def _optional_name(args: Mapping[str, Any], key: str) -> Optional[str]:
def _optional_duration(value: Any) -> Optional[float]: def _optional_duration(value: Any) -> Optional[float]:
"""Seconds, or None for "until stopped". 0 means the same as None. """Seconds, or None for "until stopped". 0 means the same as None.
Numbers and numeric strings are accepted, the same as the REST route and Numbers and numeric strings are accepted, the same as the REST route
the file mailbox take them; anything else is refused rather than guessed. takes them; anything else is refused rather than guessed.
""" """
if value is None or value == '': if value is None or value == '':
return None return None
@@ -418,7 +418,7 @@ class HelloArgs:
class OnDemandStartArgs: class OnDemandStartArgs:
"""``on_demand.start``: show a plugin (or one of its modes) now. """``on_demand.start``: show a plugin (or one of its modes) now.
The same fields the file mailbox carries. At least one of ``plugin_id`` The same fields as the REST route's body. At least one of ``plugin_id``
and ``mode`` is required; the display resolves the other. and ``mode`` is required; the display resolves the other.
""" """
plugin_id: Optional[str] = None plugin_id: Optional[str] = None
@@ -628,13 +628,12 @@ def parse_args(cmd: str, args: Mapping[str, Any]) -> CommandArgs:
def on_demand_request(request_id: str, args: Union[OnDemandStartArgs, OnDemandStopArgs], def on_demand_request(request_id: str, args: Union[OnDemandStartArgs, OnDemandStopArgs],
timestamp: float) -> Dict[str, Any]: timestamp: float) -> Dict[str, Any]:
"""The file-mailbox payload for a queued on-demand command. """The on-demand request dict for a queued on-demand command.
The display hands socket commands to the same code that handles the The display hands socket commands to the same code that handles
mailbox (``DisplayController._handle_on_demand_request``), so a command plugins' own requests (``DisplayController._handle_on_demand_request``),
behaves identically whichever way it arrived, and a request that came so a command behaves identically whichever way it arrived. (This was
both ways (a client that timed out and fell back) is processed once: the the file mailbox's payload, which the display no longer reads.)
request id is the same.
""" """
if isinstance(args, OnDemandStartArgs): if isinstance(args, OnDemandStartArgs):
return {'request_id': request_id, 'action': 'start', 'plugin_id': args.plugin_id, return {'request_id': request_id, 'action': 'start', 'plugin_id': args.plugin_id,
+13 -12
View File
@@ -3,9 +3,9 @@
A small threaded server on a Unix stream socket (``/run/ledmatrix/control.sock`` A small threaded server on a Unix stream socket (``/run/ledmatrix/control.sock``
by default; see :mod:`src.ipc.contract` for the protocol). It never touches by default; see :mod:`src.ipc.contract` for the protocol). It never touches
rendering: a command that changes the panel is validated, put on a bounded rendering: a command that changes the panel is validated, put on a bounded
queue and acknowledged, and the render thread drains that queue at the point queue and acknowledged, and the render thread drains that queue
where it reads the file mailbox (``DisplayController._poll_on_demand_requests``), (``DisplayController._poll_on_demand_requests``), handing each on-demand
handing each command to the same code. Queries (``on_demand.status``) are command to the code that handles plugins' own requests. Queries (``on_demand.status``) are
answered from a snapshot callable the display provides, and the few commands answered from a snapshot callable the display provides, and the few commands
that touch nothing the render thread owns (``errors.clear``) by a handler the that touch nothing the render thread owns (``errors.clear``) by a handler the
display registers, on the connection thread. display registers, on the connection thread.
@@ -110,8 +110,8 @@ MAX_CLIENTS = 8
#: Commands waiting for the render thread. It drains them at least every #: Commands waiting for the render thread. It drains them at least every
#: 0.25 s, so a full queue means the render thread is stuck, and the client #: 0.25 s, so a full queue means the render thread is stuck, and the client
#: is told ``busy`` instead of piling up work. The mailbox would not be read #: is told ``busy`` instead of piling up work, and the web interface reports
#: either, so the web interface reports the failure rather than fall back. #: the failure.
QUEUE_SIZE = 16 QUEUE_SIZE = 16
#: Timeout for one recv()/send() on a connection. #: Timeout for one recv()/send() on a connection.
@@ -185,7 +185,7 @@ class QueuedCommand:
outcome: Optional[CommandOutcome] = field(default=None, compare=False, repr=False) outcome: Optional[CommandOutcome] = field(default=None, compare=False, repr=False)
def as_on_demand_request(self) -> Dict[str, Any]: def as_on_demand_request(self) -> Dict[str, Any]:
"""The mailbox-shaped payload the display's on-demand handler takes.""" """The on-demand request dict the display's on-demand handler takes."""
if not isinstance(self.args, (OnDemandStartArgs, OnDemandStopArgs)): if not isinstance(self.args, (OnDemandStartArgs, OnDemandStopArgs)):
raise TypeError(f'{self.cmd} is not an on-demand command') raise TypeError(f'{self.cmd} is not an on-demand command')
return on_demand_request(self.request_id, self.args, self.received_at) return on_demand_request(self.request_id, self.args, self.received_at)
@@ -619,8 +619,8 @@ class ControlServer:
def start(self) -> bool: def start(self) -> bool:
"""Bind and start serving. False (logged) when the socket cannot be served. """Bind and start serving. False (logged) when the socket cannot be served.
Never raises: without the socket the web interface uses the file Never raises: without the socket the display runs, but the web
mailbox, exactly as before. interface cannot send it commands.
""" """
if not socket_supported(): if not socket_supported():
logger.debug("Control socket not started: no Unix sockets on this platform") logger.debug("Control socket not started: no Unix sockets on this platform")
@@ -632,7 +632,7 @@ class ControlServer:
self._bind() self._bind()
except OSError as e: except OSError as e:
logger.warning("Control socket not started at %s (%s); the web interface " logger.warning("Control socket not started at %s (%s); the web interface "
"will use the file mailbox", self.path, e) "cannot send this display commands", self.path, e)
self._close_socket() self._close_socket()
return False return False
self._stopping.clear() self._stopping.clear()
@@ -1134,12 +1134,13 @@ def start_control_server(status_provider: Optional[StatusProvider] = None,
"""Start the display's control socket, or return None when it can't run. """Start the display's control socket, or return None when it can't run.
None covers Windows, ``LEDMATRIX_CONTROL_SOCKET=off`` and any failure to None covers Windows, ``LEDMATRIX_CONTROL_SOCKET=off`` and any failure to
bind; in every case the web interface falls back to the file mailbox bind; in every case the web interface cannot send the display commands,
and to the cache keys the display still writes. and reads the cache keys the display still writes.
""" """
path = server_socket_path(environ) path = server_socket_path(environ)
if path is None: if path is None:
logger.debug("Control socket disabled or unsupported here; using the file mailbox only") logger.debug("Control socket disabled or unsupported here; the web interface "
"cannot send this display commands")
return None return None
server = ControlServer(path, status_provider, resolve_socket_group(cache_dir), server = ControlServer(path, status_provider, resolve_socket_group(cache_dir),
state_hub=state_hub, handlers=handlers) state_hub=state_hub, handlers=handlers)
+7 -7
View File
@@ -1093,16 +1093,16 @@ class BasePlugin(ABC):
Returns: Returns:
The request id once the display has queued it, or None when The request id once the display has queued it, or None when
there is no display in this process to ask (the web interface, there is no display in this process to ask (the web interface,
scripts/check_plugin.py) or its queue is full. A plugin that scripts/check_plugin.py) or its queue is full. Nothing else can
also runs on cores without this method writes the take the request then: the ``display_on_demand_request`` file
``display_on_demand_request`` mailbox on None, as before; see mailbox older cores read is gone, and a write to it is dropped
"On-demand display" in docs/PLUGIN_API_REFERENCE.md. with a warning. See "On-demand display" in
docs/PLUGIN_API_REFERENCE.md.
Example:: Example::
if not (hasattr(self, 'request_on_demand') if self.request_on_demand(mode='my_alert', duration=15) is None:
and self.request_on_demand(mode='my_alert', duration=15)): self.logger.info("No display to show the alert on")
self._write_on_demand_mailbox(...) # older cores
""" """
request = getattr(getattr(self, 'plugin_manager', None), 'request_on_demand', None) request = getattr(getattr(self, 'plugin_manager', None), 'request_on_demand', None)
if not callable(request): if not callable(request):
+1 -1
View File
@@ -1863,7 +1863,7 @@ class PluginManager:
"""Route plugins' on-demand requests to ``handler`` (None: nowhere). """Route plugins' on-demand requests to ``handler`` (None: nowhere).
The display controller sets its ``submit_plugin_on_demand`` here The display controller sets its ``submit_plugin_on_demand`` here
before any plugin loads. The handler takes a mailbox-shaped request before any plugin loads. The handler takes an on-demand request dict
from any thread, queues it for the render thread and returns True, from any thread, queues it for the render thread and returns True,
or False when it could not. A plugin manager with no handler (the or False when it could not. A plugin manager with no handler (the
web interface's, a test's, scripts/check_plugin.py's) has no screen web interface's, a test's, scripts/check_plugin.py's) has no screen
+15 -9
View File
@@ -155,13 +155,6 @@ class FakeCache:
self._writes += 1 self._writes += 1
self._written[key] = self._writes self._written[key] = self._writes
def file_signature(self, key):
"""CacheManager.file_signature: None without a file, else a value
that changes with every write."""
if key not in self.data:
return None
return (self._written.get(key, 0), 0, 0)
def delete(self, key): def delete(self, key):
self.data.pop(key, None) self.data.pop(key, None)
@@ -729,10 +722,23 @@ class RunLoopHarness:
self.controller.available_modes.append(mode) self.controller.available_modes.append(mode)
def on_demand_request(self, t: float, request_id: str, action: str = "start", **fields): def on_demand_request(self, t: float, request_id: str, action: str = "start", **fields):
"""An on-demand start or stop from the web interface at ``t``: a
command on the control socket (served for the run if no test did),
which is the only way the web interface reaches the display."""
from src.ipc.contract import Command, parse_args
from src.ipc.server import QueuedCommand
server = self.controller._control_server
if not isinstance(server, FakeControlServer):
server = self.control_socket()
cmd = Command.ON_DEMAND_START if action == "start" else Command.ON_DEMAND_STOP
command = QueuedCommand(request_id=request_id, cmd=cmd,
args=parse_args(cmd, fields if action == "start" else {}),
received_at=0.0)
def post(): def post():
self.log("request", f"{action}:{request_id}") self.log("request", f"{action}:{request_id}")
self.cache.set("display_on_demand_request", server.queue.append(command)
{"request_id": request_id, "action": action, **fields})
self.clock.at(t, post) self.clock.at(t, post)
def restore_on_demand(self, plugin_id: str, mode: Optional[str] = None, def restore_on_demand(self, plugin_id: str, mode: Optional[str] = None,
+3 -3
View File
@@ -1,16 +1,16 @@
{ {
"screens": [ "screens": [
[0.0, "clock", 20.0, "duration", 20, false], [0.0, "clock", 20.0, "duration", 20, false],
[20.0, "weather", 5.0, "on-demand-start", 6, true], [20.0, "weather", 5.0, "on-demand-start", 5, true],
[25.0, "sports_recent", 15.0, "duration", 15, true], [25.0, "sports_recent", 15.0, "duration", 15, true],
[40.0, "sports_upcoming", 15.0, "duration", 15, true], [40.0, "sports_upcoming", 15.0, "duration", 15, true],
[55.0, "sports_recent", 15.0, "duration", 15, true], [55.0, "sports_recent", 15.0, "duration", 15, true],
[70.0, "sports_upcoming", 15.0, "duration", 15, true], [70.0, "sports_upcoming", 15.0, "duration", 15, true],
[85.0, "sports_recent", 10.0, "on-demand-requested-stop", 11, true], [85.0, "sports_recent", 10.0, "on-demand-requested-stop", 10, true],
[95.0, "weather", 20.0, "duration", 20, true], [95.0, "weather", 20.0, "duration", 20, true],
[115.0, "sports_recent", 15.0, "duration", 15, true], [115.0, "sports_recent", 15.0, "duration", 15, true],
[130.0, "sports_upcoming", 15.0, "duration", 15, true], [130.0, "sports_upcoming", 15.0, "duration", 15, true],
[145.0, "clock", 5.0, "on-demand-start", 6, true], [145.0, "clock", 5.0, "on-demand-start", 5, true],
[150.0, "weather", 20.0, "duration", 20, true], [150.0, "weather", 20.0, "duration", 20, true],
[170.0, "weather", 10.0, "on-demand-expired", 10, true], [170.0, "weather", 10.0, "on-demand-expired", 10, true],
[180.0, "clock", 20.0, "duration", 20, true], [180.0, "clock", 20.0, "duration", 20, true],
+4 -4
View File
@@ -1,18 +1,18 @@
{ {
"screens": [ "screens": [
[0.0, "clock", 5.0, "on-demand-start", 6, false], [0.0, "clock", 5.0, "on-demand-start", 5, false],
[5.0, "sports_live", 15.0, "duration", 15, true], [5.0, "sports_live", 15.0, "duration", 15, true],
[20.0, "sports_recent", 15.0, "duration", 15, true], [20.0, "sports_recent", 15.0, "duration", 15, true],
[35.0, "sports_upcoming", 5.0, "on-demand-requested-stop", 6, true], [35.0, "sports_upcoming", 5.0, "on-demand-requested-stop", 5, true],
[40.0, "clock", 20.0, "duration", 20, true], [40.0, "clock", 20.0, "duration", 20, true],
[60.0, "sports_live", 15.0, "display-false", 11, true], [60.0, "sports_live", 15.0, "display-false", 11, true],
[75.0, "sports_recent", 15.0, "duration", 15, true], [75.0, "sports_recent", 15.0, "duration", 15, true],
[90.0, "sports_upcoming", 10.0, "on-demand-start", 11, true], [90.0, "sports_upcoming", 10.0, "on-demand-start", 10, true],
[100.0, "sports_live", 0.0, "empty", 1, true], [100.0, "sports_live", 0.0, "empty", 1, true],
[100.0, "sports_recent", 15.0, "duration", 15, true], [100.0, "sports_recent", 15.0, "duration", 15, true],
[115.0, "sports_upcoming", 15.0, "duration", 15, true], [115.0, "sports_upcoming", 15.0, "duration", 15, true],
[130.0, "sports_live", 0.0, "empty", 1, true], [130.0, "sports_live", 0.0, "empty", 1, true],
[130.0, "sports_recent", 10.0, "on-demand-requested-stop", 11, true], [130.0, "sports_recent", 10.0, "on-demand-requested-stop", 10, true],
[140.0, "sports_upcoming", 15.0, "duration", 15, true], [140.0, "sports_upcoming", 15.0, "duration", 15, true],
[155.0, "clock", 5.0, "horizon", 5, true] [155.0, "clock", 5.0, "horizon", 5, true]
], ],
+2 -2
View File
@@ -1,11 +1,11 @@
{ {
"screens": [ "screens": [
[0.0, "clock", 12.0, "on-demand-start", 13, false], [0.0, "clock", 12.0, "on-demand-start", 12, false],
[12.0, "sports_upcoming", 15.0, "duration", 15, true], [12.0, "sports_upcoming", 15.0, "duration", 15, true],
[27.0, "sports_upcoming", 15.0, "duration", 15, true], [27.0, "sports_upcoming", 15.0, "duration", 15, true],
[42.0, "sports_upcoming", 15.0, "duration", 15, true], [42.0, "sports_upcoming", 15.0, "duration", 15, true],
[57.0, "sports_upcoming", 15.0, "duration", 15, true], [57.0, "sports_upcoming", 15.0, "duration", 15, true],
[72.0, "sports_upcoming", 8.0, "on-demand-start", 9, true], [72.0, "sports_upcoming", 8.0, "on-demand-start", 8, true],
[80.0, "app_a", 0.0, "empty", 1, true], [80.0, "app_a", 0.0, "empty", 1, true],
[80.0, "app_b", 10.0, "duration", 10, true], [80.0, "app_b", 10.0, "duration", 10, true],
[90.0, "app_a", 0.0, "empty", 1, true], [90.0, "app_a", 0.0, "empty", 1, true],
+11 -11
View File
@@ -6,22 +6,22 @@
[70.255, "sports_live", 20.0, "duration", 20, true], [70.255, "sports_live", 20.0, "duration", 20, true],
[90.255, "sports_live", 20.0, "display-false", 11, false], [90.255, "sports_live", 20.0, "display-false", 11, false],
[110.255, "<vegas>", 30.008, "duration", 3751, null], [110.255, "<vegas>", 30.008, "duration", 3751, null],
[140.263, "<vegas>", 10.0, "on-demand-start", 1250, null], [140.263, "<vegas>", 9.744, "on-demand-start", 1218, null],
[150.263, "clock", 20.0, "duration", 20, true], [150.007, "clock", 20.0, "duration", 20, true],
[170.263, "clock", 5.0, "on-demand-expired", 5, true], [170.007, "clock", 5.0, "on-demand-expired", 5, true],
[175.263, "<vegas>", 24.959, "vegas-interrupt", 3120, null], [175.007, "<vegas>", 25.999, "vegas-interrupt", 3250, null],
[200.222, "<wifi>", 3.0, "duration", 6, null], [201.006, "<wifi>", 2.0, "duration", 4, null],
[203.222, "<vegas>", 30.008, "duration", 3751, null], [203.006, "<vegas>", 30.008, "duration", 3751, null],
[233.23, "<vegas>", 26.77, "horizon", 3347, null] [233.014, "<vegas>", 26.986, "horizon", 3374, null]
], ],
"events": [ "events": [
[70.255, "vegas-live"], [70.255, "vegas-live"],
[70.255, "live", "sports_live"], [70.255, "live", "sports_live"],
[150.0, "request", "start:v1"], [150.0, "request", "start:v1"],
[150.263, "on-demand-start", "clock"], [150.007, "on-demand-start", "clock"],
[150.263, "vegas-interrupt"], [150.007, "vegas-interrupt"],
[175.263, "on-demand-expired"], [175.007, "on-demand-expired"],
[200.0, "wifi-file", "Connected to HomeNet"], [200.0, "wifi-file", "Connected to HomeNet"],
[200.222, "vegas-interrupt"] [201.006, "vegas-interrupt"]
] ]
} }
+66 -83
View File
@@ -5,18 +5,19 @@ the web UI and the MQTT bridge send) as "restart": with the service running it
ran ``systemctl stop``, slept 1.5s and started it again. Every on-demand or ran ``systemctl stop``, slept 1.5s and started it again. Every on-demand or
"Preview on display" click therefore cold-restarted the display process -- "Preview on display" click therefore cold-restarted the display process --
every plugin reloaded, the panel blank for seconds -- to deliver a request the every plugin reloaded, the panel blank for seconds -- to deliver a request the
running process polls for every ON_DEMAND_POLL_INTERVAL anyway (see running process takes within a frame over its control socket anyway (see
test_on_demand_mailbox.py and test_display_pending_changes.py for the display test_display_pending_changes.py for the display side: commands land
side: the mailbox is read mid-dwell, mid-screen and mid-Vegas-iteration). mid-dwell, mid-screen and mid-Vegas-iteration).
The restart did not buy anything either: a freshly started display restores The restart did not buy anything either: a freshly started display restores
only the on-demand session it saved itself (``display_on_demand_config``), so only the on-demand session it saved itself (``display_on_demand_config``).
the new request reached it through the same mailbox, one cold start later.
This file previously pinned that restart path (it guarded a broken This file previously pinned that restart path (it guarded a broken
``import _pkg.time`` inside it). The path is gone; these tests pin its ``import _pkg.time`` inside it). The path is gone; these tests pin its
replacement: a running service is left alone, a stopped one is started (only replacement: a running service is left alone, a stopped one is started (only
when start_service is set), and the request lands in the mailbox either way. when start_service is set), and the request goes over the control socket
either way -- to a stopped display once it has started and its socket is up.
Nothing is ever written to the cache: the file mailbox is gone (stage 5).
The service helpers are patched where they run. display.py binds The service helpers are patched where they run. display.py binds
_get_display_service_status by value, while _ensure_display_service_running _get_display_service_status by value, while _ensure_display_service_running
@@ -34,6 +35,8 @@ sys.path.insert(0, str(Path(__file__).parent.parent))
from test._api_v3_test_helpers import api_v3_client, api_v3_module # noqa: F401,E402 from test._api_v3_test_helpers import api_v3_client, api_v3_module # noqa: F401,E402
from src.ipc import client as control_client # noqa: E402
START_URL = "/api/v3/display/on-demand/start" START_URL = "/api/v3/display/on-demand/start"
STOP_URL = "/api/v3/display/on-demand/stop" STOP_URL = "/api/v3/display/on-demand/stop"
MAILBOX = "display_on_demand_request" MAILBOX = "display_on_demand_request"
@@ -46,7 +49,10 @@ def service(api_v3_module):
plugin_manager and config_manager are None so the route skips plugin plugin_manager and config_manager are None so the route skips plugin
resolution (not what is under test here). The cache is the blueprint's resolution (not what is under test here). The cache is the blueprint's
MagicMock cache_manager, so mailbox writes are visible as set() calls. MagicMock cache_manager, so a write would be visible as a set() call.
The control socket answers while the service is active and is missing
(``no_socket``) while it is not; ``sent`` records what it carried.
""" """
api_v3_module.api_v3.plugin_catalog = None api_v3_module.api_v3.plugin_catalog = None
api_v3_module.api_v3.config_manager = None api_v3_module.api_v3.config_manager = None
@@ -62,7 +68,32 @@ def service(api_v3_module):
state["active"] = False state["active"] = False
return {"returncode": 0, "stdout": "", "stderr": ""} return {"returncode": 0, "stdout": "", "stderr": ""}
with patch("web_interface.blueprints.api_v3._get_display_service_status", sent = []
def socket(action):
def call(request_id, *args, **kwargs):
if not state["active"]:
raise control_client.ControlError("no_socket", "x", sent=False)
sent.append((action, request_id) + args)
return {"accepted": True, "request_id": request_id}
return call
class Clock:
now = 1000.0
def monotonic(self):
return self.now
def time(self):
return self.now
def sleep(self, seconds):
self.now += seconds
with patch("web_interface.blueprints.api_v3.time", Clock()), \
patch(f"{DISPLAY}.control_client.on_demand_start", side_effect=socket("start")), \
patch(f"{DISPLAY}.control_client.on_demand_stop", side_effect=socket("stop")), \
patch("web_interface.blueprints.api_v3._get_display_service_status",
side_effect=status), \ side_effect=status), \
patch("web_interface.blueprints.api_v3.display._get_display_service_status", patch("web_interface.blueprints.api_v3.display._get_display_service_status",
side_effect=status), \ side_effect=status), \
@@ -74,6 +105,7 @@ def service(api_v3_module):
"systemctl": run_systemctl, "systemctl": run_systemctl,
"stop_service": stop_service, "stop_service": stop_service,
"cache": api_v3_module.api_v3.cache_manager, "cache": api_v3_module.api_v3.cache_manager,
"sent": sent,
} }
@@ -99,19 +131,15 @@ class TestStartWhileTheServiceIsRunning:
assert _systemctl_verbs(service["systemctl"]) == [], ( assert _systemctl_verbs(service["systemctl"]) == [], (
"a running display service was sent a systemctl command") "a running display service was sent a systemctl command")
def test_the_request_is_posted_for_the_running_display(self, api_v3_client, service): def test_the_request_is_sent_to_the_running_display(self, api_v3_client, service):
response = api_v3_client.post( response = api_v3_client.post(
START_URL, json={"plugin_id": "weather", "mode": "weather_current", START_URL, json={"plugin_id": "weather", "mode": "weather_current",
"duration": 60, "pinned": True}) "duration": 60, "pinned": True})
data = response.get_json()["data"] data = response.get_json()["data"]
writes = _mailbox_writes(service["cache"]) assert service["sent"] == [("start", data["request_id"], "weather",
assert len(writes) == 1 "weather_current", 60, True)]
assert writes[0]["action"] == "start" assert data["transport"] == "socket"
assert writes[0]["request_id"] == data["request_id"] assert _mailbox_writes(service["cache"]) == []
assert writes[0]["plugin_id"] == "weather"
assert writes[0]["mode"] == "weather_current"
assert writes[0]["duration"] == 60
assert writes[0]["pinned"] is True
def test_the_response_reports_the_service_was_not_started(self, api_v3_client, service): def test_the_response_reports_the_service_was_not_started(self, api_v3_client, service):
data = api_v3_client.post(START_URL, json={"plugin_id": "weather"}).get_json()["data"] data = api_v3_client.post(START_URL, json={"plugin_id": "weather"}).get_json()["data"]
@@ -132,8 +160,9 @@ class TestStartWhileTheServiceIsStopped:
assert response.status_code == 200, response.get_json() assert response.status_code == 200, response.get_json()
assert _systemctl_verbs(service["systemctl"]) == ["start"] assert _systemctl_verbs(service["systemctl"]) == ["start"]
service["stop_service"].assert_not_called() service["stop_service"].assert_not_called()
# Written before the start, so the new process finds it on its first poll. # Sent once the started display's socket answered.
assert len(_mailbox_writes(service["cache"])) == 1 assert [s[0] for s in service["sent"]] == ["start"]
assert _mailbox_writes(service["cache"]) == []
def test_without_start_service_it_is_left_stopped(self, api_v3_client, service): def test_without_start_service_it_is_left_stopped(self, api_v3_client, service):
service["state"]["active"] = False service["state"]["active"] = False
@@ -141,6 +170,7 @@ class TestStartWhileTheServiceIsStopped:
START_URL, json={"plugin_id": "weather", "start_service": "false"}) START_URL, json={"plugin_id": "weather", "start_service": "false"})
assert response.status_code == 400 assert response.status_code == 400
assert _systemctl_verbs(service["systemctl"]) == [] assert _systemctl_verbs(service["systemctl"]) == []
assert service["sent"] == []
def test_a_start_that_fails_is_reported(self, api_v3_client, service): def test_a_start_that_fails_is_reported(self, api_v3_client, service):
service["state"]["active"] = False service["state"]["active"] = False
@@ -151,31 +181,12 @@ class TestStartWhileTheServiceIsStopped:
assert response.get_json()["status"] == "error" assert response.get_json()["status"] == "error"
class _Mailbox:
"""The CacheManager calls the routes make, over a dict."""
def __init__(self):
self.entries = {}
def set(self, key, value, ttl=None):
self.entries[key] = value
def get(self, key, max_age=300, memory_ttl=None):
return self.entries.get(key)
def delete(self, key):
self.entries.pop(key, None)
class TestARefusedStartLeavesNoRequestBehind: class TestARefusedStartLeavesNoRequestBehind:
"""A start the route answers with an error must not run later. """A start the route answers with an error must not run later.
The request was posted (to the mailbox, with the display stopped) before With the mailbox, the request was posted before the route refused it, and
the route refused it, and the display reads the mailbox for an hour a display started later ran it. Now nothing is written anywhere: the
without looking at a request's age. So "Display service is not running" request only ever goes over the socket, to a display that answers.
(start_service off) or "Failed to start display service" left the
request waiting, and the next time the display started -- minutes later,
by hand -- it ran that plugin, pinned if the request said so.
A socket acknowledgement is the other side of it: the display answered, A socket acknowledgement is the other side of it: the display answered,
so it is running and has the request, whatever systemd says (a display so it is running and has the request, whatever systemd says (a display
@@ -184,76 +195,48 @@ class TestARefusedStartLeavesNoRequestBehind:
""" """
@pytest.fixture @pytest.fixture
def mailbox(self, api_v3_module, service): def stopped(self, service):
box = _Mailbox()
api_v3_module.api_v3.cache_manager = box
service["state"]["active"] = False service["state"]["active"] = False
return box return service
@pytest.mark.parametrize("body", [ @pytest.mark.parametrize("body", [
{"plugin_id": "weather", "start_service": False}, {"plugin_id": "weather", "start_service": False},
{"plugin_id": "weather"}, # start_service defaults on {"plugin_id": "weather"}, # start_service defaults on
]) ])
def test_a_socket_ack_is_a_success_whatever_systemd_says( def test_a_socket_ack_is_a_success_whatever_systemd_says(
self, api_v3_client, service, mailbox, body): self, api_v3_client, stopped, body):
with patch(f"{DISPLAY}.control_client.on_demand_start", with patch(f"{DISPLAY}.control_client.on_demand_start",
side_effect=lambda request_id, *a: {"accepted": True}): side_effect=lambda request_id, *a: {"accepted": True}):
response = api_v3_client.post(START_URL, json=body) response = api_v3_client.post(START_URL, json=body)
assert response.status_code == 200, response.get_json() assert response.status_code == 200, response.get_json()
assert response.get_json()["data"]["transport"] == "socket" assert response.get_json()["data"]["transport"] == "socket"
assert MAILBOX not in mailbox.entries assert _systemctl_verbs(stopped["systemctl"]) == [], (
assert _systemctl_verbs(service["systemctl"]) == [], (
"a unit was started beside a display that answered the socket") "a unit was started beside a display that answered the socket")
def test_without_start_service_the_request_is_taken_back( def test_without_start_service_nothing_is_left_behind(self, api_v3_client, stopped):
self, api_v3_client, service, mailbox):
response = api_v3_client.post(START_URL, json={ response = api_v3_client.post(START_URL, json={
"plugin_id": "weather", "pinned": True, "start_service": False}) "plugin_id": "weather", "pinned": True, "start_service": False})
assert response.status_code == 400 assert response.status_code == 400
assert response.get_json()["status"] == "error" assert response.get_json()["status"] == "error"
assert MAILBOX not in mailbox.entries assert stopped["cache"].set.call_count == 0
assert stopped["sent"] == []
def test_a_start_that_fails_takes_its_request_back(self, api_v3_client, service, mailbox): def test_a_start_that_fails_leaves_nothing_behind(self, api_v3_client, stopped):
service["systemctl"].side_effect = lambda args: { stopped["systemctl"].side_effect = lambda args: {
"returncode": 1, "stdout": "", "stderr": "denied"} "returncode": 1, "stdout": "", "stderr": "denied"}
response = api_v3_client.post(START_URL, json={"plugin_id": "weather"}) response = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert response.status_code == 500 assert response.status_code == 500
assert MAILBOX not in mailbox.entries assert stopped["cache"].set.call_count == 0
assert stopped["sent"] == []
def test_a_newer_request_is_left_alone_on_the_400(self, api_v3_client, service, mailbox):
newer = {"request_id": "someone-else", "action": "start", "plugin_id": "clock"}
def stopped_and_another_post_lands(*args):
mailbox.entries[MAILBOX] = newer
return {"active": False}
with patch(f"{DISPLAY}._get_display_service_status",
side_effect=stopped_and_another_post_lands):
response = api_v3_client.post(START_URL, json={
"plugin_id": "weather", "start_service": False})
assert response.status_code == 400
assert mailbox.entries[MAILBOX] is newer
def test_a_newer_request_is_left_alone_on_the_500(self, api_v3_client, service, mailbox):
newer = {"request_id": "someone-else", "action": "start", "plugin_id": "clock"}
def start_fails_after_another_post(args):
mailbox.entries[MAILBOX] = newer
return {"returncode": 1, "stdout": "", "stderr": "denied"}
service["systemctl"].side_effect = start_fails_after_another_post
response = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert response.status_code == 500
assert mailbox.entries[MAILBOX] is newer
class TestStop: class TestStop:
def test_stop_posts_a_stop_request_and_leaves_the_service_running( def test_stop_sends_a_stop_request_and_leaves_the_service_running(
self, api_v3_client, service): self, api_v3_client, service):
response = api_v3_client.post(STOP_URL, json={}) response = api_v3_client.post(STOP_URL, json={})
assert response.status_code == 200, response.get_json() assert response.status_code == 200, response.get_json()
writes = _mailbox_writes(service["cache"]) assert [s[0] for s in service["sent"]] == ["stop"]
assert [w["action"] for w in writes] == ["stop"] assert _mailbox_writes(service["cache"]) == []
service["stop_service"].assert_not_called() service["stop_service"].assert_not_called()
assert _systemctl_verbs(service["systemctl"]) == [] assert _systemctl_verbs(service["systemctl"]) == []
+231 -85
View File
@@ -1,15 +1,12 @@
"""POST /display/on-demand/start and /stop: control socket first, mailbox fallback. """POST /display/on-demand/start and /stop: the control socket is the only way.
The routes hand the request to the display over the control socket The routes hand the request to the display over the control socket
(src/ipc) and get an acknowledgement. When the socket could not carry the (src/ipc) and get an acknowledgement. The file mailbox they used to fall
request -- no socket (a stopped display, or one older than the socket), a back to (``display_on_demand_request``) is gone (stage 5), so nothing is
refused or timed-out connect, a display too old to know the command, a bug ever written to the cache. When no display is listening (a stopped one, or
in the client -- they write the file mailbox exactly as they did before the one still starting) the start route starts the service if asked to and
socket existed. When the display had the request and failed it (a full sends the request again once the socket is up; every other failure is
queue, bad arguments, no answer in time) the route says so and writes answered as what it is.
nothing. These tests pin each path, that at most one of them is used, that
the response says which, and that the request id is the same either way (the
display deduplicates on it).
The socket client is patched at the route's module attribute; the last class The socket client is patched at the route's module attribute; the last class
runs a real server on a temp socket (Linux/macOS only). runs a real server on a temp socket (Linux/macOS only).
@@ -33,11 +30,12 @@ START_URL = "/api/v3/display/on-demand/start"
STOP_URL = "/api/v3/display/on-demand/stop" STOP_URL = "/api/v3/display/on-demand/stop"
MAILBOX = "display_on_demand_request" MAILBOX = "display_on_demand_request"
CLIENT = "web_interface.blueprints.api_v3.display.control_client" CLIENT = "web_interface.blueprints.api_v3.display.control_client"
DISPLAY = "web_interface.blueprints.api_v3.display"
@pytest.fixture @pytest.fixture
def service(api_v3_module): def service(api_v3_module):
"""A running display service; records systemctl calls and mailbox writes.""" """A running display service; records systemctl calls and cache writes."""
api_v3_module.api_v3.plugin_catalog = None api_v3_module.api_v3.plugin_catalog = None
api_v3_module.api_v3.config_manager = None api_v3_module.api_v3.config_manager = None
state = {"active": True} state = {"active": True}
@@ -101,85 +99,240 @@ class TestSocketPath:
assert _mailbox_writes(service["cache"]) == [] assert _mailbox_writes(service["cache"]) == []
class TestMailboxFallback: class FakeTime:
@pytest.mark.parametrize("reason", [ """Stands in for the route's ``time`` module: sleep() moves the clock."""
"no_socket", "refused", "timeout", "closed", "bad_response", "invalid_request",
"busy", "forbidden", "unknown_command", "unsupported_version", "disabled",
"unsupported",
])
def test_a_request_the_socket_never_carried_writes_the_mailbox(
self, api_v3_client, service, reason):
# sent=False: the display never had it (no socket, a refused or
# timed-out connect, turned away at the door).
with patch(f"{CLIENT}.on_demand_start",
side_effect=control_client.ControlError(reason, "x", sent=False)):
resp = api_v3_client.post(START_URL, json={
"plugin_id": "weather", "mode": "weather_current",
"duration": 60, "pinned": True})
assert resp.status_code == 200
data = resp.get_json()["data"]
assert data["transport"] == "mailbox"
assert data["socket_error"] == reason
[write] = _mailbox_writes(service["cache"])
assert write["request_id"] == data["request_id"]
assert write["action"] == "start"
assert (write["plugin_id"], write["mode"], write["duration"], write["pinned"]) == \
("weather", "weather_current", 60, True)
def test_a_client_bug_still_falls_back(self, api_v3_client, service): def __init__(self):
self.now = 1000.0
self.sleeps = 0
def monotonic(self):
return self.now
def time(self):
return self.now
def sleep(self, seconds):
self.sleeps += 1
self.now += seconds
@pytest.fixture
def clock():
fake = FakeTime()
with patch("web_interface.blueprints.api_v3.time", fake):
yield fake
def _attempts(*outcomes, calls=None, clock=None):
"""A fake on_demand_start/stop that answers ``outcomes`` in turn (an
exception is raised, anything else acks); the last one repeats."""
outcomes = list(outcomes)
seen = calls if calls is not None else []
def attempt(request_id, *a, **kw):
seen.append(clock.now if clock is not None else None)
outcome = outcomes.pop(0) if len(outcomes) > 1 else outcomes[0]
if isinstance(outcome, BaseException):
raise outcome
return _ack(request_id)
return attempt
def _no_socket():
return control_client.ControlError("no_socket", "x", sent=False)
class TestNoDisplayListening:
"""No socket to talk to: the display is stopped, or still starting."""
def test_a_display_still_starting_gets_the_request_once_it_listens(
self, api_v3_client, service, clock):
calls = []
with patch(f"{CLIENT}.on_demand_start",
side_effect=_attempts(_no_socket(), _no_socket(), "ack",
calls=calls, clock=clock)):
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert resp.status_code == 200, resp.get_json()
data = resp.get_json()["data"]
assert data["transport"] == "socket" and "socket_error" not in data
assert data["service"]["started"] is False
assert len(calls) == 3
assert not [c for c in service["calls"] if c[0] == "systemctl"]
assert _mailbox_writes(service["cache"]) == []
def test_a_stopped_display_is_started_and_then_sent_the_request(
self, api_v3_client, service, clock):
service["state"]["active"] = False
calls = []
with patch(f"{CLIENT}.on_demand_start",
side_effect=_attempts(*[_no_socket()] * 6, "ack",
calls=calls, clock=clock)) as start:
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather",
"duration": 30})
assert resp.status_code == 200, resp.get_json()
data = resp.get_json()["data"]
assert data["transport"] == "socket"
assert data["service"]["started"] is True
assert service["calls"] == [("systemctl", "start")]
assert len(calls) == 7
# The same request, the same id, every time.
assert {call.args[0] for call in start.call_args_list} == {data["request_id"]}
assert _mailbox_writes(service["cache"]) == []
def test_a_stopped_display_without_start_service_is_an_error(
self, api_v3_client, service, clock):
service["state"]["active"] = False
with patch(f"{CLIENT}.on_demand_start", side_effect=_no_socket()) as start:
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather",
"start_service": False})
assert resp.status_code == 400
body = resp.get_json()
assert "not running" in body["message"]
assert body["data"]["socket_error"] == "no_socket"
assert start.call_count == 1 and clock.sleeps == 0
assert service["calls"] == []
def test_a_display_that_never_comes_up_is_given_up_on(self, api_v3_client, service, clock):
from web_interface.blueprints.api_v3 import display
service["state"]["active"] = False
calls = []
with patch(f"{CLIENT}.on_demand_start",
side_effect=_attempts(_no_socket(), calls=calls, clock=clock)):
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert resp.status_code == 503
body = resp.get_json()
assert body["data"]["socket_error"] == "no_socket"
assert body["data"]["service"]["started"] is True
assert "did not answer within 45 seconds" in body["message"]
waited = calls[-1] - calls[1]
assert display.ON_DEMAND_SOCKET_WAIT_SECONDS - 1 <= waited \
<= display.ON_DEMAND_SOCKET_WAIT_SECONDS
assert _mailbox_writes(service["cache"]) == []
def test_a_running_service_without_a_socket_is_waited_for_less(
self, api_v3_client, service, clock):
from web_interface.blueprints.api_v3 import display
calls = []
with patch(f"{CLIENT}.on_demand_start",
side_effect=_attempts(_no_socket(), calls=calls, clock=clock)):
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert resp.status_code == 503
assert f"within {int(display.ON_DEMAND_SOCKET_WAIT_RUNNING_SECONDS)} seconds" \
in resp.get_json()["message"]
assert calls[-1] - calls[0] <= display.ON_DEMAND_SOCKET_WAIT_RUNNING_SECONDS
assert not [c for c in service["calls"] if c[0] == "systemctl"]
def test_a_service_that_will_not_start_is_an_error(self, api_v3_client, service, clock):
service["state"]["active"] = False
with patch("web_interface.blueprints.api_v3._run_systemctl_command",
return_value={"returncode": 1, "stdout": "", "stderr": "nope"}), \
patch(f"{CLIENT}.on_demand_start", side_effect=_no_socket()) as start:
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert resp.status_code == 500
assert "Failed to start display service" in resp.get_json()["message"]
assert start.call_count == 1
def test_a_different_failure_while_waiting_ends_the_wait(self, api_v3_client, service,
clock):
calls = []
busy = control_client.ControlError("busy", "x", sent=True)
with patch(f"{CLIENT}.on_demand_start",
side_effect=_attempts(_no_socket(), busy, calls=calls, clock=clock)):
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert resp.status_code == 503
assert resp.get_json()["data"]["socket_error"] == "busy"
assert len(calls) == 2
def test_stop_with_no_display_running_is_an_error(self, api_v3_client, service, clock):
service["state"]["active"] = False
with patch(f"{CLIENT}.on_demand_stop", side_effect=_no_socket()) as stop:
resp = api_v3_client.post(STOP_URL, json={})
assert resp.status_code == 503
body = resp.get_json()
assert "not running" in body["message"]
assert body["data"]["socket_error"] == "no_socket"
assert stop.call_count == 1 and clock.sleeps == 0
assert service["calls"] == []
assert _mailbox_writes(service["cache"]) == []
def test_stop_with_a_running_service_but_no_socket_is_an_error(
self, api_v3_client, service, clock):
with patch(f"{CLIENT}.on_demand_stop",
side_effect=control_client.ControlError("refused", "x")):
resp = api_v3_client.post(STOP_URL, json={})
assert resp.status_code == 503
assert "still be starting" in resp.get_json()["message"]
def test_stop_with_stop_service_stops_it_anyway(self, api_v3_client, service, clock):
with patch(f"{CLIENT}.on_demand_stop", side_effect=_no_socket()), \
patch(f"{DISPLAY}._stop_display_service",
return_value={"active": False}) as stop:
resp = api_v3_client.post(STOP_URL, json={"stop_service": True})
assert resp.status_code == 200
assert resp.get_json()["data"]["socket_error"] == "no_socket"
stop.assert_called_once()
assert _mailbox_writes(service["cache"]) == []
def test_the_socket_is_off_in_the_test_suite(self, api_v3_client, service):
# conftest's _hermetic_control_socket: a suite run on a device must
# not drive the live display. Nothing is retried or started for it.
assert os.environ[c.SOCKET_PATH_ENV] == "off"
service["state"]["active"] = False
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert resp.status_code == 503
assert resp.get_json()["data"]["socket_error"] in ("disabled", "unsupported")
assert service["calls"] == []
class TestNothingElseIsRetried:
@pytest.mark.parametrize("reason,sent,status", [
("timeout", False, 503), ("busy", False, 503), ("forbidden", False, 503),
("invalid_request", False, 503), ("disabled", False, 503),
("unsupported", False, 503), ("unknown_command", True, 503),
("unsupported_version", True, 503),
])
def test_answered_at_once_and_nothing_written(self, api_v3_client, service, clock,
reason, sent, status):
service["state"]["active"] = False
with patch(f"{CLIENT}.on_demand_start",
side_effect=control_client.ControlError(reason, "x", sent=sent)) as start:
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert resp.status_code == status
body = resp.get_json()
assert body["status"] == "error"
assert body["data"]["socket_error"] == reason
assert start.call_count == 1 and clock.sleeps == 0
assert service["calls"] == []
def test_a_client_bug_is_an_error(self, api_v3_client, service):
with patch(f"{CLIENT}.on_demand_start", side_effect=RuntimeError("boom")): with patch(f"{CLIENT}.on_demand_start", side_effect=RuntimeError("boom")):
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"}) resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert resp.status_code == 200 assert resp.status_code == 503
assert resp.get_json()["data"]["socket_error"] == "internal" assert resp.get_json()["data"]["socket_error"] == "internal"
assert len(_mailbox_writes(service["cache"])) == 1 assert _mailbox_writes(service["cache"]) == []
def test_an_unknown_reason_is_reported_as_other(self, api_v3_client, service): def test_an_unknown_reason_is_reported_as_other(self, api_v3_client, service):
# Only known codes are echoed back; anything else stays server-side. # Only known codes are echoed back; anything else stays server-side.
with patch(f"{CLIENT}.on_demand_start", with patch(f"{CLIENT}.on_demand_start",
side_effect=control_client.ControlError("/run/secret/path", "x")): side_effect=control_client.ControlError("/run/secret/path", "x")):
data = api_v3_client.post(START_URL, json={"plugin_id": "weather"}).get_json()["data"] resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert data["transport"] == "mailbox" assert resp.status_code == 503
assert data["socket_error"] == "other" assert resp.get_json()["data"]["socket_error"] == "other"
assert len(_mailbox_writes(service["cache"])) == 1 assert "/run/secret" not in resp.get_data(as_text=True)
def test_every_display_error_code_is_reportable(self): def test_every_display_error_code_is_reportable(self):
from web_interface.blueprints.api_v3 import display from web_interface.blueprints.api_v3 import display
codes = {v for k, v in vars(c.ErrorCode).items() if not k.startswith("_")} codes = {v for k, v in vars(c.ErrorCode).items() if not k.startswith("_")}
assert codes <= set(display._REPORTABLE_SOCKET_REASONS) assert codes <= set(display._REPORTABLE_SOCKET_REASONS)
def test_stop_falls_back(self, api_v3_client, service):
with patch(f"{CLIENT}.on_demand_stop",
side_effect=control_client.ControlError("timeout")):
data = api_v3_client.post(STOP_URL, json={}).get_json()["data"]
assert data["transport"] == "mailbox"
[write] = _mailbox_writes(service["cache"])
assert write == {"request_id": data["request_id"], "action": "stop",
"timestamp": write["timestamp"]}
def test_a_stopped_display_gets_the_mailbox_before_it_is_started(
self, api_v3_client, service):
service["state"]["active"] = False
with patch(f"{CLIENT}.on_demand_start",
side_effect=control_client.ControlError("no_socket")):
resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert resp.status_code == 200
assert service["calls"] == [("cache", MAILBOX), ("systemctl", "start")]
def test_the_socket_is_off_in_the_test_suite(self, api_v3_client, service):
# conftest's _hermetic_control_socket: a suite run on a device must
# not drive the live display.
assert os.environ[c.SOCKET_PATH_ENV] == "off"
data = api_v3_client.post(START_URL, json={"plugin_id": "weather"}).get_json()["data"]
assert data["transport"] == "mailbox"
assert data["socket_error"] in ("disabled", "unsupported") # Linux, Windows
class TestTheDisplayHadIt: class TestTheDisplayHadIt:
"""Once the display has the request, its answer stands: no mailbox copy. """Once the display has the request, its answer stands.
A busy queue, a refusal or silence after the request was sent mean the A busy queue, a refusal or silence after the request was sent mean the
display may have applied it, or would refuse the mailbox copy too, so display may have applied it, so the route reports the failure and does
the route reports the failure instead of posting it a second time. not send it again.
""" """
@pytest.mark.parametrize("reason,status", [ @pytest.mark.parametrize("reason,status", [
@@ -217,16 +370,6 @@ class TestTheDisplayHadIt:
stop.assert_called_once() stop.assert_called_once()
assert _mailbox_writes(service["cache"]) == [] assert _mailbox_writes(service["cache"]) == []
@pytest.mark.parametrize("reason", ["unknown_command", "unsupported_version"])
def test_an_older_display_that_does_not_speak_it_gets_the_mailbox(
self, api_v3_client, service, reason):
# The upgrade case: new web interface, display still on an old build.
with patch(f"{CLIENT}.on_demand_start",
side_effect=control_client.ControlError(reason, "x", sent=True)):
data = api_v3_client.post(START_URL, json={"plugin_id": "weather"}).get_json()["data"]
assert data["transport"] == "mailbox" and data["socket_error"] == reason
assert len(_mailbox_writes(service["cache"])) == 1
@pytest.mark.skipif(not c.socket_supported(), reason="AF_UNIX sockets are Linux/macOS only") @pytest.mark.skipif(not c.socket_supported(), reason="AF_UNIX sockets are Linux/macOS only")
class TestRealSocket: class TestRealSocket:
@@ -259,11 +402,14 @@ class TestRealSocket:
assert data["transport"] == "socket" assert data["transport"] == "socket"
assert [x.request_id for x in live.drain()] == [data["request_id"]] assert [x.request_id for x in live.drain()] == [data["request_id"]]
def test_a_display_that_went_away_falls_back(self, api_v3_client, service, live): def test_a_display_that_went_away_is_an_error(self, api_v3_client, service, live,
monkeypatch):
monkeypatch.setattr(f"{DISPLAY}.ON_DEMAND_SOCKET_WAIT_RUNNING_SECONDS", 0.3)
live.close() live.close()
data = api_v3_client.post(START_URL, json={"plugin_id": "weather"}).get_json()["data"] resp = api_v3_client.post(START_URL, json={"plugin_id": "weather"})
assert data["transport"] == "mailbox" and data["socket_error"] == "no_socket" assert resp.status_code == 503
assert len(_mailbox_writes(service["cache"])) == 1 assert resp.get_json()["data"]["socket_error"] == "no_socket"
assert _mailbox_writes(service["cache"]) == []
def test_a_full_queue_is_reported_not_mailed(self, api_v3_client, service, monkeypatch): def test_a_full_queue_is_reported_not_mailed(self, api_v3_client, service, monkeypatch):
import shutil import shutil
+36 -37
View File
@@ -6,7 +6,7 @@ a Vegas iteration runs for vegas_scroll.max_cycle_duration (240s here). On a
real Pi on 2026-09-23: real Pi on 2026-09-23:
* an on-demand request posted at 10:54:27 was activated at 10:57:24, when the * an on-demand request posted at 10:54:27 was activated at 10:57:24, when the
Vegas iteration it arrived during finally ended -- nothing read the mailbox Vegas iteration it arrived during finally ended -- nothing read the request
in between, because _check_vegas_interrupt only looked at a flag that the in between, because _check_vegas_interrupt only looked at a flag that the
main-loop read sets; main-loop read sets;
* two brightness saves 12s apart inside one 30s screen never showed at all. * two brightness saves 12s apart inside one 30s screen never showed at all.
@@ -15,6 +15,11 @@ _service_pending_changes is the fix: a throttled pass the dwell sleep, the
render loops and the Vegas interrupt check all call. These tests drive those render loops and the Vegas interrupt check all call. These tests drive those
long stretches on a fake clock and check a change lands within one throttle long stretches on a fake clock and check a change lands within one throttle
interval -- and that the throttle holds, since the callers run at frame rate. interval -- and that the throttle holds, since the callers run at frame rate.
The on-demand requests here come from a plugin in the display process
(submit_plugin_on_demand), the way in that needs no socket; the file mailbox
these tests used to write is gone (stage 5). A queued request skips the
throttle, so it lands at the next pass's call, not the next interval.
""" """
import threading import threading
@@ -28,7 +33,6 @@ from src.vegas_mode.config import VegasModeConfig
from src.vegas_mode.coordinator import VegasModeCoordinator from src.vegas_mode.coordinator import VegasModeCoordinator
VEGAS_ITERATION_SECONDS = 240 VEGAS_ITERATION_SECONDS = 240
REQUEST_KEY = 'display_on_demand_request'
class FakeClock: class FakeClock:
@@ -75,26 +79,15 @@ def clock(monkeypatch):
@pytest.fixture @pytest.fixture
def controller(test_display_controller, clock): def controller(test_display_controller, clock):
"""A controller at rest: no schedule, full brightness, empty mailbox.""" """A controller at rest: no schedule, full brightness, nothing queued."""
c = test_display_controller c = test_display_controller
c._refresh_config_cache({'display': {'hardware': {'brightness': 90}}}) c._refresh_config_cache({'display': {'hardware': {'brightness': 90}}})
c.current_brightness = 90 c.current_brightness = 90
c.is_display_active = True c.is_display_active = True
c._check_wifi_status_message = MagicMock(return_value=None) c._check_wifi_status_message = MagicMock(return_value=None)
c.mailbox = {} # what the web process has written c.cache_manager.get = MagicMock(return_value=None)
c.cache_manager.delete = MagicMock()
def cache_get(key, *args, **kwargs):
if key == REQUEST_KEY:
return c.mailbox.get('request')
return None
def cache_delete(key):
if key == REQUEST_KEY:
c.mailbox.pop('request', None)
c.cache_manager.get = MagicMock(side_effect=cache_get)
c.cache_manager.delete = MagicMock(side_effect=cache_delete)
c.cache_manager.set = MagicMock() c.cache_manager.set = MagicMock()
c.display_manager.set_brightness = MagicMock(return_value=True) c.display_manager.set_brightness = MagicMock(return_value=True)
c.display_manager.update_display = MagicMock() c.display_manager.update_display = MagicMock()
@@ -110,11 +103,12 @@ def controller(test_display_controller, clock):
return c return c
def post_request(controller, request_id='r1', mode='clock'): def post_request(controller, request_id='r1', mode='clock', action='start'):
controller.mailbox['request'] = { """A plugin asking for the screen (or giving it back) from its thread."""
'request_id': request_id, 'action': 'start', assert controller.submit_plugin_on_demand({
'plugin_id': mode, 'mode': mode, 'request_id': request_id, 'action': action,
} 'plugin_id': mode, 'mode': mode, 'source': 'plugin',
})
def save_brightness(controller, brightness): def save_brightness(controller, brightness):
@@ -124,9 +118,11 @@ def save_brightness(controller, brightness):
{'display': {'hardware': {'brightness': brightness}}}) {'display': {'hardware': {'brightness': brightness}}})
def mailbox_reads(controller): def count_passes(controller):
return sum(1 for call in controller.cache_manager.get.call_args_list """Count the pending-changes passes that got past the throttle."""
if call.args and call.args[0] == REQUEST_KEY) controller._poll_on_demand_requests = MagicMock(
wraps=controller._poll_on_demand_requests)
return controller._poll_on_demand_requests
def vegas_coordinator(controller): def vegas_coordinator(controller):
@@ -207,15 +203,16 @@ class TestOnDemandDuringVegas:
"interrupt checker never saw the request") "interrupt checker never saw the request")
assert controller.on_demand_active assert controller.on_demand_active
def test_an_empty_mailbox_lets_the_iteration_run_out(self, controller, clock): def test_a_quiet_iteration_runs_out(self, controller, clock):
coord = vegas_coordinator(controller) coord = vegas_coordinator(controller)
passes = count_passes(controller)
assert coord.run_iteration() is True assert coord.run_iteration() is True
assert not controller.on_demand_active assert not controller.on_demand_active
# And the read is throttled: at most one per interval, not per check. # And the pass is throttled: at most one per interval, not per check.
max_reads = VEGAS_ITERATION_SECONDS / controller.PENDING_CHANGES_INTERVAL + 1 max_passes = VEGAS_ITERATION_SECONDS / controller.PENDING_CHANGES_INTERVAL + 1
assert 0 < mailbox_reads(controller) <= max_reads assert 0 < passes.call_count <= max_passes
checks = coord.frames // coord._interrupt_check_interval checks = coord.frames // coord._interrupt_check_interval
assert mailbox_reads(controller) < checks / 2 assert passes.call_count < checks / 2
class TestBrightnessIsAppliedMidScreen: class TestBrightnessIsAppliedMidScreen:
@@ -295,23 +292,25 @@ class TestBrightnessIsAppliedMidScreen:
class TestThrottle: class TestThrottle:
def test_no_reads_or_brightness_calls_between_passes(self, controller, clock): def test_no_passes_or_brightness_calls_between_passes(self, controller, clock):
controller._service_pending_changes() controller._service_pending_changes()
reads = mailbox_reads(controller) passes = count_passes(controller)
save_brightness(controller, 40) save_brightness(controller, 40)
post_request(controller)
for _ in range(500): # a few seconds of frames, all inside one interval for _ in range(500): # a few seconds of frames, all inside one interval
controller._service_pending_changes() controller._service_pending_changes()
clock.t += controller.PENDING_CHANGES_INTERVAL / 1000 clock.t += controller.PENDING_CHANGES_INTERVAL / 1000
assert mailbox_reads(controller) == reads assert passes.call_count == 0
controller.display_manager.set_brightness.assert_not_called() controller.display_manager.set_brightness.assert_not_called()
assert not controller.on_demand_active
clock.t += controller.PENDING_CHANGES_INTERVAL clock.t += controller.PENDING_CHANGES_INTERVAL
controller._service_pending_changes() controller._service_pending_changes()
# The poll, plus the consume step's re-read of the request it acted on. assert passes.call_count == 1
assert mailbox_reads(controller) > reads
controller.display_manager.set_brightness.assert_called_once_with(40) controller.display_manager.set_brightness.assert_called_once_with(40)
def test_a_queued_request_skips_the_throttle(self, controller, clock):
controller._service_pending_changes()
post_request(controller)
controller._service_pending_changes() # inside the interval
assert controller.on_demand_active assert controller.on_demand_active
def test_between_passes_it_does_no_work_at_all(self, controller, clock): def test_between_passes_it_does_no_work_at_all(self, controller, clock):
@@ -398,7 +397,7 @@ class TestScheduleAndDwells:
controller._service_pending_changes() controller._service_pending_changes()
assert controller.on_demand_active assert controller.on_demand_active
clock.t += controller.PENDING_CHANGES_INTERVAL clock.t += controller.PENDING_CHANGES_INTERVAL
controller.mailbox['request'] = {'request_id': 'r2', 'action': 'stop'} post_request(controller, request_id='r2', action='stop')
start = clock.t start = clock.t
controller._sleep_with_plugin_updates(30) controller._sleep_with_plugin_updates(30)
assert not controller.on_demand_active assert not controller.on_demand_active
+138 -211
View File
@@ -24,7 +24,7 @@ sys.path.insert(0, str(Path(__file__).parent.parent))
from src.cache_manager import CacheManager # noqa: E402 from src.cache_manager import CacheManager # noqa: E402
from src import error_aggregator as errors # noqa: E402 from src import error_aggregator as errors # noqa: E402
from src.error_aggregator import ( # noqa: E402 from src.error_aggregator import ( # noqa: E402
ERROR_CLEAR_REQUEST_KEY, ERROR_SNAPSHOT_KEY, ErrorAggregator, ERROR_SNAPSHOT_KEY, ErrorAggregator,
ErrorSnapshotPublisher, ErrorSnapshotPublisher,
) )
from test._api_v3_test_helpers import api_v3_client, api_v3_module # noqa: F401,E402 from test._api_v3_test_helpers import api_v3_client, api_v3_module # noqa: F401,E402
@@ -314,151 +314,36 @@ class TestRoutes:
assert secret not in published, secret assert secret not in published, secret
class TestClear:
def test_clear_is_applied_by_the_display_and_republished(self, web, display):
aggregator, publisher, _ = display
_fail(aggregator)
_fail(aggregator)
publisher.tick()
response = web.post("/api/v3/errors/clear", json={"all": True})
assert response.status_code == 200
body = response.get_json()["data"]
assert body["clear_requested"] is True
assert body["cleared_count"] == 2
# The display applies it on its next tick, throttle or not...
assert publisher.tick() is True
assert aggregator.get_error_summary()["total_errors"] == 0
data = _summary(web)
assert data["total_errors"] == 0 and data["clear_pending"] is False
# ...and only once.
assert publisher.tick() is False
def test_summary_hides_cleared_errors_before_the_display_applies_it(self, web, display):
aggregator, publisher, _ = display
for _ in range(5):
_fail(aggregator)
publisher.tick()
web.post("/api/v3/errors/clear", json={"all": True})
# No display tick yet.
data = _summary(web)
assert data["clear_pending"] is True
assert data["total_errors"] == 0
assert data["recent_errors"] == [] and data["active_patterns"] == {}
assert data["plugin_error_counts"] == {}
plugin = web.get("/api/v3/errors/plugin/p1").get_json()["data"]
assert plugin["status"] == "healthy" and plugin["total_errors"] == 0
def test_a_snapshot_written_just_before_the_clear_cannot_bring_errors_back(
self, web, display, shared_cache):
# The race: the display builds a snapshot, the user clicks Clear, and
# the display's write lands after the request.
aggregator, publisher, _ = display
display_cache, _, _ = shared_cache
for _ in range(3):
_fail(aggregator)
stale = aggregator.build_snapshot()
web.post("/api/v3/errors/clear", json={"all": True})
stale["applied_clear_id"] = None
display_cache.set(ERROR_SNAPSHOT_KEY, stale)
assert _summary(web)["total_errors"] == 0
def test_errors_after_the_clear_are_kept(self, web, display):
aggregator, publisher, clock = display
_fail(aggregator, plugin_id="before")
publisher.tick()
web.post("/api/v3/errors/clear", json={"all": True})
# An error lands after the request but before the display applies it.
for record in aggregator._records:
record.timestamp -= timedelta(seconds=5)
_fail(aggregator, plugin_id="after")
publisher.tick()
data = _summary(web)
assert data["plugin_error_counts"] == {"after": {"ValueError": 1}}
assert data["clear_pending"] is False
def test_age_based_clear(self, web, display):
aggregator, publisher, _ = display
_fail(aggregator, plugin_id="old")
_fail(aggregator, plugin_id="old")
for record in aggregator._records:
record.timestamp -= timedelta(hours=3)
_fail(aggregator, plugin_id="new")
publisher.tick()
body = web.post("/api/v3/errors/clear", json={"max_age_hours": 1}).get_json()["data"]
assert body["cleared_count"] == 2
pending = _summary(web)
assert pending["clear_pending"] is True
assert [r["plugin_id"] for r in pending["recent_errors"]] == ["new"]
publisher.tick()
data = _summary(web)
assert data["plugin_error_counts"] == {"new": {"ValueError": 1}}
assert data["total_errors"] == 1
def test_a_narrower_clear_does_not_undo_a_pending_wider_one(self, web, display):
aggregator, publisher, _ = display
for _ in range(3):
_fail(aggregator)
publisher.tick()
web.post("/api/v3/errors/clear", json={"all": True})
web.post("/api/v3/errors/clear", json={"max_age_hours": 24})
assert _summary(web)["total_errors"] == 0
publisher.tick()
assert aggregator.get_error_summary()["total_errors"] == 0
def test_default_body_still_means_older_than_24_hours(self, web, display):
aggregator, publisher, _ = display
_fail(aggregator)
publisher.tick()
response = web.post("/api/v3/errors/clear")
assert response.status_code == 200
assert response.get_json()["data"]["cleared_count"] == 0
publisher.tick()
assert _summary(web)["total_errors"] == 1
def test_validation_is_unchanged_but_all_skips_it(self, web):
assert web.post("/api/v3/errors/clear", json={"max_age_hours": 0}).status_code == 400
assert web.post("/api/v3/errors/clear", json={"max_age_hours": 9000}).status_code == 400
assert web.post("/api/v3/errors/clear",
json={"all": True, "max_age_hours": "junk"}).status_code == 200
def test_a_request_that_did_not_reach_the_cache_is_an_error(self, web, api_v3_module): # noqa: F811
cache = MagicMock()
cache.get.return_value = None
api_v3_module.api_v3.cache_manager = cache
response = web.post("/api/v3/errors/clear", json={"all": True})
assert response.status_code == 500
assert "clear request" in response.get_json()["message"]
CLIENT = "web_interface.blueprints.api_v3.control_client" CLIENT = "web_interface.blueprints.api_v3.control_client"
RETIRED_CLEAR_KEY = "plugin_error_clear_request"
def _mailbox_file(shared_cache): def _mailbox_file(shared_cache):
_, _, directory = shared_cache _, _, directory = shared_cache
return directory / f"{ERROR_CLEAR_REQUEST_KEY}.json" return directory / f"{RETIRED_CLEAR_KEY}.json"
class TestClearOverTheSocket: @pytest.fixture
"""``errors.clear``: the display applies the clear before it answers, and def socket_up(display, monkeypatch):
the mailbox is written only when the socket could not carry it.""" """The control socket, as the display serves it: errors_clear runs the
display's own handler against its publisher."""
from src.ipc import client as control_client
from src.ipc.contract import ErrorsClearArgs
_, publisher, _ = display
monkeypatch.setattr(errors, "_snapshot_publisher", publisher)
calls = []
@pytest.fixture def errors_clear(request_id, cutoff, **kw):
def socket_up(self, display, monkeypatch): calls.append((request_id, cutoff))
"""The control socket, as the display serves it: errors_clear runs return errors.apply_error_clear(request_id, ErrorsClearArgs(cutoff=cutoff))
the display's own handler against its publisher."""
from src.ipc import client as control_client
from src.ipc.contract import ErrorsClearArgs
_, publisher, _ = display
monkeypatch.setattr(errors, "_snapshot_publisher", publisher)
calls = []
def errors_clear(request_id, cutoff, **kw): monkeypatch.setattr(f"{CLIENT}.errors_clear", errors_clear)
calls.append((request_id, cutoff)) assert control_client.errors_clear is errors_clear
return errors.apply_error_clear(request_id, ErrorsClearArgs(cutoff=cutoff)) return calls
monkeypatch.setattr(f"{CLIENT}.errors_clear", errors_clear)
assert control_client.errors_clear is errors_clear class TestClear:
return calls """``errors.clear``: the display applies the clear before it answers."""
def test_socket_clear_is_applied_before_the_answer(self, web, display, socket_up, def test_socket_clear_is_applied_before_the_answer(self, web, display, socket_up,
shared_cache): shared_cache):
@@ -471,6 +356,7 @@ class TestClearOverTheSocket:
body = response.get_json() body = response.get_json()
data = body["data"] data = body["data"]
assert data["transport"] == "socket" and data["applied"] is True assert data["transport"] == "socket" and data["applied"] is True
assert data["clear_requested"] is True
assert data["cleared_count"] == 3 assert data["cleared_count"] == 3
assert body["message"] == "Cleared all errors" assert body["message"] == "Cleared all errors"
[(request_id, _)] = socket_up [(request_id, _)] = socket_up
@@ -479,90 +365,134 @@ class TestClearOverTheSocket:
assert aggregator.get_error_summary()["total_errors"] == 0 assert aggregator.get_error_summary()["total_errors"] == 0
summary = _summary(web) summary = _summary(web)
assert summary["total_errors"] == 0 and summary["clear_pending"] is False assert summary["total_errors"] == 0 and summary["clear_pending"] is False
# And no mailbox file. assert not _mailbox_file(shared_cache).exists()
# Nothing left for a tick to do.
assert publisher.tick() is False
def test_errors_after_the_clear_are_kept(self, web, display, socket_up):
aggregator, publisher, _ = display
_fail(aggregator, plugin_id="before")
for record in aggregator._records:
record.timestamp -= timedelta(seconds=5)
publisher.tick()
web.post("/api/v3/errors/clear", json={"all": True})
_fail(aggregator, plugin_id="after")
publisher.min_interval = 0
publisher.tick()
data = _summary(web)
assert data["plugin_error_counts"] == {"after": {"ValueError": 1}}
assert data["clear_pending"] is False
def test_age_based_clear(self, web, display, socket_up):
aggregator, publisher, _ = display
_fail(aggregator, plugin_id="old")
_fail(aggregator, plugin_id="old")
for record in aggregator._records:
record.timestamp -= timedelta(hours=3)
_fail(aggregator, plugin_id="new")
publisher.tick()
body = web.post("/api/v3/errors/clear", json={"max_age_hours": 1}).get_json()["data"]
assert body["cleared_count"] == 2
data = _summary(web)
assert data["plugin_error_counts"] == {"new": {"ValueError": 1}}
assert data["total_errors"] == 1
def test_default_body_still_means_older_than_24_hours(self, web, display, socket_up):
aggregator, publisher, _ = display
_fail(aggregator)
publisher.tick()
response = web.post("/api/v3/errors/clear")
assert response.status_code == 200
assert response.get_json()["data"]["cleared_count"] == 0
assert _summary(web)["total_errors"] == 1
def test_validation_is_unchanged_but_all_skips_it(self, web, socket_up):
assert web.post("/api/v3/errors/clear", json={"max_age_hours": 0}).status_code == 400
assert web.post("/api/v3/errors/clear", json={"max_age_hours": 9000}).status_code == 400
assert web.post("/api/v3/errors/clear",
json={"all": True, "max_age_hours": "junk"}).status_code == 200
class TestClearWithoutTheSocket:
"""Stage 5: no mailbox to fall back to. The route says why it failed and
writes nothing; the errors stay as the display last reported them."""
def _post(self, web, display, monkeypatch, error):
monkeypatch.setattr(f"{CLIENT}.errors_clear", MagicMock(side_effect=error))
aggregator, publisher, _ = display
_fail(aggregator)
publisher.tick()
return web.post("/api/v3/errors/clear", json={"all": True})
@pytest.mark.parametrize("reason", ["no_socket", "refused"])
def test_a_stopped_display_is_an_error(self, web, display, shared_cache, monkeypatch,
reason):
from src.ipc import client as control_client
response = self._post(web, display, monkeypatch,
control_client.ControlError(reason, sent=False))
assert response.status_code == 503
body = response.get_json()
assert body["context"]["socket_error"] == reason
assert "not running" in body["message"]
assert not _mailbox_file(shared_cache).exists()
# Nothing hides them: they are still the display's last report.
summary = _summary(web)
assert summary["total_errors"] == 1 and summary["clear_pending"] is False
@pytest.mark.parametrize("reason", ["disabled", "unsupported"])
def test_no_socket_here_is_an_error(self, web, display, shared_cache, monkeypatch, reason):
from src.ipc import client as control_client
response = self._post(web, display, monkeypatch,
control_client.ControlError(reason, sent=False))
assert response.status_code == 503
assert "not available" in response.get_json()["message"]
assert not _mailbox_file(shared_cache).exists() assert not _mailbox_file(shared_cache).exists()
def test_an_older_mailbox_request_does_not_read_as_pending(self, web, display, socket_up, def test_an_older_display_is_told_to_restart(self, web, display, shared_cache,
shared_cache, monkeypatch): monkeypatch):
# A clear that went to the mailbox while the socket was down, then a
# wider one over the socket: the old request has nothing left to hide.
from unittest.mock import patch
from src.ipc import client as control_client from src.ipc import client as control_client
aggregator, publisher, _ = display response = self._post(web, display, monkeypatch,
_fail(aggregator) control_client.ControlError("unknown_command", sent=True))
publisher.tick() assert response.status_code == 503
with patch(f"{CLIENT}.errors_clear", assert "restart" in response.get_json()["message"]
side_effect=control_client.ControlError("no_socket")): assert not _mailbox_file(shared_cache).exists()
data = web.post("/api/v3/errors/clear", json={"max_age_hours": 1}).get_json()["data"]
assert data["transport"] == "mailbox"
assert _mailbox_file(shared_cache).exists()
data = web.post("/api/v3/errors/clear", json={"all": True}).get_json()["data"]
assert data["transport"] == "socket"
assert _summary(web)["clear_pending"] is False
@pytest.mark.parametrize("reason", ["no_socket", "refused", "disabled", "unsupported"])
def test_no_socket_writes_the_mailbox(self, web, display, shared_cache, monkeypatch, reason):
from src.ipc import client as control_client
monkeypatch.setattr(f"{CLIENT}.errors_clear", MagicMock(
side_effect=control_client.ControlError(reason, sent=False)))
aggregator, publisher, _ = display
_fail(aggregator)
publisher.tick()
data = web.post("/api/v3/errors/clear", json={"all": True}).get_json()["data"]
assert data["transport"] == "mailbox" and data["applied"] is False
assert _mailbox_file(shared_cache).exists()
assert _summary(web)["clear_pending"] is True
publisher.tick()
assert aggregator.get_error_summary()["total_errors"] == 0
def test_an_older_display_gets_the_mailbox(self, web, display, shared_cache, monkeypatch):
# The upgrade case: new web interface, a display from before errors.clear.
from src.ipc import client as control_client
monkeypatch.setattr(f"{CLIENT}.errors_clear", MagicMock(
side_effect=control_client.ControlError("unknown_command", sent=True)))
aggregator, publisher, _ = display
_fail(aggregator)
publisher.tick()
data = web.post("/api/v3/errors/clear", json={"all": True}).get_json()["data"]
assert data["transport"] == "mailbox"
publisher.tick()
assert aggregator.get_error_summary()["total_errors"] == 0
@pytest.mark.parametrize("reason", ["internal", "timeout", "busy", "invalid_args"]) @pytest.mark.parametrize("reason", ["internal", "timeout", "busy", "invalid_args"])
def test_a_display_that_had_it_and_failed_is_an_error(self, web, display, shared_cache, def test_a_display_that_had_it_and_failed_is_an_error(self, web, display, shared_cache,
monkeypatch, reason): monkeypatch, reason):
from src.ipc import client as control_client from src.ipc import client as control_client
monkeypatch.setattr(f"{CLIENT}.errors_clear", MagicMock( response = self._post(web, display, monkeypatch,
side_effect=control_client.ControlError(reason, sent=True))) control_client.ControlError(reason, sent=True))
response = web.post("/api/v3/errors/clear", json={"all": True})
assert response.status_code == 503 assert response.status_code == 503
assert response.get_json()["context"]["socket_error"] == reason body = response.get_json()
assert body["context"]["socket_error"] == reason
assert body["message"] == "The display service did not apply the clear"
assert not _mailbox_file(shared_cache).exists() assert not _mailbox_file(shared_cache).exists()
def test_the_default_test_setup_has_no_socket(self, web, display, shared_cache):
class TestPublisherMailboxPoll: # conftest turns the socket off: the real client answers "disabled".
def test_the_mailbox_is_read_only_when_its_file_changed(self, display, shared_cache): aggregator, publisher, _ = display
_, publisher, _ = display _fail(aggregator)
_, web_cache, _ = shared_cache
publisher.tick() publisher.tick()
response = web.post("/api/v3/errors/clear", json={"all": True})
assert response.status_code == 503
assert response.get_json()["context"]["socket_error"] in ("disabled", "unsupported")
class TestPublisher:
def test_a_tick_reads_no_clear_request(self, display, shared_cache):
_, publisher, clock = display
_, web_cache, directory = shared_cache
# An old web interface's leftover request file is ignored.
(directory / f"{RETIRED_CLEAR_KEY}.json").write_text(
'{"timestamp": 1, "data": {"request_id": "old", "cutoff": 9e9}}')
publisher.cache_manager = MagicMock(wraps=publisher.cache_manager) publisher.cache_manager = MagicMock(wraps=publisher.cache_manager)
def reads():
return [c for c in publisher.cache_manager.get.call_args_list
if c.args[0] == ERROR_CLEAR_REQUEST_KEY]
for _ in range(5): for _ in range(5):
clock.now += 60
publisher.tick() publisher.tick()
assert reads() == [] # no file: a stat per tick, no read publisher.cache_manager.get.assert_not_called()
errors.request_error_clear(web_cache, 1.0) snapshot = web_cache.get(ERROR_SNAPSHOT_KEY, max_age=None, memory_ttl=0)
publisher.tick() assert snapshot["applied_clear_id"] is None
assert len(reads()) == 1
for _ in range(5):
publisher.tick()
assert len(reads()) == 1 # unchanged file: not read again
errors.request_error_clear(web_cache, 2.0)
publisher.tick()
assert len(reads()) == 2
def test_clear_now_publishes_what_it_applied(self, display, shared_cache): def test_clear_now_publishes_what_it_applied(self, display, shared_cache):
aggregator, publisher, _ = display aggregator, publisher, _ = display
@@ -572,7 +502,6 @@ class TestPublisherMailboxPoll:
snapshot = web_cache.get(ERROR_SNAPSHOT_KEY, max_age=None, memory_ttl=0) snapshot = web_cache.get(ERROR_SNAPSHOT_KEY, max_age=None, memory_ttl=0)
assert snapshot["applied_clear_id"] == "sock-1" assert snapshot["applied_clear_id"] == "sock-1"
assert snapshot["total_errors"] == 0 assert snapshot["total_errors"] == 0
assert snapshot["applied_clear_cutoff"] is not None
def test_the_handler_needs_a_running_publisher(self, monkeypatch): def test_the_handler_needs_a_running_publisher(self, monkeypatch):
from src.ipc.contract import ErrorsClearArgs from src.ipc.contract import ErrorsClearArgs
@@ -583,12 +512,10 @@ class TestPublisherMailboxPoll:
@pytest.mark.skipif(not hasattr(os, "fchmod") or os.name == "nt", @pytest.mark.skipif(not hasattr(os, "fchmod") or os.name == "nt",
reason="POSIX file modes") reason="POSIX file modes")
def test_both_files_are_group_readable(web, display, shared_cache): def test_the_snapshot_is_group_readable(web, display, shared_cache):
aggregator, publisher, _ = display aggregator, publisher, _ = display
_, _, directory = shared_cache _, _, directory = shared_cache
_fail(aggregator) _fail(aggregator)
publisher.tick() publisher.tick()
web.post("/api/v3/errors/clear", json={"all": True}) mode = stat.S_IMODE(os.stat(directory / f"{ERROR_SNAPSHOT_KEY}.json").st_mode)
for key in (ERROR_SNAPSHOT_KEY, ERROR_CLEAR_REQUEST_KEY): assert mode == 0o660, oct(mode)
mode = stat.S_IMODE(os.stat(directory / f"{key}.json").st_mode)
assert mode == 0o660, (key, oct(mode))
+3 -3
View File
@@ -3,7 +3,7 @@
Pure data, so every test here runs on every platform. What they pin: Pure data, so every test here runs on every platform. What they pin:
* a request and a response survive encode -> decode -> parse unchanged, and * a request and a response survive encode -> decode -> parse unchanged, and
the on-demand arguments carry exactly what the file mailbox carries; the on-demand arguments carry exactly what the REST route sends;
* the envelope and the arguments refuse what the display could not act on * the envelope and the arguments refuse what the display could not act on
(missing ids, wrong types, a non-finite duration) with a stable error code; (missing ids, wrong types, a non-finite duration) with a stable error code;
* framing never holds more than one message's worth of bytes, however the * framing never holds more than one message's worth of bytes, however the
@@ -184,8 +184,8 @@ class TestOnDemandArgs:
class TestMailboxShape: class TestMailboxShape:
"""Socket commands are handed to the mailbox's own handler, so they must """Socket commands are handed to the display's on-demand handler, so they
look exactly like what the web route writes to the mailbox.""" must look exactly like the request dict it takes."""
def test_start(self): def test_start(self):
args = OnDemandStartArgs(plugin_id='clock', mode='clock_main', duration=60.0, args = OnDemandStartArgs(plugin_id='clock', mode='clock_main', duration=60.0,
+26 -58
View File
@@ -1,14 +1,13 @@
"""DisplayController's side of the control socket. """DisplayController's side of the control socket.
The server's handlers only queue; the render thread drains the queue where The server's handlers only queue; the render thread drains the queue
it reads the file mailbox (_poll_on_demand_requests) and hands each command (_poll_on_demand_requests) and hands each on-demand command to
to the mailbox's own handler (_handle_on_demand_request). These tests pin _handle_on_demand_request, which plugins' own requests use too. These tests
that hook: pin that hook:
* a socket command is applied by the same code as a mailbox request, with * a socket command is applied with its request id, at once, and touches no
its request id, and without waiting for the mailbox's 0.25 s read floor; cache key (the file mailbox and the persisted processed id are gone);
* a request that arrives both ways (a client that timed out after the * a start sent twice with one request id is activated once;
command was queued, then wrote the mailbox) is activated once;
* a command that fails is contained, and the ones after it still run; * a command that fails is contained, and the ones after it still run;
* cleanup closes the socket; a disabled socket changes nothing. * cleanup closes the socket; a disabled socket changes nothing.
""" """
@@ -58,28 +57,15 @@ def controller(test_display_controller):
c_ = test_display_controller c_ = test_display_controller
c_.on_demand_active = False c_.on_demand_active = False
c_.on_demand_request_id = None c_.on_demand_request_id = None
c_._last_on_demand_poll = None c_.cache_manager.get = MagicMock(return_value=None)
mailbox = {'value': None}
def fake_get(key, *a, **kw):
if key == 'display_on_demand_request':
return mailbox['value']
return None
def fake_delete(key):
if key == 'display_on_demand_request':
mailbox['value'] = None
c_.cache_manager.get = MagicMock(side_effect=fake_get)
c_.cache_manager.set = MagicMock() c_.cache_manager.set = MagicMock()
c_.cache_manager.delete = MagicMock(side_effect=fake_delete) c_.cache_manager.delete = MagicMock()
c_._activate_on_demand = MagicMock() c_._activate_on_demand = MagicMock()
c_.mailbox = mailbox
return c_ return c_
class TestDrain: class TestDrain:
def test_a_socket_start_goes_through_the_mailbox_handler(self, controller): def test_a_socket_start_is_activated_with_its_request_id(self, controller):
controller._control_server = FakeServer(_start('sock-1', duration=30.0, pinned=True)) controller._control_server = FakeServer(_start('sock-1', duration=30.0, pinned=True))
controller._poll_on_demand_requests() controller._poll_on_demand_requests()
controller._activate_on_demand.assert_called_once() controller._activate_on_demand.assert_called_once()
@@ -89,47 +75,28 @@ class TestDrain:
assert request['plugin_id'] == 'clock' assert request['plugin_id'] == 'clock'
assert request['duration'] == 30.0 and request['pinned'] is True assert request['duration'] == 30.0 and request['pinned'] is True
assert controller.on_demand_request_id == 'sock-1' assert controller.on_demand_request_id == 'sock-1'
# The same restart-replay guard as a mailbox request. # No mailbox, and no persisted processed id.
controller.cache_manager.set.assert_any_call( keys = {call.args[0] for m in (controller.cache_manager.get,
'display_on_demand_processed_id', 'sock-1', ttl=3600) controller.cache_manager.set,
controller.cache_manager.delete)
for call in m.call_args_list}
assert not keys & {'display_on_demand_request', 'display_on_demand_processed_id'}
def test_socket_commands_skip_the_mailbox_floor(self, controller): def test_socket_commands_land_at_once(self, controller):
server = FakeServer() server = FakeServer()
controller._control_server = server controller._control_server = server
controller._poll_on_demand_requests() # reads the mailbox, sets the floor controller._poll_on_demand_requests()
reads = controller.cache_manager.get.call_count
server.commands.append(_start('quick')) server.commands.append(_start('quick'))
controller._poll_on_demand_requests() # within the floor
controller._activate_on_demand.assert_called_once()
mailbox_reads = [call for call in controller.cache_manager.get.call_args_list[reads:]
if call.args[0] == 'display_on_demand_request']
# Only _consume_on_demand_request's compare-before-delete re-read.
assert len(mailbox_reads) <= 1
def test_a_request_that_came_both_ways_is_activated_once(self, controller):
controller._control_server = FakeServer(_start('dup'))
controller.mailbox['value'] = {'request_id': 'dup', 'action': 'start',
'plugin_id': 'clock'}
controller._poll_on_demand_requests()
controller._last_on_demand_poll = None
controller._poll_on_demand_requests()
controller._activate_on_demand.assert_called_once()
assert controller.mailbox['value'] is None, "the duplicate was left in the mailbox"
def test_a_fallback_write_landing_later_is_ignored(self, controller):
controller._control_server = FakeServer(_start('late'))
controller._poll_on_demand_requests()
controller.mailbox['value'] = {'request_id': 'late', 'action': 'start',
'plugin_id': 'clock'}
controller._last_on_demand_poll = None
controller._poll_on_demand_requests() controller._poll_on_demand_requests()
controller._activate_on_demand.assert_called_once() controller._activate_on_demand.assert_called_once()
def test_the_mailbox_still_works_alongside(self, controller): def test_a_start_sent_twice_is_activated_once(self, controller):
controller._control_server = FakeServer() server = FakeServer(_start('dup'))
controller.mailbox['value'] = {'request_id': 'mb', 'action': 'start', 'plugin_id': 'p'} controller._control_server = server
controller._poll_on_demand_requests() controller._poll_on_demand_requests()
assert controller._activate_on_demand.call_args.args[0]['request_id'] == 'mb' server.commands.append(_start('dup'))
controller._poll_on_demand_requests()
controller._activate_on_demand.assert_called_once()
def test_a_socket_stop_ends_on_demand(self, controller): def test_a_socket_stop_ends_on_demand(self, controller):
controller.on_demand_active = True controller.on_demand_active = True
@@ -159,10 +126,11 @@ class TestDrain:
controller._poll_on_demand_requests() controller._poll_on_demand_requests()
assert calls == ['bad', 'good'] assert calls == ['bad', 'good']
def test_no_server_means_mailbox_only(self, controller): def test_no_server_means_nothing_to_apply(self, controller):
controller._control_server = None controller._control_server = None
controller._poll_on_demand_requests() controller._poll_on_demand_requests()
controller._activate_on_demand.assert_not_called() controller._activate_on_demand.assert_not_called()
controller.cache_manager.get.assert_not_called()
class TestPendingChangesFloor: class TestPendingChangesFloor:
+135 -206
View File
@@ -1,14 +1,13 @@
"""Stage 4 of the control socket: the file mailboxes are only a fallback. """Stages 4 and 5 of the control socket: the socket is the only way in.
* The client knows whether the display had the request (``ControlError.sent``) * The client knows whether the display had the request (``ControlError.sent``)
and ``should_fall_back`` allows a mailbox write only when it did not, or and ``display_not_listening`` says when no display was there to take it
when the display is too old to know the command (the upgrade case). (stopped or still starting), the one case a later retry can fix.
* ``errors.clear`` is answered on the connection thread by a handler the * ``errors.clear`` is answered on the connection thread by a handler the
display registers; a display without one answers like an older display. display registers; a display without one answers like an older display.
* The display looks at the on-demand mailbox once a second while the socket * Stage 5: the display no longer reads the ``display_on_demand_request``
is up (0.25 s without it), reads it only when its file changed, never mailbox at all, and the cache refuses writes to the retired mailbox keys,
touches it for a socket command, and logs who still writes it. warning once per writer.
* ``CacheManager.file_signature`` / ``MailboxWatch`` make a look one stat().
The web routes are covered in test_api_v3_on_demand_socket.py and The web routes are covered in test_api_v3_on_demand_socket.py and
test_error_snapshot_cross_process.py. test_error_snapshot_cross_process.py.
@@ -23,7 +22,8 @@ from unittest.mock import MagicMock, patch
import pytest import pytest
from src.cache_manager import CacheManager, MailboxWatch from src import cache_manager as cache_module
from src.cache_manager import CacheManager
from src.ipc import client from src.ipc import client
from src.ipc import contract as c from src.ipc import contract as c
from src.ipc.contract import Command, ErrorsClearArgs, OnDemandStartArgs, ProtocolError from src.ipc.contract import Command, ErrorsClearArgs, OnDemandStartArgs, ProtocolError
@@ -81,38 +81,41 @@ class TestSent:
def test_an_answer_is_returned(self): def test_an_answer_is_returned(self):
assert _call(FakeSock([_reply('rid-1', ok=True, result={'pong': True})])) == {'pong': True} assert _call(FakeSock([_reply('rid-1', ok=True, result={'pong': True})])) == {'pong': True}
@pytest.mark.parametrize('reason', ['no_socket', 'refused', 'timeout', 'busy']) @pytest.mark.parametrize('reason,listening', [('no_socket', False), ('refused', False),
def test_a_failed_connect_was_not_sent(self, reason): ('timeout', True), ('busy', True)])
def test_a_failed_connect_was_not_sent(self, reason, listening):
e = _error(connect_error=client.ControlError(reason)) e = _error(connect_error=client.ControlError(reason))
assert e.reason == reason and e.sent is False assert e.reason == reason and e.sent is False
assert client.should_fall_back(e) # Only "nothing there" is worth waiting for: a timeout or a full
# backlog is a display that is there and stuck.
assert client.display_not_listening(e) is not listening
def test_a_send_that_timed_out_was_not_sent(self): def test_a_send_that_timed_out_was_not_sent(self):
e = _error(sock=FakeSock(send_error=socket.timeout())) e = _error(sock=FakeSock(send_error=socket.timeout()))
assert e.reason == 'timeout' and e.sent is False assert e.reason == 'timeout' and e.sent is False
assert client.should_fall_back(e) assert not client.display_not_listening(e)
def test_silence_after_the_request_was_sent(self): def test_silence_after_the_request_was_sent(self):
e = _error(sock=FakeSock(recv_error=socket.timeout())) e = _error(sock=FakeSock(recv_error=socket.timeout()))
assert e.reason == 'timeout' and e.sent is True assert e.reason == 'timeout' and e.sent is True
assert not client.should_fall_back(e) assert not client.display_not_listening(e)
def test_a_hang_up_after_the_request_was_sent(self): def test_a_hang_up_after_the_request_was_sent(self):
e = _error(sock=FakeSock([])) e = _error(sock=FakeSock([]))
assert e.reason == 'closed' and e.sent is True assert e.reason == 'closed' and e.sent is True
assert not client.should_fall_back(e) assert not client.display_not_listening(e)
def test_a_garbled_reply(self): def test_a_garbled_reply(self):
e = _error(sock=FakeSock([b'not json\n'])) e = _error(sock=FakeSock([b'not json\n']))
assert e.reason == 'bad_response' and e.sent is True assert e.reason == 'bad_response' and e.sent is True
assert not client.should_fall_back(e) assert not client.display_not_listening(e)
@pytest.mark.parametrize('code', ['busy', 'invalid_args', 'internal', 'pending', 'failed']) @pytest.mark.parametrize('code', ['busy', 'invalid_args', 'internal', 'pending', 'failed'])
def test_a_display_error_with_an_id_was_sent(self, code): def test_a_display_error_with_an_id_was_sent(self, code):
sock = FakeSock([_reply('rid-1', ok=False, error={'code': code, 'message': 'x'})]) sock = FakeSock([_reply('rid-1', ok=False, error={'code': code, 'message': 'x'})])
e = _error(sock=sock) e = _error(sock=sock)
assert e.reason == code and e.sent is True assert e.reason == code and e.sent is True
assert not client.should_fall_back(e) assert not client.display_not_listening(e)
@pytest.mark.parametrize('code', ['forbidden', 'busy']) @pytest.mark.parametrize('code', ['forbidden', 'busy'])
def test_a_refusal_at_the_door_was_not_sent(self, code): def test_a_refusal_at_the_door_was_not_sent(self, code):
@@ -122,23 +125,27 @@ class TestSent:
'error': {'code': code, 'message': 'x'}}) + '\n').encode()]) 'error': {'code': code, 'message': 'x'}}) + '\n').encode()])
e = _error(sock=sock) e = _error(sock=sock)
assert e.reason == code and e.sent is False assert e.reason == code and e.sent is False
assert client.should_fall_back(e) assert not client.display_not_listening(e)
@pytest.mark.parametrize('code', ['unknown_command', 'unsupported_version']) @pytest.mark.parametrize('code', ['unknown_command', 'unsupported_version'])
def test_an_older_display_is_fallen_back_from(self, code): def test_an_older_display_is_listening(self, code):
sock = FakeSock([_reply('rid-1', ok=False, error={'code': code, 'message': 'x'})]) sock = FakeSock([_reply('rid-1', ok=False, error={'code': code, 'message': 'x'})])
e = _error(sock=sock) e = _error(sock=sock)
assert e.sent is True assert e.sent is True
assert client.should_fall_back(e) assert not client.display_not_listening(e)
def test_a_request_refused_locally_never_left(self): def test_a_request_refused_locally_never_left(self):
with pytest.raises(client.ControlError) as e: with pytest.raises(client.ControlError) as e:
client.request(Command.ERRORS_CLEAR, {'cutoff': 'soon'}, paths=['/x.sock']) client.request(Command.ERRORS_CLEAR, {'cutoff': 'soon'}, paths=['/x.sock'])
assert e.value.reason == 'invalid_request' and e.value.sent is False assert e.value.reason == 'invalid_request' and e.value.sent is False
assert client.should_fall_back(e.value) assert not client.display_not_listening(e.value)
def test_a_client_bug_falls_back(self): @pytest.mark.parametrize('reason', ['disabled', 'unsupported'])
assert client.should_fall_back(RuntimeError('boom')) def test_a_client_without_the_socket_is_not_waiting_for_a_display(self, reason):
assert not client.display_not_listening(client.ControlError(reason))
def test_a_client_bug_is_not_a_missing_display(self):
assert not client.display_not_listening(RuntimeError('boom'))
# -- errors.clear on the server ------------------------------------------------------ # -- errors.clear on the server ------------------------------------------------------
@@ -204,37 +211,28 @@ class TestErrorsClearOnTheServer:
assert Command.ERRORS_CLEAR in result['commands'] assert Command.ERRORS_CLEAR in result['commands']
# -- the display's mailbox poll ------------------------------------------------------ # -- stage 5: the display reads no mailbox --------------------------------------------
class SignedCache: class CountingCache:
"""The slice of CacheManager the poll uses, counting what it costs.""" """The slice of CacheManager the on-demand path uses, counting every call."""
def __init__(self): def __init__(self):
self.data = {} self.data = {}
self.writes = 0 self.calls = []
self.version = {}
self.reads = []
self.stats = 0
self.deletes = []
self.sets = []
def file_signature(self, key): def __getattr__(self, name):
self.stats += 1 # Any other method (file_signature, delete, ...) is recorded too.
return (self.version[key], 0, 0) if key in self.data else None def call(*a, **kw):
self.calls.append((name, a[0] if a else None))
return call
def get(self, key, *a, **kw): def get(self, key, *a, **kw):
self.reads.append(key) self.calls.append(('get', key))
return self.data.get(key) return self.data.get(key)
def set(self, key, value, *a, **kw): def set(self, key, value, *a, **kw):
self.sets.append(key) self.calls.append(('set', key))
self.data[key] = value self.data[key] = value
self.writes += 1
self.version[key] = self.writes
def delete(self, key):
self.deletes.append(key)
self.data.pop(key, None)
class FakeServer: class FakeServer:
@@ -250,209 +248,140 @@ class FakeServer:
return out return out
class Clock:
def __init__(self):
self.t = 1000.0
def __call__(self):
return self.t
@pytest.fixture @pytest.fixture
def controller(test_display_controller, monkeypatch): def controller(test_display_controller):
dc = test_display_controller dc = test_display_controller
dc.cache_manager = SignedCache() dc.cache_manager = CountingCache()
dc._activate_on_demand = MagicMock() dc._activate_on_demand = MagicMock()
dc.on_demand_active = False dc.on_demand_active = False
dc.on_demand_request_id = None dc.on_demand_request_id = None
dc._last_on_demand_poll = None
dc._on_demand_mailbox = None
dc._mailbox_writers_logged = frozenset()
clock = Clock()
monkeypatch.setattr('src.display_controller.time.monotonic', clock)
dc.clock = clock
return dc return dc
def _post(dc, rid, action='start', **fields): class TestNoMailbox:
dc.cache_manager.set(MAILBOX, dict({'request_id': rid, 'action': action}, **fields)) @pytest.mark.parametrize('with_socket', [False, True])
def test_polling_touches_no_cache_key(self, controller, with_socket):
controller._control_server = FakeServer() if with_socket else None
def _poll_for(dc, seconds, step=1 / 16): # exact in binary: no drift past a floor controller.cache_manager.data[MAILBOX] = {'request_id': 'left', 'action': 'start',
end = dc.clock.t + seconds 'plugin_id': 'clock'}
while dc.clock.t < end: for _ in range(200):
dc._poll_on_demand_requests()
dc.clock.t += step
class TestMailboxCadence:
def test_without_a_socket_it_is_looked_at_every_quarter_second(self, controller):
controller._control_server = None
_poll_for(controller, 10.0)
assert 38 <= controller.cache_manager.stats <= 42
def test_with_a_socket_it_is_looked_at_once_a_second(self, controller):
controller._control_server = FakeServer()
_poll_for(controller, 10.0)
assert 9 <= controller.cache_manager.stats <= 11
def test_a_look_that_finds_nothing_reads_nothing(self, controller):
controller._control_server = FakeServer()
_poll_for(controller, 10.0)
assert controller.cache_manager.reads == []
def test_an_unchanged_mailbox_is_not_read_again(self, controller):
# An already-processed start the delete could not remove, say.
controller._control_server = FakeServer()
controller.cache_manager.delete = MagicMock() # the file stays
_post(controller, 'once', plugin_id='clock')
_poll_for(controller, 10.0)
assert controller.cache_manager.reads.count(MAILBOX) <= 2 # the read + the re-check
controller._activate_on_demand.assert_called_once()
def test_a_mailbox_request_lands_within_a_second_with_the_socket_up(self, controller):
# The upgrade case the other way round: a new display, and a web
# interface (or a plugin) that still writes the mailbox.
controller._control_server = FakeServer()
controller._poll_on_demand_requests()
controller.clock.t += 0.1
_post(controller, 'old-web', plugin_id='clock')
posted = controller.clock.t
while not controller._activate_on_demand.called:
controller._poll_on_demand_requests() controller._poll_on_demand_requests()
controller.clock.t += 0.05 assert controller.cache_manager.calls == []
assert controller.clock.t - posted < 1.5 controller._activate_on_demand.assert_not_called()
assert controller.clock.t - posted <= controller.MAILBOX_POLL_INTERVAL_WITH_SOCKET + 0.06
assert MAILBOX in controller.cache_manager.deletes # consumed
def test_socket_commands_still_land_at_once(self, controller): def test_socket_commands_land_at_once(self, controller):
server = controller._control_server = FakeServer() server = controller._control_server = FakeServer()
controller._poll_on_demand_requests()
server.commands.append(QueuedCommand('sock', Command.ON_DEMAND_START, server.commands.append(QueuedCommand('sock', Command.ON_DEMAND_START,
OnDemandStartArgs(plugin_id='clock'), time.time())) OnDemandStartArgs(plugin_id='clock'), time.time()))
controller._poll_on_demand_requests() # inside the mailbox interval controller._poll_on_demand_requests()
controller._activate_on_demand.assert_called_once() controller._activate_on_demand.assert_called_once()
def test_a_start_is_applied_once_and_writes_no_processed_id(self, controller):
class TestSocketCommandsLeaveTheMailboxAlone:
def test_a_socket_start_reads_and_deletes_no_mailbox(self, controller):
server = controller._control_server = FakeServer() server = controller._control_server = FakeServer()
controller._poll_on_demand_requests() for _ in range(2):
before = list(controller.cache_manager.reads) server.commands.append(QueuedCommand('same', Command.ON_DEMAND_START,
server.commands.append(QueuedCommand('s1', Command.ON_DEMAND_START, OnDemandStartArgs(plugin_id='clock'), time.time()))
OnDemandStartArgs(plugin_id='clock'), time.time())) controller._poll_on_demand_requests()
controller._poll_on_demand_requests()
controller._activate_on_demand.assert_called_once() controller._activate_on_demand.assert_called_once()
assert MAILBOX not in controller.cache_manager.reads[len(before):] assert controller.cache_manager.calls == []
assert controller.cache_manager.deletes == []
def test_a_socket_stop_reads_and_deletes_no_mailbox(self, controller): def test_a_socket_stop_touches_no_cache_key(self, controller):
from src.ipc.contract import OnDemandStopArgs from src.ipc.contract import OnDemandStopArgs
controller.on_demand_active = True controller.on_demand_active = True
controller._clear_on_demand = MagicMock() controller._clear_on_demand = MagicMock()
server = controller._control_server = FakeServer() server = controller._control_server = FakeServer()
server.commands.append(QueuedCommand('s2', Command.ON_DEMAND_STOP, server.commands.append(QueuedCommand('s2', Command.ON_DEMAND_STOP,
OnDemandStopArgs(), time.time())) OnDemandStopArgs(), time.time()))
controller.clock.t += 5
controller._drain_control_commands() controller._drain_control_commands()
controller._clear_on_demand.assert_called_once() controller._clear_on_demand.assert_called_once()
assert MAILBOX not in controller.cache_manager.reads assert controller.cache_manager.calls == []
assert controller.cache_manager.deletes == []
def test_a_mailbox_copy_of_a_socket_command_is_dropped(self, controller): def test_the_mailbox_helpers_are_gone(self):
# An older web interface timed out after the display queued the from src import display_controller as dcm
# command, then wrote the mailbox too. from src import error_aggregator as ea
server = controller._control_server = FakeServer() for name in ('ON_DEMAND_MAILBOX_KEY', 'MailboxWatch'):
server.commands.append(QueuedCommand('both', Command.ON_DEMAND_START, assert not hasattr(dcm, name)
OnDemandStartArgs(plugin_id='clock'), time.time())) assert not hasattr(ea, 'ERROR_CLEAR_REQUEST_KEY')
controller._poll_on_demand_requests() assert not hasattr(cache_module, 'MailboxWatch')
_post(controller, 'both', plugin_id='clock') assert not hasattr(CacheManager, 'file_signature')
_poll_for(controller, 2.0) assert not hasattr(client, 'should_fall_back')
controller._activate_on_demand.assert_called_once() for name in ('_consume_on_demand_request', '_note_mailbox_request',
assert MAILBOX not in controller.cache_manager.data '_mailbox_poll_interval', 'MAILBOX_POLL_INTERVAL_WITH_SOCKET'):
assert not hasattr(dcm.DisplayController, name)
class TestDeprecationLog: # -- stage 5: writes to the retired keys are refused, with one warning per writer -----
def test_each_mailbox_writer_is_logged_once(self, controller, caplog):
controller._control_server = FakeServer()
caplog.set_level(logging.INFO, logger='src.display_controller')
for i, plugin in enumerate(['on-air', 'on-air', 'pomodoro-timer']):
_post(controller, f'r{i}', plugin_id=plugin)
_poll_for(controller, 1.2)
lines = [r.getMessage() for r in caplog.records if 'file mailbox' in r.getMessage()]
assert len(lines) == 2
assert 'on-air' in lines[0] and 'pomodoro-timer' in lines[1]
def test_nothing_is_logged_without_a_socket(self, controller, caplog):
controller._control_server = None
caplog.set_level(logging.INFO, logger='src.display_controller')
_post(controller, 'r', plugin_id='on-air')
_poll_for(controller, 1.0)
controller._activate_on_demand.assert_called_once()
assert not [r for r in caplog.records if 'file mailbox' in r.getMessage()]
# -- file_signature and MailboxWatch -------------------------------------------------
@pytest.fixture @pytest.fixture
def real_cache(tmp_path, monkeypatch): def real_cache(tmp_path, monkeypatch):
monkeypatch.setattr(CacheManager, '_get_writable_cache_dir', lambda self: str(tmp_path)) monkeypatch.setattr(CacheManager, '_get_writable_cache_dir', lambda self: str(tmp_path))
monkeypatch.setattr(cache_module, '_retired_writers_warned', set())
cache = CacheManager() cache = CacheManager()
yield cache yield cache
cache.stop_cleanup_thread() cache.stop_cleanup_thread()
class TestFileSignature: class OldPlugin:
def test_absent_key(self, real_cache): """What an old plugin looks like on the stack: BasePlugin gives every
assert real_cache.file_signature('nothing') is None plugin ``plugin_id`` and ``cache_manager``."""
def test_every_write_is_a_new_signature(self, real_cache): def __init__(self, plugin_id, cache):
seen = set() self.plugin_id = plugin_id
for i in range(20): self.cache_manager = cache
# Same size each time, written as fast as possible.
real_cache.set(MAILBOX, {'request_id': f'r{i:02d}'})
sig = real_cache.file_signature(MAILBOX)
assert isinstance(sig, tuple)
seen.add(sig)
assert len(seen) == 20
def test_gone_after_a_delete(self, real_cache): def trigger(self, target=None):
real_cache.set(MAILBOX, {'a': 1}) self.cache_manager.set(MAILBOX, {'request_id': 'r', 'action': 'start',
real_cache.delete(MAILBOX) 'plugin_id': target or self.plugin_id})
assert real_cache.file_signature(MAILBOX) is None
class TestMailboxWatch: def _warnings(caplog):
def test_reads_once_per_write(self, real_cache): return [r.getMessage() for r in caplog.records
watch = MailboxWatch(MAILBOX) if r.levelno == logging.WARNING and 'retired' in r.getMessage()]
assert watch.changed(real_cache) is False # no file
real_cache.set(MAILBOX, {'request_id': 'a'})
assert watch.changed(real_cache) is True
assert watch.changed(real_cache) is False
real_cache.set(MAILBOX, {'request_id': 'b'})
assert watch.changed(real_cache) is True
def test_forget_reads_again(self, real_cache):
watch = MailboxWatch(MAILBOX)
real_cache.set(MAILBOX, {'request_id': 'a'})
assert watch.changed(real_cache) is True
watch.forget()
assert watch.changed(real_cache) is True
def test_a_rewrite_after_a_delete_is_seen(self, real_cache): class TestRetiredKeys:
watch = MailboxWatch(MAILBOX) @pytest.mark.parametrize('key', sorted(cache_module.RETIRED_MAILBOX_KEYS))
real_cache.set(MAILBOX, {'request_id': 'a'}) def test_a_write_stores_nothing(self, real_cache, key):
assert watch.changed(real_cache) real_cache.set(key, {'request_id': 'r'})
real_cache.delete(MAILBOX) real_cache.save_cache(key, {'request_id': 'r2'})
assert watch.changed(real_cache) is False assert real_cache.get(key, max_age=None, memory_ttl=0) is None
real_cache.set(MAILBOX, {'request_id': 'a'}) assert not [f for f in os.listdir(real_cache.cache_dir) if key in f]
assert watch.changed(real_cache) is True
def test_a_cache_that_cannot_tell_is_read_every_time(self): def test_other_keys_are_unaffected(self, real_cache):
watch = MailboxWatch(MAILBOX) real_cache.set('display_on_demand_state', {'active': True})
assert watch.changed(MagicMock()) is True assert real_cache.get('display_on_demand_state', max_age=None,
assert watch.changed(MagicMock()) is True memory_ttl=0) == {'active': True}
assert watch.changed(object()) is True
def test_the_writing_plugin_is_named_once(self, real_cache, caplog):
caplog.set_level(logging.WARNING)
on_air = OldPlugin('on-air', real_cache)
for _ in range(3):
on_air.trigger()
OldPlugin('pomodoro-timer', real_cache).trigger()
lines = _warnings(caplog)
assert len(lines) == 2
assert "plugin 'on-air'" in lines[0] and 'display_on_demand_request' in lines[0]
assert 'request_on_demand' in lines[0]
assert "plugin 'pomodoro-timer'" in lines[1]
def test_the_writer_is_the_caller_not_the_target(self, real_cache, caplog):
caplog.set_level(logging.WARNING)
OldPlugin('mqtt-notifications', real_cache).trigger(target='clock')
(line,) = _warnings(caplog)
assert "plugin 'mqtt-notifications'" in line and 'clock' not in line
def test_without_a_plugin_on_the_stack_the_request_names_it(self, real_cache, caplog):
caplog.set_level(logging.WARNING)
real_cache.set(MAILBOX, {'request_id': 'r', 'action': 'start', 'plugin_id': 'gif-player'})
(line,) = _warnings(caplog)
assert "plugin 'gif-player' (named in the request)" in line
def test_otherwise_unknown(self, real_cache, caplog):
caplog.set_level(logging.WARNING)
real_cache.set('plugin_error_clear_request', {'request_id': 'r', 'cutoff': 1.0})
real_cache.set('plugin_error_clear_request', {'request_id': 'r2', 'cutoff': 2.0})
(line,) = _warnings(caplog)
assert 'by unknown' in line and '/api/v3/errors/clear' in line
# -- end to end over a real socket --------------------------------------------------- # -- end to end over a real socket ---------------------------------------------------
@@ -479,24 +408,24 @@ class TestOverTheSocket:
finally: finally:
server.close() server.close()
def test_an_older_display_is_an_upgrade_fallback(self, sock_path): def test_an_older_display_is_listening(self, sock_path):
server = ControlServer(sock_path) # no errors.clear handler server = ControlServer(sock_path) # no errors.clear handler
assert server.start() assert server.start()
try: try:
with pytest.raises(client.ControlError) as e: with pytest.raises(client.ControlError) as e:
client.errors_clear('clr-2', 1.0, paths=[sock_path]) client.errors_clear('clr-2', 1.0, paths=[sock_path])
assert e.value.reason == 'unknown_command' and e.value.sent is True assert e.value.reason == 'unknown_command' and e.value.sent is True
assert client.should_fall_back(e.value) assert not client.display_not_listening(e.value)
finally: finally:
server.close() server.close()
def test_no_display_is_a_fallback(self, sock_path): def test_no_display_is_not_listening(self, sock_path):
with pytest.raises(client.ControlError) as e: with pytest.raises(client.ControlError) as e:
client.errors_clear('clr-3', 1.0, paths=[sock_path]) client.errors_clear('clr-3', 1.0, paths=[sock_path])
assert e.value.reason == 'no_socket' and e.value.sent is False assert e.value.reason == 'no_socket' and e.value.sent is False
assert client.should_fall_back(e.value) assert client.display_not_listening(e.value)
def test_a_full_queue_is_not_a_fallback(self, sock_path): def test_a_full_queue_is_listening(self, sock_path):
server = ControlServer(sock_path, queue_size=1) server = ControlServer(sock_path, queue_size=1)
assert server.start() assert server.start()
try: try:
@@ -504,6 +433,6 @@ class TestOverTheSocket:
with pytest.raises(client.ControlError) as e: with pytest.raises(client.ControlError) as e:
client.on_demand_start('q2', 'clock', None, paths=[sock_path]) client.on_demand_start('q2', 'clock', None, paths=[sock_path])
assert e.value.reason == 'busy' and e.value.sent is True assert e.value.reason == 'busy' and e.value.sent is True
assert not client.should_fall_back(e.value) assert not client.display_not_listening(e.value)
finally: finally:
server.close() server.close()
+2 -7
View File
@@ -337,13 +337,8 @@ class TestResumingAfterTheSession:
class TestStopClearsAnError: class TestStopClearsAnError:
def _post_stop(self, c): def _post_stop(self, c):
stop = {'request_id': 'S1', 'action': 'stop'} c._handle_on_demand_request({'request_id': 'S1', 'action': 'stop',
c._last_on_demand_poll = None 'source': 'socket'})
c.cache_manager.get = MagicMock(
side_effect=lambda key, *a, **kw:
stop if key == 'display_on_demand_request' else None)
c.cache_manager.delete = MagicMock()
c._poll_on_demand_requests()
def test_a_stop_after_a_failed_request_clears_the_error(self, controller): def test_a_stop_after_a_failed_request_clears_the_error(self, controller):
_start(controller, plugin_id='uninstalled') _start(controller, plugin_id='uninstalled')
-106
View File
@@ -1,106 +0,0 @@
"""The on-demand request mailbox: how often it is read, and how it is consumed.
The mailbox is a cache key the web process writes and the display process
reads. Two properties matter and neither is obvious from the call site:
* it is polled after every rendered frame, so an uncached read here is a
disk read at frame rate;
* consuming it must not throw away a request that arrived while the previous
one was being processed.
"""
from unittest.mock import MagicMock
import pytest
class TestPollingIsBounded:
"""_poll_on_demand_requests runs ~125x/second on a scrolling mode.
The read is deliberately uncached (memory_ttl=0) because a cached one
pinned the first request for an hour. That makes the call a real disk read,
so it needs a floor -- without one it was ~125 reads per second to find
nothing at all.
"""
def test_first_call_always_reads(self, test_display_controller):
c = test_display_controller
c.cache_manager.get = MagicMock(return_value=None)
c._poll_on_demand_requests()
assert c.cache_manager.get.call_count == 1
def test_immediate_second_call_does_not_read(self, test_display_controller):
c = test_display_controller
c.cache_manager.get = MagicMock(return_value=None)
c._poll_on_demand_requests()
for _ in range(50):
c._poll_on_demand_requests()
assert c.cache_manager.get.call_count == 1, "polling was not bounded"
def test_reads_again_once_the_interval_has_passed(self, test_display_controller, monkeypatch):
c = test_display_controller
c.cache_manager.get = MagicMock(return_value=None)
clock = {"t": 1000.0}
monkeypatch.setattr("src.display_controller.time.monotonic", lambda: clock["t"])
c._poll_on_demand_requests()
clock["t"] += c.ON_DEMAND_POLL_INTERVAL / 2
c._poll_on_demand_requests()
assert c.cache_manager.get.call_count == 1, "read before the interval elapsed"
clock["t"] += c.ON_DEMAND_POLL_INTERVAL
c._poll_on_demand_requests()
assert c.cache_manager.get.call_count == 2
def test_the_interval_is_short_enough_to_feel_instant(self, test_display_controller):
# A person clicking in the web UI must not notice the floor.
assert test_display_controller.ON_DEMAND_POLL_INTERVAL <= 0.5
class TestMailboxIsConsumedByIdentity:
"""Deleting whatever is in the mailbox loses a request that raced in."""
def _arrange(self, controller, first, later):
"""Mailbox returns `first`, then `later` on the pre-delete re-read."""
controller.on_demand_active = False
controller.on_demand_request_id = None
controller._last_on_demand_poll = None
reads = iter([first, later])
def fake_get(key, *a, **kw):
if key == 'display_on_demand_request':
return next(reads, later)
return None # processed-id lookup
controller.cache_manager.get = MagicMock(side_effect=fake_get)
controller.cache_manager.set = MagicMock()
controller.cache_manager.delete = MagicMock()
controller._activate_on_demand = MagicMock()
REQ_A = {'request_id': 'A', 'action': 'start', 'plugin_id': 'p', 'mode': 'm'}
REQ_B = {'request_id': 'B', 'action': 'start', 'plugin_id': 'p', 'mode': 'm'}
def test_own_request_is_deleted(self, test_display_controller):
c = test_display_controller
self._arrange(c, self.REQ_A, self.REQ_A)
c._poll_on_demand_requests()
c.cache_manager.delete.assert_called_once_with('display_on_demand_request')
def test_a_newer_request_is_left_for_the_next_poll(self, test_display_controller):
c = test_display_controller
self._arrange(c, self.REQ_A, self.REQ_B)
c._poll_on_demand_requests()
assert c.cache_manager.delete.call_count == 0, \
"request B was deleted without ever being processed"
def test_an_already_empty_mailbox_is_still_cleared(self, test_display_controller):
c = test_display_controller
self._arrange(c, self.REQ_A, None)
c._poll_on_demand_requests()
c.cache_manager.delete.assert_called_once_with('display_on_demand_request')
def test_the_request_is_still_processed(self, test_display_controller):
c = test_display_controller
self._arrange(c, self.REQ_A, self.REQ_B)
c._poll_on_demand_requests()
c._activate_on_demand.assert_called_once()
+13 -38
View File
@@ -8,8 +8,9 @@ Three separate gaps, all reachable from the web UI's force-display dialog:
* restarting while on-demand was active loaded *only* the on-demand plugin, * restarting while on-demand was active loaded *only* the on-demand plugin,
so normal rotation had nothing to return to for the life of the process; so normal rotation had nothing to return to for the life of the process;
* a stop request was exempt from the duplicate guards on purpose and was * a stop request was exempt from the duplicate guards on purpose and was
never removed from the mailbox, so it was re-processed on every poll never removed from the file mailbox, so it was re-processed on every poll
forever. forever. The mailbox is gone (stage 5); a stop still skips the guards,
so a second click stops a session a race left running.
""" """
from unittest.mock import MagicMock from unittest.mock import MagicMock
@@ -185,51 +186,25 @@ class TestRestartDoesNotStarveTheOtherPlugins:
assert controller.on_demand_active is False assert controller.on_demand_active is False
class TestStopRequestsAreConsumed: class TestStopRequestsSkipTheDuplicateGuard:
"""A stop request is exempt from the duplicate guards, so the mailbox """A stop is exempt from the request-id guard: every one is acted on."""
delete is the only thing that ends it."""
STOP = {'request_id': 'S1', 'action': 'stop'}
def _arrange(self, controller, active): def _arrange(self, controller, active):
controller.on_demand_active = active controller.on_demand_active = active
controller.on_demand_status = 'active' if active else 'idle' controller.on_demand_status = 'active' if active else 'idle'
controller._last_on_demand_poll = None
controller.cache_manager.get = MagicMock(
side_effect=lambda key, *a, **kw:
self.STOP if key == 'display_on_demand_request' else None)
controller.cache_manager.set = MagicMock()
controller.cache_manager.delete = MagicMock()
controller._clear_on_demand = MagicMock() controller._clear_on_demand = MagicMock()
def test_a_handled_stop_is_removed_from_the_mailbox(self, test_display_controller): def test_the_stop_is_acted_on(self, test_display_controller):
c = test_display_controller c = test_display_controller
self._arrange(c, active=True) self._arrange(c, active=True)
c._poll_on_demand_requests() c._handle_on_demand_request({'request_id': 'S1', 'action': 'stop',
c.cache_manager.delete.assert_called_once_with('display_on_demand_request') 'source': 'socket'})
def test_a_stop_arriving_while_idle_is_also_removed(self, test_display_controller):
"""Otherwise a stop sent to an idle display re-fires forever."""
c = test_display_controller
self._arrange(c, active=False)
c._poll_on_demand_requests()
c.cache_manager.delete.assert_called_once_with('display_on_demand_request')
def test_the_stop_is_still_acted_on(self, test_display_controller):
c = test_display_controller
self._arrange(c, active=True)
c._poll_on_demand_requests()
c._clear_on_demand.assert_called_once_with(reason='requested-stop') c._clear_on_demand.assert_called_once_with(reason='requested-stop')
def test_a_start_racing_in_behind_a_stop_is_not_discarded(self, test_display_controller): def test_the_same_stop_twice_is_acted_on_twice(self, test_display_controller):
"""The compare-before-delete applies to stops too."""
c = test_display_controller c = test_display_controller
self._arrange(c, active=True) self._arrange(c, active=True)
newer = {'request_id': 'S2', 'action': 'start', 'plugin_id': 'p', 'mode': 'm'} for _ in range(2):
reads = iter([self.STOP, newer]) c._handle_on_demand_request({'request_id': 'S1', 'action': 'stop',
c.cache_manager.get = MagicMock( 'source': 'socket'})
side_effect=lambda key, *a, **kw: assert c._clear_on_demand.call_count == 2
next(reads, newer) if key == 'display_on_demand_request' else None)
c._poll_on_demand_requests()
assert c.cache_manager.delete.call_count == 0
+38 -50
View File
@@ -2,19 +2,17 @@
and end_on_demand(). and end_on_demand().
A plugin running in the display process used to write the A plugin running in the display process used to write the
``display_on_demand_request`` mailbox, which the display reads once a second ``display_on_demand_request`` mailbox, which the display no longer reads
while the control socket is up. These tests pin the way in that replaces it: (stage 5). These tests pin the way in that replaced it:
* BasePlugin -> PluginManager -> DisplayController.submit_plugin_on_demand, * BasePlugin -> PluginManager -> DisplayController.submit_plugin_on_demand,
which only queues, from any thread; which only queues, from any thread;
* the render thread applies the queue where it applies socket commands, * the render thread applies the queue where it applies socket commands,
through the mailbox's own handler, without the mailbox's read floor, and through _handle_on_demand_request, at once, and woken by the control
woken by the control socket when it is up; socket when it is up;
* a plugin's stop ends only its own session; * a plugin's stop ends only its own session;
* no display to ask (the web interface's plugin manager, an old core's * no display to ask (the web interface's plugin manager, an old core's
plugin manager) answers None, which is a plugin's cue to fall back to the plugin manager) answers None.
mailbox;
* the mailbox still works for plugins that write it.
""" """
import logging import logging
@@ -73,19 +71,10 @@ def controller(test_display_controller):
c_ = test_display_controller c_ = test_display_controller
c_.on_demand_active = False c_.on_demand_active = False
c_.on_demand_request_id = None c_.on_demand_request_id = None
c_._last_on_demand_poll = None c_.cache_manager.get = MagicMock(return_value=None)
mailbox = {'value': None}
def fake_get(key, *a, **kw):
if key == 'display_on_demand_request':
return mailbox['value']
return None
c_.cache_manager.get = MagicMock(side_effect=fake_get)
c_.cache_manager.set = MagicMock() c_.cache_manager.set = MagicMock()
c_.cache_manager.delete = MagicMock() c_.cache_manager.delete = MagicMock()
c_._activate_on_demand = MagicMock() c_._activate_on_demand = MagicMock()
c_.mailbox = mailbox
return c_ return c_
@@ -101,7 +90,7 @@ class TestWiring:
controller.plugin_manager.set_on_demand_handler.assert_called_once_with( controller.plugin_manager.set_on_demand_handler.assert_called_once_with(
controller.submit_plugin_on_demand) controller.submit_plugin_on_demand)
def test_a_start_reaches_the_mailbox_handler(self, wired): def test_a_start_reaches_the_on_demand_handler(self, wired):
controller, manager = wired controller, manager = wired
rid = _plugin('pomodoro-timer', manager).request_on_demand( rid = _plugin('pomodoro-timer', manager).request_on_demand(
mode='pomodoro', duration=30, pinned=True) mode='pomodoro', duration=30, pinned=True)
@@ -139,15 +128,6 @@ class TestWiring:
controller._poll_on_demand_requests() controller._poll_on_demand_requests()
assert seen == ['a', 'b', 'c'] assert seen == ['a', 'b', 'c']
def test_the_mailbox_still_works_for_older_plugins(self, wired):
controller, manager = wired
controller.mailbox['value'] = {'request_id': 'mb', 'action': 'start',
'plugin_id': 'birdnet-go'}
_plugin('on-air', manager).request_on_demand()
controller._poll_on_demand_requests()
ids = [call.args[0]['request_id'] for call in controller._activate_on_demand.call_args_list]
assert 'mb' in ids and len(ids) == 2
def test_a_failing_request_is_contained(self, wired): def test_a_failing_request_is_contained(self, wired):
controller, manager = wired controller, manager = wired
calls = [] calls = []
@@ -174,10 +154,10 @@ class TestPromptness:
controller._service_pending_changes() # well inside the 0.25 s floor controller._service_pending_changes() # well inside the 0.25 s floor
controller._activate_on_demand.assert_called_once() controller._activate_on_demand.assert_called_once()
def test_a_plugin_request_skips_the_mailbox_floor(self, wired): def test_a_plugin_request_lands_on_the_next_poll(self, wired):
controller, manager = wired controller, manager = wired
controller._control_server = _WakeServer() controller._control_server = _WakeServer()
controller._poll_on_demand_requests() # sets the 1 s mailbox floor controller._poll_on_demand_requests()
_plugin('p', manager).request_on_demand() _plugin('p', manager).request_on_demand()
controller._poll_on_demand_requests() controller._poll_on_demand_requests()
controller._activate_on_demand.assert_called_once() controller._activate_on_demand.assert_called_once()
@@ -286,14 +266,13 @@ class TestStop:
controller._poll_on_demand_requests() controller._poll_on_demand_requests()
controller._clear_on_demand.assert_not_called() controller._clear_on_demand.assert_not_called()
def test_a_mailbox_stop_still_ends_any_session(self, wired): def test_a_socket_stop_still_ends_any_session(self, wired):
controller, _ = wired controller, _ = wired
controller.on_demand_active = True controller.on_demand_active = True
controller.on_demand_plugin_id = 'clock' controller.on_demand_plugin_id = 'clock'
controller._clear_on_demand = MagicMock() controller._clear_on_demand = MagicMock()
controller.mailbox['value'] = {'request_id': 's', 'action': 'stop', controller._handle_on_demand_request({'request_id': 's', 'action': 'stop',
'plugin_id': 'on-air'} 'source': 'socket'})
controller._poll_on_demand_requests()
controller._clear_on_demand.assert_called_once_with(reason='requested-stop') controller._clear_on_demand.assert_called_once_with(reason='requested-stop')
def test_start_then_stop_from_one_thread_ends_the_session(self, wired): def test_start_then_stop_from_one_thread_ends_the_session(self, wired):
@@ -314,7 +293,7 @@ class TestStop:
class TestNoDisplay: class TestNoDisplay:
"""None is a plugin's cue to write the mailbox instead.""" """None: no display in this process took the request."""
def test_a_manager_with_no_handler_answers_none(self): def test_a_manager_with_no_handler_answers_none(self):
plugin = _plugin('p', _manager()) plugin = _plugin('p', _manager())
@@ -353,21 +332,30 @@ class TestNoDisplay:
assert bare._plugin_on_demand_pending() is False assert bare._plugin_on_demand_pending() is False
bare._drain_plugin_on_demand() # nothing to do, no error bare._drain_plugin_on_demand() # nothing to do, no error
def test_the_feature_detection_pattern(self): def test_a_mailbox_write_after_none_is_dropped_with_a_warning(self, tmp_path,
"""The hasattr pattern from docs/PLUGIN_API_REFERENCE.md.""" monkeypatch, caplog):
writes = [] """What a plugin written for older cores does on None now: its
fallback write to the retired key stores nothing, and the log names
class OldCorePlugin: # an older core's BasePlugin has no such method it once."""
pass from src import cache_manager as cache_module
from src.cache_manager import CacheManager
for plugin, expect_mailbox in ((OldCorePlugin(), True), monkeypatch.setattr(CacheManager, '_get_writable_cache_dir',
(_plugin('p', _manager()), True), lambda self: str(tmp_path))
(_plugin('p', _manager(lambda r: True)), False)): monkeypatch.setattr(cache_module, '_retired_writers_warned', set())
writes.clear() cache = CacheManager()
if not (hasattr(plugin, 'request_on_demand') try:
and plugin.request_on_demand(mode='m')): plugin = _plugin('birdnet-go', _manager())
writes.append('mailbox') plugin.cache_manager = cache
assert (writes == ['mailbox']) is expect_mailbox caplog.set_level(logging.WARNING)
for _ in range(2):
if plugin.request_on_demand(mode='m') is None:
plugin.cache_manager.set('display_on_demand_request', {
'request_id': 'r', 'action': 'start', 'plugin_id': 'birdnet-go'})
assert cache.get('display_on_demand_request', max_age=None, memory_ttl=0) is None
lines = [r.getMessage() for r in caplog.records if 'retired' in r.getMessage()]
assert len(lines) == 1 and "plugin 'birdnet-go'" in lines[0]
finally:
cache.stop_cleanup_thread()
class TestArguments: class TestArguments:
@@ -401,7 +389,7 @@ class TestArguments:
class TestMockManagers: class TestMockManagers:
def test_a_magicmock_manager_reads_as_not_taken(self): def test_a_magicmock_manager_reads_as_not_taken(self):
"""A plugin's test with a MagicMock manager keeps its mailbox path.""" """A plugin's test with a MagicMock manager reads as "not taken"."""
plugin = _plugin('p', MagicMock()) plugin = _plugin('p', MagicMock())
assert plugin.request_on_demand(mode='m') is None assert plugin.request_on_demand(mode='m') is None
assert plugin.end_on_demand() is None assert plugin.end_on_demand() is None
+10 -19
View File
@@ -12,8 +12,8 @@ frame, so a command is applied:
* at the next frame in Vegas (8 ms here, at 125 fps). * at the next frame in Vegas (8 ms here, at 125 fps).
Each test runs the real run() loop on the fake clock of Each test runs the real run() loop on the fake clock of
test/_run_loop_harness.py and compares the socket with the mailbox for the test/_run_loop_harness.py. The latencies are the fake clock's, so they are
same request. The latencies are the fake clock's, so they are exact. exact. (The file mailbox these were once compared with is gone: stage 5.)
""" """
import os import os
@@ -32,13 +32,10 @@ def _event_time(trace, kind):
return next(e[0] for e in trace["events"] if e[1] == kind) return next(e[0] for e in trace["events"] if e[1] == kind)
def _on_demand_latency(tmp_path, build, via, horizon=40): def _on_demand_latency(tmp_path, build, horizon=40):
h = RunLoopHarness(tmp_path, horizon=horizon) h = RunLoopHarness(tmp_path, horizon=horizon)
build(h) build(h)
if via == "socket": h.control_socket().post(POSTED, Command.ON_DEMAND_START, {"plugin_id": "weather"})
h.control_socket().post(POSTED, Command.ON_DEMAND_START, {"plugin_id": "weather"})
else:
h.on_demand_request(POSTED, "mb1", plugin_id="weather")
trace = h.run() trace = h.run()
return round(_event_time(trace, "on-demand-start") - POSTED, 3), trace return round(_event_time(trace, "on-demand-start") - POSTED, 3), trace
@@ -60,18 +57,12 @@ def _vegas(h):
h.enable_vegas(cycle=30) h.enable_vegas(cycle=30)
@pytest.mark.parametrize("build, mailbox_latency", [ @pytest.mark.parametrize("build", [_static, _dwell, _vegas],
(_static, 0.7), # the next 1 s frame, at t=11 ids=["static-screen", "dwell", "vegas"])
(_dwell, 0.2), # the next 0.25 s tick, at t=10.5 def test_a_socket_command_lands_at_once(tmp_path, build):
(_vegas, 0.02), # the next 10-frame check: 80 ms at 125 fps, ~0.4 s on a Pi 4 # Before stage 2 these waited for the next 1 s frame, the next 0.25 s
], ids=["static-screen", "dwell", "vegas"]) # dwell tick, or the next 10-frame Vegas check.
def test_a_socket_command_lands_at_once(tmp_path, build, mailbox_latency): socket_latency, trace = _on_demand_latency(tmp_path, build)
(tmp_path / "s").mkdir()
(tmp_path / "m").mkdir()
socket_latency, trace = _on_demand_latency(tmp_path / "s", build, "socket")
via_mailbox, _ = _on_demand_latency(tmp_path / "m", build, "mailbox")
assert via_mailbox == pytest.approx(mailbox_latency, abs=0.002)
if build is _vegas: if build is _vegas:
# One 8 ms frame: Vegas checks the queue every frame now. # One 8 ms frame: Vegas checks the queue every frame now.
assert socket_latency <= 0.008 assert socket_latency <= 0.008
+125 -123
View File
@@ -33,87 +33,74 @@ def _cache_manager():
class _NotDelivered(Exception): #: How long the start route waits for a display it has just started (or one
"""The display took an on-demand request over the socket and did not #: systemd already reports running, which may still be loading its plugins)
accept it (``busy``, ``invalid_args``, ...) or did not answer in time.""" #: to serve its control socket, before it gives up. The socket comes up when
#: the display's run loop starts, after every plugin has loaded.
def __init__(self, reason): ON_DEMAND_SOCKET_WAIT_SECONDS = 45.0
super().__init__(reason) #: The same wait when the service was already running: a display that has
self.reason = reason #: just been restarted by someone else. Shorter, because a running display
#: normally has its socket.
ON_DEMAND_SOCKET_WAIT_RUNNING_SECONDS = 10.0
#: Gap between two attempts while waiting for the socket.
ON_DEMAND_SOCKET_RETRY_INTERVAL = 0.5
def _deliver_on_demand(payload): def _send_on_demand(payload):
"""Hand an on-demand request to the display: control socket, else mailbox. """Hand an on-demand request to the display over the control socket.
The socket (src/ipc) answers with an acknowledgement as soon as the Returns the display's acknowledgement: it has the command queued for
display has the command queued for its render thread. The file mailbox its render thread. Raises ``control_client.ControlError`` when it did
is written only when the socket could not carry the request at all not take it; there is no other way to reach the display (the file
(``control_client.should_fall_back``): no socket (the display is stopped mailbox ``display_on_demand_request`` is gone).
or predates it), a refused connection, or a display too old to know the
command. The display reads it within its mailbox poll interval.
A display that had the request and refused it, or did not answer in
time, raises :class:`_NotDelivered`: a mailbox copy would be refused
the same way, or hide a stuck display behind a "success".
Returns ``(transport, socket_error)``: ``'socket'`` and None, or
``'mailbox'`` and the socket failure's reason code.
""" """
try: if payload['action'] == 'start':
if payload['action'] == 'start': return control_client.on_demand_start(
control_client.on_demand_start( payload['request_id'], payload.get('plugin_id'), payload.get('mode'),
payload['request_id'], payload.get('plugin_id'), payload.get('mode'), payload.get('duration'), bool(payload.get('pinned', False)))
payload.get('duration'), bool(payload.get('pinned', False))) return control_client.on_demand_stop(payload['request_id'])
else:
control_client.on_demand_stop(payload['request_id'])
return 'socket', None
except control_client.ControlError as e:
reason = _socket_reason_code(e.reason)
if not control_client.should_fall_back(e):
logger.warning("The display did not accept on-demand %s %s (%s)",
payload['action'], payload['request_id'], e)
raise _NotDelivered(reason) from None
if reason in _QUIET_SOCKET_REASONS:
logger.debug("On-demand %s via the mailbox: %s", payload['action'], e)
else:
logger.warning("Control socket did not take on-demand %s (%s); "
"using the mailbox", payload['action'], e)
except Exception: # never let the socket path break the route
logger.exception("Control socket client failed; using the mailbox")
reason = 'internal'
_cache_manager().set('display_on_demand_request', payload)
return 'mailbox', reason
def _not_delivered_response(request_id, action, reason): def _send_on_demand_when_listening(payload, wait_seconds):
"""The answer when the display had the request and did not accept it.""" """_send_on_demand, retried while no display is listening yet (a display
still starting), for up to ``wait_seconds``. Any other failure, or the
last one once the time is up, raises ``control_client.ControlError``."""
deadline = _pkg.time.monotonic() + wait_seconds
while True:
try:
return _send_on_demand(payload)
except control_client.ControlError as e:
if (not control_client.display_not_listening(e)
or _pkg.time.monotonic() + ON_DEMAND_SOCKET_RETRY_INTERVAL > deadline):
raise
_pkg.time.sleep(ON_DEMAND_SOCKET_RETRY_INTERVAL)
def _socket_error_response(request_id, action, reason, message=None, **extra):
"""The answer when the display did not take an on-demand request: ``400``
for arguments it refused, else ``503``."""
status = 400 if reason == 'invalid_args' else 503 status = 400 if reason == 'invalid_args' else 503
data = {'request_id': request_id, 'transport': 'socket', 'socket_error': reason}
data.update(extra)
return jsonify({ return jsonify({
'status': 'error', 'status': 'error',
'message': (f'The display service did not accept the on-demand {action} ' 'message': message or (f'The display service did not accept the on-demand {action} '
f'request ({reason})'), f'request ({reason})'),
'data': {'request_id': request_id, 'transport': 'socket', 'socket_error': reason}, 'data': data,
}), status }), status
def _withdraw_on_demand(request_id): def _socket_failure_reason(error):
"""Take a start request the route has refused back out of the mailbox. """The reportable reason code for an exception from _send_on_demand, logged."""
if isinstance(error, control_client.ControlError):
The display reads the mailbox for an hour without looking at a reason = _socket_reason_code(error.reason)
request's age, so one left there after an error answer ran whenever the if reason in _QUIET_SOCKET_REASONS:
display next started. Only this request is removed: the mailbox is logger.debug("On-demand request not taken over the control socket: %s", error)
re-read and cleared only while it still holds this request_id, as the else:
display's _consume_on_demand_request does, so a newer request posted in logger.warning("On-demand request not taken over the control socket: %s", error)
the meantime stays for the display to take. return reason
""" logger.error("Control socket client failed", exc_info=error)
cache = _cache_manager() return 'internal'
try:
current = cache.get('display_on_demand_request', max_age=3600, memory_ttl=0)
if isinstance(current, dict) and current.get('request_id') == request_id:
cache.delete('display_on_demand_request')
except Exception: # the route is answering an error already
logger.warning("Could not withdraw on-demand request %s from the mailbox",
request_id, exc_info=True)
@api_v3.route('/display/current', methods=['GET']) @api_v3.route('/display/current', methods=['GET'])
@@ -289,11 +276,10 @@ def start_on_demand_display():
resolved_plugin, resolved_plugin,
) )
# Deliver the request over the control socket, or post it to the # The request goes over the control socket, the only way to reach the
# mailbox the display process polls (DisplayController. # display. A display that is not listening (stopped, or still starting)
# _poll_on_demand_requests). Done before any service start: a stopped # is started when start_service asks for it, and the request is sent
# display has no socket, so the request lands in the mailbox, where a # again once its socket is up.
# freshly started display finds it on its first poll.
request_id = data.get('request_id') or str(uuid.uuid4()) request_id = data.get('request_id') or str(uuid.uuid4())
request_payload = { request_payload = {
'request_id': request_id, 'request_id': request_id,
@@ -305,68 +291,73 @@ def start_on_demand_display():
'timestamp': _pkg.time.time() 'timestamp': _pkg.time.time()
} }
try: try:
transport, socket_error = _deliver_on_demand(request_payload) _send_on_demand(request_payload)
except _NotDelivered as e: except Exception as e: # pylint: disable=broad-except
return _not_delivered_response(request_id, 'start', e.reason) error = e
else:
# A socket acknowledgement is the display itself answering: it is # A socket acknowledgement is the display itself answering: it is
# running and has the request queued, whatever systemd says (a display # running and has the request queued, whatever systemd says (a
# run by hand or in the emulator has no active unit). So nothing is # display run by hand or in the emulator has no active unit). So
# checked or started for it -- that answered "not running" for a request # nothing is checked or started for it. The service is still
# that had already taken effect. The service is still reported the way # reported the way _ensure_display_service_running reports a
# _ensure_display_service_running reports a running one. # running one.
if transport == 'socket':
service_result = (dict(_get_display_service_status(), started=False) service_result = (dict(_get_display_service_status(), started=False)
if start_service else None) if start_service else None)
return _on_demand_started(request_id, resolved_plugin, resolved_mode, return _on_demand_started(request_id, resolved_plugin, resolved_mode,
duration, pinned, service_result, transport, duration, pinned, service_result)
socket_error)
reason = _socket_failure_reason(error)
if not control_client.display_not_listening(error):
# The display had it and refused it, is too old for the command, or
# this web process cannot use the socket at all (switched off, no
# Unix sockets): starting a service would not change that.
return _socket_error_response(request_id, 'start', reason)
service_status = _get_display_service_status() service_status = _get_display_service_status()
if not service_status.get('active') and not start_service: if not service_status.get('active') and not start_service:
# The request is in the mailbox, and the display reads it whenever
# it next starts: taken back out, or a request answered with this
# error ran later anyway.
_withdraw_on_demand(request_id)
return jsonify({ return jsonify({
'status': 'error', 'status': 'error',
'message': 'Display service is not running. Please start the display service or enable "Start Service" option.', 'message': 'Display service is not running. Please start the display service or enable "Start Service" option.',
'service_status': service_status 'service_status': service_status,
'data': {'request_id': request_id, 'transport': 'socket', 'socket_error': reason},
}), 400 }), 400
# start_service means "start it if it is not running", as the UI's # start_service means "start it if it is not running", as the UI's
# checkbox says; _ensure_display_service_running leaves a running service # checkbox says; _ensure_display_service_running leaves a running
# alone. This used to stop a running service, sleep 1.5s and start it # service alone (restarting it cost seconds of blank panel for nothing).
# again, so every on-demand or "Preview on display" click -- and every # Either way the display has no socket yet: wait for it, then send the
# MQTT on-demand command, which posts here with the default -- cold- # request again.
# restarted the display process: every plugin reloaded and the panel was wait = ON_DEMAND_SOCKET_WAIT_RUNNING_SECONDS
# blank for seconds. The restart bought nothing. The running process
# looks at this mailbox at least once a second, from its dwell sleep,
# its render loops and Vegas's interrupt check as well as the main loop
# (DisplayController._mailbox_poll_interval), and a restarted one got
# the request the same way: the
# startup path only restores a session the display itself saved
# (display_on_demand_config), so it loaded nothing it would not have had.
service_result = None service_result = None
if start_service: if not service_status.get('active'):
service_result = _ensure_display_service_running() service_result = _ensure_display_service_running()
# Check if service actually started
if service_result and not service_result.get('active'): if service_result and not service_result.get('active'):
_withdraw_on_demand(request_id)
return jsonify({ return jsonify({
'status': 'error', 'status': 'error',
'message': 'Failed to start display service. Please check service logs or start it manually.', 'message': 'Failed to start display service. Please check service logs or start it manually.',
'service_result': service_result 'service_result': service_result
}), 500 }), 500
wait = ON_DEMAND_SOCKET_WAIT_SECONDS
elif start_service:
service_result = dict(service_status, started=False)
try:
_send_on_demand_when_listening(request_payload, wait)
except Exception as e: # pylint: disable=broad-except
reason = _socket_failure_reason(e)
if control_client.display_not_listening(e):
message = (f'The display service is running but its control socket did not '
f'answer within {int(wait)} seconds ({reason}). It may still be '
f'starting; try again shortly, or check its logs.')
return _socket_error_response(request_id, 'start', reason, message,
service=service_result)
return _socket_error_response(request_id, 'start', reason, service=service_result)
return _on_demand_started(request_id, resolved_plugin, resolved_mode, return _on_demand_started(request_id, resolved_plugin, resolved_mode,
duration, pinned, service_result, transport, duration, pinned, service_result)
socket_error)
def _on_demand_started(request_id, plugin_id, mode, duration, pinned, def _on_demand_started(request_id, plugin_id, mode, duration, pinned, service_result):
service_result, transport, socket_error):
"""The success answer of /display/on-demand/start.""" """The success answer of /display/on-demand/start."""
response_data = { response_data = {
'request_id': request_id, 'request_id': request_id,
@@ -375,10 +366,8 @@ def _on_demand_started(request_id, plugin_id, mode, duration, pinned,
'duration': duration, 'duration': duration,
'pinned': pinned, 'pinned': pinned,
'service': service_result, 'service': service_result,
'transport': transport, 'transport': 'socket',
} }
if socket_error:
response_data['socket_error'] = socket_error
return jsonify({'status': 'success', 'data': response_data}) return jsonify({'status': 'success', 'data': response_data})
@api_v3.route('/display/on-demand/stop', methods=['POST']) @api_v3.route('/display/on-demand/stop', methods=['POST'])
def stop_on_demand_display(): def stop_on_demand_display():
@@ -387,23 +376,34 @@ def stop_on_demand_display():
# _coerce_to_bool: bool("false") is True, which stopped the service. # _coerce_to_bool: bool("false") is True, which stopped the service.
stop_service = _coerce_to_bool(data.get('stop_service', False)) stop_service = _coerce_to_bool(data.get('stop_service', False))
# The running display takes the stop over the control socket, or reads # The running display takes the stop over the control socket and
# it from the mailbox within ON_DEMAND_POLL_INTERVAL, and resumes normal # resumes normal rotation in place (_clear_on_demand); nothing is
# rotation in place (_clear_on_demand); nothing is restarted. # restarted.
request_id = data.get('request_id') or str(uuid.uuid4()) request_id = data.get('request_id') or str(uuid.uuid4())
request_payload = { request_payload = {
'request_id': request_id, 'request_id': request_id,
'action': 'stop', 'action': 'stop',
'timestamp': _pkg.time.time() 'timestamp': _pkg.time.time()
} }
socket_error = None
try: try:
transport, socket_error = _deliver_on_demand(request_payload) _send_on_demand(request_payload)
except _NotDelivered as e: except Exception as e: # pylint: disable=broad-except
socket_error = _socket_failure_reason(e)
if not stop_service: if not stop_service:
return _not_delivered_response(request_id, 'stop', e.reason) if control_client.display_not_listening(e):
service_status = _get_display_service_status()
message = ('Display service is not running, so the stop could not be '
'delivered. If it resumes an on-demand session when it starts, '
'stop it then.' if not service_status.get('active') else
f'The display service is running but its control socket did '
f'not answer ({socket_error}). It may still be starting; '
f'try again shortly.')
return _socket_error_response(request_id, 'stop', socket_error, message,
service=service_status)
return _socket_error_response(request_id, 'stop', socket_error)
# Stopping the service ends on-demand too, whatever the display did # Stopping the service ends on-demand too, whatever the display did
# with the request. # with the request.
transport, socket_error = 'socket', e.reason
service_result = None service_result = None
if stop_service: if stop_service:
@@ -412,11 +412,13 @@ def stop_on_demand_display():
response_data = { response_data = {
'request_id': request_id, 'request_id': request_id,
'service': service_result, 'service': service_result,
'transport': transport, 'transport': 'socket',
} }
if socket_error: if socket_error:
response_data['socket_error'] = socket_error response_data['socket_error'] = socket_error
return jsonify({'status': 'success', 'data': response_data}) return jsonify({'status': 'success', 'data': response_data})
@api_v3.route('/display/current-status', methods=['GET']) @api_v3.route('/display/current-status', methods=['GET'])
def get_current_display_status(): def get_current_display_status():
"""Return the display mode/plugin currently intended to be shown. """Return the display mode/plugin currently intended to be shown.
+25 -36
View File
@@ -370,25 +370,13 @@ def _redact_error_record(record):
def _read_errors(): def _read_errors():
snapshot, clear_request = _errors.read_error_report(_errors_cache()) return _errors.read_error_report(_errors_cache())
return snapshot, clear_request
def _send_error_clear(request_id, cutoff): def _send_error_clear(request_id, cutoff):
"""``errors.clear`` over the control socket: the display's answer, or None """``errors.clear`` over the control socket: the display's answer.
when the socket could not carry it (no socket, or a display older than Raises ControlError when it did not take or apply it."""
the command) and the clear goes to the mailbox instead. A display that return _pkg.control_client.errors_clear(request_id, cutoff)
took the request and failed raises ControlError (no second copy)."""
client = _pkg.control_client
try:
return client.errors_clear(request_id, cutoff)
except client.ControlError as e:
if not client.should_fall_back(e):
raise
_pkg._log_socket_failure('errors.clear', e, _pkg._socket_reason_code(e.reason))
except Exception: # never let the socket path break the route
logger.exception("Control socket client failed clearing errors; using the mailbox")
return None
@api_v3.route('/errors/summary', methods=['GET']) @api_v3.route('/errors/summary', methods=['GET'])
@@ -402,7 +390,7 @@ def get_error_summary():
until it has reported; ``generated_at`` says when it did. until it has reported; ``generated_at`` says when it did.
""" """
try: try:
summary = _errors.error_summary_from_report(*_read_errors()) summary = _errors.error_summary_from_report(_read_errors())
summary['recent_errors'] = [_redact_error_record(r) for r in summary['recent_errors']] summary['recent_errors'] = [_redact_error_record(r) for r in summary['recent_errors']]
for pattern in summary['active_patterns'].values(): for pattern in summary['active_patterns'].values():
if isinstance(pattern, dict) and isinstance(pattern.get('sample_messages'), list): if isinstance(pattern, dict) and isinstance(pattern.get('sample_messages'), list):
@@ -430,7 +418,7 @@ def get_plugin_errors(plugin_id):
recorded errors is "healthy". recorded errors is "healthy".
""" """
try: try:
health = _errors.plugin_health_from_report(*_read_errors(), plugin_id) health = _errors.plugin_health_from_report(_read_errors(), plugin_id)
health['last_error'] = _redact_error_record(health['last_error']) health['last_error'] = _redact_error_record(health['last_error'])
return success_response(data=health, message="Plugin health retrieved") return success_response(data=health, message="Plugin health retrieved")
except Exception as e: except Exception as e:
@@ -449,9 +437,10 @@ def clear_old_errors():
max_age_hours: Maximum age in hours (default: 24, max: 8760 = 1 year) max_age_hours: Maximum age in hours (default: 24, max: 8760 = 1 year)
all: true clears every error recorded so far (max_age_hours ignored) all: true clears every error recorded so far (max_age_hours ignored)
The errors live in the display service, so this records a clear request The errors live in the display service, so the clear is sent to it over
that it applies within a few seconds. Reads hide the cleared errors from the control socket, and it has applied it when this answers. Without a
the moment the request is recorded. running display it fails with 503: the errors shown are then the last
run's, and the display's next run starts with none.
""" """
try: try:
data = request.get_json(silent=True) or {} data = request.get_json(silent=True) or {}
@@ -492,28 +481,28 @@ def clear_old_errors():
send=_send_error_clear) send=_send_error_clear)
except _pkg.control_client.ControlError as e: except _pkg.control_client.ControlError as e:
reason = _pkg._socket_reason_code(e.reason) reason = _pkg._socket_reason_code(e.reason)
logger.warning("The display did not apply the error clear: %s", e) _pkg._log_socket_failure('errors.clear', e, reason)
if _pkg.control_client.display_not_listening(e):
message = ("The display service is not running (or is still starting), "
"so the errors could not be cleared. The errors shown are "
"from its last run; it starts again with none.")
elif reason in _pkg.control_client.UPGRADE_REASONS:
message = ("The running display service is too old to clear errors; "
"restart it to pick up the installed version")
elif reason in _pkg._QUIET_SOCKET_REASONS:
message = ("The control socket is not available here, so the errors "
"could not be cleared")
else:
message = "The display service did not apply the clear"
return error_response( return error_response(
error_code=ErrorCode.SYSTEM_ERROR, error_code=ErrorCode.SYSTEM_ERROR,
message="The display service did not apply the clear", message=message,
context={'socket_error': reason}, context={'socket_error': reason},
status_code=503 status_code=503
) )
except OSError as e:
logger.error("Could not record an error clear request: %s", e)
return error_response(
error_code=ErrorCode.SYSTEM_ERROR,
message="Could not record the clear request in the shared cache",
status_code=500
)
scope = "all errors" if clear_all else f"errors older than {max_age_hours} hours" scope = "all errors" if clear_all else f"errors older than {max_age_hours} hours"
if result.get('applied'): return success_response(data=result, message=f"Cleared {scope}")
message = f"Cleared {scope}"
else:
message = (f"Clear of {scope} requested; the display service applies it "
f"within about {int(_errors.SNAPSHOT_TICK_INTERVAL)} seconds")
return success_response(data=result, message=message)
except Exception as e: except Exception as e:
logger.error(f"Error clearing old errors: {e}", exc_info=True) logger.error(f"Error clearing old errors: {e}", exc_info=True)
return error_response( return error_response(