doc: progress log 2026-04-27 — poolmgr reuse fix + console cleanup

This commit is contained in:
Naeel
2026-04-27 15:16:36 +03:00
parent 96a02b4d72
commit fcc3449469
5 changed files with 820 additions and 0 deletions
+86
View File
@@ -0,0 +1,86 @@
Состояние на 2026-04-27
Что уже исправлено
- Починен вход по валидному JWT в test mode без ослабления поведения при FISSION_TEST_MODE=false.
- Добавлены тесты на auth.
- Починен статус инициализации namespace в UI: console получил права читать pod'ы control-plane.
- Убран баг с кешем ensured namespace: если namespace удалили вручную, EnsureUserNS теперь проверяет его существование и пересоздаёт.
- Live console раскатан по digest, не по tag.
- Правила обновлены: не откатывать без явной команды пользователя, после каждого исправления делать отдельный commit.
Что важно помнить
- Все shell-команды только через SSH:
ssh -i ~/.ssh/naeel_vm_id_ed25519 -o StrictHostKeyChecking=no -o ConnectTimeout=10 naeel@5.172.178.213 '...'
- Ничего не откатывать без явной команды пользователя.
- После каждого реального исправления нужен отдельный commit.
- Пользователь очень чувствителен к "нереальным" тестам. Предпочтение только live user-flow проверкам.
Текущий live state
- Репозиторий: /home/naeel/remote_dev/fission
- Live deployment console уже работает на digest:
naeel/fission-console@sha256:5f0846c53267bd275f173981afbc8181e7808c3cf98c3902acaa659d6183e8a9
- Пользовательский namespace:
fission-ffd1f598c169b0ae
- Проблемная функция:
phppp
Текущая активная проблема
- В UI при invoke функции phppp показывается ошибка:
invoke "phppp" timeout after 20s: function specialization likely failed (for example, syntax error)
- Но это generic fallback из console/internal/api/handlers.go, а не доказанный root cause.
Что уже установлено по phppp
- Функция phppp, package phppp-pkg, environment console-php-env и httptrigger существуют в namespace fission-ffd1f598c169b0ae.
- Function spec:
- environment: console-php-env
- functionName: main.php::handler
- Environment runtime:
- image: ghcr.io/fission/php-env
- Package literal успешно извлечён.
- Реальный код main.php внутри package это тяжёлая PHP-функция примерно на 10 секунд.
- В коде используются bcadd и bcmul, то есть есть сильное подозрение на отсутствие расширения bcmath в PHP runtime.
Критически важное наблюдение
- Executor log уже показал, что specialization для phppp проходит успешно:
- choosing pod from pool
- calling fetcher to copy function
- specializing pod
- specialized pod
- added function service
- Значит проблема, скорее всего, не в specialization, а уже в runtime execution внутри PHP env или в неверном timeout/error mapping со стороны console.
Что пошло не так в последней диагностике
- Логи pod были сняты не с php pod, а с pod другой функции, где был nodejs runtime.
- Поэтому точная runtime ошибка phppp ещё не поймана.
Следующий правильный шаг
1. Найти именно pod, у которого labels/functionName=phppp или environment=console-php-env и namespace=fission-ffd1f598c169b0ae.
2. Снять logs именно с php container этого pod.
3. Проверить, есть ли в runtime расширение bcmath.
4. Если bcmath отсутствует, исправить корень проблемы, а не маскировать timeout.
5. После исправления сделать отдельный commit и live-проверку invoke.
Файлы, которые уже были важны в этой истории
- console/internal/api/auth.go
- console/internal/api/handlers.go
- console/internal/api/ns_status.go
- console/internal/cloud/tenant.go
- console/internal/fission/namespace.go
- console/deploy/console.yaml
- deploy/rbac/console-ns-manager.yaml
- .github/copilot-instructions.md
Что не надо делать
- Не откатывать image, manifests, deployment или код.
- Не считать сообщение про specialization доказательством syntax error.
- Не использовать synthetic тесты вместо live-проверки, если пользователь просит именно user-flow.
@@ -0,0 +1,324 @@
# Postmortem: Fission poolmgr reuse bug — полное исследование и fix
**Дата**: 2026-04-27
**Статус**: РЕШЕНО
**Image**: `naeel/fission-bundle:v1.22.0-multi-ns-10`
**Commit**: `0cae275 executor: update gpm.podLister in AddNamespace to fix IsValid nil panic`
---
## Симптом
При последовательных invoke одной и той же poolmgr-функции executor каждый раз делал `choosePod + specializePod` вместо reuse уже существующего специализированного pod.
**Наблюдаемые признаки:**
- `phppp` (PHP): 10/10 HTTP 200, но `PHP_PODS_BEFORE=1 → PHP_PODS_AFTER=11`
- `88` (Python): 3/10 HTTP 200, затем HTTP 000 (timeout), `PY_PODS_BEFORE=1 → PY_PODS_AFTER=4`
- В executor logs на каждый invoke: `choosing pod from pool`, `relabel pod`, `specializing pod`, `added function service`
- Через ~2 минуты idle reaper убирал накопившиеся pods: `release idle function resources`
- **Не было ни одной строчки**: `served from cache` или аналогичного
---
## Архитектура reuse path (как должно работать)
```
[router RoundTrip]
├─ getServiceEntry(ctx)
│ └─ getServiceEntryFromExecutor() ─── POST /v2/getServiceForFunction
│ │
│ │ [executor api.go]
│ ├─ GetFuncSvcFromCache(fn) ─── poolcache.GetSvcValue(CacheKeyURG, rpp, concurrency)
│ │ ├─ CACHE HIT → activeRequests++ → return fsvc
│ │ └─ CACHE MISS → getServiceForFunction → choosePod → specializePod → AddFunc → activeRequests=1
│ │
│ └─ IsValid(ctx, fsvc) ─── podLister[ns].Get(pod.Name)
│ ├─ pod ready + IP match → return true → "served from cache"
│ └─ nil panic / not found → return false → DeleteFuncSvcFromCache → choosePod
├─ defer unTapService(ctx, fn, serviceURL)
│ └─ POST /v2/unTapService
│ │ [executor api.go → gpm.UnTapService]
│ └─ fsCache.MarkAvailable(CacheKeyURGFromMeta(fnMeta), svcHost)
│ └─ poolcache.markAvailable → activeRequests--
└─ [NEXT INVOKE]: GetFuncSvcFromCache видит activeRequests=0 → CACHE HIT → reuse
```
**Условие reuse**: `activeRequests < requestsPerPod` (default: `requestsPerPod=1`, т.е. нужно `activeRequests=0`).
---
## Bug #1 (исправлен ранее, commit `775845b`)
### Что было не так
`UnTapService` в `pkg/executor/client/client.go` передавал `FnMetadata` без поля `Generation`:
```go
// ДО fix (client.go UnTapService):
FnMetadata: metav1.ObjectMeta{
Name: fnMeta.Name,
Namespace: fnMeta.Namespace,
ResourceVersion: fnMeta.ResourceVersion,
UID: fnMeta.UID,
// Generation отсутствовал!
},
```
### Где ломалось
`CacheKeyURGFromMeta` в `pkg/crd/key.go`:
```go
func CacheKeyURGFromMeta(metadata *metav1.ObjectMeta) CacheKeyURG {
return CacheKeyURG{
UID: metadata.UID,
ResourceVersion: metadata.ResourceVersion,
Generation: metadata.Generation, // был 0 вместо реального
}
}
```
Кэш записывался с ключом `{UID, RV, Generation=1}`.
`MarkAvailable` искал по ключу `{UID, RV, Generation=0}`.
`cache[{UID, RV, Generation=0}]` не существовал → `activeRequests` никогда не уменьшался.
### Fix
Добавлен `Generation: fnMeta.Generation` в `TapService` и `UnTapService` в `client.go`.
### Почему fix был необходим, но недостаточен
После fix `MarkAvailable` стал находить правильный ключ и декрементировал `activeRequests` до 0.
Следующий `GetFuncSvcFromCache` успешно находил запись (0 < 1) → инкрементировал до 1 → возвращал `fsvc`.
Дальше вызывался `IsValid(ctx, fsvc)` — и здесь находился второй баг.
---
## Bug #2 (исправлен в v1.22.0-multi-ns-10, commit `0cae275`) — ROOT CAUSE
### Точная цепочка отказа
**1. `IsValid` в `gpm.go` строка 289:**
```go
func (gpm *GenericPoolManager) IsValid(ctx context.Context, fsvc *fscache.FuncSvc) bool {
for _, obj := range fsvc.KubernetesObjects {
if strings.ToLower(obj.Kind) == "pod" {
pod, err := gpm.podLister[obj.Namespace].Pods(obj.Namespace).Get(obj.Name)
// ^^^^^^^^^^^^^^^^
// NIL для user namespace!
```
**2. `gpm.podLister` инициализируется только один раз при старте** в `MakeGenericPoolManager`:
```go
for ns, informerFactory := range gpmInformerFactory {
gpm.podLister[ns] = informerFactory.Core().V1().Pods().Lister()
}
```
**3. `gpmInformerFactory` строится из `DefaultNSResolver()`**, который читает env vars executor:
```json
"FISSION_FUNCTION_NAMESPACE": "",
"FISSION_RESOURCE_NAMESPACES": "default"
```
Итог: `gpm.podLister = {"default": <lister>}`**только namespace `default`**.
**4. При создании нового user namespace** `fission-ffd1f598c169b0ae` вызывается `AddNamespace`:
```go
func (gpm *GenericPoolManager) AddNamespace(ctx context.Context, ns string, ...) error {
// ... создаёт gpmInformer для нового NS ...
gpm.poolPodC.AddNamespaceInformers(ctx, ns, finformer, gpmInformer)
// ↑ регистрирует poolPodC.podLister[ns] — ОК
// НО gpm.podLister[ns] НЕ обновлялся ← БАГ
gpmInformer.Start(ctx.Done())
}
```
`AddNamespaceInformers` регистрировал `podLister` только в **`poolPodC`** (для `PoolPodController`), но **не в `gpm`** (для `IsValid`).
**5. Результат**: `gpm.podLister["fission-ffd1f598c169b0ae"]` = **nil**.
**6. `nil.Pods(ns).Get(name)`****nil pointer dereference panic**.
**7. `net/http` перехватывает panic** в handler goroutine → разрывает соединение.
**8. Router's `retryablehttp`** видит connection error → retry.
**9. На retry**: `GetFuncSvcFromCache` видит `activeRequests=1` (был инкрементирован на шаге cache hit, до panic, и не был декрементирован), `1 >= requestsPerPod=1`**cache miss**`choosePod`**новый pod**.
### Почему каждый invoke создавал ровно 1 новый pod
| Invoke N | Что происходит | Состояние после |
|----------|----------------|-----------------|
| 1 | Cache miss (первый invoke) → pod₁ specialized, `activeRequests=1`. UnTap → `activeRequests=0` | pod₁ ready, AR=0 |
| 2 | Cache HIT (AR=0→1), IsValid → nil panic, retry: AR=1≥1 → miss → pod₂ specialized | pod₁ stuck AR=1, pod₂ AR=1→0 |
| 3 | Cache hit pod₂ (AR=0→1), IsValid → nil panic; retry: AR=1≥1 → miss → pod₃ specialized | pod₁ stuck AR=1, pod₂ stuck AR=1, pod₃ AR=1→0 |
| … | То же | +1 pod каждый invoke |
| 10 | | 10 stuck pods + 1 "live" pod |
**Итого после 10 invokes**: 11 pods (`PHP_PODS_BEFORE=1 → PHP_PODS_AFTER=11`). Совпадает с наблюдением.
Каждые ~2 минуты idle reaper убирал stuck pods (у которых `activeRequests=1` но запросов нет — баг idle reaper в отдельной логике списания).
---
## Fix
**Файл**: `pkg/executor/executortype/poolmgr/gpm.go`
**Функция**: `AddNamespace`
**Изменение**: добавлена одна строка — обновление `gpm.podLister[ns]` после `AddNamespaceInformers`
```go
// Register the new informers with PoolPodController.
if err := gpm.poolPodC.AddNamespaceInformers(ctx, ns, finformer, gpmInformer); err != nil {
return fmt.Errorf("AddNamespace %s: register informers: %w", ns, err)
}
// Also update gpm.podLister so IsValid can resolve pods in this namespace.
// Without this line gpm.podLister[ns] is nil for dynamically-added user namespaces,
// causing a nil-pointer panic in IsValid, which leaves activeRequests permanently stuck at 1.
gpm.podLister[ns] = gpmInformer.Core().V1().Pods().Lister() // ← PATCH
// Start the factories — they will begin syncing immediately.
finformer.Start(ctx.Done())
gpmInformer.Start(ctx.Done())
```
### Почему именно здесь, а не в `AddNamespaceInformers`
`AddNamespaceInformers` — метод `PoolPodController`, который знает только о своём `podLister`.
`gpm.podLister` — поле `GenericPoolManager`, логически отдельное от `poolPodC`.
Обновлять оба необходимо, чтобы `IsValid` (метод `GenericPoolManager`) работал корректно.
`gpmInformer` уже создан и передан в `AddNamespaceInformers` — повторное использование того же объекта безопасно.
---
## Live validation
### Методология
1. Удалить все накопленные specialized pods в user namespace (сброс состояния).
2. Запустить 10 последовательных invokes с паузой 2s.
3. Считать число php pods до и после.
4. Ожидаемый результат: `NEW_PODS_CREATED=1` (первый cold start) и `REUSE_WORKING=YES`.
### Результат после patch (v1.22.0-multi-ns-10)
```
=== CLEAN BASELINE: PHP_PODS_BEFORE=1 ===
--- 10 sequential phppp invokes (2s apart) ---
invoke 1: HTTP=200
invoke 2: HTTP=200
invoke 3: HTTP=200
invoke 4: HTTP=200
invoke 5: HTTP=200
invoke 6: HTTP=200
invoke 7: HTTP=200
invoke 8: HTTP=200
invoke 9: HTTP=200
invoke 10: HTTP=200
PHP_PODS_BEFORE=1
PHP_PODS_AFTER=2
NEW_PODS_CREATED=1
REUSE_WORKING=YES_REUSE_FIXED
```
**Интерпретация**:
- `NEW_PODS_CREATED=1` — ровно 1 pod создан для cold start первого invoke.
- invokes 210 полностью reuse тот же pod (`activeRequests` корректно 0→1→0 на каждый цикл).
- `REUSE_WORKING=YES_REUSE_FIXED` — условие `delta ≤ 1` выполнено.
**До patch (v1.22.0-multi-ns-9)**:
```
PHP_PODS_BEFORE=1 → PHP_PODS_AFTER=11
NEW_PODS_CREATED=10
REUSE_WORKING=NO
```
---
## Build и deploy summary
| Шаг | Команда / артефакт |
|-----|-------------------|
| Patch | `gpm.go`: добавлена строка `gpm.podLister[ns] = gpmInformer.Core().V1().Pods().Lister()` |
| Compile check | `go build ./pkg/executor/...` — ошибок нет |
| Commit | `0cae275 executor: update gpm.podLister in AddNamespace to fix IsValid nil panic` |
| Binary build | `CGO_ENABLED=0 GOOS=linux GOARCH=amd64 go build -o _build/linux_amd64/fission-bundle ./cmd/fission-bundle/` |
| Docker build | `naeel/fission-bundle:v1.22.0-multi-ns-10` |
| Docker push | `sha256:f3a054408e7ffe6e89ae2059614ece6250c0658154902b3b772236ccee89dafa` |
| Rollout executor | `kubectl set image deployment/executor executor=naeel/fission-bundle:v1.22.0-multi-ns-10 -n fission` |
| Rollout router | `kubectl set image deployment/router router=naeel/fission-bundle:v1.22.0-multi-ns-10 -n fission` |
| Rollout status | `deployment "executor" successfully rolled out` / `deployment "router" successfully rolled out` |
---
## История двух bugов в timeline
```
[Сессия 1]
Симптом: quota saturation + 504
Причина: quota limits слишком низкие + reuse не работает (оба бага)
Действие: поднята quota
[Сессия 2]
Симптом: phppp 10/10 200, но pods 1→11
Найден Bug #1: Generation отсутствует в TapService/UnTapService
Fix: добавлен Generation в client.go
Commit: 775845b
Image: v1.22.0-multi-ns-9
Результат: MarkAvailable теперь находит ключ, НО IsValid паникует → reuse всё ещё сломан
[Сессия 3 (текущая)]
Симптом: phppp 10/10 200, pods 1→11 (то же)
Найден Bug #2: gpm.podLister не обновляется в AddNamespace
Fix: добавлена одна строка в gpm.AddNamespace
Commit: 0cae275
Image: v1.22.0-multi-ns-10
Результат: phppp 10/10 200, pods 1→2 (1 cold start + 9 reuse) ✓
```
---
## Файлы затронутые в этом исследовании
| Файл | Роль | Изменён |
|------|------|---------|
| `pkg/crd/key.go` | Определение `CacheKeyURG`, `CacheKeyURGFromMeta` | Нет |
| `pkg/executor/client/client.go` | Router→executor HTTP client, `TapService`/`UnTapService` | Да (Bug #1, `775845b`) |
| `pkg/executor/api.go` | HTTP endpoints `/v2/getServiceForFunction`, `/v2/unTapService`, `/v2/tapServices` | Нет |
| `pkg/executor/executor.go` | `serveCreateFuncServices` goroutine, `createServiceForFunction` | Нет |
| `pkg/executor/fscache/functionServiceCache.go` | `GetFuncSvc`, `AddFunc`, `MarkAvailable` (delegating to PoolCache) | Нет |
| `pkg/executor/fscache/poolcache.go` | `activeRequests` accounting, `getValue`, `markAvailable` | Нет |
| `pkg/executor/executortype/poolmgr/gp.go` | `getFuncSvc`, `choosePod`, `specializePod`, `AddFunc` | Нет |
| `pkg/executor/executortype/poolmgr/gpm.go` | `IsValid`, `UnTapService`, `AddNamespace` | Да (Bug #2, `0cae275`) |
| `pkg/executor/executortype/poolmgr/poolpodcontroller.go` | `AddNamespaceInformers`, `podLister` для PoolPodController | Нет |
| `pkg/router/functionHandler.go` | `RoundTrip`, `unTapService`, `getServiceEntry` | Нет |
| `pkg/utils/namespace.go` | `DefaultNSResolver`, `NamespaceResolver` | Нет |
| `pkg/utils/informer.go` | `GetInformerFactoryByExecutor` | Нет |
---
## Ключевые инварианты для будущей поддержки
1. **`gpm.podLister` и `poolPodC.podLister` — два разных объекта.** При добавлении нового namespace нужно обновлять оба. Сейчас это обеспечено патчем.
2. **`CacheKeyURG` = `{UID + ResourceVersion + Generation}`.** Любой код, вызывающий `MarkAvailable` или `GetFuncSvc`, обязан передавать все три поля в `FnMetadata`.
3. **`activeRequests` — единственный критерий reuse.** Если он не возвращается к 0 (из-за паники, незавершённого UnTap и т.д.), pod навсегда "застревает" как занятый, а `listAvailableValue` (idle reaper) не уберёт его пока `activeRequests > 0`.
4. **poolmgr всегда ходит в executor** (`getServiceEntryFromExecutor`) для каждого invoke — кэш в router (`fmap`) для poolmgr не используется (см. `getServiceEntry`). Кэш живёт только на стороне executor в `connFunctionCache`.
5. **`requestsPerPod` default = 1.** Значит: один pod может обслуживать только один одновременный запрос. Для reuse нужно завершить предыдущий UnTap до следующего GetFuncSvc.
@@ -0,0 +1,353 @@
# Handoff: Fission poolmgr reuse still broken after partial fix
## Goal
Нужно разобраться, почему в live Fission при последовательных invoke одной и той же function с executor `poolmgr` executor каждый раз снова делает `choosePod + specializePod`, вместо reuse уже существующего specialized pod/function service.
Ключевой симптом:
- после завершения invoke resources не reuse-ятся для следующего вызова;
- executor продолжает создавать новый specialized pod почти на каждый invoke;
- для тяжелых функций это приводит к росту pod count и затем к timeout/504.
## Environment
- Local workspace: `/home/naeel/remote_dev/fission`
- Remote console repo: `/home/naeel/terra/fission`
- Remote Fission runtime repo: `/home/naeel/terra/fission-src`
- Live cluster access only via SSH:
```bash
ssh -i ~/.ssh/naeel_vm_id_ed25519 -o StrictHostKeyChecking=no -o ConnectTimeout=10 naeel@5.172.178.213 '...'
```
- Fission namespace: `fission`
- Live user namespace under test: `fission-ffd1f598c169b0ae`
## Functions under test
Namespace: `fission-ffd1f598c169b0ae`
- `phppp`
- env: `console-php-env`
- executor: `poolmgr`
- route: `/f598c169b0ae/phppp`
- `88`
- env: `console-python-env`
- executor: `poolmgr`
- route: `/f598c169b0ae/88`
HTTP invoke path used for live validation:
```bash
https://fission.kube5s.ru/fn/f598c169b0ae/phppp
https://fission.kube5s.ru/fn/f598c169b0ae/88
```
Valid user token used for direct invoke is in:
- `/home/naeel/remote_dev/terraform/TEST_STAND/POSTGRES/terraform.tfvars`
- remote mirror: `/home/naeel/terra/terraform/TEST_STAND/POSTGRES/terraform.tfvars`
## What was already found earlier
Изначально казалось, что проблема только в namespace quota saturation, потому что при многократных invoke возникали `504`, а quota по CPU/memory/pods реально упирались в потолок.
Но затем был найден реальный runtime bug:
- reuse key в executor uses `UID + ResourceVersion + Generation`
- `CacheKeyURGFromMeta(...)` in `pkg/crd/key.go`
- router/executor client path previously sent `FnMetadata` in `TapService`/`UnTapService` without `Generation`
- из-за этого `UnTapService -> MarkAvailable` не попадал в тот же cache key
- `activeRequests` не уменьшался у правильного cached function service
- следующий invoke видел cache miss и создавал новый specialized pod
### Previous fix already made
File changed in runtime repo:
- `pkg/executor/client/client.go`
Change:
- added `Generation: fnMeta.Generation` in `TapService(...)`
- added `Generation: fnMeta.Generation` in `UnTapService(...)`
Remote commit already made:
- `775845b executor: preserve generation in untap metadata`
## Important: this fix is already rolled out to live
New bundle image built and deployed:
- image: `naeel/fission-bundle:v1.22.0-multi-ns-9`
- digest: `sha256:5348bca2eacb78a030e639d7f4f7ac392369b6f702677ac47a69ea9f61f50a12`
Live deployment state after rollout:
- `router` image = `naeel/fission-bundle:v1.22.0-multi-ns-9`
- `executor` image = `naeel/fission-bundle:v1.22.0-multi-ns-9`
So: the `Generation` fix is **already in live**, but reuse is **still broken**.
## Current live reproduction
### `phppp`
Command pattern:
```bash
USER_TOKEN=$(grep -m1 '^api_token' /home/naeel/terra/terraform/TEST_STAND/POSTGRES/terraform.tfvars | sed -E 's/^api_token = "(.*)"$/\1/')
curl -sk -o /tmp/phppp.out -w '%{http_code}' --max-time 40 \
"https://fission.kube5s.ru/fn/f598c169b0ae/phppp" \
-H "Authorization: Bearer $USER_TOKEN"
```
Observed result:
- 10 of 10 invokes returned `200`
- BUT php specialized pod count grew from `1` to `11`
Exact observed summary:
- `PHP_PODS_BEFORE=1`
- invokes `1..10`: all `HTTP=200`
- `PHP_PODS_AFTER=11`
This proves:
- invoke itself works
- auth token is valid
- runtime is still specializing a new pod on each invoke instead of reusing
### `88`
Command pattern:
```bash
USER_TOKEN=$(grep -m1 '^api_token' /home/naeel/terra/terraform/TEST_STAND/POSTGRES/terraform.tfvars | sed -E 's/^api_token = "(.*)"$/\1/')
curl -sk -o /tmp/88.out -w '%{http_code}' --max-time 40 \
"https://fission.kube5s.ru/fn/f598c169b0ae/88" \
-H "Authorization: Bearer $USER_TOKEN"
```
Observed result:
- first 3 invokes returned `200`
- then invokes 4..10 returned `000` / timeout-like failure from curl
- python pod count grew from `1` to `4`
Exact observed summary:
- `PY_PODS_BEFORE=1`
- tries 1..3: `HTTP=200`
- tries 4..10: `HTTP=000`
- `PY_PODS_AFTER=4`
This suggests:
- same reuse bug path still exists for python too
- when function is heavier, pod growth quickly returns the original operational problem
## Most important executor logs
After rollout, executor logs still show for `phppp` on nearly every invoke:
- `choosing pod from pool`
- `relabel pod`
- `specializing pod`
- `added function service`
Example pattern repeated for each invoke:
```text
choosing pod from pool
relabel pod
chose pod ... poolmgr-console-php-env-...-5dcc862z4hm
calling fetcher to copy function
specializing pod
specialized pod ... podIP=172.16.1.80
added function service ... serviceHost=172.16.1.80:8888
choosing pod from pool
relabel pod
chose pod ... poolmgr-console-php-env-...-5dcc86k2zlk
calling fetcher to copy function
specializing pod
specialized pod ... podIP=172.16.3.209
added function service ... serviceHost=172.16.3.209:8888
choosing pod from pool
relabel pod
chose pod ... poolmgr-console-php-env-...-5dcc86ftzfp
calling fetcher to copy function
specializing pod
specialized pod ... podIP=172.16.3.52
added function service ... serviceHost=172.16.3.52:8888
```
That is, executor behavior in live clearly remains:
- no effective reuse of existing function service
- no steady-state one-pod serving repeated invokes
Also later there is only idle cleanup like:
```text
release idle function resources
function=phppp
address=172.16.2.155:8888
```
That confirms pods are being reaped later, but not reused immediately for next request.
## What is already ruled out
### Not an auth issue
- token from `terraform.tfvars` is valid
- direct `/fn/...` invoke works with bearer token
### Not just quota
- quota pressure was real earlier
- but now we have a cleaner reproduction where repeated invoke still creates new specialized pod even before total failure
- for `phppp`, 10 requests succeed but pod count still grows `1 -> 11`
### Not only missing `Generation` anymore
- `Generation` was indeed missing before
- that fix is already committed, built, deployed
- live logs prove reuse is still broken after that fix
## Highest-value question now
Where else in the path does executor fail to map the completion of request back to the existing cached function service?
In other words: why does `UnTapService -> MarkAvailable` still not make the current function service reusable for the next invoke?
## Narrow code path to inspect
Please focus on the smallest path controlling release/reuse:
- `pkg/router/functionHandler.go`
- request lifecycle
- `getServiceEntry`
- `unTapService`
- what metadata and service URL/address are sent back after request completes
- `pkg/executor/client/client.go`
- `TapService(...)`
- `UnTapService(...)`
- `pkg/executor/api.go`
- `/v2/getServiceForFunction`
- `/v2/unTapService`
- `/v2/tapServices`
- `pkg/executor/fscache/functionServiceCache.go`
- `GetFuncSvc`
- `AddFunc`
- `MarkAvailable`
- `TouchByAddress`
- `pkg/executor/fscache/poolcache.go`
- activeRequests accounting
- `markAvailable`
- `pkg/executor/executortype/poolmgr/gp.go`
- `getFuncSvc`
- `choosePod`
- `specializePod`
- `pkg/executor/executortype/poolmgr/gpm.go`
- `TapService`
- `UnTapService`
- idle reaper logic
- `pkg/crd/key.go`
- `CacheKeyURGFromMeta`
## Strong suspicion
There is still a mismatch in at least one of these dimensions:
1. metadata key used by cache lookup / mark available
2. service address format used for matching existing function service
3. path by which router reports completion back to executor
4. activeRequests decrement path in pool cache
5. tap/untap batching behavior versus per-request lifecycle
### Concrete symptoms that support this
- every next invoke still enters `choosePod`
- `added function service` repeats with new pod IP every time
- there is no visible log evidence that the just-used address became available in time for the next invoke
## Helpful concrete questions for investigation
1. Does router send the same logical function identity on `getServiceForFunction` and `unTapService` after the `Generation` fix, or is there still some field mismatch?
2. Is `serviceURL`/address normalized differently between tap and untap, so the address cannot match the cached function service?
3. Does `MarkAvailable` expect `serviceHost` without scheme while router sends full URL or vice versa?
4. Is `activeRequests` decremented on the same object/key that `GetFuncSvc` checks on the next invoke?
5. Could `TouchByAddress` / `MarkAvailable` be operating on a stale or different cache entry than `AddFunc` created?
6. Is the router definitely calling untap on successful invoke for these direct `/fn/...` requests?
7. Is there any race where the next invoke starts before previous untap is processed, making this appear as no reuse even for sequential calls with ~4-5s spacing?
8. For `phppp`, since calls are sequential and each lasts ~4s, why is a new pod still chosen 5 seconds later if previous invoke already completed?
## Useful live commands already used
Check live deployment images:
```bash
ssh -i ~/.ssh/naeel_vm_id_ed25519 -o StrictHostKeyChecking=no -o ConnectTimeout=10 naeel@5.172.178.213 \
'kubectl describe deploy router -n fission | sed -n "/Containers:/,/Conditions:/p"'
ssh -i ~/.ssh/naeel_vm_id_ed25519 -o StrictHostKeyChecking=no -o ConnectTimeout=10 naeel@5.172.178.213 \
'kubectl describe deploy executor -n fission | sed -n "/Containers:/,/Conditions:/p"'
```
Check function and trigger:
```bash
ssh -i ~/.ssh/naeel_vm_id_ed25519 -o StrictHostKeyChecking=no -o ConnectTimeout=10 naeel@5.172.178.213 \
'kubectl get function phppp -n fission-ffd1f598c169b0ae -o yaml | sed -n "1,220p"'
ssh -i ~/.ssh/naeel_vm_id_ed25519 -o StrictHostKeyChecking=no -o ConnectTimeout=10 naeel@5.172.178.213 \
'kubectl get httptrigger phppp-route -n fission-ffd1f598c169b0ae -o yaml | sed -n "1,220p"'
```
Live smoke used to prove bug remains:
```bash
ssh -i ~/.ssh/naeel_vm_id_ed25519 -o StrictHostKeyChecking=no -o ConnectTimeout=10 naeel@5.172.178.213 <<'SSH'
set -e
USER_TOKEN=$(grep -m1 '^api_token' /home/naeel/terra/terraform/TEST_STAND/POSTGRES/terraform.tfvars | sed -E 's/^api_token = "(.*)"$/\1/')
NS=fission-ffd1f598c169b0ae
BEFORE=$(kubectl get pods -n "$NS" --no-headers | grep 'poolmgr-console-php-env' | wc -l)
echo "PHP_PODS_BEFORE=$BEFORE"
for i in 1 2 3 4 5 6 7 8 9 10; do
code=$(curl -sk -o /tmp/phppp.out -w '%{http_code}' --max-time 40 "https://fission.kube5s.ru/fn/f598c169b0ae/phppp" -H "Authorization: Bearer $USER_TOKEN" || true)
body=$(tr '\n' ' ' </tmp/phppp.out 2>/dev/null | head -c 200 || true)
echo "TRY=$i HTTP=$code BODY=$body"
done
AFTER=$(kubectl get pods -n "$NS" --no-headers | grep 'poolmgr-console-php-env' | wc -l)
echo "PHP_PODS_AFTER=$AFTER"
SSH
```
Executor logs:
```bash
ssh -i ~/.ssh/naeel_vm_id_ed25519 -o StrictHostKeyChecking=no -o ConnectTimeout=10 naeel@5.172.178.213 \
'kubectl logs -n fission deploy/executor --since=15m | egrep "phppp| 88 |functionName=88|choosing pod from pool|specializing pod|added function service|marking function service|MarkAvailable|tapService|unTapService" | tail -n 240'
```
## What is wanted from Sonnet
Не просто общая гипотеза, а конкретно:
1. pinpoint the next exact root cause in code
2. explain why the already-deployed `Generation` fix was necessary but insufficient
3. propose the smallest correct patch
4. say exactly how to validate that patch in live
Best outcome:
- a minimal patch in one or a few files
- explanation of the failing cache/release path
- exact reason repeated invokes still go through `choosePod` after success of prior invoke
+47
View File
@@ -506,3 +506,50 @@
- Deployment обновлен и успешно прокатан.
- Проверено в live HTML: отдается
- `<link rel="icon" type="image/png" href="https://nubes.ru/themes/custom/nubes_2025/favicon.png">`.
---
## 2026-04-27
### Сессия: poolmgr reuse fix (Bug #1 + Bug #2) + console cleanup
#### Bug #1 — Generation в TapService/UnTapService (`client.go`, commit `775845b`)
- Симптом: 10/10 HTTP 200, но pod count рос 1→11 (новый pod на каждый invoke).
- Root cause: `Generation` не передавался в `TapService`/`UnTapService`. `MarkAvailable` строил ключ `{UID, RV, Generation=0}` вместо `{UID, RV, Generation=1}``activeRequests` никогда не декрементировался → всегда cache miss.
- Fix: добавить `Generation: fnMeta.Generation` в оба вызова в `pkg/executor/client/client.go`.
- Image: `naeel/fission-bundle:v1.22.0-multi-ns-9`.
#### Bug #2 — `gpm.podLister[ns]` nil для user namespace (`gpm.go`, commit `0cae275`)
- Симптом: после Bug #1 fix — reuse всё ещё не работал.
- Root cause: `AddNamespace` обновлял только `poolPodC.podLister[ns]`, но не `gpm.podLister[ns]`. `IsValid` вызывал `gpm.podLister[ns].Pods(...).Get(...)` → nil pointer panic → net/http рвал соединение → router retry → `activeRequests=1` (stuck) → cache miss → новый pod.
- Fix: добавить одну строку в `AddNamespace` в `pkg/executor/executortype/poolmgr/gpm.go`:
```go
gpm.podLister[ns] = gpmInformer.Core().V1().Pods().Lister()
```
- Image: `naeel/fission-bundle:v1.22.0-multi-ns-10`.
- Live validation: `PHP_PODS_BEFORE=1 → PHP_PODS_AFTER=2, NEW_PODS_CREATED=1, REUSE_WORKING=YES_REUSE_FIXED`.
- Postmortem: `doc/POOLMGR_REUSE_BUG_POSTMORTEM_2026-04-27.md`.
#### Console: убрана карточка тайм-триггеров (`console/ui/index.html`, commit `96a02b4`)
- Убрана карточка "Тайм-триггеры" из dashboard (счётчик `0`).
- Убраны JS-строки: `getJSON('/timetriggers')`, `setText('time-count', ...)`, `const [..., time]`.
- Образ: `naeel/fission-console:v1.1` (sha256:0713fee1...).
- Деплой: `kubectl set image deployment/fission-console console=naeel/fission-console:v1.1 -n fission`.
- **Важно**: container name в deployment = `console` (не `fission-console`!).
#### TODO: тайм-триггеры (не реализовано, отложено)
Нужно реализовать:
1. Поле "Cron" в форме создания функции (или отдельная форма/таблица)
2. `POST /console/api/timetriggers` → handler `handleCreateTimeTrigger`
3. `DELETE /console/api/timetriggers/:name` → handler
4. `model.CreateTimeTriggerRequest {Name, FunctionName, Cron string}`
5. CRD builder: `fission.io/v1` kind `TimeTrigger`, spec: `{cron, functionref: {name, namespace}}`
6. Таблица тайм-триггеров в UI с колонками: имя, функция, расписание, удалить
#### Текущее состояние live кластера
- Fission bundle: `naeel/fission-bundle:v1.22.0-multi-ns-10` (executor + router)
- Console: `naeel/fission-console:v1.1`
- User namespace: `fission-ffd1f598c169b0ae`
- Функции: `88` (Python), `88node` (Node.js), `phppp` (PHP), `rub` (Ruby)
- Маршруты: `/f598c169b0ae/{name}`
- SSH: `naeel@5.172.178.213`, key `~/.ssh/naeel_vm_id_ed25519`
- Token: `grep -m1 "^api_token" /home/naeel/terra/terraform/TEST_STAND/POSTGRES/terraform.tfvars | sed -E "s/^api_token = \"(.*)\"$/\1/"`
+10
View File
@@ -0,0 +1,10 @@
api_token = "eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJhdXRoLWFwaSIsInN1YiI6IjAxOWNjMjY4LTZjNmEtNzgxZS04NjEzLTRiZWQ0ZWM3Y2QyMCIsImV4cCI6MTc4OTAxNTg2NywiaWF0IjoxNzczNDYzODY3LCJqdGkiOiJmYjRkMGFiNy1lYT>
# s3_uid = "332cdb0d-34bf-43bf-864d-4adcc3b556fc"
s3_uid = "332cdb0d-34bf-43bf-864d-4adcc3b556fb"
# realm = "k8s-5-sandbox-nubes-ru"
realm = "k8s-3-sandbox-nubes-ru"
#realm = "naeel-test-3"
eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJhdXRoLWFwaSIsInN1YiI6IjAxOWNjMjY4LTZjNmEtNzgxZS04NjEzLTRiZWQ0ZWM3Y2QyMCIsImV4cCI6MTc4OTAxNTg2Nywia