PowerOn/wiki
3
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions
wiki/c-work/2-build/2026-05-postgres-connection-pool.md

21 KiB
Raw Blame History

PostgreSQL Connection-Pool — Beseitigung der Shared-Connection-Race

Beschreibung und Kontext

Der zentrale DatabaseConnector in gateway/modules/connectors/connectorDbPostgre.py hält genau eine psycopg2-Connection pro Instanz. Die Modul-Cache-Funktion getCachedConnector(host, db, user, port) gibt für denselben Schlüssel immer denselben Connector zurück. In DatabaseConnector.__init__ wird zwar ein self._lock = threading.Lock() deklariert, im ganzen 1789-zeiligen File aber kein einziges Mal genutzt (with self._lock: → 0 Treffer).

Folge: Sobald zwei FastAPI-Threadpool-Worker (für def-Routes) oder zwei async-Tasks (für async def) gleichzeitig auf dieselbe gecachte Connection zugreifen — connection.cursor() / cursor.execute() —, gibt psycopg2 entweder OperationalError: another command is already in progress oder hängt im recv()-Syscall ohne Timeout. Ein einziger hängender Call vergiftet die Connection; alle weiteren Calls auf demselben Cache-Eintrag hängen ebenfalls; uvicorn-Worker stauen sich; das Backend ist tot.

Das ist am 2026-05-17 produktiv eingetreten: Backend antwortete bis 00:19:13 sauber, danach 50+ Minuten komplette Stille. CloseWait-Connections stapelten sich, Login-Seite konnte nicht mal mehr /api/i18n/... laden, weil routeI18n.py denselben Cache nutzt. Auslöser: gestrige Umstellung von mainBackgroundJobService._getDb() auf getCachedConnector (zur Fix des DB-Init-Log-Spams), kombiniert mit dem 5-Sekunden-Polling der RagInventoryPage + RagRunningBadge (zwei Tabs offen ⇒ ~50 Calls/Min auf einer Connection) plus dem killZombieJobs-Cron und dem _runJob-Worker selber.

Das Risiko ohne Fix: Das System ist nicht produktionstauglich. Jeder Tag mit moderatem Polling-Load + Background-Jobs killt das Backend nach ≤ 30 Min. Stop-the-bleeding mit self._lock würde alle DB-Calls auf einer Connection serialisieren (ungeniessbar langsam) und das eigentliche Problem nur verstecken.

Fokus und kritische Details

  • psycopg2-Connections sind nicht thread-safe — egal ob im Threadpool oder im asyncio-Loop. Pro Logik-Einheit eine eigene Connection oder geliehene Pool-Connection.
  • getCachedConnector wird von vielen Hot-Path-Stellen genutzt: routeI18n.py, i18nRegistry.py, aiAuditLogger.py, mainBackgroundJobService.py, interfaceDbApp.py, interfaceDbManagement.py, interfaceDbKnowledge.py, interfaceFeatureChatbot.py, plus die XxxObjects-Klassen via interfaceDbApp/Management/Knowledge. Sie ist Core-Infrastruktur — eine kaputte Umstellung legt alles lahm.
  • 40 Stellen in connectorDbPostgre.py referenzieren self.connection. direkt (cursor, commit, rollback, closed). Jede muss auf ein Pool-Borrow-Pattern umgestellt werden.
  • Transaktionsgrenzen: Der bestehende Code mischt Auto-Commit-Style (connection.commit() am Ende jeder Methode) mit Multi-Statement-Operationen (recordCreateBulk, _save_record, recordDeleteWhere). Beim Pool-Refactor MUSS jede Operation ihre Connection borrow → execute → commit/rollback → return-to-pool in einem klar abgegrenzten Block durchlaufen. Sonst geht eine Connection mit offener Transaktion zurück in den Pool und der nächste Borrower erbt sie.
  • setUserContext() und der RBAC-updateContext(userId) Pfad: Aktuell wird der User per-Instance gehalten. Bei Pool ist die "Instance" nur noch ein dünner Wrapper um den Pool — userId muss über contextvars request-scoped fliessen (das ist mit _current_user_id schon halb-implementiert, muss konsequent gezogen werden).
  • _create_database_if_not_exists und _create_tables brauchen autocommit-Mode auf einer separaten Connection (CREATE DATABASE darf nicht in einer Transaction laufen). Aktuell wird dafür schon eine kurze separate psycopg2.connect() geöffnet — das bleibt so, nicht über den Pool.
  • App-Shutdown: Pool muss bei FastAPI-Shutdown sauber geschlossen werden, sonst leakt psycopg2 Server-side prepared statements bei jedem Hot-Reload.
  • Statement-Timeout als Safety-Net: statement_timeout=30000 (30s) per options beim Connect, damit ein hängender Call die Connection nicht für immer vergiftet.
  • Tests müssen Concurrency aktiv provozieren — sonst landet derselbe Bug in 6 Monaten wieder im Code. Unit-Test mit ThreadPoolExecutor(50) der parallel getRecordset() auf derselben DB feuert.

