mirror of
https://github.com/maziggy/bambuddy.git
synced 2026-08-11 00:30:12 -04:00
An H2D armed five 12-hour drying cycles inside four hours, one of them six seconds after the previous one ended, and none ran more than a couple of hours. Two things combine. The firmware ends a cycle when it decides the filament is dry rather than when the clock runs out, and reports no fault doing it -- across this printer's history the run length tracks how wet the spools were, from nearly the full 12 hours starting at 32% down to minutes once the unit sat at 10-13%. That part is the AMS doing its job. The loop is ours. An AMS reports higher relative humidity while it is warm than once it has cooled: the same unit read 10-13% cold and 15-20% through every cycle. With the threshold at 14% the reading at the moment a cycle ended was always still above it, so the next 30-second pass armed another 12-hour cycle. Nothing counted, nothing waited, and it only stopped when the box finally cooled enough to read 13%. Auto-drying now waits 30 minutes after a cycle ends before arming another on the same unit, and gives up on a unit after two consecutive cycles that bring the reading no lower -- logging why and sending a new notification, on by default because it reports that Bambuddy has stopped acting. Progress is judged against the lowest reading any cycle on that unit has ended at, not against the threshold, so a genuinely wet spool in a humid room coming down 40-37-35 keeps drying however far it still is from the target; comparing against the best so far rather than the previous end stops a sensor wobbling by one point reading as progress every other cycle. The suspension lifts by itself once the reading falls below the threshold. Neither guard can stop a running cycle, and a cycle Bambuddy cut short for a print, or that the user stopped by hand, is not counted against the unit -- so a farm that dries between queue jobs is unaffected. The threshold field now warns below 20%, and every cycle end logs the unit's temperature and humidity, which is what made this diagnosable. The same bundle showed unrelated tasks failing with "database is locked", each inside a 30.000-second Discord connect timeout. Alarms are raised from inside the loop that records sensor history, at a point where the new rows are added but not committed; the first read in the notification path flushed them to satisfy itself, opening a write transaction, and the provider was then contacted over the network with that transaction still open. SQLite allows one writer and 30 seconds outlives the 15-second busy timeout, so every other write in that window failed. The two reads that run before a provider is contacted no longer flush the caller's pending work, and the connect timeout is 5 seconds rather than 30 -- the body keeps the full 30, so image uploads on a slow uplink are unaffected. SQLite only; Postgres has no single-writer limit.
102 lines
4.1 KiB
Python
102 lines
4.1 KiB
Python
"""A notification must never be sent while holding the SQLite write lock (#2770).
|
|
|
|
The reporter's bundle has two "database is locked" failures, and both sit inside
|
|
a Discord connect timeout::
|
|
|
|
17:36:55 Sending humidity alarm ... 15.0% > 14.0%
|
|
17:37:12 WARNING Printer sensor history recording failed: database is locked
|
|
17:37:25 ERROR httpx.ConnectTimeout <- exactly 30.000s later
|
|
|
|
The mechanism is not contention from writing too much. The AMS sensor loop does
|
|
``db.add(history)`` and only commits *after* the alarms have been dispatched, so
|
|
the first SELECT inside the notification path used to autoflush that pending
|
|
INSERT — opening a write transaction — and the provider was then contacted over
|
|
the network with that transaction still open. SQLite allows one writer, and the
|
|
30 s connect timeout comfortably outlived the 15 s ``busy_timeout``, so unrelated
|
|
background tasks failed.
|
|
|
|
These tests pin the two reads that run before the network call. They assert the
|
|
caller's pending row is still unflushed afterwards, which is the same thing as
|
|
"no write transaction was opened on its behalf" and holds on any dialect.
|
|
"""
|
|
|
|
import pytest
|
|
from sqlalchemy.ext.asyncio import async_sessionmaker, create_async_engine
|
|
|
|
import backend.app.models # noqa: F401 - populate Base.metadata
|
|
from backend.app.core.database import Base
|
|
from backend.app.models.notification import NotificationProvider
|
|
from backend.app.models.notification_template import NotificationTemplate
|
|
from backend.app.services.notification_service import NotificationService
|
|
|
|
|
|
@pytest.fixture
|
|
async def session(tmp_path):
|
|
engine = create_async_engine(f"sqlite+aiosqlite:///{tmp_path / 'notify-lock.db'}")
|
|
async with engine.begin() as conn:
|
|
await conn.run_sync(Base.metadata.create_all)
|
|
maker = async_sessionmaker(engine, expire_on_commit=False)
|
|
async with maker() as s:
|
|
yield s
|
|
await engine.dispose()
|
|
|
|
|
|
def _pending_row() -> NotificationProvider:
|
|
"""A row the caller has added but not committed — the sensor loop's position."""
|
|
return NotificationProvider(name="pending", provider_type="discord", config="{}", enabled=False)
|
|
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_provider_lookup_does_not_flush_the_callers_pending_writes(session):
|
|
service = NotificationService()
|
|
session.add(NotificationProvider(name="Discord", provider_type="discord", config="{}", enabled=True))
|
|
await session.commit()
|
|
|
|
pending = _pending_row()
|
|
session.add(pending)
|
|
|
|
providers = await service._get_providers_for_event(session, "on_ams_drying_suspended")
|
|
|
|
assert [p.name for p in providers] == ["Discord"]
|
|
assert pending in session.new, "the caller's pending INSERT was flushed, taking the SQLite write lock"
|
|
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_template_lookup_does_not_flush_the_callers_pending_writes(session):
|
|
service = NotificationService()
|
|
session.add(
|
|
NotificationTemplate(
|
|
event_type="ams_drying_suspended",
|
|
name="Auto-Drying Suspended",
|
|
title_template="t",
|
|
body_template="b",
|
|
is_default=True,
|
|
)
|
|
)
|
|
await session.commit()
|
|
|
|
pending = _pending_row()
|
|
session.add(pending)
|
|
|
|
template = await service._get_template(session, "ams_drying_suspended")
|
|
|
|
assert template is not None
|
|
assert pending in session.new, "the caller's pending INSERT was flushed, taking the SQLite write lock"
|
|
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_connect_timeout_stays_under_the_sqlite_busy_timeout():
|
|
"""15 s is the ``busy_timeout`` set in database.py. A connect timeout at or
|
|
above it guarantees the "database is locked" failure whenever a site's
|
|
internet is down, whatever else is fixed."""
|
|
service = NotificationService()
|
|
client = await service._get_client()
|
|
try:
|
|
assert client.timeout.connect is not None
|
|
assert client.timeout.connect < 15.0
|
|
# The body still gets the generous budget — image uploads on a slow
|
|
# uplink must not start failing.
|
|
assert client.timeout.read == 30.0
|
|
assert client.timeout.write == 30.0
|
|
finally:
|
|
await service.close()
|