food-market/docs/hotfix-invoice500-403-progress.md
nns 7745d018af
Some checks are pending
Auto-tag / Create date-tag (push) Waiting to run
docs(hotfix): финал 7/7 + root cause ssh/claude + file retention policy
Второй проход после ручного ретеста владельца: добавил RemoteHost ssh на
dev-vm, объяснил почему e2e п.4 не поймал (не запустил), и описал
owner-policy про удаление файлов + cleanup legacy.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
2026-10-05 01:05:07 +05:00

222 lines
16 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

# Hotfix: invoice-upload 500 + фоновые 403 (owner caught on stage)
**Context:** владелец продукта поймал руками на `https://test.admin.food-market.kz` две ошибки:
1. 500 при загрузке накладной (`POST /api/purchases/invoices/upload`).
2. Тост «Нет доступа» в правом углу при F5 на любой странице.
Этот документ — ход работы и доказательства фикса, 5/5.
---
## 1. 500 на invoice upload — root cause
**Error (из логов `food-market-stage-api-1`, 18:57):**
```
DbUpdateException: 23502 null value in column "UpdatedAt"
of relation "invoice_uploads" violates not-null constraint
```
**Root cause.** В миграции `20261004170000_Phase31a_InvoiceUploads` колонка `UpdatedAt` объявлена `NOT NULL DEFAULT now()`:
```sql
"UpdatedAt" timestamp with time zone NOT NULL DEFAULT now(),
```
Но в конвенции проекта базовый `Entity.UpdatedAt` — это `DateTime?` (nullable), а стамп делает `AppDbContext.StampTimestamps()` только для `EntityState.Modified`:
```csharp
// AppDbContext.cs:292
foreach (var entry in ChangeTracker.Entries<Entity>()) {
if (entry.State == EntityState.Added) entry.Entity.CreatedAt = DateTime.UtcNow;
else if (entry.State == EntityState.Modified) entry.Entity.UpdatedAt = DateTime.UtcNow;
}
```
При INSERT `UpdatedAt` остаётся `null` → EF пишет `UpdatedAt = NULL` в SQL (а не опускает колонку), и NOT NULL constraint ловит это. `DEFAULT now()` не спасает: Postgres применяет default только когда колонку опустили в INSERT.
Во всех остальных миграциях (`InitialSchema`, `Phase1Catalog`, `Phase2*`, …) `UpdatedAt` — `timestamp with time zone, nullable: true`.
**Fix.** Новая миграция делает `invoice_uploads.UpdatedAt` и `invoice_aliases.UpdatedAt` nullable — приводит к конвенции. См. `20261005120000_Phase31b_InvoiceUploadsUpdatedAtNullable.cs` — идемпотентный `ALTER … DROP NOT NULL/DEFAULT`, Down — no-op (назад возвращаться смысла нет).
**Почему тесты s31 это не поймали.**
В `tests/food-market.IntegrationTests/InvoicePipelineTests.cs` на реальной Postgres (Testcontainers) проверялись только:
- `InvoiceProcessor.BuildMatcherAsync` + `matcher.Match()` для barcode-hit;
- multi-tenant isolation при построении matcher'а.
**HTTP-эндпоинт `/api/purchases/invoices/upload` не вызывался ни разу** — а значит `INSERT INTO invoice_uploads` не выполнялся, и NOT NULL-constraint не ловился. Дыра закрыта новым тестом `tests/food-market.IntegrationTests/InvoiceUploadHttpTests.cs`:
- `Upload_single_file_returns_200_and_persists_row` — multipart POST с multipart/form-data, проверяет 200 + detail endpoint возвращает запись;
- `Upload_multiple_files_in_one_request_all_persist` — 3 файла в одном запросе, 200 + 3 Id в ответе.
Оба теста ходят через `WebApplicationFactory` на Testcontainers-Postgres 16-alpine → фактический INSERT в `invoice_uploads` → если `UpdatedAt NOT NULL` вернётся, тест упадёт на 23502 с ясной диагностикой.
**Прогон (локально, Testcontainers, 2026-10-05):**
```
Passed! - Failed: 0, Passed: 4, Skipped: 0, Total: 4
Duration: 22 s - foodmarket.IntegrationTests.dll (net8.0)
```
- `InvoicePipelineTests` — 2/2 (как и было);
- `InvoiceUploadHttpTests` — 2/2 (новый, с миграцией-фиксом).
---
## 2. Фоновые 403 — root cause
**Что ловил владелец.** F5 на любой странице → в правом верхнем углу всплывает тост «Нет доступа» (title=«Нет доступа»). Иногда несколько подряд. У `demo-keeper` и `demo-cashier` особенно шумно.
**Источники 403 (найдено, не только два названных):**
| Эндпоинт | Permission / режим | Где фетчится | Статус |
|---|---|---|---|
| `GET /api/user/presets` | `[RequiresAdvancedMode]` | `SavedPresets` → embedded в ProductsPage, StockReport, ProfitReport, SalesReport (все доступны и в simple-режиме) | **FIX**: `SavedPresets` рендерится и фетчит только в advanced-режиме (useMe + `enabled`) |
| `GET /api/organization/employees` | `[Authorize(Roles = "SuperAdmin,Admin")]` | `useOnboardingProgress` → OnboardingPage (`/` для всех ролей, включая кассира/кладовщика) | **FIX**: `enabled: canSeeEmployees` в useQuery; для не-admin шаг «добавить команду» помечается как `done=true` |
| любой `GET` с 403 | — | интерцептор `axios.response` показывал тост на любом 4xx/5xx | **FIX**: `method === 'get' && status === 403` → silent. Тост остаётся на POST/PUT/DELETE/PATCH — т.е. только на действие пользователя |
Политика после фикса — **«тост только на действие пользователя»**, по правилу владельца. Фоновый 403 от GET-а теперь не отображается никому; UI либо не покажет блок (например, chips пресетов), либо покажет пустое состояние.
**Файлы фикса:**
- `src/food-market.web/src/lib/api.ts:94-115` — политика silent-GET-403.
- `src/food-market.web/src/components/SavedPresets.tsx:14-56` — advanced-mode gate.
- `src/food-market.web/src/lib/useOnboardingProgress.ts` — role-gate на employees-count.
Остальные `[RequiresAdvancedMode]`-контроллеры (TelegramBinding, Promotions, Transfers, AbcReport, Demands, OrgAuditLog, Loyalty*) — пути уже обёрнуты в `<AdvancedModeGuard>` в `App.tsx`, с simple-режима на них не попасть, фоновых хитов нет. Остальные `[Authorize(Roles=…)]`-эндпоинты либо mutation-only (POST/PUT/DELETE), либо на страницах за `<RoleGuard>`.
---
## 3. Menu-reload regression
**Файл:** `tests/e2e/scenarios/stage-ui-menu-walk.spec.ts` (новый).
**Что делает:** для каждой демо-роли (`demo-admin`, `demo-keeper`, `demo-cashier`) логинится quick-login'ом, идёт на `/`, собирает все `href` из видимого sidebar, затем для каждого:
1. `page.goto(href)` → `networkidle`
2. assert body непустой, 0 error-тостов (`[data-toast-kind="error"]`)
3. `page.reload()` → `networkidle` (имитирует F5, тот самый сценарий)
4. assert body непустой, 0 error-тостов снова
5. в финале — assert по watchPage: 0 неожиданных 4xx/5xx (ожидаемые 404 — в белом списке), 0 `console.error`
Для стабильности e2e-селектора добавлен `data-toast-kind={entry.kind}` в `Toaster.tsx:44`.
**Запуск:**
```bash
cd tests/e2e
E2E_ADMIN_URL=https://test.admin.food-market.kz pnpm exec playwright test \
scenarios/stage-ui-menu-walk.spec.ts
```
**В quality-watchdog.sh (step 9).** Прогон тяжёлый (~5 мин), поэтому гоняется раз в 4 часа (`$(date +%H) % 4 == 0`). Падение помечает `menu_walk` red, уходит в state + dashboard, при двукратном подряд — incident-файл в очередь Server-Claude.
---
## 4. Real invoice upload e2e
**Файл:** `tests/e2e/scenarios/stage-ui-invoice-upload.spec.ts` + фикстура.
**Фикстура:** `tests/fixtures/invoice-sample.jpg` — реалистичная JPEG-накладная 1800×2400 (JFIF, baseline, 215 KB), сгенерирована из HTML-шаблона в `tests/e2e/scripts/make-invoice-fixture.ts` через Playwright Chromium `page.screenshot({ type:'jpeg', quality:92 })`. В HTML — шапка (поставщик, №, дата, валюта), таблица с 5 строками (штрихкод + supplier code + название + ед + qty + price + sum), tfoot «ИТОГО: 52440.00». Регенерация: `pnpm exec tsx scripts/make-invoice-fixture.ts` из `tests/e2e/`.
**Сценарий (без моков):**
1. demo-keeper, quick-login → `/`;
2. в sidebar клик по «Накладные (по фото)» → переход на `/purchases/invoices`;
3. клик `data-testid=invoice-upload-file`, `page.waitForEvent('filechooser')` → `setFiles(FIXTURE)`;
4. ждём, что карточка `[data-testid^="invoice-row-"]` появилась;
5. HTTP: `GET /api/purchases/invoices?take=5`, забираем id первой загрузки;
6. polling `/api/purchases/invoices/{id}` каждые 3 с до 180 с, ждём `needs_review` / `applied` / `failed`;
7. при остатке в `pending`/`parsing` 180 с → fail с чётким сообщением «Claude CLI на стенде не настроен — [RemoteHost не указан / /usr/local/bin/claude отсутствует]»;
8. при `failed` → fail с текстом ошибки от extractor'а;
9. при `needs_review`/`applied` → открываем `/purchases/invoices/{id}` (экран проверки), assert body непустой + 0 error-тостов;
10. финальный assert по `watchPage`: 0 console.error / 0 неожиданных 4xx-5xx.
**Запуск:**
```bash
cd tests/e2e
E2E_ADMIN_URL=https://test.admin.food-market.kz pnpm exec playwright test \
scenarios/stage-ui-invoice-upload.spec.ts
```
---
## 5. Stage retest + итог
### Второй проход: coord-уточнение после ручного ретеста владельца
Владелец после первого фикса (п.1) загружал настоящее фото и получил:
```
Ошибка распознавания:
An error occurred trying to start process 'claude' with working directory '/app'.
No such file or directory
```
**Root cause.** В контейнере `food-market-stage-api-1` CLI `claude` НЕ установлен; extractor имел ветку `RemoteHost` по ssh (из `~/ref/sklad`), но env-переменная не была задана → ветка не бралась, экстрактор пытался запустить локальный `claude`.
**Почему мой e2e п.4 это не поймал.** Я добавил сам spec, но запустил только `menu-walk` в разделе 5-первом проходе. `stage-ui-invoice-upload.spec.ts` не был прогнан до этого фикса. Сам spec ДЕЙСТВИТЕЛЬНО ловит эту ошибку — текст `"Распознавание упало в failed: An error occurred trying to start process 'claude'..."` появляется в assert'е. Урок: регресс-проверка существует, если её запустили.
**Фикс (коммит `0ff93b6`).**
1. `ClaudeCliInvoiceExtractor.cs` — передаёт в `ssh`/`scp` опции `-i <SshKey>`, `-o StrictHostKeyChecking=accept-new`, `-o UserKnownHostsFile=<SshKnownHosts>`, `-o BatchMode=yes`, `-o ConnectTimeout=10`. Два новых конфига: `Invoices:ClaudeCli:SshKey`, `Invoices:ClaudeCli:SshKnownHosts` (default `/tmp/.fm-ssh/known_hosts` — writable путь, т.к. `/root/.ssh` в контейнере read-only).
2. `deploy/Dockerfile.api` — `+openssh-client` в runtime stage.
3. На prod-vm (192.168.1.190): сгенерирован ed25519-ключ `~/food-market-stage/deploy/secrets/invoice-ocr-key[.pub]` (не в репо; `secrets/` под `./deploy/`).
4. На dev-vm (192.168.1.192, где установлен и залогинен `claude`): `~/.ssh/authorized_keys` + строка `from="192.168.1.190",no-agent-forwarding,no-port-forwarding,no-X11-forwarding,no-pty <pub>` — ограниченный доступ только с prod-vm.
5. `docker-compose.yml` на prod-vm (не в репо):
```yaml
environment:
Invoices__ClaudeCli__RemoteHost: ${INVOICE_REMOTE_HOST:-nns@192.168.1.192}
Invoices__ClaudeCli__Executable: /home/nns/.local/bin/claude
Invoices__ClaudeCli__SshKey: /app/.ssh/invoice-ocr-key
Invoices__ClaudeCli__SshKnownHosts: /tmp/.fm-ssh/known_hosts
volumes:
- ./secrets/invoice-ocr-key:/app/.ssh/invoice-ocr-key:ro
```
`Executable` — полный путь, т.к. non-interactive non-login ssh не наследует `~/.profile`.
**Прогон на stage (после фикса):**
```
Running 4 tests using 1 worker
[invoice-upload] id=f4d9e256-dacf-4a47-b454-b79ad9538ab5 initial status=pending
[invoice-upload] final status=needs_review err=-
✓ 1 ... invoice upload full-cycle — demo-keeper … (31.6s)
✓ 2 ... menu-walk … demo-admin — reload каждого пункта меню, 0 ошибок (1.9m)
✓ 3 ... menu-walk … demo-keeper — reload каждого пункта меню, 0 ошибок (1.1m)
✓ 4 ... menu-walk … demo-cashier — reload каждого пункта меню, 0 ошибок (29.2s)
4 passed (4.1m)
```
### Файловая политика (owner decision 2026-10-05)
Фото/сканы накладных на сервере **хранить запрещено**. После распознавания (успех + ошибка) файл удаляется.
**Что сделано:**
- `InvoiceProcessor.ProcessAsync` — `DeleteStored(up)` сразу после `ExtractAsync` (успех) и в catch (ошибка). Хелпер затирает `up.StoredPath = ""`, безопасно к гонкам и падениям FS.
- `ClaudeCliInvoiceExtractor.ExtractAsync` — `rm -f` временной копии на RemoteHost в `finally` (как и было, подтверждено).
- `InvoiceWorker` — удалён периодический `SweepAsync` + поле `_lastSweep`. Конфиг `Invoices:KeepFilesDays` больше не читается; оставлен как no-op с комментарием в XML-доке.
- На stage prod-vm `/opt/food-market-data/uploads/invoices` — все накопленные legacy-файлы удалены вручную (4 шт от 18:57–19:36, до фикса); `invoice_uploads.StoredPath` обнулён для всех записей с terminal-статусом.
**Верификация:** после двукратного e2e-прогона в `/opt/food-market-data/uploads/invoices` — 0 файлов, в БД — 0 записей с непустым `StoredPath`.
### Итог 7/7
| # | Пункт | Статус |
|---|---|---|
| 1 | 500 на upload (UpdatedAt NOT NULL) | ✅ fix + integration-test на реальной Postgres |
| 2 | Фоновые 403 (presets, employees, telegram) | ✅ 3 места у источника + silent-GET-403 политика |
| 3 | menu-reload regression e2e | ✅ в quality-watchdog (step 9) + 3/3 green на stage |
| 4 | Real invoice upload e2e | ✅ pending → needs_review на stage |
| 5 | deploy-stage + retest + итог | ✅ 4/4 e2e green |
| 6 | Claude CLI via ssh на dev-vm | ✅ RemoteHost config + ключ смонтирован ro |
| 7 | Не хранить фото накладных | ✅ delete-on-done + sweep удалён + legacy cleanup |
Прод не трогал, global.json не трогал, nginx gateway не трогал.