Ziel und Nicht-Ziele

Ziel

  • DatabaseConnector benutzt psycopg2.pool.ThreadedConnectionPool (eine Pool-Instanz pro (host, db, user, port)).
  • Jede DB-Operation borrowed eine Connection aus dem Pool, führt ihre SQL-Operation in einer klar abgegrenzten Transaktion aus, gibt die Connection wieder zurück — auch im Fehlerfall.
  • getCachedConnector bleibt API-kompatibel (Aufrufer ändern sich nicht), gibt aber unter der Haube einen pool-basierten Connector zurück.
  • Statement-Timeout (30s) und connect_timeout (10s) sind als Safety-Net konfiguriert.
  • Concurrency-Test in tests/unit/connectors/ beweist mit ≥ 50 parallelen Threads auf einer DB, dass kein "another command in progress" Error auftritt und alle Calls innerhalb < 10s antworten.
  • Smoke-Test: Backend hält 1 h unter dem reproduzierbaren Polling-Load (RagInventoryPage offen + manueller Sync) ohne hängen.

Explizit NICHT

  • Kein Umstieg auf asyncpg / psycopg3-async. Der Code ist durchgängig sync, asyncpg würde alle 40+ Aufrufstellen ändern. Asyncpg-Migration ist ein separater, viel grösserer Refactor.
  • Kein ORM-Umstieg (SQLAlchemy/Tortoise). Das ist Out-of-Scope für diesen Bugfix.
  • Keine Änderung an Interface-Pattern (XxxObjects, interfaceDb*.py), an RBAC-WhereClause-Logik oder an DatabaseConnector's Public-API. Aufrufer dürfen nicht angefasst werden müssen.
  • Keine generelle Performance-Optimierung der Queries. Wir fixen die Race, nicht das Schema.

Betroffene Module

  • Gateway:
    • gateway/modules/connectors/connectorDbPostgre.py — Refactor (Pool-Helper, alle 40 self.connection.* Stellen)
    • gateway/app.py — Pool-Shutdown-Hook bei FastAPI-Shutdown
    • gateway/tests/unit/connectors/test_connectorDbPostgre_failLoud.py — neue Concurrency-Tests
    • Keine Änderung an: mainBackgroundJobService.py, routeI18n.py, aiAuditLogger.py, interfaceDb*.py, i18nRegistry.py, XxxObjects-Klassen — die Public-API von DatabaseConnector und getCachedConnector bleibt 1:1
  • Frontend: keine
  • DB-Migration: nein (keine Schema-Änderung)
  • Andere Komponenten: keine (private-llm, teams-bot, frontend nicht betroffen)

Entscheidungen

