SRE на практике: три истории

Теория SRE полезна, но настоящее понимание приходит через опыт. В этой статье — три реалистичных кейса из production. Каждый включает контекст, обнаружение, пошаговую диагностику, решение и postmortem с конкретными метриками.

Case 1: API latency скачок до 5 секунд

Контекст

E-commerce платформа. PHP 8.4 + Symfony, PostgreSQL 16, Redis 7. Монолитный API обслуживает мобильное приложение и веб-фронтенд. Пиковая нагрузка — 500 RPS, среднее время ответа — 80ms. В команде 12 разработчиков, on-call ротация из 4 SRE.

Мониторинг: Prometheus + Grafana, алерты через AlertManager → PagerDuty. SLO: 99.9% запросов быстрее 500ms.

Обнаружение

Понедельник, 09:47 UTC. PagerDuty будит дежурного инженера:

FIRING: HighLatencyP99
Service: api-production
p99 latency: 5247ms (threshold: 500ms)
Duration: 7 minutes
Dashboard: https://grafana.internal/d/api-red

Параллельно в Slack #incidents канале — сообщения от support: «Пользователи жалуются на тормоза в каталоге товаров, страница грузится 10+ секунд».

Диагностика

09:49 — Дежурный открывает Grafana RED-дашборд:

Before incident:          During incident:
┌────────────────────┐    ┌────────────────────┐
│ RPS: 480           │    │ RPS: 510           │
│ Error rate: 0.1%   │    │ Error rate: 4.2%   │
│ p50: 45ms          │    │ p50: 120ms         │
│ p95: 150ms         │    │ p95: 3400ms        │
│ p99: 210ms         │    │ p99: 5247ms        │
└────────────────────┘    └────────────────────┘

RPS практически не изменился — значит, проблема не в росте трафика. Error rate вырос с 0.1% до 4.2% — часть запросов падают по таймауту.

09:51 — Drill down по endpoints. PromQL:

topk(5,
  histogram_quantile(0.99,
    sum by (le, handler) (rate(http_request_duration_seconds_bucket[5m]))
  )
)

Результат: endpoint GET /api/v1/products — p99 = 5.2s, остальные endpoints в норме.

09:53 — Переход к трейсам. В Jaeger находим трейс проблемного запроса:

Trace ID: 7a8b9c0d...
[GET /api/v1/products]──────────────────── 5180ms
 ├── [Auth Middleware]────── 3ms
 ├── [ProductController]──────────────── 5170ms
 │    ├── [Doctrine: SELECT products]────────── 5150ms  ← BOTTLENECK
 │    ├── [Redis: get cache]── 2ms (MISS)
 │    └── [Serializer]── 12ms
 └── [Response]── 2ms

Doctrine query занимает 5.15 секунд. Cache miss — значит, данные не закешированы (или кеш был сброшен).

09:55 — Подключение к PostgreSQL, проверка медленных запросов:

-- Check pg_stat_statements for slow queries
SELECT query, calls, mean_exec_time, max_exec_time
FROM pg_stat_statements
WHERE mean_exec_time > 1000
ORDER BY mean_exec_time DESC
LIMIT 5;

Находим виновника:

SELECT p.*, c.name as category_name,
       COUNT(r.id) as review_count, AVG(r.rating) as avg_rating
FROM products p
JOIN categories c ON c.id = p.category_id
LEFT JOIN reviews r ON r.product_id = p.id
WHERE p.is_active = true
  AND p.category_id IN (SELECT id FROM categories WHERE parent_id = $1)
GROUP BY p.id, c.name
ORDER BY p.created_at DESC
LIMIT 50;

-- mean_exec_time: 4890ms, calls: 1247 (за последний час)

09:57 — EXPLAIN ANALYZE:

EXPLAIN (ANALYZE, BUFFERS) SELECT ...;

-- Результат (сокращённо):
Sort  (cost=89432.12 rows=50)
  -> Hash Join  (cost=78213.45 rows=12847)
       -> Seq Scan on reviews  (cost=0.00 rows=2847123)  ← FULL TABLE SCAN!
            Filter: (product_id = ANY ...)
            Rows Removed by Filter: 2834576
       -> Hash  (cost=1234.56 rows=487)
            -> Seq Scan on products
                 Filter: (is_active = true AND category_id = ANY(...))

