Spaces:
Runtime error
Runtime error
| # Error Log | |
| A searchable record of debugging investigations β non-obvious errors, what was tried, and how they were solved. | |
| **How to use this file:** | |
| - AI agents: search by category heading or tag keyword before attempting a web search | |
| - Monireach: reference for interview questions about challenges and problem-solving | |
| **Related:** `my_mistakes.md` β one-liners for careless errors (wrong parameter, typo, etc.) | |
| --- | |
| ## FastAPI Routing | |
| ### Duplicate endpoint from sequential feature branch merges β FastAPI silently uses first registered route | |
| **Date:** 2026-04-24 | |
| **Context:** `app/routers/admin_settings.py` + `app/routers/admin_apikey.py` β merging `feat/admin-api-key-rotate` into development | |
| **Tags:** `duplicate-route` `fastapi` `route-registration` `scaffolded-branch` `merge-conflict` | |
| **Error:** After merging development into `feat/admin-api-key-rotate`, both `admin_settings.py` (raw UUID rotate, merged via `feat/admin-settings`) and `admin_apikey.py` (hashed rotate, this branch) registered `POST /admin/api-key/rotate`. FastAPI does not error on duplicate paths β it silently uses the first registered router, which would have hidden the hashed (correct) implementation behind the raw one. | |
| **Tried & Failed:** | |
| - (no failed approaches β duplicate identified proactively via `git diff development...HEAD --name-only` before running tests) | |
| **Solution:** Removed `post_admin_api_key_rotate` from `admin_settings.py` (raw storage, superseded) and its 2 tests from `test_admin_settings.py`. Kept `admin_apikey.py` as the canonical home for the hashed implementation. Cleaned up unused `import hashlib` from `admin_settings.py`. | |
| **Learned:** When multiple feature branches are scaffolded at the same time and merged sequentially, a later branch may implement an endpoint that an earlier branch also implemented (differently). FastAPI silently resolves duplicate route paths by registration order β no error, no warning, just silent override. Always diff the feature branch against development (`git diff development...HEAD --name-only`) before merging to catch overlapping files. When a duplicate is found, decide which implementation is canonical, remove the superseded one, and update both the router and its tests. | |
| --- | |
| ### Chat routes completely missing from registered routes β 405 on POST /api/v1/chat | |
| **Date:** 2026-03-19 | |
| **Context:** `app/main.py` β API versioning refactor, `api_router = APIRouter(prefix="/api/v1")` | |
| **Tags:** `405` `include_router` `APIRouter` `routing` `route-not-registered` | |
| **Error:** `POST /api/v1/chat` returned 405 Method Not Allowed. Inspecting the running container's registered routes showed only KB routes and `/health` β all `api_router` routes (`/chat`, `/analytics/...`) were completely absent. | |
| **Tried & Failed:** | |
| - Restarted the container (`make dev`) β routes still missing; container was running old image | |
| - Rebuilt the Docker image (`make build && make dev`) β routes still missing; root cause not yet identified | |
| **Solution:** Moved `app.include_router(api_router)` from line 76 (before route decorators) to line 280 (after the last `@api_router` decorator, just before the static files mount). | |
| **Learned:** `include_router` snapshots `router.routes` at the moment it is called β it is a one-time copy, not a live reference. Route decorators defined after `include_router` are added to the router but never copied into the app. Fix: always call `include_router` after all `@router.post/get/...` decorators on that router are defined. Routers in separate files are safe because their decorators run at import time, before `main.py` reaches `include_router`. | |
| --- | |
| ## FastAPI Testing | |
| ### KB tests passing despite fixture using unprefixed routes (silent false positive) | |
| **Date:** 2026-03-19 | |
| **Context:** `tests/conftest.py` β `kb_client_fixture`, API versioning refactor | |
| **Tags:** `fixture` `include_router` `prefix` `false-positive` `test-isolation` | |
| **Error:** After adding `prefix="/api/v1"` to `app.include_router(knowledge_base.router)` in `main.py`, all KB tests still passed. Expected them to fail because the real routes moved to `/api/v1/kb/entries` but tests were calling `/kb/entries`. | |
| **Tried & Failed:** | |
| - (No failed attempts β this was a diagnostic puzzle, not a crash) | |
| **Solution:** Updated `kb_client_fixture` in `conftest.py` to use `test_app.include_router(knowledge_base.router, prefix="/api/v1")` and updated all KB test URLs from `/kb/entries` to `/api/v1/kb/entries`. | |
| **Learned:** Test fixtures create their own mini `FastAPI()` app β completely independent of the real `app` in `main.py`. The fixture was including `knowledge_base.router` without a prefix, so its routes were at `/kb/entries`. The tests called `/kb/entries` and matched. Changing `main.py`'s prefix has zero effect on fixture paths. When doing API versioning, the fixture must be updated separately to reflect the new prefix β otherwise tests pass for the wrong reason (wrong URL, wrong isolation). | |
| --- | |
| ## Frontend Build | |
| ### Editing `useChat.js` had no effect β browser still showing old behavior | |
| **Date:** 2026-03-19 | |
| **Context:** `frontend-widget/src/hooks/useChat.js` β updating API URL from `/chat` to `/api/v1/chat` | |
| **Tags:** `vite` `bundle` `npm-run-build` `source-vs-bundle` `frontend` `cache` | |
| **Error:** Updated `useChat.js` line 51 to use `${cfg.API_URL}/api/${cfg.API_VERSION}/chat`. Hard-reloaded the browser and tested from incognito β still getting the old URL in the request. | |
| **Tried & Failed:** | |
| - Hard reload (`Ctrl+Shift+R`) β browser still loaded old bundle | |
| - Opened incognito window β still old behavior; confirmed not a browser cache issue | |
| - Restarted frontend Docker container β still old behavior | |
| **Solution:** Ran `npm run build` from `frontend-widget/` directory. Vite bundled the updated source into `frontend/chatbot-widget.js`. Browser loaded the new bundle on next request. | |
| **Learned:** Source files in `src/` are never served to the browser β they are input for Vite. The browser only loads the compiled bundle (`chatbot-widget.js`). Editing source without running `npm run build` leaves the bundle unchanged. The full sequence when changing frontend source: (1) edit `src/`, (2) `cd frontend-widget && npm run build`, (3) hard reload browser. Because `frontend/` is bind-mounted into the backend container, the new bundle is visible immediately β no Docker restart needed after the build. | |
| --- | |
| ## Database (SQLAlchemy / Alembic) | |
| ### `tenant_id` accepted in method signature but never assigned to ORM object β query returns None | |
| **Date:** 2026-03-27 | |
| **Context:** `app/models/conversation_manager.py` β `get_or_create_user()` and `create_conversation()` β Step 5 of Task A (Conversations API) | |
| **Tags:** `sqlalchemy` `orm` `tenant_id` `nullable` `unit-test` | |
| **Error:** Test asserted `retrieved_conversation.tenant_id == tenant_id` but got `AttributeError: 'NoneType' object has no attribute 'tenant_id'`. Logs confirmed the conversation *was* saved (`Conversation saved for session ...`), so the insert ran β but the query `WHERE tenant_id == tenant_id` returned nothing. | |
| **Tried & Failed:** | |
| - Suspected mock wiring was wrong β re-checked the patch target and `.return_value` chain; both were correct | |
| - Checked if `save_conversation` was forwarding `tenant_id` to its internal calls β it was | |
| **Solution:** Read `get_or_create_user` (line 36) and `create_conversation` (line 94) β both accepted `tenant_id` as a parameter but never assigned it to the ORM object: | |
| ```python | |
| # Bug | |
| user = User(session_id=session_id) | |
| conversation = Conversation(user_id=user.id) | |
| # Fix | |
| user = User(session_id=session_id, tenant_id=tenant_id) | |
| conversation = Conversation(user_id=user.id, tenant_id=tenant_id) | |
| ``` | |
| **Learned:** A parameter in a method signature does nothing unless explicitly assigned to the ORM object. SQLAlchemy columns with `nullable=True` silently accept `NULL` β the insert succeeds but the column stays `NULL`, so `WHERE tenant_id = X` returns nothing. Also caught that `Mapped[Optional[uuid.UUID]]` + `nullable=True` was wrong on both `User` and `Conversation` β fixed to `Mapped[uuid.UUID]` + `nullable=False` to enforce the constraint at the DB level. | |
| ### Unapplied Alembic migration β `tenants.customization` column missing β 500 on all KB API calls | |
| **Date:** 2026-03-25 | |
| **Context:** `smart_chatbot` backend β `app/middleware/tenant_auth.py`, triggered by admin console `GET /api/v1/kb/entries` | |
| **Tags:** `alembic` `migration` `500` `UndefinedColumn` `tenants` `customization` `stamp` | |
| **Error:** Admin console Knowledge Base page showed "Failed to load entries. Is the backend running?" β backend returned HTTP 500 with: | |
| ``` | |
| psycopg2.errors.UndefinedColumn: column tenants.customization does not exist | |
| SELECT tenants.id, ..., tenants.customization FROM tenants WHERE tenants.api_key = ... | |
| ``` | |
| **Tried & Failed:** | |
| - Checked `.env.local` for wrong `NEXT_PUBLIC_API_BASE_URL` or missing API key β config was correct, not the issue | |
| - Ran `alembic current` inside the container β returned **empty output** (no revision hash), which looked like a full data loss but was actually just a missing stamp | |
| **Solution:** | |
| 1. Identified migration `f6988c25696e_add_customization_to_tenants.py` existed but was never applied | |
| 2. Stamped the DB at the revision just before it: `alembic stamp 5f697ba37cb7` | |
| 3. Applied the missing migration: `alembic upgrade head` | |
| **Learned:** When `alembic current` returns empty but tables already exist, the DB was created outside Alembic (e.g. via raw SQL or a previous init script) β it has no `alembic_version` row. Running `alembic upgrade head` directly from this state would attempt to apply **all** migrations from `<base>`, likely failing on `CREATE TABLE` conflicts. Always **stamp first at the known current revision**, then upgrade. Identify the correct stamp revision by checking what columns/tables exist vs what each migration adds. | |
| ### `UserPreference` not in SQLAlchemy mapper registry β worker container crashes on startup | |
| **Date:** 2026-04-08 | |
| **Context:** `app/workers/summarization_worker.py` β `summarization_worker_dev` container; `User` model in `app/models/database.py` | |
| **Tags:** `sqlalchemy` `TYPE_CHECKING` `mapper-registry` `worker` `relationship` `smart_models` | |
| **Error:** `summarization_worker_dev` showed `Exited (1)` in `docker ps -a`. Container logs contained: | |
| ``` | |
| sqlalchemy.exc.InvalidRequestError: When initializing mapper Mapper[User(users)], | |
| expression 'UserPreference' failed to locate a name ('UserPreference'). | |
| If this is a class name, consider adding this relationship() to the <class | |
| 'app.models.database.User'> class after both dependent classes have been defined. | |
| ``` | |
| **Tried & Failed:** | |
| - (diagnosed in one sequential pass β no failed approaches; root cause identified directly from traceback + import inspection) | |
| **Solution:** Added one import line at the top of `summarization_worker.py`: | |
| ```python | |
| import app.models.smart_models # noqa: F401 β registers UserPreference and related ORM classes | |
| ``` | |
| This forces `UserPreference`, `UserInsight`, and `ConversationTopic` to register with SQLAlchemy's mapper registry before any query runs. Because `docker-compose.dev.yml` mounts `./app:/project/app` as a volume, the fix was live without a service rebuild β just a restart. | |
| **Learned:** SQLAlchemy resolves string relationship names (e.g. `relationship("UserPreference", ...)`) by looking in its **mapper registry** β a global dict of all ORM classes imported at runtime. A class imported only under `TYPE_CHECKING` is **invisible at runtime** (that guard exists solely for static analysis tools like mypy). Any entrypoint β worker, CLI script, test runner β that doesn't transitively import every ORM class referenced in a string relationship will crash on first query. Rule: every entrypoint must import all ORM modules, even if it doesn't use them directly. | |
| --- | |
| ## FastAPI Testing | |
| ### httpx 0.28.x drops cookies per-request in TestClient β auth tests return 401 | |
| **Date:** 2026-04-19 | |
| **Context:** `tests/test_admin_jwt_middleware.py` β `require_admin_jwt` dependency reads `request.cookies` | |
| **Tags:** `httpx` `testclient` `cookies` `jwt` `401` `starlette` `pytest` | |
| **Error:** All auth-related tests returned 401 after migrating from `Authorization: Bearer` header to HttpOnly cookie. The JWT middleware read `request.cookies["access_token"]` but the cookie never arrived on the server side (`cookies={}` confirmed via debug print). | |
| **Tried & Failed:** | |
| - `headers={"Cookie": f"access_token={token}"}` β `cookies={}` on server | |
| - `client.cookies.set("access_token", token)` β `cookies={}` on server | |
| - `client.cookies.set("access_token", token, domain="testserver")` β `cookies={}` on server | |
| **Solution:** Pass cookies at `TestClient` construction time β the only method httpx 0.28.x reliably delivers: | |
| ```python | |
| client = TestClient(jwt_app, cookies={"access_token": token}, raise_server_exceptions=False) | |
| response = client.get("/protected") | |
| ``` | |
| Each test constructs its own `TestClient` with the appropriate token; fixture returns the `app` object, not a shared client. | |
| **Learned:** In httpx 0.28.x, the cookie jar applies domain filtering for `testserver` and silently drops cookies set via `headers=`, `client.cookies.set()`, or `cookies=` per-request kwargs. The only escape is the `cookies` parameter at `TestClient(app, cookies={...})` construction β that bypasses the domain filter. Restructure auth test fixtures to return the app, not a shared client, so each test can inject its own token at construction time. | |
| --- | |
| ## Docker & Environment | |
| ### `./tests` not mounted as Docker volume β container runs stale image-baked test files | |
| **Date:** 2026-04-19 | |
| **Context:** `docker-compose.dev.yml` β `smart-chatbot` service; `tests/` directory | |
| **Tags:** `docker` `volume-mount` `stale-tests` `pytest` `false-failures` | |
| **Error:** 43 tests failed after HttpOnly cookie migration even though the test files on the host had already been fixed in previous sessions. Debug prints confirmed the middleware logic was correct. | |
| **Tried & Failed:** | |
| - Rewrote `test_admin_jwt_middleware.py` cookie delivery logic multiple times β each approach confirmed working in isolation but the container still ran old behavior | |
| - Multiple web searches and cookie-passing strategies attempted before discovering the real cause | |
| **Solution:** Added `./tests:/project/tests` bind mount to `docker-compose.dev.yml`: | |
| ```yaml | |
| volumes: | |
| - ./app:/project/app | |
| - ./tests:/project/tests # β was missing | |
| ``` | |
| After container restart, the container picked up the already-fixed host test files and all tests passed. | |
| **Learned:** Without a volume mount for `./tests`, `docker build` bakes the test files into the image at build time β any subsequent edits on the host are invisible to the running container. Whenever a service has a bind-mounted source directory, every directory you actively edit must also be mounted. Symptom: many tests fail simultaneously after a rebuild even though the fix looks correct on disk. | |
| --- | |
| ## FastAPI Testing | |
| ### Admin endpoint tests return 401 β TenantAuthMiddleware blocking before JWT dependency runs | |
| **Date:** 2026-04-24 | |
| **Context:** `tests/test_admin_go_live.py`, `app/middleware/tenant_auth.py` β PATCH /api/v1/admin/go-live | |
| **Tags:** `middleware` `tenant-auth` `jwt` `401` `testclient` `cookies` `admin` | |
| **Error:** All authenticated tests for `PATCH /api/v1/admin/go-live` returned 401 even with a correctly signed JWT. The unauthorized test (no token) also returned 401 β same code β masking the real failure mode. | |
| **Tried & Failed:** | |
| - `cookies={"access_token": token}` per-request kwarg β 401 (deprecated Starlette API, unreliable) | |
| - `headers={"Cookie": f"access_token={token}"}` β 401 (httpx 0.28.x drops per-request cookie headers) | |
| - `client.cookies.set("access_token", token)` β 401 (still blocked β the cookie WAS being set but the request never reached `require_admin_jwt`) | |
| **Solution:** `TenantAuthMiddleware` excluded only `/admin/auth` from API-key enforcement; `/admin/go-live` fell through to the "Missing API key β 401" branch before the JWT dependency ever ran. Fixed by broadening the exclusion to `/admin` (all admin routes use JWT). Cookie pattern `client.cookies.set()` on the fixture client was already correct β it only appeared broken because of the middleware block. | |
| **Learned:** When an endpoint with JWT auth returns 401, check global middleware first β not just the dependency. If `TenantAuthMiddleware` (or any `BaseHTTPMiddleware`) runs before FastAPI's dependency injection and rejects the request, the endpoint dependency never executes and the 401 comes from the middleware, not the JWT check. Symptom: the unauthorized test and the authorized test return identical 401 responses with the same body. Correct cookie pattern for admin tests using the `client` fixture: `client.cookies.set("access_token", token)` before the call (not per-request kwargs, not `headers={"Cookie": ...}`). | |
| --- | |
| ## FastAPI Testing | |
| ### JWT auth passes but endpoint returns 404 β `TestClient(app)` bypasses `get_db` dependency override | |
| **Date:** 2026-04-24 | |
| **Context:** `tests/test_billing_summary.py` β GET /api/v1/billing/summary | |
| **Tags:** `testclient` `get_db` `dependency-override` `404` `sqlite` `fixtures` `client` | |
| **Error:** After fixing cookie delivery (JWT auth now passing, 401 gone), the authenticated test returned 404. Tenant had been created via `make_tenant(session, ...)` in the test body, but the router couldn't find it. | |
| **Tried & Failed:** | |
| - `TestClient(app, cookies={"access_token": token})` (standalone, no fixture) β 404; tenant exists in SQLite test session but router queries PostgreSQL dev DB where it doesn't exist | |
| - `client.cookies.set()` on a manually constructed `TestClient(app)` β same 404; the problem is not cookie delivery, it's the missing DB override | |
| **Solution:** Use the `client` fixture (defined in `conftest.py`), which calls `app.dependency_overrides[get_db] = lambda: session` before yielding the `TestClient`. Set the cookie on the fixture client: | |
| ```python | |
| def test_get_billing_summary(session, client: TestClient): | |
| tenant = make_tenant(session, ...) | |
| client.cookies.set("access_token", make_admin_token(tenant.id)) | |
| response = client.get("/api/v1/billing/summary") | |
| ``` | |
| ### Live Docker config drifted from hardcoded model fixture β new billing preflight returned 500 | |
| **Date:** 2026-05-19 | |
| **Context:** `tests/test_chat_billing_wiring.py`, low-balance preflight guard task, Docker test container config | |
| **Tags:** `docker-config` `test-fixture` `billing` `llm-model-rates` `phase3` | |
| **Error:** After adding the low-balance preflight reserve lookup, the `/chat` billing integration tests started returning HTTP 500 on the credits path even though the new `CreditService` helper tests passed. The endpoint was failing only inside Docker. | |
| **Tried & Failed:** | |
| - Investigated the new pricing math first by running `tests/test_credit_service.py` in isolation β it passed, so the bug was not in the reserve calculation itself. | |
| - Reran a single `/chat` billing test with full pytest output expecting a traceback from the endpoint logic β the endpoint still returned only a generic 500 because `chat()` swallows unexpected exceptions into `HTTPException(500)`. | |
| **Solution:** Read the live container startup logs and compared them against the new test fixture. The Docker config still used `CHAT_MODEL_PRIMARY=gemini/gemini-2.0-flash`, while the fixture hardcoded `gemini-2.5-flash`. The new reserve lookup was correct to fail because the configured primary had no seeded pricing row. Fixed the test helper by seeding pricing rows from `config.chat_model_primary` and `config.chat_model_fallbacks` instead of hardcoded model refs. | |
| **Learned:** When a new config-driven guard suddenly breaks only Docker integration tests, verify the live container config before blaming the business logic. Hardcoded fixtures become stale the moment runtime config changes; config-coupled tests should derive seeded dependencies from the same config object the app is using. | |
| **Learned:** Any test that seeds data via the `session` fixture must use the `client` fixture β never construct `TestClient(app)` manually. The `client` fixture is the only thing that wires `app.dependency_overrides[get_db]` to the test's in-memory SQLite session. Without it, `get_db` resolves to the real PostgreSQL session, where test-seeded rows don't exist. Distinguishing symptom: 401 gone (JWT works), but 404 on the resource β the DB override, not cookie delivery, is missing. | |
| --- | |
| ## Database (SQLAlchemy / Alembic) | |
| ### Alembic autogenerate produces empty migration for new `CheckConstraint` | |
| **Date:** 2026-04-24 | |
| **Context:** `alembic/versions/9b95a5ce2ac1` β `feat/billing-mode-gifted`; `CheckConstraint` added to `Tenant.__table_args__` in `app/models/database.py` | |
| **Tags:** `alembic` `autogenerate` `CheckConstraint` `empty-migration` `table_args` | |
| **Error:** Ran `alembic revision --autogenerate -m "add gifted billing mode check constraint"`. Generated file had empty `upgrade()` and `downgrade()` β just `pass`. The new `CheckConstraint("billing_mode IN ('credits', 'subscription', 'gifted')", name="chk_tenant_billing_mode")` in `Tenant.__table_args__` was not detected. | |
| **Tried & Failed:** | |
| - (single attempt β autogenerate ran without errors but silently skipped the constraint) | |
| **Solution:** Manually filled in the generated file: | |
| ```python | |
| def upgrade() -> None: | |
| op.create_check_constraint( | |
| "ck_tenants_chk_tenant_billing_mode", | |
| "tenants", | |
| "billing_mode IN ('credits', 'subscription', 'gifted')", | |
| ) | |
| def downgrade() -> None: | |
| op.drop_constraint("ck_tenants_chk_tenant_billing_mode", "tenants", type_="check") | |
| ``` | |
| Constraint name uses the project's naming convention: `ck_%(table_name)s_%(constraint_name)s` β `ck_tenants_chk_tenant_billing_mode`. | |
| **Learned:** Alembic's autogenerate does **not** detect `CheckConstraint` additions or removals by default β it only diffs tables, columns, indexes, foreign keys, and unique constraints. When you add a `CheckConstraint` to `__table_args__`, autogenerate will always produce an empty migration. The correct workflow: (1) let autogenerate create the file, (2) manually add `op.create_check_constraint()` in `upgrade()` and `op.drop_constraint()` in `downgrade()`. Editing the generated file is allowed β creating one from scratch is not. | |
| --- | |
| ## FastAPI Testing | |
| ### Schema field addition silently breaks test via 422 β NoneType AttributeError | |
| **Date:** 2026-04-24 | |
| **Context:** `tests/test_kb_vector_store_wiring.py::test_kb_vector_store_wiring_add` β `feat/kb-schema-upgrade`; `KBEntryCreate` schema had `title` and `category` added as required fields | |
| **Tags:** `pydantic` `422` `schema` `NoneType` `test` `required-fields` | |
| **Error:** `AttributeError: 'NoneType' object has no attribute 'tenant_id'` at `kb_entry = session.scalars(...).first()` β the error pointed to `kb_entry.tenant_id` on the assertion line, not to the POST call. | |
| **Tried & Failed:** | |
| - (single-step diagnosis β traceback pointed to the wrong line) | |
| **Solution:** The POST body was `{"entry": mock_entry}`, missing the newly-required `title` and `category` fields. FastAPI returned 422 (validation error), the entry was never saved to the DB, and `session.scalars(...).first()` returned `None`. The test then crashed on `None.tenant_id` β a red herring. Fix: add `"title": "Test Entry", "category": "General"` to the POST body. | |
| **Learned:** When a Pydantic schema gains a new required field, existing tests that POST without it will receive a 422 silently β the test doesn't assert `response.status_code`, so the failure propagates downstream as a `NoneType` error on a DB query that returns nothing. Rule: when adding required fields to a schema, grep all test files for POST/PUT calls to that endpoint and verify the body includes every required field. | |
| --- | |
| ## Authentication | |
| ### TOTP verify always returns "Invalid code" β pyotp default `valid_window=0` rejects codes at window boundary | |
| **Date:** 2026-04-26 | |
| **Context:** `app/services/totp_service.py::verify_totp_code` β POST `/api/v1/admin/auth/totp/verify` | |
| **Tags:** `totp` `pyotp` `valid_window` `clock-drift` `2fa` `authentication` | |
| **Error:** Admin console TOTP step always showed "Invalid code. Try again or use a backup code." even when the 6-digit code was visually correct at time of entry. Docker container and host clocks were both confirmed at UTC β no clock skew. | |
| **Tried & Failed:** | |
| - Verified host and container clocks were in sync (`date` on both) β no drift found | |
| - Assumed user error (entering code after expiry) β error persisted across multiple attempts | |
| **Solution:** `pyotp.TOTP.verify()` defaults to `valid_window=0`, accepting only the code for the exact current 30-second window. A code entered near the end of a window (or with any human latency) falls into the next window and is rejected. Fix: pass `valid_window=1` to accept Β±1 window (Β±30 seconds): | |
| ```python | |
| # Before | |
| return pyotp.TOTP(raw_secret).verify(code) | |
| # After | |
| return pyotp.TOTP(raw_secret).verify(code, valid_window=1) | |
| ``` | |
| All 14 TOTP tests pass after the change β wrong codes are still rejected. | |
| **Learned:** `pyotp.verify()` with `valid_window=0` is too strict for real-world use. The TOTP spec (RFC 6238) recommends allowing Β±1 window to account for human latency and minor device drift. `valid_window=1` is the standard production setting β it does not weaken security against brute force (the 6-digit space is unchanged). Always set `valid_window=1` for any TOTP verification in production. | |
| --- | |
| ## Docker & Environment | |
| ### TOTP verify POST returns 500 β `FERNET_KEY` missing from `docker-compose.dev.yml` environment block | |
| **Date:** 2026-04-26 | |
| **Context:** `docker-compose.dev.yml` backend service env block β POST `/api/v1/admin/auth/totp/verify` | |
| **Tags:** `docker-compose` `env-vars` `fernet` `500` `totp` `missing-env` | |
| **Error:** After confirming `valid_window=1` was applied, TOTP verify still returned 500. FastAPI logs showed an unhandled exception (not a 401), with ~5s response time consistent with a Fernet decryption crash. | |
| **Tried & Failed:** | |
| - Checked `app/services/totp_service.py` for logic errors β code looked correct | |
| - Suspected JWT decode failure β `JWT_SECRET_KEY` was present in container | |
| **Solution:** `FERNET_KEY` was defined in `.env` and in `.env.example`, but was never added to the `environment:` block of the backend service in `docker-compose.dev.yml`. The container received `""` (empty string default from `os.getenv`), causing `Fernet("".encode())` to throw `ValueError` β an unhandled exception β 500. Fix: add `FERNET_KEY: ${FERNET_KEY}` to `docker-compose.dev.yml`. | |
| **Learned:** `.env` is not automatically passed into Docker containers β every key needed at runtime must be explicitly declared in `docker-compose.yml` under `environment:`. Pattern: `KEY: ${KEY}` (reads from host `.env` via Docker Compose variable substitution). After any auth feature that introduces a new secret (JWT key, Fernet key, OAuth client ID), immediately add it to `docker-compose.dev.yml` and verify with `docker exec <container> printenv KEY`. Three auth vars were added late in this project: `GOOGLE_CLIENT_ID`, `JWT_SECRET_KEY`, `FERNET_KEY`. | |
| --- | |
| ### 502 Bad Gateway immediately after `make restart-be` β uvicorn not accepting connections during 52-second embedding model load | |
| **Date:** 2026-04-26 | |
| **Context:** `docker-compose.dev.yml` backend service β nginx-proxy upstream; application startup | |
| **Tags:** `502` `nginx-proxy` `startup` `embedding-model` `uvicorn` `timing` | |
| **Error:** All backend API calls returned 502 Bad Gateway immediately after restarting the backend container. nginx-proxy logs showed `connect() failed (111: Connection refused)` to the backend's IP:8000. | |
| **Tried & Failed:** | |
| - Suspected nginx-proxy lost the backend's IP after restart β container IP was unchanged | |
| - Suspected env var issue β all required vars were confirmed present | |
| **Solution:** No code change needed. The embedding model (`sentence-transformers`) takes ~52 seconds to load during the lifespan startup event. uvicorn does not begin accepting connections until `Application startup complete.` is logged. Any requests during that window receive a connection refused β 502 from nginx-proxy. Waiting ~60 seconds after restart resolves it. | |
| **Learned:** FastAPI lifespan startup events block uvicorn from accepting connections until they complete. Heavy model loading (embedding models, ML weights) during startup creates a long window where the container is `Up` in Docker but not yet serving. Do not hit the backend immediately after `make restart-be` β wait for `Application startup complete.` in `docker logs <container> --tail 5`. Long-term fix: move embedding model loading to a lazy-load pattern (load on first request) to reduce cold-start time. | |
| --- | |
| ### Backend 502 after Qdrant migration β stale Docker image plus HuggingFace Xet startup stall | |
| **Date:** 2026-05-01 | |
| **Context:** `smart-chatbot:dev` image, `docker-compose.dev.yml`, `app/services/qdrant_vector_store.py`, FastAPI lifespan embedding warmup | |
| **Tags:** `docker` `qdrant-client` `stale-image` `huggingface` `xet` `502` `startup` | |
| **Error:** Admin console calls to `/api/v1/admin/me`, `/api/v1/conversations`, and `/api/v1/billing/summary` returned nginx `502 Bad Gateway`. Backend logs first showed: | |
| ```text | |
| ModuleNotFoundError: No module named 'qdrant_client' | |
| ``` | |
| After that import was repaired, the backend still stayed in `Waiting for application startup` and nginx kept returning 502 until startup finished. | |
| **Tried & Failed:** | |
| - Checked `pyproject.toml` and `uv.lock` β `qdrant-client` was already declared, so the source dependency manifest was not the problem. | |
| - Started a full Docker rebuild β canceled after more than 30 minutes because the dependency layer was downloading the large ML/CUDA stack. | |
| - Synced `qdrant-client==1.17.1` into the running app image/container β fixed the import, but the backend still did not accept connections because startup hung during embedding warmup. | |
| **Solution:** Repaired the local dev runtime by syncing `qdrant-client==1.17.1` into the stale `smart-chatbot:dev` image/container. Then identified the second blocker by running a standalone `SentenceTransformer("BAAI/bge-small-en-v1.5")` load: it stalled in HuggingFace Hub's Xet transfer path. Added `HF_HUB_DISABLE_XET=1` to `Dockerfile`, dev/prod Compose services, `.env.example`, and the environment files. Recreated the backend container, verified `Application startup complete`, and confirmed `/api/v1/admin/me` returned `401 Unauthorized` instead of nginx `502`. | |
| **Learned:** A correct `pyproject.toml`/`uv.lock` does not update an already-built Docker image; if an import fails inside a container, verify the actual container environment, not just the source manifest. Also, fixing the first startup exception does not mean the service is ready β check for `Application startup complete` and an open port. HuggingFace Hub's Xet transfer path can stall SentenceTransformer startup in containers; `HF_HUB_DISABLE_XET=1` is a practical Docker runtime guard. | |
| --- | |
| ## Database (SQLAlchemy / Alembic) | |
| ### KB entries 500 after schema redesign β Alembic behind app code and `sync_jobs` pre-created by startup | |
| **Date:** 2026-05-01 | |
| **Context:** `GET /api/v1/kb/entries`, `alembic/versions/a53f4c8d9b21_kb_schema_redesign_and_sync_jobs.py`, local PostgreSQL | |
| **Tags:** `alembic` `migration` `UndefinedColumn` `create_all` `sync_jobs` `knowledge_base` `500` | |
| **Error:** Admin console showed repeated `GET /api/v1/kb/entries 500`. Backend traceback showed: | |
| ```text | |
| sqlalchemy.exc.ProgrammingError: (psycopg2.errors.UndefinedColumn) | |
| column knowledge_base.content does not exist | |
| ``` | |
| The app queried the redesigned schema (`content`, `source_url`, `origin`), but local PostgreSQL still had the old schema (`entry`, `category`, `tag`). | |
| **Tried & Failed:** | |
| - Reproduced through the admin-console proxy without a session and got `401`, which did not hit the failing authenticated query path. | |
| - Checked backend logs and found the real authenticated traceback from the admin console. | |
| - Ran `alembic upgrade head` β it failed because `sync_jobs` already existed, created earlier by `Base.metadata.create_all()` during startup even though the Alembic revision had not been applied. | |
| **Solution:** Patched migration `a53f4c8d9b21` to inspect the database and skip `op.create_table("sync_jobs")` if the table already exists. Then ran `alembic upgrade head` successfully. Verified `alembic current` returned `a53f4c8d9b21 (head)`, `knowledge_base` had `content/source_url/origin`, and authenticated `GET /api/v1/kb/entries` returned `200 OK`. | |
| **Learned:** Mixing `Base.metadata.create_all()` with Alembic can create a partial schema state: new tables may exist while old tables still need migrations. In that state, `alembic upgrade head` can fail on duplicate tables even though the real missing piece is an altered column on an existing table. For local/dev migrations, either avoid startup `create_all()` after Alembic is adopted or make migrations tolerate pre-created additive tables when the project already has that startup behavior. | |
| --- | |
| ## FastAPI Testing | |
| ### DELETE /kb/entries 500 after Qdrant migration β MagicMock masked missing contract method | |
| **Date:** 2026-05-02 | |
| **Context:** `app/routers/knowledge_base.py::delete_entry`, `app/services/qdrant_vector_store.py`, `tests/test_delete_entry.py` | |
| **Tags:** `MagicMock` `VectorStore` `Qdrant` `delete` `delete_docs` `contract` `500` `AttributeError` | |
| **Error:** Smoke test reported `DELETE /api/v1/kb/entries/{id}` returning `500 Internal Server Error` for synced KB entries after the Qdrant migration (2026-05-01). Manual entries described as "deleting fine." | |
| **Tried & Failed:** | |
| - Suspected FK cascade constraint on `sync_jobs` (synced entries have `origin='synced'`) β DB query for FK constraints showed only `tenant_id` FKs; no FK between `knowledge_base` and `sync_jobs`. Dead end. | |
| - Checked if `QdrantVectorStore` inherited from the ChromaDB `VectorStore` class (which has a `delete` convenience wrapper) β no, it is a standalone class with no inheritance. | |
| **Solution:** `VectorStoreContract` (the Protocol both adapters implement) declares `delete_docs(tenant_id, entry_ids)` but NOT `delete(tenant_id, entry_id)`. The old ChromaDB `VectorStore` had a `delete` convenience wrapper; `QdrantVectorStore` never added it. The router called `vector_store.delete(...)` β which raises `AttributeError` at runtime on Qdrant but silently passes in tests because `conftest.py` injects a `MagicMock()`, which auto-creates any attribute called on it. Fix: changed router to call `vector_store.delete_docs(tenant_id=..., entry_ids=[...])` (the contract method). Also updated test assertions to assert `delete_docs` was called rather than relying on `MagicMock` accepting anything. Note: the "manual entries fine" claim in the smoke test was inaccurate β all deletes failed; only synced entries were tested in that session. | |
| **Learned:** `MagicMock()` will silently accept ANY method call, including calls to methods that don't exist on the real implementation. When tests inject `MagicMock` as a dependency, they cannot catch "method doesn't exist on the real adapter" bugs. Rule: mock assertions must assert the exact contract method name (`delete_docs`, not `delete`), not just that *something* was called. When adding a new adapter (e.g. Qdrant replacing ChromaDB), audit every mock assertion in the test suite to ensure it calls a method that actually exists on the new adapter. | |
| ### Second chat turn 500 β hierarchical history used the wrong message schema | |
| **Date:** 2026-05-07 | |
| **Context:** `app/models/conversation_manager.py::get_response`, `app/models/conversation_manager.py::build_hierarchical_context`, `app/utils/token_counter.py` | |
| **Tags:** `conversation_history` `KeyError` `role/content` `count_tokens` `500` `hierarchical_context` | |
| **Error:** The first chat turn worked, but the second turn always returned `Error: HTTP 500: Internal Server Error`. Backend logs showed: | |
| ```text | |
| KeyError: 'content' | |
| ``` | |
| The crash happened only after conversation history existed. | |
| **Tried & Failed:** | |
| - Checked the frontend widget and API key path first β the browser was reaching the backend, so the failure was not the embed script. | |
| - Investigated auth, credits, and LLM billing state β those were separate earlier blockers, but this request reached the chat handler and then failed inside history assembly. | |
| - Inspected the token counter β it expected `messages[*]["content"]`, but the hierarchical history builder was returning raw `{user_input, bot_response}` objects. | |
| **Solution:** Changed `build_hierarchical_context()` to convert verbatim history into OpenAI-style `{"role": "...", "content": "..."}` messages before returning it. Updated the hierarchical context regression test to assert the new shape. Verified the second turn with a real two-turn chat: both requests now return `200 OK`. | |
| **Learned:** Every helper in the chat pipeline has to agree on one message schema. Raw conversation records (`user_input` / `bot_response`) are fine for storage and summarization, but anything that flows into token counting or LLM calls must be normalized to `role` / `content` first. A second-turn-only crash usually means the history path, not the initial request path, is broken. | |
| ## Chat Billing | |
| ### Local chat `Failed to fetch` β demo tenant mapping and billing lookup both had to be fixed | |
| **Date:** 2026-05-07 | |
| **Context:** `frontend-smart-chatbot.local`, `frontend/config.js`, `app/middleware/tenant_auth.py`, `app/main.py` billing path | |
| **Tags:** `failed-to-fetch` `tenant-auth` `billing` `credits` `llm-rate` `demo-key` | |
| **Error:** Sending a message from the local widget returned `Error: Failed to fetch` in the browser. | |
| **Tried & Failed:** | |
| - Checked the widget/embed path and local host setup first β the request was reaching the backend, so it was not a browser-only or routing-only issue. | |
| - Inspected tenant auth and credits next β the demo API key mapped to a tenant with zero credits, and the billing path still expected a `provider/model` rate key even when LiteLLM returned a bare model name. | |
| **Solution:** Added a development-only demo-key fallback in tenant auth, accepted bare model names in the billing rate lookup, and topped up/reactivated the demo tenant so the chat path could return a normal response again. | |
| **Learned:** A browser `Failed to fetch` can hide a backend 402/500 chain. Always verify tenant mapping, credits, and model-rate normalization before assuming the frontend is broken. | |
| ## Vector Store / Retrieval | |
| ### KB row missing from Qdrant after Chroma migration β SQL existed but retrieval index did not | |
| **Date:** 2026-05-07 | |
| **Context:** `app/routers/knowledge_base.py`, `app/services/qdrant_vector_store.py`, tenant Qdrant collection | |
| **Tags:** `qdrant` `chroma-migration` `missing-index` `retrieval` `kb-sync` | |
| **Error:** The chatbot answered that it could not find a KB fact even though the row existed in PostgreSQL. Qdrant queries for the tenant returned unrelated documents and did not return the missing entry. | |
| **Tried & Failed:** | |
| - Tried prompt-level RAG tuning first β it did not help because the KB row was not present in the vector index. | |
| - Verified the SQL row existed and queried the tenant collection directly β the entry was still absent from Qdrant. | |
| **Solution:** Rebuild the tenant index / resync the entry so the PostgreSQL KB row is written into Qdrant again. The backend already has `scripts/rebuild_tenant_index.py`; the missing piece is exposing that repair flow in the admin console. | |
| **Learned:** After a vector DB migration, SQL and the vector index can diverge. The UI needs to surface unsynced KB rows and provide an explicit repair path. | |
| ## Frontend Integration | |
| ### Widget used the demo tenant instead of Monireach β admin changes did not affect chat | |
| **Date:** 2026-05-07 | |
| **Context:** `frontend/config.js`, `frontend-widget/src/hooks/useChat.js`, `app/routers/widget_settings.py`, admin console Persona / Behavior settings | |
| **Tags:** `tenant-mismatch` `widget-config` `Alita` `greeting` `demo-key` | |
| **Error:** The chatbot greeted users generically and did not reflect the `Alita` name, greeting, or behavior rules configured in the admin console. | |
| **Tried & Failed:** | |
| - Changed the Persona and Behavior settings in the admin console alone β there was no visible change because the widget was still configured with the demo tenant key. | |
| - Checked the widget runtime settings path β it was resolving tenant data for the wrong tenant. | |
| **Solution:** Point the local widget at the Monireach tenant key and fetch bot name/greeting from backend widget settings so the widget and admin console target the same tenant. | |
| **Learned:** Admin-console changes only show up when the widget and the admin session resolve to the same tenant. Hardcoded tenant keys create false negatives during demos. | |
| ## Docker & Environment | |
| ### 502 on all API routes caused by missing env var in container environment block | |
| **Date:** 2026-05-26 | |
| **Context:** `docker-compose.dev.yml`, backend service startup, `app/main.py` lifespan | |
| **Tags:** `docker` `environment-block` `502` `startup-crash` `gemini-embedding` `env-var` | |
| **Error:** All admin routes (`GET /api/v1/admin/me`, `POST /api/v1/admin/auth/google`) returned 502. The `.env` file contained `GEMINI_EMBEDDING_API_KEY` but the backend was crashing on startup. | |
| **Tried & Failed:** | |
| - Assumed the 502 was a network/nginx routing issue β it was not; the backend container was starting and immediately crashing. | |
| **Solution:** Added `GEMINI_EMBEDDING_API_KEY: ${GEMINI_EMBEDDING_API_KEY}` to the `environment:` block of the backend service in both `docker-compose.dev.yml` and `docker-compose.prod.yml`. Also added `EMBEDDING_MODEL: ${EMBEDDING_MODEL}` which was only in the worker service block, not the backend block. | |
| **Learned:** Docker Compose does NOT automatically pass all `.env` vars to containers. Only vars explicitly listed under `environment:` in the service definition are injected. A var can exist in `.env` and be invisible to the container if it is not whitelisted. The symptom is a startup crash that manifests as 502 on all routes β check `docker logs <container>` first, not nginx. | |
| --- | |
| ### `docker compose restart` does not reload `.env` β env var change silently ignored | |
| **Date:** 2026-05-26 | |
| **Context:** `docker-compose.dev.yml`, `QDRANT_COLLECTION_NAME` cutover after Qdrant migration | |
| **Tags:** `docker` `restart` `env-var` `force-recreate` `qdrant` `cutover` | |
| **Error:** Updated `QDRANT_COLLECTION_NAME=smart_chatbot_kb_v2` in `.env`, then ran `docker compose restart smart-chatbot`. The container came back up still using `smart_chatbot_kb` (old value). `/health` still reported `qdrant: degraded`. | |
| **Tried & Failed:** | |
| - `docker compose -f docker-compose.dev.yml restart smart-chatbot` β container restarted with the old env var value because `restart` does not re-read `.env`. | |
| **Solution:** `docker compose -f docker-compose.dev.yml up -d --force-recreate smart-chatbot` β this destroys and recreates the container, re-reading `.env` in the process. | |
| **Learned:** `docker compose restart` only stops and starts the existing container β it does NOT re-read `.env` or update env vars. To pick up env var changes, use `up -d --force-recreate <service>`. Use `docker exec <container> printenv <VAR>` to verify the running container actually has the new value before assuming the change took effect. | |
| --- | |
| ### `ModuleNotFoundError: No module named 'app'` running script inside Docker with `uv run` | |
| **Date:** 2026-05-26 | |
| **Context:** `scripts/migrate_qdrant_collection.py`, `docker exec chatbot_backend_dev uv run python scripts/...` | |
| **Tags:** `docker` `uv` `pythonpath` `module-not-found` `scripts` `sys-path` | |
| **Error:** Running `docker exec chatbot_backend_dev uv run python scripts/migrate_qdrant_collection.py` failed with `ModuleNotFoundError: No module named 'app'`, even though the working directory was `/project` and `app/` exists there. | |
| **Tried & Failed:** | |
| - Added `-w /project` flag to `docker exec` β same error; `uv run` creates a subprocess where `/project` is not on `sys.path`. | |
| **Solution:** Pass `PYTHONPATH` explicitly: `docker exec -e PYTHONPATH=/project chatbot_backend_dev uv run python scripts/migrate_qdrant_collection.py`. | |
| **Learned:** `uv run` does not automatically add the current working directory to `sys.path` the way `python -m` does. When a script in `scripts/` needs to import from `app/`, the project root must be in `sys.path` explicitly via `PYTHONPATH`. The pytest suite works because pytest adds the project root to `sys.path` itself β scripts run directly do not get this treatment. | |
| --- | |
| ### Certbot ACME challenge: `Connection refused` β nginx/certbot chicken-and-egg on first deployment | |
| **Date:** 2026-06-03 | |
| **Context:** `scripts/init-letsencrypt.sh`, `docker-compose.prod.yml`, first production SSL setup | |
| **Tags:** `docker` `nginx` `certbot` `letsencrypt` `ssl` `chicken-and-egg` `production` | |
| **Error:** Running `make prod-certbot` failed with `Connection refused` when Let's Encrypt tried to fetch the challenge file at `http://chatbot.monireach.com/.well-known/acme-challenge/...`. The server IP was correct and DNS resolved fine. | |
| **Tried & Failed:** | |
| - Running `make prod-nginx` before `make prod-certbot` β nginx refused to start because the SSL cert files referenced in the 443 server block (`/etc/letsencrypt/live/${NGINX_DOMAIN}/fullchain.pem`) did not exist yet. Port 80 never opened because nginx itself crashed on startup. | |
| **Solution:** `scripts/init-letsencrypt.sh` β a bootstrap script that: (1) creates a temporary self-signed cert with openssl so nginx can load its config and start, (2) starts nginx (port 80 is now open), (3) runs certbot to obtain the real cert, (4) reloads nginx with the real cert. Triggered via `make prod-init`. | |
| **Learned:** nginx refuses to start if any file referenced in its config does not exist β including SSL cert paths in a server block that is not yet active. If the 443 block is in the config, the cert files must exist before nginx starts, even if HTTPS is not yet needed. The standard solution is a one-time bootstrap script that creates dummy certs first, then replaces them. | |
| --- | |
| ### `docker compose run --entrypoint "sh -c '...'"` silently fails β wrong entrypoint syntax | |
| **Date:** 2026-06-03 | |
| **Context:** `scripts/init-letsencrypt.sh`, Step 1 dummy cert creation | |
| **Tags:** `docker` `docker-compose` `entrypoint` `silent-failure` `shell` `init-script` | |
| **Error:** `init-letsencrypt.sh` printed "==> Temporary certificate created." but nginx still failed to start because no cert file existed in the volume. The dummy cert creation step appeared to succeed but produced nothing. | |
| **Tried & Failed:** | |
| - `docker compose run --rm --entrypoint "sh -c 'openssl ...'" certbot` β Docker interprets the entire string `sh -c 'openssl ...'` as a single executable name (not a shell command), tries to find a binary literally named `sh -c 'openssl ...'`, fails immediately, and exits non-zero β but because `set -e` only catches non-zero exit codes from the compose run wrapper (which itself may exit 0), the failure was silent. | |
| **Solution:** `docker compose run --rm --entrypoint sh certbot -c "openssl ..."` β `--entrypoint` takes only the executable (`sh`), and the command arguments (`-c "..."`) are passed separately after the service name. | |
| **Learned:** `docker compose run --entrypoint` accepts only the executable path, not a full shell command. `--entrypoint "sh -c 'cmd'"` does not invoke sh β it tries to find a binary with that exact string as its name. Always separate the entrypoint executable from its arguments: `--entrypoint sh service -c "command"`. | |
| --- | |
| ### nginx health check permanently unhealthy: wget follows 301 redirect to self-signed HTTPS cert | |
| **Date:** 2026-06-03 | |
| **Context:** `docker-compose.prod.yml` nginx healthcheck, production deployment | |
| **Tags:** `docker` `nginx` `healthcheck` `wget` `ssl` `redirect` `self-signed-cert` `production` | |
| **Error:** `container chatbot_nginx_prod is unhealthy` after every `make prod-init` attempt, even after nginx was confirmed running and all other services were healthy. The error persisted across multiple fix attempts over several hours. | |
| **Tried & Failed:** | |
| - Added `location /health { return 200; }` to port 80 nginx server block β did not resolve the issue (the block was not taking effect in the deployed template). | |
| - Fixed `--entrypoint` syntax in init script (separate bug, fixed separately) β nginx still unhealthy. | |
| **Root cause confirmed via:** `docker logs chatbot_nginx_prod` showed `GET /health HTTP/1.1 301` on every health check attempt. `docker inspect chatbot_nginx_prod --format '{{range .State.Health.Log}}{{.Output}}{{end}}'` showed `SSL routines: certificate verify failed` and `wget: error getting response: Connection reset by peer`. | |
| **Solution:** Changed health check from `wget --quiet --tries=1 --spider http://localhost:80/health` to `wget -q --tries=1 --no-check-certificate http://localhost:80/health -O /dev/null`. With `--no-check-certificate`, wget follows the 301 redirect to HTTPS, accepts the self-signed cert, reaches the backend `/health` endpoint (200), and exits 0. | |
| **Learned:** `wget --spider` follows redirects by default. A port 80 β HTTPS 301 redirect causes wget to attempt SSL verification, which fails against a self-signed bootstrap cert. Always check `docker inspect <container> --format '{{range .State.Health.Log}}{{.Output}}{{end}}'` to see the actual health check error output β `docker logs` only shows nginx access logs, not why the health check failed. For nginx health checks behind HTTPβHTTPS redirect, use `--no-check-certificate` so the check succeeds regardless of cert validity. | |
| --- | |
| ### certbot renewal container crash-loop: shell script treated as certbot config file path | |
| **Date:** 2026-06-04 | |
| **Context:** `docker-compose.prod.yml` certbot service, production deployment | |
| **Tags:** `docker` `docker-compose` `certbot` `entrypoint` `command` `crash-loop` `shell` | |
| **Error:** `chatbot_certbot_prod` kept restarting with exit code 2. Logs showed: `certbot: error: Unable to open config file: apk add --no-cache docker-cli -q && trap exit TERM; while :; do certbot renew...; done. Error: No such file or directory` | |
| **Tried & Failed:** | |
| - (could not solve independently β solved with AI assistance) | |
| **Solution:** Override the certbot service entrypoint in `docker-compose.prod.yml`: | |
| ```yaml | |
| entrypoint: ["/bin/sh", "-c"] | |
| command: ["apk add --no-cache docker-cli -q && trap exit TERM; while :; do certbot renew ..."] | |
| ``` | |
| **Learned:** The `certbot/certbot` Docker image sets `ENTRYPOINT ["certbot"]`. Writing `command: sh -c "..."` in docker-compose does NOT invoke a shell β it appends `sh`, `-c`, and the script string as arguments to the certbot binary. Certbot sees `-c` as its own config-file flag and treats the script as a file path, failing immediately. To run a shell script in a container whose entrypoint is a binary, always override `entrypoint` explicitly. | |
| --- | |
| ### ACME challenge 403: nginx template not re-rendered on reload + server-level return 301 | |
| **Date:** 2026-06-04 | |
| **Context:** `nginx/templates/default.conf.template`, `make prod-certbot`, Let's Encrypt webroot challenge | |
| **Tags:** `nginx` `certbot` `letsencrypt` `acme` `403` `envsubst` `template` `return-301` `location-priority` | |
| **Error:** `make prod-certbot` failed repeatedly with: `Invalid response from https://chatbot.monireach.com/.well-known/acme-challenge/...: 403`. Let's Encrypt was reaching HTTPS instead of HTTP, getting 403. | |
| **Tried & Failed:** | |
| - Confirmed `location /.well-known/acme-challenge/` was present in port 80 block β still 403 | |
| - Moved `return 301` from server level into `location /` β still 403 (fix was correct but never took effect) | |
| - Ran `make prod-nginx` (which does `nginx -s reload`) after each template change β still 403 | |
| **Solution:** Two fixes required together: | |
| 1. Changed `location /.well-known/acme-challenge/` to `location ^~ /.well-known/acme-challenge/` (explicit priority prefix) | |
| 2. Force-recreated the nginx container: `docker compose up -d --force-recreate nginx` | |
| **Learned:** Two independent root causes: (1) nginx uses `envsubst` to render templates into `conf.d/` **only on container start**, not on `nginx -s reload`. Every template fix was correct but never reached the live config because the container kept running the old rendered config. Always use `--force-recreate` after changing nginx templates. (2) `return` at the nginx server context level is processed during the rewrite phase, **before** location matching β so a server-level `return 301` redirects ALL requests including `/.well-known/acme-challenge/`. Always put `return 301` inside `location /`, and use `location ^~ /.well-known/acme-challenge/` so the prefix match explicitly beats the catch-all. | |
| --- | |
| ### certbot "live directory exists": bootstrap self-signed cert blocks real cert issuance | |
| **Date:** 2026-06-04 | |
| **Context:** `certbot_certs` Docker volume, `make prod-certbot`, first real cert issuance after bootstrap | |
| **Tags:** `certbot` `letsencrypt` `ssl` `bootstrap` `self-signed` `volume` `live-directory` | |
| **Error:** `make prod-certbot` failed with: `live directory exists for chatbot.monireach.com`. Certbot refused to issue a real cert. | |
| **Tried & Failed:** | |
| - (could not solve independently β solved with AI assistance) | |
| **Solution:** | |
| 1. Inspect the volume to confirm it's the bootstrap cert (`issuer=CN=localhost`, `subject=CN=localhost`) | |
| 2. Delete only the three lineage paths for this domain (never the whole volume): | |
| ```bash | |
| docker run --rm -v smart_chatbot_certbot_certs:/etc/letsencrypt alpine:3 sh -c \ | |
| 'rm -rf /etc/letsencrypt/live/chatbot.monireach.com \ | |
| /etc/letsencrypt/archive/chatbot.monireach.com \ | |
| /etc/letsencrypt/renewal/chatbot.monireach.com.conf' | |
| ``` | |
| 3. Run `make prod-certbot` β issues the real cert | |
| 4. Run `docker exec nginx nginx -s reload` β nginx picks up the real cert | |
| **Learned:** The bootstrap script (`init-letsencrypt.sh`) creates a raw `openssl` self-signed cert at `/etc/letsencrypt/live/<domain>/` so nginx can start before the real cert exists. When `certbot certonly` runs later, it sees a pre-existing `live/<domain>/` directory it didn't create and refuses to overwrite it. `certbot delete` won't work here because there's no `renewal/*.conf` (the cert was made by openssl, not certbot). The fix is to manually remove the three lineage directories, then issue cleanly. Always verify with `openssl x509 -noout -issuer` before deleting β `issuer == subject` confirms self-signed. | |
| ## Docker & Environment | |
| ### `summarization_worker_prod` crash loop causing high server load on idle prod server | |
| **Date:** 2026-06-06 | |
| **Context:** Production server `rermork-staging`, `summarization_worker_prod` Docker container | |
| **Tags:** `docker` `celery` `crash-loop` `alembic` `load-average` `missing-migration` `restart-always` | |
| **Error:** Hosting provider sent a high-load alert: load average 5.13 on a 2-core machine, threshold 5. Server had no real users yet. `docker ps` showed `summarization_worker_prod: Restarting (1) 2 seconds ago`. | |
| **Tried & Failed:** | |
| - (could not solve independently β diagnosed with AI assistance) | |
| **Solution:** | |
| 1. SSH in and run `docker stats --no-stream` β `summarization_worker_prod` at 100% CPU | |
| 2. `docker logs --tail 20 summarization_worker_prod` β `sqlalchemy.exc.ProgrammingError: relation "summarization_jobs" does not exist` | |
| 3. `docker inspect summarization_worker_prod` β `RestartCount: 1960` | |
| 4. Root cause: `summarization_jobs` table was added to SQLAlchemy models but the Alembic migration was never run against the production DB. Container starts, queries the missing table, crashes, Docker's `restart: always` relaunches it β tight loop consuming a full core. | |
| 5. Fix required three steps uncovered in sequence (see DB entries below for details on each): | |
| - a. Fix `%` escaping in `alembic/env.py` β DB password contained `%` characters that crashed `ConfigParser` before migrations could run | |
| - b. Rewrite empty root migration `90fb3f29fbaf_initial.py` β on the fresh prod DB the root migration was `pass`, so incremental migrations tried to ALTER tables that were never created | |
| - c. Run `docker exec chatbot_backend_prod uv run alembic upgrade head` β 12 tables created, reached `head` | |
| 6. Restart all workers: `make prod-up` | |
| 7. Confirmed: all 9 containers `Up`, load dropped from 5.13 β 0.12 | |
| **Learned:** A `restart: always` policy turns a missing migration into a server-level CPU spike. The load alert looked like a traffic issue but was a crash loop. `docker stats --no-stream` + `docker logs` is the fastest path to the real culprit. Add a CPU resource limit to worker containers in `docker-compose.prod.yml` (`deploy.resources.limits.cpus: "0.50"`) so crash loops can't consume a full core. Run `alembic upgrade head` as part of every prod deploy sequence. On fresh-DB deployments, the root Alembic migration must create baseline tables β not `pass`. | |
| --- | |
| ## Database (SQLAlchemy / Alembic) | |
| ### `ValueError: invalid interpolation syntax` β `%` in DB password crashes `alembic upgrade head` | |
| **Date:** 2026-06-06 | |
| **Context:** `alembic/env.py` line 23, `alembic upgrade head` inside `chatbot_backend_prod` | |
| **Tags:** `alembic` `configparser` `database-url` `password` `percent` `interpolation` `migration` | |
| **Error:** `alembic upgrade head` crashed with: | |
| ``` | |
| ValueError: invalid interpolation syntax in "postgresql://chatbot_user:...%QnN...%qtO7{@postgres:5432/chatbot_prod" at position 45 | |
| ``` | |
| **Tried & Failed:** | |
| - (could not solve independently β diagnosed with AI assistance) | |
| **Solution:** Alembic passes the database URL to Python's `ConfigParser` via `config.set_main_option()`. `ConfigParser` treats `%` as an interpolation trigger β `%Q` is read as `%(Q)s`, which is invalid syntax. DB passwords containing `%` characters crash the call. Fix in `alembic/env.py` line 23: | |
| ```python | |
| # Before | |
| config.set_main_option("sqlalchemy.url", config_manager.get_config().database_url) | |
| # After | |
| config.set_main_option("sqlalchemy.url", config_manager.get_config().database_url.replace("%", "%%")) | |
| ``` | |
| `ConfigParser` converts `%%` back to `%` when reading the value, so SQLAlchemy receives the correct URL. | |
| **Learned:** Any `%` character in a value passed to `ConfigParser.set()` must be escaped as `%%`. This is a silent Python stdlib rule β the error message says "invalid interpolation syntax" and points to a character position in the URL, which looks like a connection string problem but is actually a ConfigParser escaping issue. Always apply `.replace("%", "%%")` when passing secrets through `set_main_option` in `alembic/env.py`. Note: this fix was necessary but not sufficient on a fresh DB β the root migration was also empty. See 'Empty root Alembic migration breaks fresh-DB deployment' entry below. | |
| --- | |
| ### Empty root Alembic migration breaks fresh-DB deployment: `relation "conversations" does not exist` | |
| **Date:** 2026-06-06 | |
| **Context:** `alembic/versions/90fb3f29fbaf_initial.py`, fresh production PostgreSQL database | |
| **Tags:** `alembic` `migration` `fresh-db` `baseline` `root-migration` `pass` `relation-does-not-exist` | |
| **Error:** After fixing the `%` escaping issue, `alembic upgrade head` still failed: | |
| ``` | |
| sqlalchemy.exc.ProgrammingError: (psycopg2.errors.UndefinedTable) relation "conversations" does not exist | |
| ``` | |
| The incremental migration `8a175fbba9af` tried to `ALTER TABLE conversations ADD COLUMN tenant_id` on a table that had never been created. | |
| **Tried & Failed:** | |
| - Temporary workaround: `docker exec chatbot_postgres_prod python -c "from app.models.database import Base, engine; Base.metadata.create_all(engine)"` + `alembic stamp head` β works for the immediate crisis, but not repeatable on any future fresh-DB deployment | |
| **Solution:** Rewrote the root migration `90fb3f29fbaf_initial.py` in-place (same revision ID, same `down_revision = None`) to create the 4 baseline tables in their original pre-incremental form: | |
| - `users` β no `tenant_id` yet; added by `5f697ba37cb7` | |
| - `conversations` β no `tenant_id`, `last_message_preview`, or `context_summary` yet | |
| - `messages` β `entities` as `TEXT` (converted to `JSONB` by `e5cc44e2040a`) | |
| - `knowledge_base` β column named `entry` (renamed to `content` by `a53f4c8d9b21`); `tenant_id` has no FK (tenants table doesn't exist yet; FK added by `5f697ba37cb7`) | |
| Existing DBs: already stamped at `90fb3f29fbaf`, so Alembic skips the rewritten `upgrade()` entirely. | |
| Fresh DBs: creates the 4 baseline tables, then applies all incremental migrations on top. | |
| Final result: `alembic upgrade head` created all 12 tables and reached `00f16d0affc6 (head)` cleanly. | |
| **Learned:** When base tables were originally created by `Base.metadata.create_all()` during development, the root Alembic migration is left as `pass`. This works fine on existing DBs (already stamped) but silently breaks any fresh-DB deployment β incremental migrations try to ALTER tables that were never created. The permanent fix is to rewrite the root migration in-place (keep the same revision ID) so it creates baseline tables in their original form. This is the standard Alembic "baseline migration" pattern. Never leave the root migration as `pass` once any incremental migration performs schema changes (ADD COLUMN, ALTER COLUMN, etc.) on those tables. | |