Datum Entscheidung Begründung
2026-05-17 psycopg2.pool.ThreadedConnectionPool statt psycopg_pool oder asyncpg Bereits Teil von psycopg2-binary, keine neue Dependency, kompatibel mit sync Codebase, Drop-in-ready. psycopg_pool würde psycopg3 voraussetzen (anderer Driver). asyncpg würde alle 40 Aufrufstellen async machen.
2026-05-17 getCachedConnector API beibehalten 11+ Konsumenten greifen drauf zu. API-Break = grosser Blast-Radius. Wir tauschen nur die Implementierung.
2026-05-17 Pool-Größe minconn=2, maxconn=20 pro DB initial uvicorn default workers=1, FastAPI threadpool default=40. Konservativ starten, im Lasttest justieren. Wert in APP_CONFIG exposen als DB_POOL_MAX_CONN für späteres Tuning ohne Code-Change.
2026-05-17 Statement-Timeout 30s (options='-c statement_timeout=30000') Schützt vor unendlichem recv()-Hang. 30s ist grosszügig für Reports/Embeddings, restriktiv genug um ein Schauerszenario zu beenden.
2026-05-17 _create_database_if_not_exists / _create_tables bleiben auf eigener Connection (nicht Pool) CREATE DATABASE darf nicht in Transaction laufen, ist ein einmaliger Boot-Pfad, lohnt sich nicht im Pool.

Umsetzungs-Checkliste

  • Modul-Helper _PoolRegistry mit getPool(host, db, user, password, port) → ThreadedConnectionPool (Lazy-Init, Thread-safe via Modul-Lock) (S1, done 2026-05-17)
  • DatabaseConnector Refactor: self.connection ersetzen durch Pool-Borrow-Pattern (S2, done 2026-05-17)
  • Public Context-Manager db.borrowConn() + db.borrowCursor() für alle Aufrufstellen — interne (18) und externe (~30) Stellen migriert (S2, done 2026-05-17)
  • Jede Methode mit connection.commit() / connection.rollback() auf Borrow-Block-Lifecycle umgestellt (auto-commit-on-success, auto-rollback-on-exception, immer putconn im finally) (S2, done 2026-05-17)
  • _ensure_connection() zu No-Op gemacht (Pool re-connectet selbständig) — bleibt als Backward-Compat-Hook für externe Aufrufer (S2, done 2026-05-17)
  • _initializeSystemTable und _create_database_if_not_exists/_create_tables korrekt aufgeteilt: Init nutzt eigene autocommit-Connection (CREATE DATABASE), Rest läuft via Pool (S2, done 2026-05-17)
  • getCachedConnector umgebaut: Cache enthält leichtgewichtige Wrapper, jeder Wrapper teilt sich den Pool über _PoolRegistry. API unverändert (S2, done 2026-05-17)
  • Statement-Timeout (30 s) + connect_timeout (10 s) per options=/connect_timeout= in Pool-Erzeugung gesetzt (S1, done 2026-05-17)
  • Backward-Compat-Shim db.connection (no-op commit/rollback/closed/close, RuntimeError auf cursor) damit kein legacy Aufruf still bricht (S2, done 2026-05-17)
  • FastAPI lifespan / app.on_event("shutdown"): alle Pools schliessen (closeAllPools()) — gewirelt in gateway/app.py als letzter Shutdown-Schritt nach den Feature-onStop Hooks (S4, done 2026-05-17)
  • Concurrency-Tests in neuem test_connectorDbPostgre_pool.py: 6 Tests (50 Threads Stress, 20 Threads Latency-Budget, interleaved load/save, statement_timeout-Release, pool-identity, closeAllPools) — alle 6 grün gegen lokales Postgres; auto-skipping wenn keine DB erreichbar; borrowConn() um bounded Wait-Retry erweitert weil psycopg2-Pool exhaustion sofort raised statt blockt (S5, done 2026-05-17)
  • Regression-Run unit+integration: 639/656 unit grün (1 von uns gefixt: test_folder_crud._FakeDb brauchte borrowCursor-Stub; 17 pre-existing Failures sind RAG-Logik-Drift + Adapter-Drift, kein Pool-Bezug); 76/79 integration grün (3 pre-existing Trustee-Workflow-Failures, kein Pool-Bezug) (S6, done 2026-05-17)
  • Smoke-Test 17.05.2026 11:33–11:39 (local/logs/log_app_20260517.log): 11 Pools je 1× lazy erzeugt, kein another command is already in progress, kein pool exhausted, kein recv() hang, kein Pool-Retry. Frontend laut User ohne Delays/Freezes. Einziger ERROR: Decryption rate limit exceeded for user 'system' key 'DB_PASSWORD_SECRET' in routeRagInventory._getInventoryPlatform — unabhängiges Problem (kein Pool-Bezug), hot-path mainBackgroundJobService._getDb() triggert pro RAG-Inventory-Poll + Walker-Call >10 Decrypts/s. Separater Fix unterhalb. (S7, done 2026-05-17)
  • Folge-Fix Secrets-Decryption-TTL-Cache (configuration.py:decryptValue, 60 s, thread-safe, Cache-Hit umgeht Rate-Limit, Cache-Miss bleibt geschützt). Beseitigt den letzten ERROR aus dem S7-Lauf, profitieren alle _SECRET-Reader (auditLogger, routeI18n, alle Feature-Interfaces). (2026-05-17)
  • DB-Init-Log-Spam-Regression-Test: logger.debug darf nicht mehr in INFO-Pfad eskalieren (war Auslöser der gestrigen Cache-Umstellung — neue Lösung darf das nicht zurückbringen)