Planning Time: 2.1ms
Execution Time: 4891.3ms

Seq Scan на таблице reviews (2.8M строк). Нет индекса на reviews.product_id.

09:59 — Проверка истории миграций:

# Check recent migrations
ls -la migrations/ | tail -5

Находим: миграция от пятницы Version20260228_AddReviewsTable.php создала таблицу reviews, но не добавила индекс на product_id. В пятницу таблица была пустой, запросы работали быстро. За выходные импорт данных загрузил 2.8M отзывов, и без индекса запрос стал full table scan.

Решение

10:02 — Создание индекса (CONCURRENTLY, без блокировки таблицы):

-- Non-blocking index creation
CREATE INDEX CONCURRENTLY idx_reviews_product_id ON reviews (product_id);

-- Execution time: 47 seconds (2.8M rows)

10:03 — Проверка EXPLAIN ANALYZE после индекса:

EXPLAIN (ANALYZE, BUFFERS) SELECT ...;

-- Index Scan using idx_reviews_product_id on reviews
-- Execution Time: 12.3ms

10:04 — Сброс Redis кеша для продуктов:

redis-cli KEYS "products:*" | xargs redis-cli DEL

10:05 — Проверка Grafana: p99 latency вернулся к 85ms, error rate 0.1%.

Метрики до/после

Postmortem

Timeline:

Root Cause: Миграция создала таблицу reviews без индекса на product_id. Это не было заметно при пустой таблице, но после загрузки 2.8M строк привело к full table scan.

Action Items:

Уроки

1. Всегда проверяй EXPLAIN ANALYZE после миграции — пустая таблица не покажет проблему
2. Индексы на FK — обязательны, CI должен это проверять
3. Мониторинг slow queries (pg_stat_statements) должен быть настроен
4. Cold cache после выходных — распространённый триггер для latency-проблем

Case 2: Out of Memory kills каждые 2 часа

Контекст

Микросервис на Go 1.23, обрабатывает сообщения из RabbitMQ — обогащение данных из внешних API и сохранение в PostgreSQL. Запущен в Kubernetes (resource limits: 512Mi RAM, 200m CPU). Обрабатывает ~200 сообщений/секунду. В команде 6 разработчиков.

Мониторинг: Prometheus + Grafana, контейнерные метрики через cAdvisor.

Обнаружение

Среда, 14:22 UTC. Алерт в Slack:

FIRING: PodRestartingTooOften
Pod: enrichment-service-7b4d9f8c6-x2k9m
Restarts in last hour: 6
Restart reason: OOMKilled

Проверка истории:

$ kubectl get events --sort-by='.lastTimestamp' | grep OOM

14:22  OOMKilled  enrichment-service-7b4d9f8c6-x2k9m
12:18  OOMKilled  enrichment-service-7b4d9f8c6-x2k9m
10:15  OOMKilled  enrichment-service-7b4d9f8c6-x2k9m
08:12  OOMKilled  enrichment-service-7b4d9f8c6-x2k9m

Контейнер убивается каждые ~2 часа. Паттерн стабильный — классическая утечка памяти.

Диагностика

14:25 — Grafana: график потребления памяти контейнера:

Memory Usage (container_memory_working_set_bytes)

512Mi ┤                          ╱ OOM ╱ OOM ╱ OOM
      │                        ╱     ╱     ╱
400Mi ┤                      ╱     ╱     ╱
      │                    ╱     ╱     ╱
300Mi ┤                  ╱     ╱     ╱
      │                ╱     ╱     ╱
200Mi ┤              ╱     ╱     ╱
      │            ╱     ╱     ╱
100Mi ┤──────────╱     ╱     ╱
      │  start        restart  restart
      └──────┬─────────┬────────┬──────── time
           08:00     10:15    12:18

Линейный рост памяти — утечка подтверждена. Память растёт с ~100Mi до 512Mi за ~2 часа.

Скорость утечки: (512 - 100) / 120 мин ≈ 3.4 Mi/мин.

14:28 — Включение pprof для профилирования. Сервис уже экспортирует pprof (стандартная практика для Go):

import _ "net/http/pprof"

go func() {
    http.ListenAndServe(":6060", nil)
}()

Port-forward к поду:

