docs(pilot): 25.05 — incident supplier:session РАЗРЕШЁН (бага нет, auto-refresh работает)

TTL-арифметика 2 cron-тиков (implied write 02:01:09 + 03:01:08 = journalctl
DONE) доказала: cron обновляет сессию каждый час. Ранний вывод «zombie lock»
был ошибкой замера. Root cause 3-дневного простоя — worker бежал со stale
--timeout=60 (timeout.conf=300 от 22.05 не подхвачен без рестарта); recycle
00:18 UTC подхватил правильный конфиг → самовосстановление.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
This commit is contained in:
Дмитрий
2026-05-25 06:04:09 +03:00
parent 81f52fd1c6
commit 2ec8707a03
+1 -1
View File
@@ -10,7 +10,7 @@
**Снимок снят:** 25.05.2026 (день) — **🛠 РАЗРАБОТКА (прод НЕ затронут): Биллинг v2 Спек C Phase 1 backend готов на ветке.** Чисто feature-фаза, на боевой `liderra.ru` НИЧЕГО не выкачено, БД/код прода не менялись. Ветка `feat/billing-v2-spec-c` на origin HEAD `d8955f57` (9 коммитов ahead of main; спек/план уже в истории main `af6c3289`). **Phase 1 (защита баланса от заказа лидов клиентам без денег):** заморозка/разморозка клиента на вечернем cut-off 18:00 MSK (`BalancePreflightSweepJob`, `tenants.frozen_by_balance_at` + project-level `projects.preflight_blocked_at`, фильтр frozen-проектов в `SyncSupplierProjectsJob` — формула `computeOrder` НЕ меняется); `ProjectController::store/update` → HTTP 409 `balance_insufficient` при перегрузке (с `force_save_blocked` → точечная заморозка проекта); 4 письма (frozen/reminder+1д/final+3д/unfrozen) + cron 18:30 MSK; one-time `billing:preflight-initial-sweep`. **Safe fallback:** без активных `pricing_tiers` проверка баланса пропускается (legacy/без-биллинга). Pest 13/13 GREEN, 0 регрессий. **Schema v8.35→v8.36** (после merge main с legacy-webhook-removal + router stages 2+3): +`balance_freeze_log` / +2 колонки / +3 индекса (метрики 74 base / 123 idx / 41 RLS). **Перед деплоем на прод:** разово `billing:preflight-initial-sweep` после миграции + настроить `pricing_tiers` (иначе fallback-skip). **Осталось:** Task 1.10 frontend (баннер/индикатор/диалог), Phase 2 VTB безнал PDF+админка, Phase 3 СБП/карты-заглушки, Phase 4 тесты, Phase 5 доки. Спек/план в `docs/superpowers/{specs,plans}/2026-05-24-billing-v2-spec-c-preflight-vtb*.md`. Worktree `.claude/worktrees/billing-v2-spec-c` сохранён.
**Снимок снят:** 25.05.2026 (утро UTC) — **🔥 INCIDENT RECOVERY: Компания 1 не получала лидов с 22.05** (3 дня тишины). **Корень — `supplier:session` в Redis истёк/пуст**: `Cache::store('redis')->put('supplier:session', $session, now()->addHours(6))` записывает в `liderra-database-liderra-cache-supplier:session` (Cache connection = db1, не Queue db0). Ключ был пустой во всех Redis DB. Без сессии: SupplierPortalClient падает на любых запросах → CsvReconcileJob recovery=0 → SyncSupplierProjectsJob 7 дней нулевых записей → поставщик не активирует выдачу. **Диагностика:** `failed_jobs` показал 28 RefreshSupplierSessionJob fails 22.05 по `Illuminate\Queue\TimeoutExceededException` (worker timeout 60с default против Playwright cold-start 65с). После 22.05 — 0 новых fails (worker config drop-in `--timeout=300` от 22.05 уже исправлен; scheduler hourly entry в routes/console.php есть; `liderra-queue` systemd active; cron `/etc/cron.d/liderra-scheduler` каждую минуту). journalctl `liderra-queue` за 3 часа показал `RefreshSupplierSessionJob ... RUNNING → DONE 1 мин 5 сек` КАЖДЫЙ ЧАС (23:00/00:00/01:00 UTC). НО `scheduler_heartbeats.last_success_at` = 25.05 01:00:02, а Redis ключ всё равно пуст — DONE без exception, но `Cache::put` внутри `Lock::block(95)` не отрабатывало (вероятно zombie lock после 22.05 worker-крахов держал `supplier:session:refresh` без release, `block(95)` молча возвращал без callback). **Hot-fix:** ручной `RefreshSupplierSessionJob::dispatchSync()` через `cat | ssh ... php artisan tinker` (workaround quirk #109`--execute` ломается на multi-level escape, stdin чист) → **SUCCESS**, сессия в Redis db1 (TTL 21593с = 5ч59м, 215 байт cookies+csrf). Каскадный `CsvReconcileJob::dispatchSync()` → SUCCESS, но recovered=0 / drift=0.425 / status=drift_alert — **false-positive**: из 73 CSV-rows за окно 42 уже в supplier_leads, 31 — мусор от поставщика (телефоны/URL в поле project, `parseProjectField` корректно скипает с info-логом `csv_reconcile.unparseable_project_skipped`). **Состояние Компании 1 на момент починки:** tenant_id=2, `balance_rub=75000.00` / `balance_leads=999731` (старый seed, не обнулён `billing:migrate-leads-to-rub` — non-destructive) / `delivered_in_month=275`; 117 проектов все active; sum_daily_limit=6330; sum_delivered_today=0; **все 275 lead_charges = `prepaid` (старая схема)**, последний 22.05 — НИ ОДНОГО `charge_source='rub'` за всю историю прода (новая тарификация ни разу не сработала живьём). Биллинг v2 Phase A на проде с 24.05 ночь — код готов, ждёт первого нового лида чтобы впервые применить tier-lookup. **Не починено (отдельная задача):** root cause «3 дня DONE без write в Redis» — точно не установлено, возможно zombie lock. Профилактика: дождаться cron `02:00 UTC` для auto-verify (TTL должен обновиться). Если повторится — копать journalctl за 22-25.05 более глубоко (журналы могут уже ротировать). **Урок:** Schedule::job hb.onSuccess = «dispatch в queue OK», не «job выполнился» → false-positive в heartbeats. Запушен только этот snapshot (диагностические команды read-only, кода не правили).
**Снимок снят:** 25.05.2026 (утро UTC) — **🔥 INCIDENT RECOVERY: Компания 1 не получала лидов с 22.05** (3 дня тишины). **Корень — `supplier:session` в Redis истёк/пуст**: `Cache::store('redis')->put('supplier:session', $session, now()->addHours(6))` записывает в `liderra-database-liderra-cache-supplier:session` (Cache connection = db1, не Queue db0). Ключ был пустой во всех Redis DB. Без сессии: SupplierPortalClient падает на любых запросах → CsvReconcileJob recovery=0 → SyncSupplierProjectsJob 7 дней нулевых записей → поставщик не активирует выдачу. **Диагностика:** `failed_jobs` показал 28 RefreshSupplierSessionJob fails 22.05 по `Illuminate\Queue\TimeoutExceededException` (worker timeout 60с default против Playwright cold-start 65с). После 22.05 — 0 новых fails (worker config drop-in `--timeout=300` от 22.05 уже исправлен; scheduler hourly entry в routes/console.php есть; `liderra-queue` systemd active; cron `/etc/cron.d/liderra-scheduler` каждую минуту). journalctl `liderra-queue` за 3 часа показал `RefreshSupplierSessionJob ... RUNNING → DONE 1 мин 5 сек` КАЖДЫЙ ЧАС (23:00/00:00/01:00 UTC). НО `scheduler_heartbeats.last_success_at` = 25.05 01:00:02, а Redis ключ всё равно пуст — DONE без exception, но `Cache::put` внутри `Lock::block(95)` не отрабатывало (вероятно zombie lock после 22.05 worker-крахов держал `supplier:session:refresh` без release, `block(95)` молча возвращал без callback). **Hot-fix:** ручной `RefreshSupplierSessionJob::dispatchSync()` через `cat | ssh ... php artisan tinker` (workaround quirk #109`--execute` ломается на multi-level escape, stdin чист) → **SUCCESS**, сессия в Redis db1 (TTL 21593с = 5ч59м, 215 байт cookies+csrf). Каскадный `CsvReconcileJob::dispatchSync()` → SUCCESS, но recovered=0 / drift=0.425 / status=drift_alert — **false-positive**: из 73 CSV-rows за окно 42 уже в supplier_leads, 31 — мусор от поставщика (телефоны/URL в поле project, `parseProjectField` корректно скипает с info-логом `csv_reconcile.unparseable_project_skipped`). **Состояние Компании 1 на момент починки:** tenant_id=2, `balance_rub=75000.00` / `balance_leads=999731` (старый seed, не обнулён `billing:migrate-leads-to-rub` — non-destructive) / `delivered_in_month=275`; 117 проектов все active; sum_daily_limit=6330; sum_delivered_today=0; **все 275 lead_charges = `prepaid` (старая схема)**, последний 22.05 — НИ ОДНОГО `charge_source='rub'` за всю историю прода (новая тарификация ни разу не сработала живьём). Биллинг v2 Phase A на проде с 24.05 ночь — код готов, ждёт первого нового лида чтобы впервые применить tier-lookup. **РАЗРЕШЕНО (systematic-debugging Phase 1 + 2 cron-тика):** бага НЕТ. TTL-арифметика двух замеров доказала auto-refresh: 02:52:46 UTC TTL=18503 → implied write 02:01:09; 03:03:12 UTC TTL=21476 → implied write 03:01:08 — оба = journalctl cron DONE timestamps. Cron обновляет сессию каждый час. Ранний вывод «zombie lock / DONE без write» был ошибкой замера (оценил TTL как мою ручную запись, на деле — cron). **Пересмотренный root cause 3-дневного простоя:** worker 22-25.05 бежал со stale `--timeout=60` (drop-in timeout.conf=300 от 22.05 не подхвачен без рестарта worker'а), Playwright cold-start 65с > 60с → job умирал по TimeoutExceededException → сессия не писалась → истекала. Worker recycle сегодня 00:18 UTC подхватил `--timeout=300` → самовосстановление. Мой ручной dispatchSync был мостиком до cron. **Отдельный фикс не нужен.** Урок: при TTL-debugging вычислять implied-write = max_ttl current_ttl и сверять с реальными timestamps. И: `Schedule::job hb.onSuccess` = «dispatch в queue OK», не «job выполнился».
**Снимок снят:** 24.05.2026 (вечер) — **✅ ВЫКАЧЕНО на боевой `liderra.ru`: legacy webhook removal** (origin/main `62626399`+`d377d977`+helper-skip-migration manual). Удалён рудимент pre-sharing эпохи: `ProcessWebhookJob` + `WebhookReceiveController` + публичный роут `POST /api/webhook/{token}` + модели `RejectedDealsLog`/`WebhookDedupKey` (последняя оставлена — Phase 1 RED FLAG, используется `HistoricalImportService` CSV-канала) + методы `NotificationService::notifyLowBalance/notifyZeroBalance` + Mailable классы `LowBalanceNotification`/`ZeroBalanceNotification` + 5 тест-файлов целиком + чистка 7 тестов и фабрики `TenantFactory`. **БД (миграция `2026_05_24_140000_drop_legacy_webhook_artefacts`):** DROP `webhook_log` (партиционированная, 13 партиций), DROP `rejected_deals_log`, ALTER `tenants` DROP COLUMN `webhook_token`+`webhook_token_rotated_at`, DELETE seed `low_balance_threshold_leads`. **NB:** `webhook_dedup_keys` НЕ удалена (живая для CSV reconcile). **Инцидент при первом деплое (15:52→16:35 UTC):** чужая pending-миграция `2026_05_22_000002_webhook_log_supplier_columns.php` (от параллельной сессии) написана с дефолтным `pgsql` connection (crm_app_user) без owner-прав на `webhook_log``redeploy.sh` упал → моя миграция не дошла → mixed-state (код новый, БД старая). **Rollback ✅:** scp `git archive c7f603aa app/ db/` через cat-pipe (scp падал из-за sftp slot), `sudo tar -xf` + восстановление legacy-файлов + chown + cache:clear + reload php-fpm → портал HTTP 200 за 0.8с. БД нетронута (бэкап `/home/ubuntu/deploy-backups/liderra-schema-pre-legacy-webhook-removal-20260524-155213.sql` 1.6 MB остался как safety net, не использован). **Fix чужей миграции (commit `d377d977`):** заменён `DB::unprepared($sql)``DB::connection('pgsql_supplier')->unprepared($sql)` + `Schema::hasTable``$conn->getSchemaBuilder()->hasTable` (паттерн Спека B). Запушен в main. **Повторный деплой:** новый tar HEAD → cat-pipe stdin (scp не работает на этой машине) → extract → rm 11 legacy files → chown → `INSERT INTO migrations` чтобы пометить чужую `2026_05_22_000002` как ran (под `crm_supplier_worker` всё равно нет owner-прав на партиции `webhook_log_y2026_m02`, но моя миграция дропает таблицу целиком сразу после) → `php artisan migrate --force`**моя миграция применилась за 57.85ms ✅**`optimize:clear` + `config:clear` + `route:clear` + `php-fpm reload`. **Smoke на проде:** https://liderra.ru/ 200 (0.8s), /login 200 (0.8s), /api/webhook/{token} 405 (Method Not Allowed — роут больше не существует с POST, это правильно), /api/webhook/supplier/test с моего IP timeout (WAF/ModSecurity блокирует `webhook/supplier/*` от моего ISP, pre-existing — локально с сервера curl 127.0.0.1 даёт 404 за 0.1s, шеринг-канал жив). **БД-state ✅:** `webhook_log` отсутствует, `rejected_deals_log` отсутствует, `webhook_dedup_keys` ЖИВА (для CSV), `tenants.webhook_token`+`webhook_token_rotated_at` УДАЛЕНЫ. **Гл. урок:** SSH/SCP background-команды на этой машине systematic обрываются → workaround: `cat tar | ssh ... 'cat >'` через stdin + короткие команды + не цепочка `&&`. Чужие pending-миграции на проде — потенциальный блокер деплоя; pre-flight нужен migrate:status diff + fix-or-skip. Спек: `docs/superpowers/specs/2026-05-24-legacy-direct-webhook-removal-design.md`. План: `docs/superpowers/plans/2026-05-24-legacy-direct-webhook-removal.md` (13 commits через subagent-driven). Worktree `.claude/worktrees/legacy-webhook-removal` сохранён.