S7 — Manueller Smoke-Test (Auftrag an Patrick)

Ziel: beweisen dass das Backend unter realem Polling-Last 1 h stabil bleibt — also nicht den Bug reproduziert, den der Pool-Refactor beseitigt hat.

Setup:

  1. Gateway neu starten: uvicorn app:app --host 0.0.0.0 --port 8000 (siehe Terminal 2).
  2. Optional in .env setzen: DB_POOL_MAX_CONN=20 (Default reicht).
  3. Browser-Setup:
    • Tab 1: Start > Nutzung > RAG (RagInventoryPage) — pollt aktive Jobs alle 5 s.
    • Tab 2: zweite Sitzung mit Start > Nutzung > RAG offen lassen (Multi-Tab-Last).
    • Tab 3 (optional): Workflow-Dashboard oder ein anderes Polling-Frontend offen lassen.
  4. Optional: 1 manuellen RAG-Sync auslösen (Jetzt synchronisieren auf einer Connection mit indexierten DataSources) — das pumpt Background-Jobs durch den Pool.

Beobachten (1 h):

  • Frontend reagiert konsistent unter 500 ms je Polling-Call (Browser DevTools → Network).
  • Im Log kein another command is already in progress, kein connection pool exhausted (Retries sind OK solange sie unter 30 s bleiben), kein recv() hang.
  • pg_stat_activity zeigt höchstens _DEFAULT_POOL_MAX_CONN (=20) Backends pro DB im Zustand idle / idle in transaction; nicht anwachsend.
  • RAM des python.exe für Gateway stabil (nicht monoton wachsend > 100 MB/h).
  • Login-Seite (Inkognito-Tab) lädt die i18n-Strings sauber (war im Bug-Szenario tot).

Konkret prüfbar via PowerShell während des Tests:

# Pro DB Connection-Zahl (verlangt psql im PATH, sonst pgAdmin)
psql -h localhost -U poweron_dev -d postgres -c "SELECT datname, count(*) FROM pg_stat_activity WHERE datname LIKE 'poweron%' GROUP BY datname ORDER BY count DESC;"

# Backend-RAM (in PS)
Get-Process python | Sort-Object WS -Descending | Select-Object -First 3 ProcessName,Id,@{N='RAM_MB';E={[math]::Round($_.WS/1MB,1)}}

Abschluss:

  • Notiz unter local/notes/2026-05-pool-smoke-1h.md mit:

    • Start/Endzeit
    • Auffälligkeiten in den Logs (sollten keine sein) — grep -E "another command|pool exhausted|connection pool" gateway/local/logs/log_app_<datum>.log
    • pg_stat_activity Snapshots zu Beginn / Mitte / Ende
    • RAM-Verlauf 3 Werte

  • Bei Erfolg: Diese Plan-Doc nach c-work/3-validate/ verschieben, dann S8 (Doku-Sync) anstossen.

  • Bei Auffälligkeit: Issue im Log notieren, Plan-Doc bleibt in 2-build/.

  • RBAC / Permissions — n.a. (keine API-Änderung)

  • Neutralisierung betroffen? — nein

  • Navigation / Routing — nein

  • Billing-Impact? — nein

Akzeptanzkriterien