kubectl port-forward pod/enrichment-service-7b4d9f8c6-x2k9m 6060:6060

14:30 — Снимаем heap profile:

# Snapshot 1
go tool pprof http://localhost:6060/debug/pprof/heap
(pprof) top 10

Showing top 10 nodes out of 87
      flat  flat%   sum%        cum   cum%
  180.50MB 42.3%  42.3%   180.50MB 42.3%  net/http.(*Transport).dialConn
   95.20MB 22.3%  64.6%    95.20MB 22.3%  bufio.NewReaderSize
   45.80MB 10.7%  75.3%    45.80MB 10.7%  bufio.NewWriterSize
   32.10MB  7.5%  82.8%    32.10MB  7.5%  bytes.makeSlice

42.3% памяти в dialConn — создаются HTTP-подключения, но не закрываются.

14:32 — Goroutine profile:

go tool pprof http://localhost:6060/debug/pprof/goroutine
(pprof) top 5

   3847  67.2%  67.2%     3847  67.2%  net/http.(*persistConn).readLoop
   3847  67.2%          3847  67.2%  net/http.(*persistConn).writeLoop
    412   7.2%  81.6%     412   7.2%  runtime.gopark

3847 goroutine в readLoop — каждое незакрытое HTTP-соединение создаёт goroutine, которая ждёт данные. Это goroutine leak.

14:35 — Поиск в коде. Находим проблемное место:

::code-group

package enricher

import (
	"encoding/json"
	"fmt"
	"net/http"
)

// EnrichData fetches additional data from external API.
// BUG: response body is never closed — causes goroutine and memory leak.
func (e *Enricher) EnrichData(itemID string) (*EnrichedData, error) {
	resp, err := http.Get(fmt.Sprintf("%s/api/items/%s", e.apiURL, itemID))
	if err != nil {
		return nil, fmt.Errorf("fetch item %s: %w", itemID, err)
	}

	// BUG: resp.Body is NEVER closed!
	// Each unclosed body keeps:
	//   - TCP connection open (fd leak)
	//   - readLoop goroutine alive (goroutine leak)
	//   - bufio.Reader allocated (memory leak)

	if resp.StatusCode != http.StatusOK {
		return nil, fmt.Errorf("unexpected status: %d", resp.StatusCode)
	}

	var data EnrichedData
	if err := json.NewDecoder(resp.Body).Decode(&data); err != nil {
		return nil, fmt.Errorf("decode response: %w", err)
	}

	return &data, nil
}

::

Проблема: resp.Body.Close() никогда не вызывается. При 200 сообщениях/секунду это 200 незакрытых соединений/секунду = 12000/мин = 720000/час. Каждое соединение ~200 байт + goroutine ~8KB = ~1.6GB/час утечки (ОС успевает закрыть часть по таймауту, поэтому реально ~3.4MB/мин).

Дополнительная проблема: при ошибочном статусе (не 200) тело тоже не читается и не закрывается — это блокирует повторное использование TCP-соединения.

Решение

::code-group

package enricher

import (
	"context"
	"encoding/json"
	"fmt"
	"io"
	"net"
	"net/http"
	"time"
)

// NewEnricher creates an enricher with a properly configured HTTP client.
func NewEnricher(apiURL string) *Enricher {
	return &Enricher{
		apiURL: apiURL,
		client: &http.Client{
			Timeout: 10 * time.Second, // global timeout
			Transport: &http.Transport{
				MaxIdleConns:        100,
				MaxIdleConnsPerHost: 20,
				IdleConnTimeout:     90 * time.Second,
				DialContext: (&net.Dialer{
					Timeout:   5 * time.Second,
					KeepAlive: 30 * time.Second,
				}).DialContext,
			},
		},
	}
}

