mirror of
https://github.com/ChuckBuilds/LEDMatrix.git
synced 2026-10-05 23:05:10 +00:00
feat(web): a start that waits for the display answers 202 and is delivered in the background
The start route held a request open for up to 45 s while a cold-started display loaded its plugins; the MQTT bridge (15 s timeout) and browsers reported a failure for a request that was then delivered. Now, when no display is listening, the route starts the service if asked and answers 202 with status "starting" at once. A single worker in the web process (web_interface/on_demand_dispatch.py) sends the request until the display acknowledges it or the wait runs out (45 s cold start, 10 s for a running service without a socket yet). A newer start supersedes the pending one; a stop cancels it (and succeeds, with cancelled_request_id, even with no display listening). The outcome is reported by /display/on-demand/status (source "web": starting, or error with start-timeout or the socket's reason, until the display publishes something newer) and by /display/current-status as on_demand_pending. Callers: the web UI's on-demand modal and "Preview on display" treat "starting" as taken (an info toast); the MQTT bridge already treats any non-error 2xx as success (now pinned by a test). Tests: the dispatcher (ack, retry then ack, start-timeout, other failures, superseded, an in-flight ack for a superseded start, stop while pending, a per-start wait, outcome lifetime); the routes (202, status routes while pending and after a timeout, a later display state replacing the failure, stop while pending, a new start superseding); a JS suite for app.js. Mutation check: 20 mutants on the worker, the routes and app.js, 20 killed. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
Chuck
@@ -9,7 +9,7 @@ from web_interface.blueprints.api_v3 import (
|
||||
_get_display_service_status, _socket_reason_code, _stop_display_service, api_v3,
|
||||
jsonify, logger, request, uuid,
|
||||
)
|
||||
from web_interface import display_preview, display_state
|
||||
from web_interface import display_preview, display_state, on_demand_dispatch
|
||||
import web_interface.blueprints.api_v3 as _pkg
|
||||
from src.ipc import client as control_client
|
||||
# Read through the module rather than bound by value: tests patch these
|
||||
@@ -33,17 +33,29 @@ def _cache_manager():
|
||||
|
||||
|
||||
|
||||
#: How long the start route waits for a display it has just started (or one
|
||||
#: systemd already reports running, which may still be loading its plugins)
|
||||
#: 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.
|
||||
ON_DEMAND_SOCKET_WAIT_SECONDS = 45.0
|
||||
#: The same wait when the service was already running: a display that has
|
||||
#: just been restarted by someone else. Shorter, because a running display
|
||||
#: normally has its socket.
|
||||
#: How long a start is sent again to a service that systemd reports running
|
||||
#: but that has no socket yet (a display still loading its plugins, or one
|
||||
#: someone else just restarted). A cold start gets the dispatcher's own
|
||||
#: START_WAIT_SECONDS. Either way the route answers at once (202) and the
|
||||
#: web process's dispatcher does the waiting.
|
||||
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 _dispatcher():
|
||||
"""The web process's on-demand dispatcher (web_interface/on_demand_dispatch.py)."""
|
||||
return on_demand_dispatch.get_dispatcher(_send_on_demand)
|
||||
|
||||
|
||||
def _pending_start_state():
|
||||
"""A start the dispatcher is still delivering, or one it gave up on:
|
||||
the state the status routes report instead of the display's. None when
|
||||
there is none (or it was delivered, after which the display's own
|
||||
state is the truth)."""
|
||||
dispatcher = on_demand_dispatch.current()
|
||||
status = dispatcher.status() if dispatcher is not None else None
|
||||
if status is None or status.get('status') not in ('starting', 'error'):
|
||||
return None
|
||||
return status
|
||||
|
||||
|
||||
def _send_on_demand(payload):
|
||||
@@ -61,21 +73,6 @@ def _send_on_demand(payload):
|
||||
return control_client.on_demand_stop(payload['request_id'])
|
||||
|
||||
|
||||
def _send_on_demand_when_listening(payload, wait_seconds):
|
||||
"""_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``."""
|
||||
@@ -205,6 +202,7 @@ def get_on_demand_status():
|
||||
"""
|
||||
state = display_state.on_demand_state(display_state.read_state())
|
||||
source = 'socket'
|
||||
pending = _pending_start_state()
|
||||
if state is None:
|
||||
source = 'cache'
|
||||
cache = _cache_manager()
|
||||
@@ -213,6 +211,10 @@ def get_on_demand_status():
|
||||
# copy it read for the full max_age -- "active" for two minutes after
|
||||
# the display had already stopped.
|
||||
state = cache.get('display_on_demand_state', max_age=120, memory_ttl=0)
|
||||
if pending is not None and _shadows(pending, state):
|
||||
# A start the web process is still delivering, or gave up on
|
||||
# (start-timeout): newer than anything the display has said.
|
||||
state, source = pending, 'web'
|
||||
if state is None:
|
||||
state = {
|
||||
'active': False,
|
||||
@@ -228,6 +230,18 @@ def get_on_demand_status():
|
||||
'source': source,
|
||||
}
|
||||
})
|
||||
def _shadows(pending, state):
|
||||
"""Whether the web process's pending start (or its failure) is newer
|
||||
than the display's on-demand ``state``. While it is still being sent it
|
||||
always is; a failure is, until the display publishes something later."""
|
||||
if pending.get('status') == 'starting' or not isinstance(state, dict):
|
||||
return True
|
||||
shown = state.get('last_updated')
|
||||
if not isinstance(shown, (int, float)) or isinstance(shown, bool):
|
||||
return True
|
||||
return shown < (pending.get('last_updated') or 0)
|
||||
|
||||
|
||||
@api_v3.route('/display/on-demand/start', methods=['POST'])
|
||||
def start_on_demand_display():
|
||||
"""Request the display controller to run a specific plugin on-demand."""
|
||||
@@ -290,6 +304,11 @@ def start_on_demand_display():
|
||||
'pinned': pinned,
|
||||
'timestamp': _pkg.time.time()
|
||||
}
|
||||
# This start supersedes one the dispatcher is still delivering,
|
||||
# whatever becomes of it: an older request must not land after it.
|
||||
dispatcher = on_demand_dispatch.current()
|
||||
if dispatcher is not None:
|
||||
dispatcher.cancel('superseded')
|
||||
try:
|
||||
_send_on_demand(request_payload)
|
||||
except Exception as e: # pylint: disable=broad-except
|
||||
@@ -325,8 +344,10 @@ def start_on_demand_display():
|
||||
# start_service means "start it if it is not running", as the UI's
|
||||
# checkbox says; _ensure_display_service_running leaves a running
|
||||
# service alone (restarting it cost seconds of blank panel for nothing).
|
||||
# Either way the display has no socket yet: wait for it, then send the
|
||||
# request again.
|
||||
# Either way the display has no socket yet. The route does not wait for
|
||||
# it -- a cold start can outlast a client's timeout (the MQTT bridge's is
|
||||
# 15 s) -- but answers 202 and leaves the sending to the dispatcher,
|
||||
# whose outcome the status routes report.
|
||||
wait = ON_DEMAND_SOCKET_WAIT_RUNNING_SECONDS
|
||||
service_result = None
|
||||
if not service_status.get('active'):
|
||||
@@ -337,24 +358,28 @@ def start_on_demand_display():
|
||||
'message': 'Failed to start display service. Please check service logs or start it manually.',
|
||||
'service_result': service_result
|
||||
}), 500
|
||||
wait = ON_DEMAND_SOCKET_WAIT_SECONDS
|
||||
wait = on_demand_dispatch.START_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,
|
||||
duration, pinned, service_result)
|
||||
_dispatcher().submit(request_payload, wait_seconds=wait)
|
||||
return jsonify({
|
||||
'status': 'starting',
|
||||
'message': ('The display service is starting; the request is sent to it as soon '
|
||||
'as it is listening. Check the on-demand status for the outcome.'),
|
||||
'data': {
|
||||
'request_id': request_id,
|
||||
'plugin_id': resolved_plugin,
|
||||
'mode': resolved_mode,
|
||||
'duration': duration,
|
||||
'pinned': pinned,
|
||||
'service': service_result,
|
||||
'transport': 'socket',
|
||||
'socket_error': reason,
|
||||
'pending': True,
|
||||
'wait_seconds': wait,
|
||||
},
|
||||
}), 202
|
||||
|
||||
|
||||
def _on_demand_started(request_id, plugin_id, mode, duration, pinned, service_result):
|
||||
@@ -386,11 +411,15 @@ def stop_on_demand_display():
|
||||
'timestamp': _pkg.time.time()
|
||||
}
|
||||
socket_error = None
|
||||
# A start the web process is still delivering is dropped first: the
|
||||
# stop is newer, whatever happens to it below.
|
||||
dispatcher = on_demand_dispatch.current()
|
||||
cancelled = dispatcher.cancel('requested-stop') if dispatcher is not None else None
|
||||
try:
|
||||
_send_on_demand(request_payload)
|
||||
except Exception as e: # pylint: disable=broad-except
|
||||
socket_error = _socket_failure_reason(e)
|
||||
if not stop_service:
|
||||
if not stop_service and not (cancelled and control_client.display_not_listening(e)):
|
||||
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 '
|
||||
@@ -414,6 +443,9 @@ def stop_on_demand_display():
|
||||
'service': service_result,
|
||||
'transport': 'socket',
|
||||
}
|
||||
if cancelled:
|
||||
# The start it ended never reached the display.
|
||||
response_data['cancelled_request_id'] = cancelled
|
||||
if socket_error:
|
||||
response_data['socket_error'] = socket_error
|
||||
return jsonify({'status': 'success', 'data': response_data})
|
||||
@@ -448,4 +480,10 @@ def get_current_display_status():
|
||||
'plugin_id': None,
|
||||
'last_updated': None,
|
||||
}
|
||||
return jsonify({'status': 'success', 'data': dict(state, source=source)})
|
||||
data = dict(state, source=source)
|
||||
pending = _pending_start_state()
|
||||
if pending is not None:
|
||||
# An on-demand start the web process is still delivering (or gave
|
||||
# up on): what the panel is about to show, or why it will not.
|
||||
data['on_demand_pending'] = pending
|
||||
return jsonify({'status': 'success', 'data': data})
|
||||
|
||||
@@ -0,0 +1,221 @@
|
||||
"""Deliver an on-demand start to a display that is not listening yet.
|
||||
|
||||
``POST /api/v3/display/on-demand/start`` can find no display on the control
|
||||
socket: the service is stopped (the route starts it) or still loading its
|
||||
plugins. The socket comes up only when the display's run loop starts, which
|
||||
can take longer than a client waits -- the MQTT bridge gives up after 15 s.
|
||||
So the route answers at once (``202``, ``status: "starting"``) and hands
|
||||
the request to the one :class:`OnDemandDispatcher` of the web process, whose
|
||||
worker thread sends it again until the display acknowledges it or
|
||||
:data:`START_WAIT_SECONDS` pass.
|
||||
|
||||
* One request at a time: a newer start replaces the pending one, and a
|
||||
stop cancels it (:meth:`OnDemandDispatcher.cancel`).
|
||||
* Its outcome is :meth:`OnDemandDispatcher.status`, which
|
||||
``GET /display/on-demand/status`` and ``/display/current-status`` report:
|
||||
``starting`` while it waits, ``delivered`` once acknowledged (the
|
||||
display's own state takes over from there), or ``error`` with
|
||||
``start-timeout`` or the socket's reason.
|
||||
|
||||
Nothing is written to disk: the file mailbox that once carried such a
|
||||
request is gone (docs/IPC_CONTROL_SOCKET.md, stage 5).
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import threading
|
||||
import time
|
||||
from typing import Any, Callable, Dict, Optional
|
||||
|
||||
from src.ipc import client as control_client
|
||||
from src.logging_config import get_logger
|
||||
|
||||
logger = get_logger(__name__)
|
||||
|
||||
#: How long the worker keeps sending a start before it gives up
|
||||
#: (``start-timeout``). The socket comes up when the display's run loop
|
||||
#: starts, after every plugin has loaded.
|
||||
START_WAIT_SECONDS = 45.0
|
||||
|
||||
#: Gap between two sends while nothing is listening.
|
||||
RETRY_INTERVAL = 0.5
|
||||
|
||||
#: How long a finished outcome (delivered, error, cancelled) is still
|
||||
#: reported, so a client polling every few seconds sees it.
|
||||
OUTCOME_SECONDS = 120.0
|
||||
|
||||
#: ``send(payload)`` hands the request to the display (the route's
|
||||
#: ``_send_on_demand``) and raises ``ControlError`` when it does not take it.
|
||||
Sender = Callable[[Dict[str, Any]], Any]
|
||||
|
||||
|
||||
class OnDemandDispatcher:
|
||||
"""One pending on-demand start, and the worker thread that delivers it."""
|
||||
|
||||
def __init__(self, send: Sender, *,
|
||||
wait_seconds: Optional[float] = None,
|
||||
retry_interval: Optional[float] = None,
|
||||
clock: Callable[[], float] = time.monotonic,
|
||||
wall_clock: Callable[[], float] = time.time):
|
||||
self._send = send
|
||||
self.wait_seconds = START_WAIT_SECONDS if wait_seconds is None else wait_seconds
|
||||
self.retry_interval = RETRY_INTERVAL if retry_interval is None else retry_interval
|
||||
self._clock = clock
|
||||
self._wall = wall_clock
|
||||
self._lock = threading.Lock()
|
||||
self._wake = threading.Event()
|
||||
# Bumped by every submit and cancel: a send that started under an
|
||||
# older generation does not report its result as the current one.
|
||||
self._generation = 0
|
||||
self._pending: Optional[Dict[str, Any]] = None
|
||||
self._deadline = 0.0
|
||||
self._status: Optional[Dict[str, Any]] = None
|
||||
self._finished_at: Optional[float] = None
|
||||
self._thread: Optional[threading.Thread] = None
|
||||
|
||||
# -- the routes' side ------------------------------------------------------
|
||||
|
||||
def submit(self, payload: Dict[str, Any], wait_seconds: Optional[float] = None) -> None:
|
||||
"""Deliver ``payload`` (an on-demand start) in the background,
|
||||
replacing any start still pending."""
|
||||
with self._lock:
|
||||
self._generation += 1
|
||||
superseded = self._pending
|
||||
self._pending = dict(payload)
|
||||
self._deadline = self._clock() + (self.wait_seconds if wait_seconds is None
|
||||
else wait_seconds)
|
||||
self._status = self._describe('starting', payload)
|
||||
self._finished_at = None
|
||||
if self._thread is None or not self._thread.is_alive():
|
||||
self._thread = threading.Thread(target=self._run, name='on-demand-dispatch',
|
||||
daemon=True)
|
||||
self._thread.start()
|
||||
if superseded is not None:
|
||||
logger.info("On-demand start %s superseded by %s before the display took it",
|
||||
superseded.get('request_id'), payload.get('request_id'))
|
||||
self._wake.set()
|
||||
|
||||
def cancel(self, reason: str = 'cancelled') -> Optional[str]:
|
||||
"""Drop the pending start (a stop arrived). Returns its request id,
|
||||
or None when nothing was pending."""
|
||||
with self._lock:
|
||||
pending = self._pending
|
||||
if pending is None:
|
||||
return None
|
||||
self._generation += 1
|
||||
self._pending = None
|
||||
self._finish(self._describe('idle', pending, last_event=reason))
|
||||
self._wake.set()
|
||||
logger.info("On-demand start %s cancelled before the display took it (%s)",
|
||||
pending.get('request_id'), reason)
|
||||
return pending.get('request_id')
|
||||
|
||||
def status(self) -> Optional[Dict[str, Any]]:
|
||||
"""The pending start's state, or its outcome for OUTCOME_SECONDS
|
||||
after it finished; None otherwise. In the shape of the display's
|
||||
on-demand state (``active``, ``status``, ``error``, ...), plus
|
||||
``source: "web"``."""
|
||||
with self._lock:
|
||||
if self._status is None:
|
||||
return None
|
||||
if (self._finished_at is not None
|
||||
and self._clock() - self._finished_at > OUTCOME_SECONDS):
|
||||
return None
|
||||
return dict(self._status)
|
||||
|
||||
def pending(self) -> bool:
|
||||
with self._lock:
|
||||
return self._pending is not None
|
||||
|
||||
# -- the worker ------------------------------------------------------------
|
||||
|
||||
def _describe(self, status: str, payload: Dict[str, Any], error: Optional[str] = None,
|
||||
last_event: Optional[str] = None) -> Dict[str, Any]:
|
||||
return {
|
||||
'active': False,
|
||||
'status': status,
|
||||
'error': error,
|
||||
'last_event': last_event,
|
||||
'request_id': payload.get('request_id'),
|
||||
'plugin_id': payload.get('plugin_id'),
|
||||
'mode': payload.get('mode'),
|
||||
'duration': payload.get('duration'),
|
||||
'pinned': bool(payload.get('pinned', False)),
|
||||
'last_updated': self._wall(),
|
||||
'source': 'web',
|
||||
}
|
||||
|
||||
def _finish(self, status: Dict[str, Any]) -> None:
|
||||
"""Record an outcome. Caller holds _lock."""
|
||||
self._status = status
|
||||
self._finished_at = self._clock()
|
||||
|
||||
def _run(self) -> None:
|
||||
while True:
|
||||
with self._lock:
|
||||
payload, generation = self._pending, self._generation
|
||||
deadline = self._deadline
|
||||
if payload is None:
|
||||
self._thread = None
|
||||
return
|
||||
outcome, error = self._attempt(payload)
|
||||
with self._lock:
|
||||
if generation != self._generation:
|
||||
continue # superseded or cancelled meanwhile
|
||||
if outcome == 'retry' and self._clock() + self.retry_interval > deadline:
|
||||
outcome, error = 'error', 'start-timeout'
|
||||
if outcome == 'delivered':
|
||||
self._pending = None
|
||||
self._finish(self._describe('delivered', payload,
|
||||
last_event='delivered'))
|
||||
elif outcome == 'error':
|
||||
self._pending = None
|
||||
self._finish(self._describe('error', payload, error=error))
|
||||
else:
|
||||
self._wake.clear()
|
||||
if outcome == 'delivered':
|
||||
logger.info("On-demand start %s delivered once the display was listening",
|
||||
payload.get('request_id'))
|
||||
elif outcome == 'error':
|
||||
logger.warning("On-demand start %s not delivered: %s",
|
||||
payload.get('request_id'), error)
|
||||
else:
|
||||
# A submit or cancel wakes the wait at once.
|
||||
self._wake.wait(self.retry_interval)
|
||||
|
||||
def _attempt(self, payload: Dict[str, Any]):
|
||||
try:
|
||||
self._send(payload)
|
||||
except control_client.ControlError as e:
|
||||
if control_client.display_not_listening(e):
|
||||
return 'retry', None
|
||||
return 'error', str(e.reason)
|
||||
except Exception: # pylint: disable=broad-except
|
||||
logger.exception("On-demand start %s: the control socket client failed",
|
||||
payload.get('request_id'))
|
||||
return 'error', 'internal'
|
||||
return 'delivered', None
|
||||
|
||||
|
||||
_dispatcher: Optional[OnDemandDispatcher] = None
|
||||
_dispatcher_lock = threading.Lock()
|
||||
|
||||
|
||||
def get_dispatcher(send: Sender) -> OnDemandDispatcher:
|
||||
"""The web process's dispatcher, created on first use."""
|
||||
global _dispatcher
|
||||
with _dispatcher_lock:
|
||||
if _dispatcher is None:
|
||||
_dispatcher = OnDemandDispatcher(send)
|
||||
return _dispatcher
|
||||
|
||||
|
||||
def current() -> Optional[OnDemandDispatcher]:
|
||||
"""The dispatcher if one was created, without creating one."""
|
||||
return _dispatcher
|
||||
|
||||
|
||||
def reset_for_tests() -> None:
|
||||
global _dispatcher
|
||||
with _dispatcher_lock:
|
||||
_dispatcher = None
|
||||
@@ -356,9 +356,12 @@ window.previewPluginNow = function(pluginId) {
|
||||
})
|
||||
.then(r => r.json())
|
||||
.then(data => {
|
||||
// 'starting' (202): the display service is starting and the request
|
||||
// follows once it listens.
|
||||
const starting = data.status === 'starting';
|
||||
showNotification(data.message || ('Previewing ' + pluginId + ' for 60 seconds'),
|
||||
data.status || 'success');
|
||||
if (data.status === 'success') window.toggleFloatingPreview(true);
|
||||
starting ? 'info' : (data.status || 'success'));
|
||||
if (data.status === 'success' || starting) window.toggleFloatingPreview(true);
|
||||
})
|
||||
.catch(err => {
|
||||
showNotification('Preview failed: ' + err.message, 'error');
|
||||
|
||||
@@ -1739,6 +1739,13 @@ function submitOnDemandRequest(event) {
|
||||
showNotification(`Requested on-demand mode for ${pluginName}`, 'success');
|
||||
closeOnDemandModal();
|
||||
setTimeout(() => loadOnDemandStatus(true), 700);
|
||||
} else if (result.status === 'starting') {
|
||||
// 202: the display service is starting; the web process sends
|
||||
// the request once it listens. The status card shows the outcome.
|
||||
const pluginName = resolvePluginDisplayName(currentOnDemandPluginId);
|
||||
showNotification(`Starting the display for ${pluginName}…`, 'info');
|
||||
closeOnDemandModal();
|
||||
setTimeout(() => loadOnDemandStatus(true), 700);
|
||||
} else {
|
||||
console.error('[submitOnDemandRequest] Request failed:', result);
|
||||
showNotification(result.message || 'Failed to start on-demand mode', 'error');
|
||||
|
||||
Reference in New Issue
Block a user