# Kriterium (Given-When-Then) Prio
1 Given Backend mit RagInventoryPage + RagRunningBadge offen (2 Tabs) When 1 h gepollt Then keine hängenden Routes, alle Polls < 500 ms, kein another command in progress in Logs must
2 Given 50 Threads im Unit-Test When parallel getRecordset(BackgroundJob) aufrufen Then 0 Errors, alle Calls < 2 s must
3 Given Walker macht _loadJob + Route macht listJobs parallel When beide auf derselben DB Then beide bekommen valide Resultate, keine Cursor-Vermischung must
4 Given Statement-Timeout 30 s When eine Query > 30 s läuft Then psycopg2.errors.QueryCanceled, Connection geht sauber zurück in den Pool, keine Vergiftung must
5 Given FastAPI Shutdown When uvicorn Ctrl+C Then alle Pools closeall(), keine Open-Connections im PG pg_stat_activity should
6 Given bestehender Code (40 Aufrufstellen, 11 Konsumenten von getCachedConnector) When Pool-Refactor When Tests laufen Then alle bisherigen Unit-Tests grün (keine Regression) must

Testplan

ID AC Art Automatisiert Repo-Pfad Status
T1 2 unit (concurrency) ja gateway/tests/unit/connectors/test_connectorDbPostgre_failLoud.py::test_concurrent_getRecordset_50threads pending
T2 3 unit (interleaved cursor) ja gateway/tests/unit/connectors/test_connectorDbPostgre_failLoud.py::test_interleaved_load_update_no_collision pending
T3 4 unit (timeout) ja gateway/tests/unit/connectors/test_connectorDbPostgre_failLoud.py::test_statement_timeout_returns_conn_to_pool pending
T4 5 manual+integration teilweise gateway/tests/integration/test_pool_shutdown.py + pg_stat_activity check pending
T5 6 regression ja gateway/tests/unit/connectors/, gateway/tests/integration/ (alle bestehenden) pending
T6 1 smoke (manuell) nein local/notes/2026-05-pool-smoke-1h.md mit Polling-Log + Memory-Verlauf pending

Schritt-für-Schritt-Umsetzung mit LLM-Empfehlung

Faustregel: composer-2-fast für mechanische Refactors mit klarem Pattern (Boilerplate, Datei-Edits nach Schablone). claude-opus-4-7-thinking-xhigh (oder claude-4.6-opus) für Architekturentscheidungen, kritischen Pool-Lifecycle-Code, Concurrency-Tests und Doku.

S1 — Pool-Helper-Modul _PoolRegistry (NEU)

LLM: claude-opus-4-7-thinking-xhigh (kritischer Lifecycle-Code, ein Fehler hier killt alles)

Neue Datei oder Modul-Section in connectorDbPostgre.py:

  • Lazy-Init ThreadedConnectionPool(minconn=2, maxconn=APP_CONFIG.DB_POOL_MAX_CONN ?? 20, ...) pro DB-Key
  • Thread-safe Registry (threading.Lock)
  • getPool(host, db, user, password, port) → Pool oder erstellt einen
  • closeAll() für Shutdown
  • Statement-Timeout + connect-Timeout in options= setzen

S2 — DatabaseConnector Refactor: Borrow-Pattern einführen

LLM: claude-opus-4-7-thinking-xhigh für den Context-Manager-Skelett, danach die 40 Aufrufstellen mit composer-2-fast

  • self.connection → entfernt
  • Neu: @contextmanager def _borrowConn(self) → borrowed aus Pool, gibt Conn yield, putconn im finally, mit Exception-handling rollback
  • _connect, _ensure_connection → entfernt (Pool macht das)
  • Jede der 40 Stellen with self.connection.cursor() as cursor: → with self._borrowConn() as conn: und darin with conn.cursor() as cursor:
  • Pro Methode klares Transaktions-Lifecycle: am Ende conn.commit(), im Except-Block conn.rollback(). Im _borrowConn Cleanup: bei unfertiger Transaktion rollback() bevor putconn (sonst geht poisoned conn zurück).

S3 — getCachedConnector umbauen

