16 Commits

Author SHA1 Message Date
serversdown 8c17af4849 fix: ignore garbled measurement-state reads (phantom STOPPED/STARTED)
A buffer desync on the shared persistent connection (commonly right after
a DRD/DOD test) can make a Measure? read return a stray value. The state
classifier treated anything not in {"Start","Measure"} as "not measuring",
so a garbled read logged a phantom STOPPED, the next clean read logged
STARTED, and that reset measurement_start_time — producing constant
STOPPED/STARTED device-log pairs and a drifting elapsed timer.

Now only recognized states drive transitions: {"Start","Measure"} =
measuring, {"Stop"} = stopped, anything else = no change. Garbled reads
are also not persisted as the cached state, so they can't poison the next
transition check. Builds on the earlier Start<->Measure normalization.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-06-08 22:50:18 +00:00
serversdown b954eb8c89 feat: per-unit deactivate and global SLMM standby
Lets an instance stop occupying a device's single TCP connection slot so
another instance (e.g. prod) can take over.

Per-unit:
- POST /api/nl43/{unit_id}/deactivate — poll_enabled=False (persisted) +
  drop the connection (waits up to 10s for in-flight ops via the device
  lock, then discards). Unit stays dormant across restarts.
- POST /api/nl43/{unit_id}/activate — re-enable polling.

Global standby:
- POST /api/nl43/_system/standby — poller idles and releases ALL
  connections; the loop keeps re-releasing so the instance holds no slots.
- POST /api/nl43/_system/resume — resume polling.
- GET  /api/nl43/_system/status — active vs standby + active_connections.
- SLMM_POLLING_ENABLED=false starts an instance in standby (persistent
  way to keep a dev box from latching onto a prod-owned device).

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-06-08 22:45:52 +00:00
serversdown 0793e7df01 feat: add per-device disconnect endpoint
POST /api/nl43/{unit_id}/disconnect cleanly closes (TCP FIN + wait_closed)
and drops the pooled connection for a single device, freeing the NL43's
one connection slot. Previously only /_connections/flush existed, which
tears down every device at once.

Idempotent; no-op if nothing is cached. Releases the idle pooled
connection only — an active DRD stream/command has the socket checked out
of the pool, so close the stream WebSocket to end a live stream.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-06-08 22:40:56 +00:00
serversdown 51dd6b682d feat: surface LN1/LN2 (L1/L10) percentiles through SLMM
Completes the SLMM side of the L1/L10 live-display contract. The NL-43's
DOD response carries percentile slots LN1-LN5 (channel 1, parts[5]/[6]);
parse the first two and expose them as ln1/ln2 end to end:

