From c580101f0cee9f0f2291547939ded3291fc49d31 Mon Sep 17 00:00:00 2001 From: Naeel Date: Sat, 11 Apr 2026 20:19:28 +0300 Subject: [PATCH] =?UTF-8?q?doc:=20=D0=B0=D0=BD=D0=B0=D0=BB=D0=B8=D0=B7=20?= =?UTF-8?q?=D0=B4=D0=B5=D0=B3=D1=80=D0=B0=D0=B4=D0=B0=D1=86=D0=B8=D0=B8=20?= =?UTF-8?q?=D0=BD=D0=B0=20=D0=B1=D0=BE=D0=BB=D1=8C=D1=88=D0=B8=D1=85=20pay?= =?UTF-8?q?load=20(3=20root=20causes)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - json.Marshal(queue) сериализует ВСЕ сообщения под Lock — O(N*msg_size) - log.Infof логирует полное тело каждого сообщения (256KB на запись) - CPU limit 500m вызывает K8s CFS throttling на тяжёлых операциях - PeriodicTasks держит глобальный Lock каждую секунду - Баг: MessageDoesNotExist возвращает Code=QueueExists --- doc/thinking/2026-04-11.md | 122 +++++++++++++++++++++++++++++++++++++ 1 file changed, 122 insertions(+) diff --git a/doc/thinking/2026-04-11.md b/doc/thinking/2026-04-11.md index fe1c6d8..a79fc66 100644 --- a/doc/thinking/2026-04-11.md +++ b/doc/thinking/2026-04-11.md @@ -296,3 +296,125 @@ no persistence, no auth. shared-sqs закрывает уникальную ни **Формат:** bash скрипт `tests/benchmark_full.sh`, запуск из локали, вывод CSV + итоговая таблица в stdout. + +--- + +## Сессия 3 — Анализ производительности большого payload +### Agent: GitHub Copilot (Claude Opus 4.6) + +### Результаты бенчмарка (ключевые) +| Размер | Yandex MQ (ms) | Наш (ms) | Отношение | +|--------|---------------|----------|-----------| +| 1 KB | 1161 | 1063 | **мы быстрее** | +| 10 KB | ~1160 | ~2000* | ~1.7x медленнее | +| 64 KB | 1177 | 11847 | **10x медленнее** | +| 256 KB | 1159 | 27088 | **23x медленнее** | + +Также: invalid receipt handle — 6106ms (наш) vs 1069ms (Yandex). + +### Расследование — большие payload + +#### Где живёт проблема: путь SendMessage для 256KB сообщения + +1. HTTP запрос → nginx ingress (TLS termination) → pod:4100 +2. `req.ParseForm()` — парсит form body (260KB+ URL-encoded) +3. Валидации, создание `SqsMessage` +4. **`models.SyncQueues.Lock()`** — глобальный мьютекс +5. Добавление сообщения в `queue.Messages` (append к слайсу) +6. **`persistence.SaveQueue(key, queue)`** — ЗДЕСЬ ПРОБЛЕМА #1 +7. `models.SyncQueues.Unlock()` +8. **`log.Infof("...Message: %s", msg.MessageBody)`** — ЗДЕСЬ ПРОБЛЕМА #2 +9. Формирование XML-ответа, return + +#### ПРОБЛЕМА #1: `json.Marshal(queue)` сериализует ВСЮ очередь + +Файл: `app/persistence/redis.go:89` + +```go +func SaveQueue(key string, queue *models.Queue) { + data, err := json.Marshal(queue) // <-- СЕРИАЛИЗАЦИЯ ВСЕХ СООБЩЕНИЙ + ... + asyncWrite(func() { Client.HSet(..., string(data)) }) +} +``` + +`json.Marshal(queue)` вызывается **синхронно под глобальным Lock**. Он сериализует +**ВСЮ** структуру Queue, включая **ВСЕ** сообщения с их телами. + +Во время бенчмарка раздела "Message sizes": +- Отправляются 3×1K + 3×10K + 3×64K + 3×256K сообщения +- Сообщения НАКАПЛИВАЮТСЯ (purge только в конце секции) +- К моменту 3-й отправки 256KB: в очереди уже ~225KB + 512KB предыдущих = ~737KB JSON +- Каждый SendMessage пере-сериализует ВСЮ эту массу + +**Это O(N × msg_size) на каждую write-операцию.** Yandex хранит сообщения отдельно → O(msg_size). + +#### ПРОБЛЕМА #2: Логирование полного тела сообщения + +Файл: `app/gosqs/send_message.go:123` + +```go +log.Infof("%s: Queue: %s, Message: %s\n", time.Now().Format("..."), queueName, msg.MessageBody) +``` + +- Логирует **ПОЛНОЕ тело** каждого сообщения на уровне INFO +- С `log.JSONFormatter{}` — каждая запись = JSON с 256KB строкой внутри +- Это синхронная запись в stdout → containerd → диск +- Для 256KB сообщения: ~256KB лог-запись на КАЖДЫЙ SendMessage + +#### ПРОБЛЕМА #3: CPU throttling (500m лимит) + +Файл: `deployments/k8s/deployment.yaml:58` + +```yaml +resources: + limits: + memory: "256Mi" + cpu: "500m" # <-- 0.5 ядра! +``` + +- `json.Marshal` 700KB+ и `log.Infof` с JSON форматированием — CPU-intensive операции +- При лимите 500m (0.5 ядра) K8s CFS throttling добавляет непредсказуемые задержки +- Для мелких сообщений CPU хватает, для больших — throttling kicks in + +### Расследование — invalid receipt handle (6106ms) + +#### Что нашёл: + +1. **`PeriodicTasks` держит глобальный Lock каждую секунду** (`app/cmd/goaws.go:134`) + - `go gosqs.PeriodicTasks(1*time.Second, quit)` — каждую секунду! + - Берёт `SyncQueues.Lock()`, итерирует ВСЕ очереди и ВСЕ сообщения + - Во время бенчмарка (много очередей/сообщений от предыдущих секций) — долго держит Lock + - `DeleteMessageV1` тоже берёт Lock → ждёт пока PeriodicTasks отпустит + +2. **Единственное измерение** — бенчмарк делает 1 замер на ошибку, без усреднения + - Возможен выброс из-за попадания на PeriodicTasks lock contention + +3. **Баг в коде ошибок** (`app/models/errors.go:9`) + ```go + "MessageDoesNotExist": {HttpError: http.StatusNotFound, Code: "AWS.SimpleQueueService.QueueExists", ...} + ``` + - Code = `QueueExists` вместо `ReceiptHandleIsInvalid` — copy-paste баг + - Не влияет на latency, но нарушает AWS-совместимость + +### Рекомендуемые исправления + +#### Критические (влияют на benchmark в 10-23x): + +1. **НЕ логировать тело сообщения** — заменить на: + ```go + log.Infof("Queue: %s, MessageId: %s, Size: %d bytes", queueName, msg.Uuid, len(messageBody)) + ``` + +2. **Хранить сообщения отдельно в Redis** — вместо `json.Marshal(entire_queue)`: + - Queue metadata → `ssq:queue:{key}` (без Messages) + - Каждое сообщение → `ssq:msg:{key}:{uuid}` (отдельно) + - Это убирает O(N × msg_size) деградацию + +3. **Увеличить CPU limit** — минимум 1000m (1 ядро), лучше 2000m + +#### Средние (улучшат общую отзывчивость): + +4. **Per-queue lock вместо глобального** — `sync.RWMutex` на каждый Queue +5. **PeriodicTasks: RLock где возможно** — для read-only проверок +6. **Исправить error code** — `MessageDoesNotExist` → `ReceiptHandleIsInvalid`