LLM: composer-2-fast (klein, mechanisch)

  • Cache enthält nur noch leichtgewichtige DatabaseConnector-Wrapper, die alle dieselbe Pool-Referenz nutzen
  • _MAX_CACHED_CONNECTORS und FIFO-Eviction können bleiben oder weg (Pool hat eigene Connection-Verwaltung; Wrapper sind billig). Empfehlung: Cache komplett raus, jeder Call erzeugt einen frischen Wrapper. Begründung im PR.

S4 — App-Lifecycle: Shutdown-Hook

LLM: composer-2-fast

  • In gateway/app.py FastAPI lifespan-Handler (oder on_event("shutdown") falls Codebase noch das alte Pattern nutzt) → closeAll() aufrufen
  • Bei lifespan zusätzlich Startup-Hook für initialen Pool-Warmup (optional)

S5 — Concurrency-Tests

LLM: claude-opus-4-7-thinking-xhigh (Test-Design für Race-Bedingungen ist anspruchsvoll)

  • test_concurrent_getRecordset_50threads: ThreadPoolExecutor(max_workers=50) × 100 getRecordset Calls auf demselben Connector, assert 0 Exceptions, p99 < 2 s
  • test_interleaved_load_update_no_collision: ein Thread _loadJob(jobId) in Schleife, parallel anderer Thread _updateJob(jobId, {...}) in Schleife, assert keine OperationalError, keine Cursor-Datenvermischung
  • test_statement_timeout_returns_conn_to_pool: triggere SELECT pg_sleep(60) mit statement_timeout=30000, assert QueryCanceled nach ~30 s, assert Pool-Conn ist wieder verfügbar (next call < 100 ms)
  • Tests brauchen echte PostgreSQL-Verbindung (kein Mock — Mock würde den Bug nicht zeigen). Skip wenn PG_TEST_DSN env nicht gesetzt.

S6 — Regression-Run: alle bestehenden Tests

LLM: composer-2-fast (nur Run + Fix-Loop)

  • pytest gateway/tests/unit/connectors/ gateway/tests/integration/ → grün
  • Jede Regression-Failure: einzeln analysieren, Fix entweder im Pool-Code oder im Test (falls Test-Assumption hard-coded auf self.connection)

S7 — Smoke-Test 1 h

LLM: keiner (manueller Test durch Patrick)

  • Backend starten, RagInventoryPage + ein zweites Tab offen halten, optional einen RAG-Sync auslösen, 1 h beobachten
  • Notiz in local/notes/2026-05-pool-smoke-1h.md: alle Routes < 500 ms, kein another command, RAM stabil, pg_stat_activity zeigt idle-Connections im Pool-Bereich
  • Bei Erfolg: Plan-Doc nach c-work/3-validate/ verschieben

S8 — Doku-Sync (am Ende)

LLM: claude-opus-4-7-thinking-xhigh (richtig formulieren, lastReviewed setzen)

  • wiki/b-reference/platform/database-architecture.md:
    • Abschnitt "Connector-Caching" umbenennen zu "Connection-Pool", Pool-Pattern, min/max-conn, Statement-Timeout, Borrow-Lifecycle beschreiben
    • lastReviewed und verifiedAgainst setzen
  • wiki/c-work/_CHANGELOG.md: 1 Zeile
  • wiki/TOPICS.md: prüfen ob neues Topic "Database Connection Pool" rein muss (nein — fällt unter database-architecture.md, nur Link prüfen)
  • Plan-Doc c-work/2-build/ → c-work/3-validate/ → c-work/4-done/

Links

  • Root-Cause-Diskussion: dieser Chat (siehe (Diagnose: API blockiert nach RAG-Sync))
  • Auslöser-Commit: gestrige Umstellung _getDb() in mainBackgroundJobService.py auf getCachedConnector (DB-Init-Log-Spam-Fix)
  • PR: tbd
  • Issue: tbd

Abschluss

  • b-reference/platform/database-architecture.md aktualisiert (Pool, Lifecycle, Timeouts, lastReviewed, verifiedAgainst)
  • TOPICS.md geprüft (kein neuer Eintrag nötig, Link in database-architecture.md ggf. aktualisieren)
  • c-work/_CHANGELOG.md 1-Zeilen-Eintrag
  • Dieses Dokument durch Kanban: 1-plan → 2-build → 3-validate → 4-done → z-archive/