- NL43Snapshot dataclass: ln1/ln2 fields
- NL43Status model: ln1/ln2 columns (+ migrate_add_ln_percentiles.py)
- DOD parser: snap.ln1=parts[5], snap.ln2=parts[6]
- persist_snapshot writes them
- all /status data dicts, StatusPayload, and the DRD stream payload emit
  ln1/ln2 (null on the DRD stream itself, which doesn't carry percentiles)

Labels: device LN1 defaults to L5, not L1 — Terra-View defaults the label
to L1/L10, so the device's Ln1/Ln2 slots must be set to 1%/10% for the
labels to be accurate (dynamic label emission is a follow-up).

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-06-08 22:01:31 +00:00
serversdown a7983d2958 fix: correct DOD field parsing and stop measurement-time resets
Two device-data bugs surfaced while scoping the live-feed work:

1. DOD parser misalignment. DOD's response has no leading counter and
   includes LE + LN1-LN5, but the parser reused the DRD field map
   (parts[0]=counter). That shifted everything: Lp was stored as the
   counter, Leq as Lp, LE as Leq, and LN1 as Lpeak (visible because
   "Lpeak" came out below Lmax, which is impossible). Parse DOD with its
   own map: Lp=0, Leq=1, Lmax=3, Lmin=4, Lpeak=10 (channel 1 = main).

2. measurement_start_time reset on every live-stream open/close. The DOD
   path tags state "Start"; the DRD stream path tags "Measure". The
   transition detector treated only "Start" as measuring, so opening the
   stream ("Start"->"Measure") read as a stop (cleared start time) and
   closing it ("Measure"->"Start") read as a start (reset to now). Every
   viewer reset the elapsed measurement time. Treat {"Start","Measure"}
   both as measuring.

LN1/LN2 (L1/L10) parsing + model/serialization is the next step.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-06-08 21:53:00 +00:00
serversdown d6dd2e736b Merge pull request 'fix: improve connection pool idle and max age checks to allow disabling' (#3) from dev-persistent into main
Reviewed-on: #3
2026-06-08 16:56:33 -04:00
serversdown af86cf713e fix: reuse pooled TCP connection for DRD streaming
stream_drd() discarded the pooled connection and forced a fresh connect.
The NL43 allows only one TCP connection at a time; over a cellular link
the device does not free its single slot fast enough for an immediate
reconnect, so the fresh connect times out — the live DRD stream fails
while start/stop commands (which reuse the warm pooled socket) keep
working. This surfaced once the persistent connection pool was enabled
(TCP_PERSISTENT_ENABLED=true).

Stream over the already-open pooled connection via acquire() instead of
discard()+_open_connection(), and release() it back to the pool on exit
(after sending SUB to stop the stream) so commands keep reusing the same
single socket. The per-device lock is held for the whole streaming
session, so the poller can't touch the socket concurrently.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-06-08 19:00:35 +00:00
serversdown e3f9ca7f5b fix: use request-first TemplateResponse signature
Modern Starlette requires `request` as the first positional arg to
TemplateResponse. The old `TemplateResponse(name, context)` form caused
the context dict to be passed as the template name, which Jinja2 then
tried to use as a cache key -> TypeError: unhashable type: 'dict' (500
on GET / and /roster).

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
2026-06-08 17:59:39 +00:00
serversdown 450509d210 stop tracking dev runtime data 2026-03-12 22:46:37 +00:00
serversdown fefa9eace8 chore: gitignore clean up 2026-03-12 21:34:14 +00:00
serversdown 98a8d357e5 chore: data-dev folder added to gitignore 2026-03-12 21:33:43 +00:00
claude 0a7422eceb Merge branch 'dev-persistent' of ssh://10.0.0.2:2222/serversdown/slmm into dev-persistent 2026-03-12 20:26:56 +00:00
claude 996b993cb9 chore: gitignore dev data 2026-03-12 20:26:53 +00:00
claude 01337696b3 feat: add connection pool status logging every 15 minutes 2026-02-19 15:09:50 +00:00
claude a302fd15d4 fix: change debug logs to info level for connection pool events 2026-02-19 06:04:34 +00:00
claude af5ecc1a92 fix: improve connection pool idle and max age checks to allow disabling 2026-02-19 01:25:01 +00:00
8 changed files with 732 additions and 34 deletions
+1
View File
@@ -1,5 +1,6 @@
/manuals/ /manuals/
/data/ /data/
/data-dev/
/SLM-stress-test/stress_test_logs/ /SLM-stress-test/stress_test_logs/
/SLM-stress-test/tcpdump-runs/ /SLM-stress-test/tcpdump-runs/
@@ -0,0 +1,403 @@
# NL-43 + RX55 TCP “Wedge” Investigation (2255 Refusal) — Full Log & Next Steps
**Last updated:** 2026-02-18
**Owner:** Brian / serversdown
**Context:** Terra-View / SLMM / field-deployed Rion NL-43 behind Sierra Wireless RX55
---
## 0) What this document is
This is a **comprehensive, chronological** record of the debugging we did to isolate a failure where the **NL-43s TCP control port (2255) eventually stops accepting connections** (“wedges”), while other services (notably FTP/21) remain reachable.
This is written to be fed back into future troubleshooting, so it intentionally includes the **full reasoning chain, experiments, commands, packet evidence, and conclusions**.
---
## 1) Architecture (as tested)
### Network path
- **Server (SLMM host):** `10.0.0.40`
- **RX55 WAN IP:** `63.45.161.30`
- **RX55 LAN subnet:** `192.168.1.0/24`
- **RX55 LAN gateway:** `192.168.1.1`
- **NL-43 LAN IP:** `192.168.1.10` (confirmed via ARP OUI + ping; see LAN validation)
### RX55 details
- **Sierra Wireless RX55**
- **OS:** 5.2
- **Firmware:** `01.14.24.00`
- **Carrier:** Verizon LTE (Band 66)
### Port forwarding rules (RX55)
- **WAN:2255 → NL-43:2255** (NL-43 TCP control)
- **WAN:21 → NL-43:21** (NL-43 FTP control)
You also experimented with additional forwards:
- **WAN:2253 → NL-43:2255** (test)
- **WAN:2253 → NL-43:2253** (test)
- **WAN:4450 → NL-43:4450** (test)
**Important:** Rule “Input zone / interface” was set to **WAN-NAT**, and Source IP left as **Any IPv4**. This is correct for inbound port-forward behavior on Sierra OS 5.x.
---
## 2) Original problem statement (the “wedge”)
After running for hours, the NL-43 becomes unreachable over TCP control.
### Symptom signature (WAN-side)
- Client attempts to connect to `63.45.161.30:2255`
- Instead of timing out, the client gets **connection refused** quickly.
- Packet-level: SYN from client → **RST,ACK** back (meaning active refusal vs silent drop)
### Critical operational behavior
- **Power cycling the NL-43 fixes it.**
- **Power cycling the RX55 does NOT fix it.**
- FTP sometimes remains available even while TCP control (2255) is dead.
This combination is what forced us to determine whether:
- The RX55 is rejecting connections, OR
- The NL-43 is no longer listening on 2255, OR
- Something about the RX55 path triggers the NL-43s control listener to die.
---
## 3) Event timeline evidence (SLMM logs)
A concrete wedge window was observed on **2026-02-18**:
- 10:55:46 AM — Poll success (Start)
- 11:00:28 AM — Measurement STOPPED (scheduled stop/download cycle succeeded)
- 11:55:50 AM — Poll success (Stop)
- 12:55:55 PM — Poll success (Stop)
- **1:55:58 PM — Poll failed (attempt 1/3): Errno 111 (connection refused)**
- 2:56:02 PM — Poll failed (attempt 2/3): Errno 111 (connection refused)
Key interpretation:
- The wedge occurred sometime between **12:55 and 1:55**.
- The failure type is **refused**, not timeout.
---
## 4) Early hypotheses (before proof)
We considered two main buckets:
### A) NL-43-side failure (most suspicious)
- NL-43 TCP control service crashes / exits / unbinds from 2255
- socket leak / accept backlog exhaustion
- “single control session allowed” and it gets stuck thinking a session is active
- mode/service manager bug (service restart fails after other activities)
- firmware bug in TCP daemon
### B) RX55-side failure (possible trigger / less likely once FTP works)
- NAT/forwarding table corruption
- firewall behavior
- helper/ALG interference
- MSS/MTU weirdness causing edge-case behavior
- session churn behavior causing downstream issues
---
## 5) Key experiments and what they proved
### 5.1) LAN-only stability test (No RX55 path)
**Test:** NL-43 tested directly on LAN (no modem path involved).
- Ran **24+ hours**
- Scheduler start/stop cycles worked
- Stress test: **500 commands @ 1/sec** → no failure
- Response time trend decreased (not degrading)
**Result:** The NL-43 appears stable in a “pure LAN” environment.
**Interpretation:** The trigger is likely related to the RX55/WAN environment, connection patterns, or service switching patterns—not just simple uptime.
---
### 5.2) Port-forward behavior: timeout vs refused (RX55 behavior characterization)
You observed:
- **If a WAN port is NOT forwarded (no rule):** connecting to that port **times out** (silent drop)
- **If a WAN port IS forwarded to NL-43 but nothing listens:** it **actively refuses** (RST)
Concrete example:
- Port **4450** with no rule → timeout
- Port **4450 → NL-43:4450** rule created → connection refused
**Interpretation:** This confirms the RX55 is actually forwarding packets to the NL-43 when a rule exists. “Refused” is consistent with the NL-43 (or RX55 relay behavior) responding quickly because the packet reached the target.
Important nuance:
- A “refused” on forwarded ports does **not** automatically prove the NL-43 is the one generating RST, because NAT hides the inside host and the RX55 could reject on behalf of an unreachable target. We needed a LAN-side proof test to close the loop.
---
### 5.3) UDP test confusion (and resolution)
You ran:
```bash
nc -vzu 63.45.161.30 2255
nc -vz 63.45.161.30 2255
```
Observed:
- UDP: “succeeded”
- TCP: “connection refused”
Resolution:
- UDP has **no handshake**. netcat prints “succeeded” if it doesnt immediately receive an ICMP unreachable. It does **not** mean a UDP service exists.
- TCP refused is meaningful: a RST implies “no listener” or “actively rejected.”
**Net effect:** UDP test did not change the diagnosis.
---
### 5.4) Packet capture proof (WAN-side)
You captured a Wireshark/tcpdump summary with these key patterns:
#### Port 2255 (TCP control)
Example:
- `10.0.0.40 → 63.45.161.30:2255` SYN
- `63.45.161.30 → 10.0.0.40` **RST, ACK** within ~50ms
This happened repeatedly.
#### Port 2253 (test port)
Multiple SYN attempts to 2253 showed **retransmissions and no response**, i.e., **silent drop** (consistent with no rule or not forwarded at that moment).
#### Port 21 (FTP)
Clean 3-way handshake:
- SYN → SYN/ACK → ACK
Then:
- FTP server banner: `220 Connection Ready`
Then:
- `530 Not logged in` (because SLMM was sending non-FTP “requests” as an experiment)
Session closes cleanly.
**Key takeaway from capture:**
- TCP transport to NL-43 via RX55 is definitely working (port 21 proves it).
- Port 2255 is being actively refused.
This strongly suggested “2255 listener is gone,” but still didnt fully prove whether the refusal was generated internally by NL-43 or by RX55 on behalf of NL-43.
---
## 6) The decisive experiment: LAN-side test while wedged (final proof)
Because the RX55 does not offer SSH, the plan was to test from **inside the LAN behind the RX55**.
### 6.1) Physical LAN tap setup
Constraint:
- NL-43 has only one Ethernet port.
Solution:
- Insert an unmanaged switch:
- RX55 LAN → switch
- NL-43 → switch
- Windows 10 laptop → switch
This creates a shared L2 segment where the laptop can test NL-43 directly.
### 6.2) Windows LAN validation
On the Windows laptop:
- `ipconfig` showed:
- IP: `192.168.1.100`
- Gateway: `192.168.1.1` (RX55)
- Initial `arp -a` only showed RX55, not NL-43.
You then:
- pinged likely host addresses and discovered NL-43 responds on **192.168.1.10**
- `arp -a` then showed:
- `192.168.1.10 → 00-10-50-14-0a-d8`
- OUI `00-10-50` recognized as **Rion** (matches NL-43)
So LAN identities were confirmed:
- RX55: `192.168.1.1`
- NL-43: `192.168.1.10`
### 6.3) The LAN port tests (the smoking gun)
From Windows:
```powershell
Test-NetConnection -ComputerName 192.168.1.10 -Port 2255
Test-NetConnection -ComputerName 192.168.1.10 -Port 21
```
Results (while the unit was “wedged” from the WAN perspective):
- **2255:** `TcpTestSucceeded : False`
- **21:** `TcpTestSucceeded : True`
**Conclusion (PROVEN):**
- The NL-43 is reachable on the LAN
- FTP port 21 is alive
- **The NL-43 is NOT listening on TCP port 2255**
- Therefore the RX55 is not the root cause of the refusal. The WAN refusal is consistent with the NL-43 having no listener on 2255.
This is now settled.
---
## 7) What we learned (final conclusions)
### 7.1) RX55 innocence (for this failure mode)
The RX55 is not “randomly rejecting” or “breaking TCP” in the way originally feared.
It successfully forwards and supports TCP to the NL-43 on port 21, and the LAN-side test proves the 2255 failure exists *even without NAT/WAN involvement*.
### 7.2) NL-43 control listener failure
The NL-43s TCP control service (port 2255) stops listening while:
- the device remains alive
- the LAN stack remains alive (ping)
- FTP remains alive (port 21)
This looks like one of:
- control daemon crash/exit
- service unbind
- stuck service state (e.g., “busy” / “session active forever”)
- resource leak (sockets/file descriptors) specific to the control service
- firmware service manager bug (start/stop of services fails after certain sequences)
---
## 8) Additional constraint discovered: “Web App mode” conflicts
You noted an important operational constraint:
> Turning on the web app disables other interfaces like TCP and FTP.
Meaning the NL-43 appears to have mutually exclusive service/mode behavior (or at least serious conflicts). That matters because:
- If any workflow toggles modes (explicitly or implicitly), it could destabilize the service lifecycle.
- It reduces the possibility of using “web UI toggle” as an easy remote recovery mechanism **if** it disables the services needed.
We have not yet run a controlled long test to determine whether:
- mode switching contributes directly to the 2255 listener dying, OR
- it happens even in a pure TCP-only mode with no switching.
---
## 9) Immediate operational decision (field tomorrow)
Because the device is needed in the field immediately, you chose:
- **Old-school manual deployment**
- **Manual SD card downloads**
- Avoid reliance on 2255/TCP control and remote workflows for now.
**Important operational note:**
The 2255 listener dying does not necessarily stop the NL-43 from measuring; it primarily breaks remote control/polling. Manual SD workflow sidesteps the entire remote control dependency.
---
## 10) Whats next (future work — when the unit is back)
Because long tests cant be run before tomorrow, the plan is to resume in a few weeks with controlled experiments designed to isolate the trigger and develop an operational mitigation.
### 10.1) Controlled experiment matrix (recommended)
Run each test for 2472 hours, or until wedge occurs, and record:
- number of TCP connects
- whether connections are persistent
- whether FTP is used
- whether any mode toggling is performed
- time-to-wedge
#### Test A — TCP-only (ideal baseline)
- TCP control only (2255)
- **True persistent connection** (open once, keep forever)
- No FTP
- No web mode toggling
Outcome interpretation:
- If stable: connection churn and/or FTP/mode switching is the trigger.
- If wedges anyway: pure 2255 daemon leak/bug.
#### Test B — TCP with connection churn
- Same as A but intentionally reconnect on a schedule (current SLMM behavior)
- No FTP
Outcome:
- If this wedges but A doesnt: churn is the trigger.
#### Test C — FTP activity + TCP
- Introduce scheduled FTP sessions (downloads) while using TCP control
- Observe whether wedge correlates with FTP use or with post-download periods.
Outcome:
- If wedge correlates with FTP, suspect internal service lifecycle conflict.
#### Test D — Web mode interaction (only if safe/possible)
- Evaluate what toggling web mode does to TCP/FTP services.
- Determine if any remote-safe “soft reset” exists.
---
## 11) Mitigation options (ranked)
### Option 1 — Make SLMM truly persistent (highest probability of success)
If the NL-43 wedges due to session churn or leaked socket states, the best mitigation is:
- Open one TCP socket per device
- Keep it open indefinitely
- Use OS keepalive
- Do **not** rotate connections on timers
- Reconnect only when the socket actually dies
This reduces:
- connect/close cycles
- NAT edge-case exposure
- resource churn inside NL-43
### Option 2 — Service “soft reset” (if possible without disabling required services)
If there exists any way to restart the 2255 service without power cycling:
- LAN TCP toggle (if it doesnt require web mode)
- any “restart comms” command (unknown)
- any maintenance menu sequence
then SLMM could:
- detect wedge
- trigger soft reset
- recover automatically
Current constraint: web app mode appears to disable other services, so this may not be viable.
### Option 3 — Hardware watchdog power cycle (industrial but reliable)
If this is a firmware bug with no clean workaround:
- Add a remotely controlled relay/power switch
- On wedge detection, power-cycle NL-43 automatically
- Optionally schedule a nightly power cycle to prevent leak accumulation
This is “field reality” and often the only long-term move with embedded devices.
### Option 4 — Vendor escalation (Rion)
You now have excellent evidence:
- LAN-side proof: 2255 dead while 21 alive
- WAN packet evidence
- clear isolation of RX55 innocence
This is strong enough to send to Rion support as a firmware defect report.
---
## 12) Repro “wedge bundle” checklist (for future captures)
When the wedge happens again, capture these before power cycling:
1) From server:
- `nc -vz 63.45.161.30 2255` (expect refused)
- `nc -vz 63.45.161.30 21` (expect success if FTP alive)
2) From LAN side (via switch/laptop):
- `Test-NetConnection 192.168.1.10 -Port 2255`
- `Test-NetConnection 192.168.1.10 -Port 21`
3) Optional: packet capture around the refused attempt.
4) Record:
- last successful poll timestamp
- last FTP session timestamp
- any scheduled start/stop/download cycles near wedge time
- SLMM connection reuse/rotation settings in effect
---
## 13) Final, current-state summary (as of 2026-02-18)
- The issue is **NOT** the RX55 rejecting inbound connections.
- The NL-43 is **alive**, reachable on LAN, and FTP works.
- The NL-43s **TCP control listener on 2255 stops listening** while the device remains otherwise healthy.
- The wedge can occur hours after successful operations.
- The unit is needed in the field immediately, so investigation pauses.
- Next phase: controlled tests to isolate trigger + implement mitigation (persistent socket or watchdog reset).
---
## 14) Notes / misc observations
- The Wireshark trace showed repeated FTP sessions were opened and closed cleanly, but SLMMs “FTP requests” were not valid FTP (causing `530 Not logged in`). That was part of experimentation, not a normal workflow.
- UDP “success” via netcat is not meaningful because UDP has no handshake; it simply indicates no ICMP unreachable was returned.
---
**End of document.**
+63 -4
View File
@@ -8,6 +8,7 @@ for fast API access without querying devices on every request.
import asyncio import asyncio
import logging import logging
import os
from datetime import datetime, timedelta from datetime import datetime, timedelta
from typing import Optional from typing import Optional
@@ -20,6 +21,11 @@ from app.device_logger import log_device_event, cleanup_old_logs
logger = logging.getLogger(__name__) logger = logging.getLogger(__name__)
# Global polling default. Set SLMM_POLLING_ENABLED=false to start an instance in
# standby (running but not polling and not holding device connections) — e.g. a
# dev box that must not latch onto a device that a prod instance owns.
POLLING_ENABLED_DEFAULT = os.getenv("SLMM_POLLING_ENABLED", "true").lower() == "true"
class BackgroundPoller: class BackgroundPoller:
""" """
@@ -38,6 +44,8 @@ class BackgroundPoller:
self._running = False self._running = False
self._logger = logger self._logger = logger
self._last_cleanup = None # Track last log cleanup time self._last_cleanup = None # Track last log cleanup time
self._last_pool_log = None # Track last connection pool heartbeat log
self._active = POLLING_ENABLED_DEFAULT # Global polling on/off (standby toggle)
async def start(self): async def start(self):
"""Start the background polling task.""" """Start the background polling task."""
@@ -70,15 +78,48 @@ class BackgroundPoller:
self._logger.info("Background poller stopped") self._logger.info("Background poller stopped")
def is_active(self) -> bool:
"""Whether background polling is currently active (vs standby)."""
return self._active
async def set_active(self, active: bool):
"""Globally enable/disable polling at runtime.
When deactivated, the loop stays alive but polls nothing and releases all
device connections, so this SLMM instance stops occupying the devices'
single connection slots (e.g. so a prod instance can take over). Runtime
state only — on restart the instance returns to SLMM_POLLING_ENABLED.
"""
self._active = active
if active:
self._logger.info("[SYSTEM] Background polling ACTIVATED")
else:
self._logger.info("[SYSTEM] Background polling DEACTIVATED (standby) — releasing connections")
await self._release_all_connections()
async def _release_all_connections(self):
"""Gracefully close every pooled device connection (no-op if none)."""
from app.services import _connection_pool
for device_key in list(_connection_pool.get_stats().get("connections", {})):
await _connection_pool.discard(device_key)
async def _poll_loop(self): async def _poll_loop(self):
"""Main polling loop that runs continuously.""" """Main polling loop that runs continuously."""
self._logger.info("Background polling loop started") self._logger.info("Background polling loop started")
while self._running: while self._running:
try: if self._active:
await self._poll_all_devices() try:
except Exception as e: await self._poll_all_devices()
self._logger.error(f"Error in poll loop: {e}", exc_info=True) except Exception as e:
self._logger.error(f"Error in poll loop: {e}", exc_info=True)
else:
# Standby: poll nothing, and keep holding no device connection slots
# so another SLMM instance (e.g. prod) can talk to the devices.
try:
await self._release_all_connections()
except Exception as e:
self._logger.warning(f"Standby connection release failed: {e}")
# Run log cleanup once per hour # Run log cleanup once per hour
try: try:
@@ -89,6 +130,24 @@ class BackgroundPoller:
except Exception as e: except Exception as e:
self._logger.warning(f"Log cleanup failed: {e}") self._logger.warning(f"Log cleanup failed: {e}")
# Log connection pool status every 15 minutes
try:
now = datetime.utcnow()
if self._last_pool_log is None or (now - self._last_pool_log).total_seconds() > 900:
from app.services import _connection_pool
stats = _connection_pool.get_stats()
conns = stats.get("connections", {})
if conns:
for key, c in conns.items():
self._logger.info(
f"[POOL] {key} — age={c['age_seconds']}s idle={c['idle_seconds']}s alive={c['alive']}"
)
else:
self._logger.info("[POOL] No active connections in pool")
self._last_pool_log = now
except Exception as e:
self._logger.warning(f"Pool status log failed: {e}")
# Calculate dynamic sleep interval # Calculate dynamic sleep interval
sleep_time = self._calculate_sleep_interval() sleep_time = self._calculate_sleep_interval()
self._logger.debug(f"Sleeping for {sleep_time} seconds until next poll cycle") self._logger.debug(f"Sleeping for {sleep_time} seconds until next poll cycle")
+2 -2
View File
@@ -76,12 +76,12 @@ app.include_router(routers.router)
@app.get("/", response_class=HTMLResponse) @app.get("/", response_class=HTMLResponse)
def index(request: Request): def index(request: Request):
return templates.TemplateResponse("index.html", {"request": request}) return templates.TemplateResponse(request, "index.html")
@app.get("/roster", response_class=HTMLResponse) @app.get("/roster", response_class=HTMLResponse)
def roster(request: Request): def roster(request: Request):
return templates.TemplateResponse("roster.html", {"request": request}) return templates.TemplateResponse(request, "roster.html")
@app.get("/health") @app.get("/health")
+2
View File
@@ -41,6 +41,8 @@ class NL43Status(Base):
lmax = Column(String, nullable=True) # Maximum level lmax = Column(String, nullable=True) # Maximum level
lmin = Column(String, nullable=True) # Minimum level lmin = Column(String, nullable=True) # Minimum level
lpeak = Column(String, nullable=True) # Peak level lpeak = Column(String, nullable=True) # Peak level
ln1 = Column(String, nullable=True) # Percentile slot LN1 (configurable; device default L5, contract L1)
ln2 = Column(String, nullable=True) # Percentile slot LN2 (configurable; device default L10)
battery_level = Column(String, nullable=True) battery_level = Column(String, nullable=True)
power_source = Column(String, nullable=True) power_source = Column(String, nullable=True)
sd_remaining_mb = Column(String, nullable=True) sd_remaining_mb = Column(String, nullable=True)
+135
View File
@@ -121,6 +121,131 @@ async def flush_connection_pool():
return {"status": "ok", "message": "All cached connections closed"} return {"status": "ok", "message": "All cached connections closed"}
@router.post("/{unit_id}/disconnect")
async def disconnect_device(unit_id: str, db: Session = Depends(get_db)):
"""Cleanly close SLMM's persistent TCP connection to a single device.
Gracefully closes (TCP FIN + wait_closed) the pooled connection for this
device and removes it from the pool, freeing the NL43's single connection
slot. Idempotent — a no-op if no connection is currently cached.
Note: this releases the *idle* pooled connection. It does not interrupt an
in-progress DRD stream or an in-flight command (those have the socket
checked out of the pool) — close the stream WebSocket to end a live stream.
"""
cfg = db.query(NL43Config).filter_by(unit_id=unit_id).first()
if not cfg:
raise HTTPException(status_code=404, detail="NL43 config not found")
from app.services import _connection_pool
device_key = f"{cfg.host}:{cfg.tcp_port}"
had_conn = device_key in _connection_pool.get_stats().get("connections", {})
await _connection_pool.discard(device_key)
return {
"status": "ok",
"unit_id": unit_id,
"device_key": device_key,
"disconnected": had_conn,
"message": "Connection closed" if had_conn else "No cached connection to close",
}
@router.post("/{unit_id}/deactivate")
async def deactivate_device(unit_id: str, db: Session = Depends(get_db)):
"""Make a single unit dormant: stop background polling for it AND drop its
connection, freeing the device's connection slot. poll_enabled=False is
persisted, so the unit stays dormant across restarts until /activate.
"""
cfg = db.query(NL43Config).filter_by(unit_id=unit_id).first()
if not cfg:
raise HTTPException(status_code=404, detail="NL43 config not found")
cfg.poll_enabled = False
db.commit()
from app.services import _connection_pool, _get_device_lock
device_key = f"{cfg.host}:{cfg.tcp_port}"
# Wait briefly for any in-flight poll/command to finish (so its connection is
# back in the pool), then drop it. If a long-lived stream holds the lock we
# don't block forever — discard the pooled connection regardless.
lock = await _get_device_lock(device_key)
acquired = False
try:
await asyncio.wait_for(lock.acquire(), timeout=10.0)
acquired = True
except asyncio.TimeoutError:
acquired = False
try:
await _connection_pool.discard(device_key)
finally:
if acquired:
lock.release()
return {
"status": "ok",
"unit_id": unit_id,
"poll_enabled": False,
"message": "Polling disabled and connection closed for this unit",
}
@router.post("/{unit_id}/activate")
async def activate_device(unit_id: str, db: Session = Depends(get_db)):
"""Resume background polling for a unit previously deactivated."""
cfg = db.query(NL43Config).filter_by(unit_id=unit_id).first()
if not cfg:
raise HTTPException(status_code=404, detail="NL43 config not found")
cfg.poll_enabled = True
db.commit()
return {
"status": "ok",
"unit_id": unit_id,
"poll_enabled": True,
"message": "Polling enabled for this unit",
}
@router.get("/_system/status")
async def system_status():
"""Report whether this SLMM instance is actively polling or in standby."""
from app.background_poller import poller
from app.services import _connection_pool
return {
"status": "ok",
"mode": "active" if poller.is_active() else "standby",
"polling_active": poller.is_active(),
"active_connections": _connection_pool.get_stats().get("active_connections", 0),
}
@router.post("/_system/standby")
async def system_standby():
"""Put this SLMM instance into standby: stop polling ALL devices and release
every connection, so it stops occupying device slots (e.g. so a prod instance
can take over). Runtime-only — on restart the instance returns to its
SLMM_POLLING_ENABLED default.
"""
from app.background_poller import poller
await poller.set_active(False)
return {"status": "ok", "mode": "standby",
"message": "Polling stopped and all device connections released"}
@router.post("/_system/resume")
async def system_resume():
"""Resume polling after standby (global)."""
from app.background_poller import poller
await poller.set_active(True)
return {"status": "ok", "mode": "active", "message": "Polling resumed"}
# ============================================================================ # ============================================================================
# GLOBAL POLLING STATUS ENDPOINT (must be before /{unit_id} routes) # GLOBAL POLLING STATUS ENDPOINT (must be before /{unit_id} routes)
# ============================================================================ # ============================================================================
@@ -450,6 +575,8 @@ def get_status(unit_id: str, db: Session = Depends(get_db)):
"lmax": status.lmax, "lmax": status.lmax,
"lmin": status.lmin, "lmin": status.lmin,
"lpeak": status.lpeak, "lpeak": status.lpeak,
"ln1": status.ln1,
"ln2": status.ln2,
"battery_level": status.battery_level, "battery_level": status.battery_level,
"power_source": status.power_source, "power_source": status.power_source,
"sd_remaining_mb": status.sd_remaining_mb, "sd_remaining_mb": status.sd_remaining_mb,
@@ -472,6 +599,8 @@ class StatusPayload(BaseModel):
lmax: str | None = None lmax: str | None = None
lmin: str | None = None lmin: str | None = None
lpeak: str | None = None lpeak: str | None = None
ln1: str | None = None
ln2: str | None = None
battery_level: str | None = None battery_level: str | None = None
power_source: str | None = None power_source: str | None = None
sd_remaining_mb: str | None = None sd_remaining_mb: str | None = None
@@ -504,6 +633,8 @@ def upsert_status(unit_id: str, payload: StatusPayload, db: Session = Depends(ge
"lmax": status.lmax, "lmax": status.lmax,
"lmin": status.lmin, "lmin": status.lmin,
"lpeak": status.lpeak, "lpeak": status.lpeak,
"ln1": status.ln1,
"ln2": status.ln2,
"battery_level": status.battery_level, "battery_level": status.battery_level,
"power_source": status.power_source, "power_source": status.power_source,
"sd_remaining_mb": status.sd_remaining_mb, "sd_remaining_mb": status.sd_remaining_mb,
@@ -1205,6 +1336,8 @@ async def stream_live(websocket: WebSocket, unit_id: str):
"lmax": snap.lmax, # Maximum level "lmax": snap.lmax, # Maximum level
"lmin": snap.lmin, # Minimum level "lmin": snap.lmin, # Minimum level
"lpeak": snap.lpeak, # Peak level "lpeak": snap.lpeak, # Peak level
"ln1": snap.ln1, # LN1 percentile (L1/L10 contract); null on DRD stream
"ln2": snap.ln2, # LN2 percentile; null on DRD stream
"raw_payload": snap.raw_payload, "raw_payload": snap.raw_payload,
}) })
except Exception as e: except Exception as e:
@@ -1876,6 +2009,8 @@ async def run_diagnostics(unit_id: str, db: Session = Depends(get_db)):
"lmax": status.lmax, "lmax": status.lmax,
"lmin": status.lmin, "lmin": status.lmin,
"lpeak": status.lpeak, "lpeak": status.lpeak,
"ln1": status.ln1,
"ln2": status.ln2,
"battery_level": status.battery_level, "battery_level": status.battery_level,
"power_source": status.power_source, "power_source": status.power_source,
"sd_remaining_mb": status.sd_remaining_mb, "sd_remaining_mb": status.sd_remaining_mb,
+68 -28
View File
@@ -46,6 +46,8 @@ class NL43Snapshot:
lmax: Optional[str] = None # Maximum level lmax: Optional[str] = None # Maximum level
lmin: Optional[str] = None # Minimum level lmin: Optional[str] = None # Minimum level
lpeak: Optional[str] = None # Peak level lpeak: Optional[str] = None # Peak level
ln1: Optional[str] = None # Percentile slot LN1 (configurable; device default L5, contract L1)
ln2: Optional[str] = None # Percentile slot LN2 (configurable; device default L10)
battery_level: Optional[str] = None battery_level: Optional[str] = None
power_source: Optional[str] = None power_source: Optional[str] = None
sd_remaining_mb: Optional[str] = None sd_remaining_mb: Optional[str] = None
@@ -69,10 +71,27 @@ def persist_snapshot(s: NL43Snapshot, db: Session):
logger.info(f"State transition check for {s.unit_id}: '{previous_state}' -> '{new_state}'") logger.info(f"State transition check for {s.unit_id}: '{previous_state}' -> '{new_state}'")
# Device returns "Start" when measuring, "Stop" when stopped # The device reports "Start" while measuring; the DOD path uses that string,
# Normalize to previous behavior for backward compatibility # but the DRD stream path tags snapshots "Measure" (and the DOD fallback also
is_measuring = new_state == "Start" # uses "Measure"). Treat ALL of these as "measuring" — otherwise opening and
was_measuring = previous_state == "Start" # closing the live stream flips state "Start"->"Measure"->"Start", which the
# old equality check misread as stop-then-start and reset measurement_start_time.
#
# Also: only act on RECOGNIZED states. A buffer desync on the shared connection
# (e.g. right after a DRD/DOD test) can make a Measure? read return a stray,
# garbled value; treating that as "not measuring" produced constant phantom
# "STOPPED -> STARTED" log pairs and reset the timer. Ignore unknown reads.
MEASURING_STATES = {"Start", "Measure"}
STOPPED_STATES = {"Stop"}
was_measuring = previous_state in MEASURING_STATES
if new_state in MEASURING_STATES:
is_measuring = True
elif new_state in STOPPED_STATES:
is_measuring = False
else:
logger.warning(f"Ignoring unrecognized measurement state for {s.unit_id}: {new_state!r}")
is_measuring = was_measuring # garbled/unknown read — no transition
if not was_measuring and is_measuring: if not was_measuring and is_measuring:
# Measurement just started - record the start time # Measurement just started - record the start time
@@ -95,13 +114,18 @@ def persist_snapshot(s: NL43Snapshot, db: Session):
except Exception: except Exception:
pass pass
row.measurement_state = new_state # Only persist a recognized state so one garbled read can't poison the next
# transition check (which would manufacture the phantom STOPPED/STARTED pair).
if new_state in MEASURING_STATES or new_state in STOPPED_STATES:
row.measurement_state = new_state
row.counter = s.counter row.counter = s.counter
row.lp = s.lp row.lp = s.lp
row.leq = s.leq row.leq = s.leq
row.lmax = s.lmax row.lmax = s.lmax
row.lmin = s.lmin row.lmin = s.lmin
row.lpeak = s.lpeak row.lpeak = s.lpeak
row.ln1 = s.ln1
row.ln2 = s.ln2
row.battery_level = s.battery_level row.battery_level = s.battery_level
row.power_source = s.power_source row.power_source = s.power_source
row.sd_remaining_mb = s.sd_remaining_mb row.sd_remaining_mb = s.sd_remaining_mb
@@ -338,14 +362,14 @@ class ConnectionPool:
if self._is_alive(conn): if self._is_alive(conn):
self._drain_buffer(conn.reader) self._drain_buffer(conn.reader)
conn.last_used_at = time.time() conn.last_used_at = time.time()
logger.debug(f"Pool hit for {device_key} (age={time.time() - conn.created_at:.0f}s)") logger.info(f"Pool hit for {device_key} (age={time.time() - conn.created_at:.0f}s)")
return conn.reader, conn.writer, True return conn.reader, conn.writer, True
else: else:
await self._close_connection(conn, reason="stale") await self._close_connection(conn, reason="stale")
# Open fresh connection # Open fresh connection
reader, writer = await self._open_connection(host, port, timeout) reader, writer = await self._open_connection(host, port, timeout)
logger.debug(f"New connection opened for {device_key}") logger.info(f"New connection opened for {device_key}")
return reader, writer, False return reader, writer, False
async def release(self, device_key: str, reader: asyncio.StreamReader, writer: asyncio.StreamWriter, host: str, port: int): async def release(self, device_key: str, reader: asyncio.StreamReader, writer: asyncio.StreamWriter, host: str, port: int):
@@ -454,11 +478,11 @@ class ConnectionPool:
"""Check whether a cached connection is still usable.""" """Check whether a cached connection is still usable."""
now = time.time() now = time.time()
# Age / idle checks # Age / idle checks (value of -1 disables the check)
if now - conn.last_used_at > self._idle_ttl: if self._idle_ttl >= 0 and now - conn.last_used_at > self._idle_ttl:
logger.debug(f"Connection {conn.device_key} idle too long ({now - conn.last_used_at:.0f}s > {self._idle_ttl}s)") logger.debug(f"Connection {conn.device_key} idle too long ({now - conn.last_used_at:.0f}s > {self._idle_ttl}s)")
return False return False
if now - conn.created_at > self._max_age: if self._max_age >= 0 and now - conn.created_at > self._max_age:
logger.debug(f"Connection {conn.device_key} too old ({now - conn.created_at:.0f}s > {self._max_age}s)") logger.debug(f"Connection {conn.device_key} too old ({now - conn.created_at:.0f}s > {self._max_age}s)")
return False return False
@@ -691,22 +715,29 @@ class NL43Client:
snap = NL43Snapshot(unit_id="", raw_payload=resp, measurement_state=measurement_state) snap = NL43Snapshot(unit_id="", raw_payload=resp, measurement_state=measurement_state)
# Parse known positions (based on NL43 communication guide - DRD format) # Parse DOD positional fields. DOD's layout is DIFFERENT from DRD: it has NO
# DRD format: d0=counter, d1=Lp, d2=Leq, d3=Lmax, d4=Lmin, d5=Lpeak, d6=LIeq, ... # leading counter and it includes LE plus LN1LN5. The device returns 4 channels
# of 16 fields each — [Lp, Leq, LE, Lmax, Lmin, LN1, LN2, LN3, LN4, LN5, Lpeak,
# LIeq, Leq_mov, Ltm5, over, under] — and channel 1 (parts[0:16]) is the main
# display. The previous code reused the DRD map (treating parts[0] as a counter),
# which shifted everything: Lp was reported as the counter, Leq as Lp, LE as Leq,
# and LN1 as Lpeak (you could spot it because "Lpeak" came out < Lmax).
try: try:
# Capture d0 (counter) for timer synchronization
if len(parts) >= 1: if len(parts) >= 1:
snap.counter = parts[0] # d0: Measurement interval counter (1-600) snap.lp = parts[0] # Lp: instantaneous sound pressure level
if len(parts) >= 2: if len(parts) >= 2:
snap.lp = parts[1] # d1: Instantaneous sound pressure level snap.leq = parts[1] # Leq: equivalent continuous level
if len(parts) >= 3: # parts[2] = LE (sound exposure level) — not currently surfaced
snap.leq = parts[2] # d2: Equivalent continuous sound level
if len(parts) >= 4: if len(parts) >= 4:
snap.lmax = parts[3] # d3: Maximum level snap.lmax = parts[3] # Lmax
if len(parts) >= 5: if len(parts) >= 5:
snap.lmin = parts[4] # d4: Minimum level snap.lmin = parts[4] # Lmin
if len(parts) >= 11:
snap.lpeak = parts[10] # Lpeak (parts[5] is LN1, NOT Lpeak)
if len(parts) >= 6: if len(parts) >= 6:
snap.lpeak = parts[5] # d5: Peak level snap.ln1 = parts[5] # LN1 percentile slot (device default L5; contract L1)
if len(parts) >= 7:
snap.ln2 = parts[6] # LN2 percentile slot (device default L10)
except (IndexError, ValueError) as e: except (IndexError, ValueError) as e:
logger.warning(f"Error parsing DOD data points: {e}") logger.warning(f"Error parsing DOD data points: {e}")
@@ -896,15 +927,20 @@ class NL43Client:
# Acquire per-device lock - held for entire streaming session # Acquire per-device lock - held for entire streaming session
device_lock = await _get_device_lock(self.device_key) device_lock = await _get_device_lock(self.device_key)
async with device_lock: async with device_lock:
# Evict any cached connection — streaming needs its own dedicated socket
await _connection_pool.discard(self.device_key)
await self._enforce_rate_limit() await self._enforce_rate_limit()
logger.info(f"Starting DRD stream for {self.device_key}") logger.info(f"Starting DRD stream for {self.device_key}")
# Reuse the pooled connection instead of discard()+reopen. The NL43
# allows only ONE TCP connection at a time, and on a cellular link the
# device does not free its single slot fast enough for an immediate
# reconnect — so a fresh connect times out (the DRD stream failure).
# The per-device lock is held for the whole session, so it already
# blocks the poller; reusing the warm socket keeps us at exactly one
# connection and lets the stream start on the slot commands already use.
try: try:
reader, writer = await _connection_pool._open_connection( reader, writer, from_cache = await _connection_pool.acquire(
self.host, self.port, self.timeout self.device_key, self.host, self.port, self.timeout
) )
except ConnectionError: except ConnectionError:
logger.error(f"DRD stream connection failed to {self.device_key}") logger.error(f"DRD stream connection failed to {self.device_key}")
@@ -981,16 +1017,20 @@ class NL43Client:
break break
finally: finally:
# Send SUB character to stop streaming # Stop streaming on the device (SUB = 0x1A), then return the warm
# connection to the pool so subsequent commands reuse this single
# socket instead of opening a second one. release() returns healthy
# sockets to the pool and closes dead ones; the next acquire()
# drains any residual stop output before reuse.
try: try:
writer.write(b"\x1A") writer.write(b"\x1A")
await writer.drain() await writer.drain()
except Exception: except Exception:
pass pass
writer.close() await _connection_pool.release(
with contextlib.suppress(Exception): self.device_key, reader, writer, self.host, self.port
await writer.wait_closed() )
logger.info(f"DRD stream ended for {self.device_key}") logger.info(f"DRD stream ended for {self.device_key}")
+58
View File
@@ -0,0 +1,58 @@
#!/usr/bin/env python3
"""
Migration script to add ln1 and ln2 percentile columns to the nl43_status table.
The NL-43 DOD response carries percentile slots LN1-LN5; the live SLM display
(Terra-View) shows two of them (default L1/L10). This adds storage for the two
surfaced slots. Run once per database to update existing schema.
"""
import sqlite3
import sys
from pathlib import Path
DB_PATH = Path(__file__).parent / "data" / "slmm.db"
def migrate():
"""Add ln1 and ln2 columns to the nl43_status table."""
if not DB_PATH.exists():
print(f"Database not found at {DB_PATH}")
print("No migration needed - database will be created with new schema")
return
conn = sqlite3.connect(DB_PATH)
cursor = conn.cursor()
try:
cursor.execute("PRAGMA table_info(nl43_status)")
columns = [row[1] for row in cursor.fetchall()]
if "ln1" in columns and "ln2" in columns:
print("✓ ln1/ln2 columns already exist, no migration needed")
return
if "ln1" not in columns:
print("Adding ln1 column...")
cursor.execute("ALTER TABLE nl43_status ADD COLUMN ln1 TEXT")
print("✓ Added ln1 column")
if "ln2" not in columns:
print("Adding ln2 column...")
cursor.execute("ALTER TABLE nl43_status ADD COLUMN ln2 TEXT")
print("✓ Added ln2 column")
conn.commit()
print("\n✓ Migration completed successfully!")
except Exception as e:
conn.rollback()
print(f"✗ Migration failed: {e}", file=sys.stderr)
sys.exit(1)
finally:
conn.close()
if __name__ == "__main__":
migrate()