// EnrichData fetches additional data from external API with proper resource cleanup.
func (e *Enricher) EnrichData(ctx context.Context, itemID string) (*EnrichedData, error) {
	req, err := http.NewRequestWithContext(ctx, http.MethodGet,
		fmt.Sprintf("%s/api/items/%s", e.apiURL, itemID), nil)
	if err != nil {
		return nil, fmt.Errorf("create request for item %s: %w", itemID, err)
	}

	resp, err := e.client.Do(req)
	if err != nil {
		return nil, fmt.Errorf("fetch item %s: %w", itemID, err)
	}
	// FIX: ALWAYS close body, even on error paths
	defer resp.Body.Close()

	if resp.StatusCode != http.StatusOK {
		// FIX: drain body before close to enable connection reuse
		_, _ = io.Copy(io.Discard, resp.Body)
		return nil, fmt.Errorf("unexpected status for item %s: %d", itemID, resp.StatusCode)
	}

	var data EnrichedData
	if err := json.NewDecoder(resp.Body).Decode(&data); err != nil {
		return nil, fmt.Errorf("decode response for item %s: %w", itemID, err)
	}

	return &data, nil
}

::

Ключевые исправления:

1. defer resp.Body.Close() — обязательное закрытие тела ответа
2. io.Copy(io.Discard, resp.Body) — дренаж тела при ошибке для повторного использования TCP-соединения
3. http.NewRequestWithContext(ctx, ...) — отмена через context вместо бесконечного ожидания
4. Настроенный http.Transport — лимиты на idle connections, таймауты
5. http.Client{Timeout: 10s} — глобальный таймаут на весь запрос

Дополнительно — алерт на goroutine count:

# alerts/goroutine-leak.yml
groups:
  - name: go-runtime
    rules:
      - alert: GoroutineLeakSuspected
        expr: |
          go_goroutines > 500
          and
          deriv(go_goroutines[30m]) > 0.5
        for: 15m
        labels:
          severity: ticket
        annotations:
          summary: "Goroutine count growing steadily"
          description: "{{ $labels.instance }}: {{ $value }} goroutines, trend is positive"

      - alert: MemoryLeakSuspected
        expr: |
          deriv(process_resident_memory_bytes[1h]) > 1e6
        for: 30m
        labels:
          severity: ticket
        annotations:
          summary: "Memory growing by >1MB/hour steadily"

Метрики до/после

Postmortem

Timeline:

Root Cause: В модуле enrichment не закрывалось тело HTTP-ответа (resp.Body.Close()), что приводило к утечке goroutine, TCP-соединений и памяти.

Action Items:

Уроки

1. defer resp.Body.Close() — всегда, сразу после проверки ошибки http.Do()
2. pprof в production — обязательно для Go-сервисов (на отдельном порту)
3. Увеличение лимитов — не решение, а маскировка проблемы
4. bodyclose linter ловит эту ошибку автоматически — включите в CI
5. Алерт на тренд (deriv) важнее алерта на абсолютное значение

Case 3: Cascade failure при обновлении зависимости

Контекст

Multi-service архитектура: 8 Go-микросервисов, PostgreSQL 16, Redis 7, RabbitMQ 3.13. Общение между сервисами — gRPC с circuit breaker (gobreaker). Kubernetes, 3 ноды. Трафик: 2000 RPS на входе (API Gateway). SLO: 99.95% availability.

                    ┌──────────┐
                    │   Users  │
                    └────┬─────┘
                         │
                    ┌────▼─────┐
                    │  API GW  │  (2000 RPS)
                    └──┬───┬───┘
                  ┌────┘   └────┐
            ┌─────▼──┐    ┌────▼────┐
            │ Svc A  │    │  Svc B  │
            │(orders)│    │(catalog)│
            └──┬──┬──┘    └────┬────┘
          ┌────┘  └───┐       │
     ┌────▼──┐   ┌───▼───┐  ┌▼───────┐
     │ Svc C │   │ Svc D │  │ Svc E  │
     │(payment)  │(invent)│  │(search)│
     └───────┘   └──┬────┘  └────────┘
                    │
               ┌────▼──┐   ┌────────┐   ┌────────┐
               │ Svc F │   │ Svc G  │   │ Svc H  │
               │(ship) │   │(notify)│   │(analytics)
               └───────┘   └────────┘   └────────┘

Обнаружение

Четверг, 11:15 UTC. Деплой Service A (orders) v3.8.0 — обновление библиотеки PostgreSQL-драйвера pgx с v5.5 на v5.7. Деплой прошёл зелёный — health check OK, readiness probe OK.

11:23 UTC (через 8 минут). Каскад алертов:

11:23 FIRING: HighErrorRate     service=api-gateway    error_rate=12%
11:24 FIRING: HighLatencyP99    service=svc-a-orders   p99=31200ms
11:24 FIRING: CircuitBreakerOpen service=svc-c-payment  state=open
11:25 FIRING: HighErrorRate     service=svc-d-inventory error_rate=8%
11:25 FIRING: CircuitBreakerOpen service=svc-d-inventory state=open
11:26 FIRING: HighErrorRate     service=svc-b-catalog   error_rate=5%
11:27 FIRING: SLOBudgetBurning  burn_rate=142x          remaining=0.3%

За 4 минуты — 7 алертов от 5 разных сервисов. Availability упала с 99.95% до 38%.

Диагностика

11:28 — Инцидент объявлен (SEV1). Собрана incident team (3 человека).

11:29 — Grafana overview dashboard:

API Gateway:
┌─────────────────────────────────────┐
│ RPS:  2000 → 2100 (норма)          │
│ Errors: 0.05% → 12% → 34% → 62%   │
│ p99:  180ms → 30s → timeout        │
└─────────────────────────────────────┘

Cascade timeline:
11:15  Deploy Svc A v3.8.0
11:20  Svc A: p99 starts climbing (200ms → 5s → 15s → 30s)
11:23  Svc C, D: circuit breakers open (Svc A не отвечает)
11:25  API GW: requests queueing (connection pool exhausted)
11:27  Svc B, E: degraded (shared API GW connection pool)

11:30 — Фокус на Service A. Трейс показывает:

Trace ID: e4f5a6b7...
[Svc A: POST /orders]────────────────────── 30120ms (TIMEOUT)
 ├── [Validate request]──── 2ms
 ├── [DB: INSERT order]────────────────────── 30001ms  ← STUCK
 │    (waiting for connection from pool)
 └── [TIMEOUT]

Service A ждёт подключение к БД. Connection pool исчерпан.

11:32 — Метрики connection pool Service A:

# Active connections (should be <= pool size 20)
pgx_conns_total_size{service="svc-a"} = 20

# Idle connections (should be > 0)
pgx_conns_idle{service="svc-a"} = 0

# Waiting for connection
pgx_conns_waiters{service="svc-a"} = 847  ← 847 goroutine ждут коннект!

Все 20 соединений заняты, 847 goroutine в очереди. Но почему?

11:34 — Проверка PostgreSQL активных запросов:

SELECT pid, state, wait_event, query, now() - query_start as duration
FROM pg_stat_activity
WHERE datname = 'orders' AND state != 'idle'
ORDER BY duration DESC;

 pid  | state  | wait_event | duration | query
------+--------+------------+----------+----------------------------------
 1234 | active | ClientRead | 00:19:12 | INSERT INTO orders ...
 1235 | active | ClientRead | 00:18:47 | UPDATE orders SET ...
 1236 | active | ClientRead | 00:18:33 | SELECT * FROM orders WHERE ...
 ...  | ...    | ...        | ...      | ...
 (20 rows — all stuck on ClientRead)

Все 20 соединений в состоянии ClientRead — PostgreSQL ждёт данные от клиента, но клиент не отправляет. Это connection leak — соединения берутся из pool, но не возвращаются.

11:36 — Анализ разницы между pgx v5.5 и v5.7. Находим breaking change:

pgx v5.6.0 CHANGELOG:
- Changed: Pool.Acquire now returns *Conn instead of *ConnResource
- Changed: Conn.Release() must be called explicitly;
  automatic release on context cancellation REMOVED

В v5.5 при отмене context (timeout) соединение автоматически возвращалось в pool. В v5.7 это поведение убрано — нужен явный defer conn.Release().

Код Service A:

// This worked in pgx v5.5 (auto-release on ctx cancel)
// but LEAKS connections in pgx v5.7
func (r *OrderRepo) Create(ctx context.Context, order *Order) error {
    conn, err := r.pool.Acquire(ctx)
    if err != nil {
        return err
    }
    // Missing: defer conn.Release()

    _, err = conn.Exec(ctx, "INSERT INTO orders ...")
    if err != nil {
        return err // connection LEAKED — never returned to pool
    }

    conn.Release() // only released on success path
    return nil
}

При ошибке conn.Release() не вызывается. В v5.5 context cancellation возвращал соединение. В v5.7 — нет.

