From 6ef3abe39330764dc8d98f4b12eb7e4371e01937 Mon Sep 17 00:00:00 2001 From: Name <2718612@2178972821991.net> Date: Sun, 19 Apr 2026 14:13:18 -0600 Subject: [PATCH] changes --- docs-es/v2.0/troubleshooting-es.md | 4 + docs/v2.0/troubleshooting.md | 4 + src/scheduler.py | 169 +++++++++++++++++++++++++++++ src/test_scheduler.py | 120 +++++++++++++++++++- 4 files changed, 292 insertions(+), 5 deletions(-) diff --git a/docs-es/v2.0/troubleshooting-es.md b/docs-es/v2.0/troubleshooting-es.md index b2befc84..16f6b3d5 100644 --- a/docs-es/v2.0/troubleshooting-es.md +++ b/docs-es/v2.0/troubleshooting-es.md @@ -137,6 +137,8 @@ Si oscila entre ready/error, valide credenciales y timeouts de integración en ` Si el shaping de arranque comienza antes de que topology runtime publique la generación actual de `shaping_inputs.json`, las versiones actuales mantienen el scheduler en un estado de espera de arranque y reintentan el shaping inicial cada pocos segundos. Un mensaje breve como `still building outputs for the current source generation` justo después de reiniciar normalmente significa que LibreQoS todavía está terminando el ciclo de importación y publicación de runtime, no que el shaping quede detenido hasta la siguiente actualización de 30 minutos. +Si una actualización programada de integración cae mientras topology runtime todavía está publicando salidas para la nueva generación de fuente, las versiones actuales mantienen el scheduler en estado de espera para esa generación y reintentan automáticamente el shaping programado en cuanto topology runtime termina. Trate `Scheduled shaping refresh deferred` como una espera transitoria solo cuando el mensaje indique que topology runtime todavía está construyendo salidas para la generación actual. Si en cambio indica que topology runtime falló para la generación actual, revise directamente esa falla de runtime. + Si el arranque del scheduler permanece demasiado tiempo en esa espera, o entra en estado degradado con un mensaje indicando que topology runtime falló para la generación actual, revise: ```bash @@ -146,6 +148,8 @@ journalctl -u lqos_scheduler --since "30 minutes ago" journalctl -u lqosd --since "30 minutes ago" ``` +Si `journalctl -u lqosd` muestra advertencias repetidas como `BeginIngest queue full`, `IngestChunk queue full` o `EndIngest queue full` durante el arranque o justo después de una importación de topología, los builds anteriores estaban descartando tramas de ingesta hacia Insight porque la cola local del canal de control era demasiado pequeña para ráfagas grandes. Los builds actuales aplican backpressure sobre el socket de Insight para esos lotes de ingesta, por lo que esas advertencias ya no deberían aparecer durante ráfagas cortas de arranque o importación. Si siguen apareciendo después de actualizar, revise primero la presión de CPU de `lqosd` y la conectividad reciente del canal de control antes de asumir que el shaping está fallando. + ### RTNETLINK answers: Invalid argument Suele indicar que no se pudo agregar correctamente qdisc MQ en la NIC (colas RX/TX insuficientes). Verifique [NICs recomendadas](requirements-es.md). diff --git a/docs/v2.0/troubleshooting.md b/docs/v2.0/troubleshooting.md index 9c341feb..527bd19a 100644 --- a/docs/v2.0/troubleshooting.md +++ b/docs/v2.0/troubleshooting.md @@ -156,6 +156,8 @@ Routine package upgrades now keep `lqosd` in charge of the main WebUI when `/etc If startup shaping begins before topology runtime has finished publishing the current generation of `shaping_inputs.json`, current builds keep the scheduler in a startup wait state and retry the initial shaping pass every few seconds. A short `still building outputs for the current source generation` message right after restart now usually means LibreQoS is still finishing the import/runtime publish cycle, not that shaping is stuck until the next 30-minute refresh. +If a scheduled integration refresh lands while topology runtime is still publishing outputs for the new source generation, current builds keep the scheduler in a waiting state for that generation and retry the scheduled shaping refresh automatically as soon as topology runtime finishes. Treat `Scheduled shaping refresh deferred` as a transient wait only when the message says topology runtime is still building outputs for the current generation. If the message instead says topology runtime failed for the current generation, investigate that runtime failure directly. + If scheduler startup stays in that wait state for an unusually long time, or degrades with a message that topology runtime failed for the current generation, inspect: ```bash @@ -175,6 +177,8 @@ cat /opt/libreqos/src/network.insight.debug.json Treat `network.insight.debug.json` as a troubleshooting snapshot only; do not edit it. +If `journalctl -u lqosd` shows repeated `BeginIngest queue full`, `IngestChunk queue full`, or `EndIngest queue full` warnings during startup or immediately after a topology import, older builds were dropping Insight ingest frames because the node's outbound control-channel queue was too small for burst uploads. Current builds apply backpressure on the Insight socket for ingest batches instead, so those warnings should no longer be expected during short import/startup bursts. If they still appear after upgrading, inspect recent `lqosd` CPU pressure and control-channel connectivity before assuming shaping itself is unhealthy. + If specific APs or switches appear multiple times with suffixed names such as `... [AP deadbeef]`, check whether UISP is returning duplicate rows for the same device ID. Current builds defensively deduplicate raw UISP devices by `identification.id` before topology graph construction, and skip any residual duplicate device IDs during graph assembly. If an integration subprocess fails, current builds keep the scheduler alive, publish a shortened output preview to the scheduler status/error surfaces, and save the full captured output to a timestamped file under `/tmp` such as `lqos_scheduler_uisp_integration_YYYYMMDD_HHMMSS.log`. diff --git a/src/scheduler.py b/src/scheduler.py index b966be7b..12e18959 100644 --- a/src/scheduler.py +++ b/src/scheduler.py @@ -34,6 +34,7 @@ INTEGRATION_FAILURE_PREVIEW_LINES = 30 INTEGRATION_FAILURE_PREVIEW_CHARS = 4000 TOPOLOGY_RUNTIME_REFRESH_SECONDS = 3 STARTUP_TOPOLOGY_RUNTIME_MAX_WAIT_SECONDS = 120 +PARTIAL_TOPOLOGY_RUNTIME_MAX_WAIT_SECONDS = 120 SCHEDULER_STARTUP_STEP_COUNT = 5 SCHEDULER_REFRESH_STEP_COUNT = 4 scheduler_status_bus_enabled = True @@ -41,6 +42,10 @@ startup_topology_runtime_pending = False startup_topology_runtime_generation = None startup_topology_runtime_started_monotonic = None startup_topology_runtime_last_report_state = None +partial_topology_runtime_pending = False +partial_topology_runtime_generation = None +partial_topology_runtime_started_monotonic = None +partial_topology_runtime_last_report_state = None def configure_scheduler_stdio(): @@ -1045,6 +1050,10 @@ def importAndShapePartialReload(): ) publish_scheduler_progress(True, "partial_topology_runtime", "Refreshing topology runtime", 3, SCHEDULER_REFRESH_STEP_COUNT) if not ensure_topology_runtime_process(wait_for_outputs=True): + ready, detail, generation = topology_runtime_readiness_detail() + if not ready and _topology_runtime_not_ready_is_transient(detail): + _begin_partial_topology_runtime_wait(generation) + return report_topology_runtime_not_ready( "Scheduled shaping refresh deferred", phase_label="Scheduler waiting for topology runtime", @@ -1195,6 +1204,18 @@ def _reset_startup_topology_runtime_wait(): startup_topology_runtime_last_report_state = None +def _reset_partial_topology_runtime_wait(): + global partial_topology_runtime_pending + global partial_topology_runtime_generation + global partial_topology_runtime_started_monotonic + global partial_topology_runtime_last_report_state + + partial_topology_runtime_pending = False + partial_topology_runtime_generation = None + partial_topology_runtime_started_monotonic = None + partial_topology_runtime_last_report_state = None + + def _topology_runtime_not_ready_is_transient(detail: str) -> bool: detail_text = str(detail or "").strip() if detail_text.startswith("Topology runtime failed for the current source generation:"): @@ -1246,6 +1267,50 @@ def _begin_startup_topology_runtime_wait(generation: str | None): _publish_startup_topology_runtime_wait(generation_token) +def _publish_partial_topology_runtime_wait(generation: str | None): + global partial_topology_runtime_last_report_state + + generation_token = str(generation or "").strip() or "unknown" + state = ("waiting", generation_token) + if partial_topology_runtime_last_report_state == state: + return + partial_topology_runtime_last_report_state = state + if generation_token != "unknown": + print( + "Scheduled shaping refresh waiting for topology runtime outputs for " + f"generation {generation_token[:12]}." + ) + else: + print("Scheduled shaping refresh waiting for topology runtime outputs.") + publish_scheduler_progress( + True, + "waiting_for_topology_runtime", + "Waiting for topology runtime", + 3, + SCHEDULER_REFRESH_STEP_COUNT, + percent=75, + ) + + +def _begin_partial_topology_runtime_wait(generation: str | None): + global partial_topology_runtime_pending + global partial_topology_runtime_generation + global partial_topology_runtime_started_monotonic + global partial_topology_runtime_last_report_state + + generation_token = str(generation or "").strip() or None + now = time.monotonic() + if ( + not partial_topology_runtime_pending + or partial_topology_runtime_generation != generation_token + ): + partial_topology_runtime_pending = True + partial_topology_runtime_generation = generation_token + partial_topology_runtime_started_monotonic = now + partial_topology_runtime_last_report_state = None + _publish_partial_topology_runtime_wait(generation_token) + + def _continue_startup_topology_runtime_wait(): global shaping_runtime_hash global startup_topology_runtime_generation @@ -1337,6 +1402,106 @@ def _continue_startup_topology_runtime_wait(): ) +def _continue_partial_topology_runtime_wait(): + global shaping_runtime_hash + global partial_topology_runtime_generation + global partial_topology_runtime_started_monotonic + global partial_topology_runtime_last_report_state + + ready, detail, generation = topology_runtime_readiness_detail() + generation_token = str(generation or "").strip() or None + now = time.monotonic() + + if generation_token != partial_topology_runtime_generation: + partial_topology_runtime_generation = generation_token + partial_topology_runtime_started_monotonic = now + partial_topology_runtime_last_report_state = None + + if ready: + publish_scheduler_progress( + True, + "partial_runtime_hash", + "Checking shaping inputs", + 4, + SCHEDULER_REFRESH_STEP_COUNT, + ) + new_hash = calculate_shaping_runtime_hash() + if new_hash == 0: + _reset_partial_topology_runtime_wait() + report_scheduler_runtime_failure( + "Scheduled shaping refresh failed", + RuntimeError( + "Shaping runtime hash was not published after topology runtime became ready." + ), + ) + return + if new_hash != shaping_runtime_hash: + publish_scheduler_progress( + True, + "partial_reload", + "Applying incremental shaper refresh", + 4, + SCHEDULER_REFRESH_STEP_COUNT, + ) + try: + refreshShapers() + except ValidationFailure as e: + _reset_partial_topology_runtime_wait() + report_scheduler_validation_failure( + "Scheduled shaping refresh blocked by validation", + e, + ) + return + except Exception as e: + _reset_partial_topology_runtime_wait() + report_scheduler_runtime_failure("Scheduled shaping refresh failed", e) + return + shaping_runtime_hash = calculate_shaping_runtime_hash() + if shaping_runtime_hash == 0: + _reset_partial_topology_runtime_wait() + report_scheduler_runtime_failure( + "Scheduled shaping refresh failed", + RuntimeError( + "Shaping runtime hash was not published after scheduled refresh." + ), + ) + return + _reset_partial_topology_runtime_wait() + clear_scheduler_error() + publish_scheduler_progress( + False, + "ready", + "Scheduler ready", + SCHEDULER_REFRESH_STEP_COUNT, + SCHEDULER_REFRESH_STEP_COUNT, + percent=100, + ) + return + + started = partial_topology_runtime_started_monotonic + if started is None: + partial_topology_runtime_started_monotonic = now + started = now + elapsed = max(0.0, now - started) + + if ( + _topology_runtime_not_ready_is_transient(detail) + and elapsed < PARTIAL_TOPOLOGY_RUNTIME_MAX_WAIT_SECONDS + ): + _publish_partial_topology_runtime_wait(generation_token) + return + + state = ("degraded", str(detail or "").strip(), generation_token or "") + if partial_topology_runtime_last_report_state == state: + return + partial_topology_runtime_last_report_state = state + report_topology_runtime_not_ready( + "Scheduled shaping refresh deferred", + phase_label="Scheduler waiting for topology runtime", + step_count=SCHEDULER_REFRESH_STEP_COUNT, + ) + + def wait_for_topology_runtime_ready(timeout_seconds=8.0): deadline = time.monotonic() + timeout_seconds while time.monotonic() < deadline: @@ -1360,6 +1525,10 @@ def topology_runtime_refresh_tick(): _continue_startup_topology_runtime_wait() return + if partial_topology_runtime_pending: + _continue_partial_topology_runtime_wait() + return + if shaping_runtime_hash == 0: return diff --git a/src/test_scheduler.py b/src/test_scheduler.py index c9cbe0a3..e69deb3f 100644 --- a/src/test_scheduler.py +++ b/src/test_scheduler.py @@ -195,6 +195,7 @@ class TestSchedulerErrorReporting(unittest.TestCase): def setUp(self): scheduler.set_scheduler_status_bus_enabled(True) scheduler._reset_startup_topology_runtime_wait() + scheduler._reset_partial_topology_runtime_wait() scheduler.shaping_runtime_hash = 0 def test_python_integration_output_does_not_set_scheduler_error(self): @@ -294,6 +295,12 @@ class TestSchedulerErrorReporting(unittest.TestCase): class TestSchedulerLogging(unittest.TestCase): + def setUp(self): + scheduler.set_scheduler_status_bus_enabled(True) + scheduler._reset_startup_topology_runtime_wait() + scheduler._reset_partial_topology_runtime_wait() + scheduler.shaping_runtime_hash = 0 + def test_configure_scheduler_stdio_enables_line_buffering_when_supported(self): class FakeStream: def __init__(self): @@ -452,6 +459,41 @@ class TestSchedulerLogging(unittest.TestCase): ) ) + def test_topology_runtime_refresh_tick_waits_for_partial_runtime_outputs(self): + scheduler.partial_topology_runtime_pending = True + scheduler.partial_topology_runtime_generation = "generation-1" + scheduler.partial_topology_runtime_started_monotonic = scheduler.time.monotonic() + scheduler.shaping_runtime_hash = 4 + + with patch.object( + scheduler, + "topology_runtime_readiness_detail", + return_value=( + False, + "Topology runtime is still building outputs for the current source generation.", + "generation-1", + ), + ): + with patch.object(scheduler, "publish_scheduler_progress") as mock_progress: + with patch.object(scheduler, "refreshShapers") as mock_refresh: + with patch.object(scheduler, "scheduler_error") as mock_scheduler_error: + with patch("builtins.print"): + scheduler.topology_runtime_refresh_tick() + + mock_refresh.assert_not_called() + mock_scheduler_error.assert_not_called() + self.assertTrue(scheduler.partial_topology_runtime_pending) + self.assertTrue( + any( + call.args[:3] == ( + True, + "waiting_for_topology_runtime", + "Waiting for topology runtime", + ) + for call in mock_progress.call_args_list + ) + ) + def test_topology_runtime_refresh_tick_completes_startup_when_runtime_ready(self): scheduler.startup_topology_runtime_pending = True scheduler.startup_topology_runtime_generation = "generation-1" @@ -506,6 +548,43 @@ class TestSchedulerLogging(unittest.TestCase): self.assertEqual(scheduler.shaping_runtime_hash, 9) self.assertFalse(scheduler.startup_topology_runtime_pending) + def test_topology_runtime_refresh_tick_completes_partial_wait_when_runtime_ready(self): + scheduler.partial_topology_runtime_pending = True + scheduler.partial_topology_runtime_generation = "generation-1" + scheduler.partial_topology_runtime_started_monotonic = scheduler.time.monotonic() + scheduler.shaping_runtime_hash = 1 + + with patch.object( + scheduler, + "topology_runtime_readiness_detail", + return_value=(True, "", "generation-1"), + ): + with patch.object(scheduler, "refreshShapers") as mock_refresh: + with patch.object( + scheduler, + "calculate_shaping_runtime_hash", + side_effect=[9, 9], + ): + with patch.object(scheduler, "publish_scheduler_progress") as mock_progress: + with patch.object(scheduler, "clear_scheduler_error") as mock_clear_error: + with patch("builtins.print"): + scheduler.topology_runtime_refresh_tick() + + mock_refresh.assert_called_once() + mock_clear_error.assert_called_once() + self.assertEqual(scheduler.shaping_runtime_hash, 9) + self.assertFalse(scheduler.partial_topology_runtime_pending) + self.assertTrue( + any( + call.args[:3] == ( + False, + "ready", + "Scheduler ready", + ) + for call in mock_progress.call_args_list + ) + ) + def test_import_and_shape_full_reload_reenables_status_bus_after_success(self): scheduler.set_scheduler_status_bus_enabled(False) @@ -763,6 +842,7 @@ class TestTopologyRuntimeReadiness(unittest.TestCase): class TestTopologyRuntimeGating(unittest.TestCase): def setUp(self): scheduler._reset_startup_topology_runtime_wait() + scheduler._reset_partial_topology_runtime_wait() scheduler.shaping_runtime_hash = 0 def test_full_reload_skips_refresh_when_topology_runtime_not_ready(self): @@ -777,13 +857,43 @@ class TestTopologyRuntimeGating(unittest.TestCase): mock_report.assert_not_called() self.assertTrue(scheduler.startup_topology_runtime_pending) - def test_partial_reload_skips_refresh_when_topology_runtime_not_ready(self): + def test_partial_reload_waits_when_topology_runtime_not_ready(self): with patch.object(scheduler, "importFromCRM"): with patch.object(scheduler, "ensure_topology_runtime_process", return_value=False): - with patch.object(scheduler, "report_topology_runtime_not_ready") as mock_report: - with patch.object(scheduler, "refreshShapers") as mock_refresh: - with patch.object(scheduler, "publish_scheduler_progress"): - scheduler.importAndShapePartialReload() + with patch.object( + scheduler, + "topology_runtime_readiness_detail", + return_value=( + False, + "Topology runtime is still building outputs for the current source generation.", + "generation-1", + ), + ): + with patch.object(scheduler, "report_topology_runtime_not_ready") as mock_report: + with patch.object(scheduler, "refreshShapers") as mock_refresh: + with patch.object(scheduler, "publish_scheduler_progress"): + scheduler.importAndShapePartialReload() + + mock_refresh.assert_not_called() + mock_report.assert_not_called() + self.assertTrue(scheduler.partial_topology_runtime_pending) + + def test_partial_reload_reports_runtime_failure_when_topology_runtime_failed(self): + with patch.object(scheduler, "importFromCRM"): + with patch.object(scheduler, "ensure_topology_runtime_process", return_value=False): + with patch.object( + scheduler, + "topology_runtime_readiness_detail", + return_value=( + False, + "Topology runtime failed for the current source generation: publish failed", + "generation-1", + ), + ): + with patch.object(scheduler, "report_topology_runtime_not_ready") as mock_report: + with patch.object(scheduler, "refreshShapers") as mock_refresh: + with patch.object(scheduler, "publish_scheduler_progress"): + scheduler.importAndShapePartialReload() mock_refresh.assert_not_called() mock_report.assert_called_once()