Каскадный эффект

1. Svc A: connection pool exhausted (20/20 busy, 847 waiting)
   ↓
2. Svc A: все запросы висят 30s (ждут pool) → timeout
   ↓
3. Svc C (payment), Svc D (inventory): ждут ответ от Svc A
   Circuit breaker threshold: 5 failures in 10s
   После 5 таймаутов → circuit breaker OPEN → все запросы к Svc A rejected
   ↓
4. API Gateway: connection pool к Svc A исчерпан
   Goroutine waiting for Svc A блокируют worker pool
   Запросы к Svc B, E тоже начинают queuing
   ↓
5. Полная деградация: 62% запросов — ошибки

Решение

11:38 — Немедленный rollback Service A на v3.7.0:

kubectl rollout undo deployment/svc-a-orders

11:39 — Проверка:

Svc A: connection pool recovering (idle: 15/20)
Circuit breakers: half-open → closed
Error rate: 62% → 8% → 0.3% → 0.05%

11:42 — Полное восстановление. Все метрики в норме.

11:45 — Инцидент closed. Начало работы над fix.

Следующий день (пятница) — исправление кода:

::code-group

package repo

import (
	"context"
	"fmt"

	"github.com/jackc/pgx/v5/pgxpool"
)

// Create inserts a new order with proper connection lifecycle.
func (r *OrderRepo) Create(ctx context.Context, order *Order) error {
	conn, err := r.pool.Acquire(ctx)
	if err != nil {
		return fmt.Errorf("acquire connection: %w", err)
	}
	// FIX: ALWAYS defer Release — works on both success and error paths
	defer conn.Release()

	_, err = conn.Exec(ctx,
		"INSERT INTO orders (id, user_id, total, status) VALUES ($1, $2, $3, $4)",
		order.ID, order.UserID, order.Total, order.Status,
	)
	if err != nil {
		return fmt.Errorf("insert order: %w", err)
	}

	return nil
}

::

Дополнительные меры:

// Circuit breaker tuning (gobreaker settings)
cb := gobreaker.NewCircuitBreaker(gobreaker.Settings{
    Name:        "svc-a-orders",
    MaxRequests: 3,                     // in half-open: allow 3 test requests
    Interval:    30 * time.Second,      // reset counter every 30s
    Timeout:     15 * time.Second,      // stay open for 15s before half-open
    ReadyToTrip: func(counts gobreaker.Counts) bool {
        return counts.ConsecutiveFailures > 3  // open after 3 consecutive failures
    },
    OnStateChange: func(name string, from, to gobreaker.State) {
        slog.Warn("circuit breaker state change",
            "name", name, "from", from, "to", to,
        )
        circuitBreakerState.WithLabelValues(name).Set(float64(to))
    },
})

Понедельник — деплой v3.8.1 через canary:

# Canary deployment: 5% traffic → monitor 30 min → 25% → 50% → 100%
apiVersion: argoproj.io/v1alpha1
kind: Rollout
spec:
  strategy:
    canary:
      steps:
        - setWeight: 5
        - pause: {duration: 30m}
        - setWeight: 25
        - pause: {duration: 15m}
        - setWeight: 50
        - pause: {duration: 15m}
        - setWeight: 100
      analysis:
        templates:
          - templateName: error-rate-check
        startingStep: 1

Метрики до/после

Postmortem

Timeline:

Root Cause: Обновление pgx с v5.5 на v5.7 содержало breaking change — автоматический возврат соединений в pool при отмене context был убран. Код, полагавшийся на это поведение, начал утекать соединения, что привело к исчерпанию connection pool и каскадному отказу.

Action Items:

Уроки

1. Canary deployment обязателен — 5% → 25% → 50% → 100% с паузами и автоматической проверкой метрик
2. Changelog dependency updates — читать breaking changes ДО деплоя, не после инцидента
3. defer resource.Release() — сразу после Acquire — шаблон, аналогичный defer resp.Body.Close()
4. Connection pool метрики — мониторить idle, active, waiters; алерт при waiters > 0
5. Circuit breaker не спасает от медленных ответов — если таймаут 30s, circuit breaker сработает только через 5 * 30s = 2.5 мин
6. Staging должен иметь реалистичный трафик — connection leak виден только под нагрузкой