Пример troubleshooting

Кейс: "Заказы перестали создаваться"

Контекст

Представьте, что вы работаете в e-commerce компании. Пятница, 14:00. Приходит алерт: "Order creation success rate dropped to 60% (normal: 99.5%)". Бизнес теряет деньги каждую минуту.

Архитектура системы

Mobile/Web Client
      │
      ▼
[API Gateway (nginx)]
      │
      ▼
[Order Service (PHP)] ──► [PostgreSQL (primary)]
      │                         │
      ├──► [Redis (cache)]      └──► [PostgreSQL (replica)]
      │
      ├──► [Payment Service] ──► [Stripe API]
      │
      └──► [RabbitMQ] ──► [Inventory Worker]
                      ──► [Notification Worker]

Фаза 1: Detect (Обнаружение)

Первые действия

<?php

declare(strict_types=1);

/**
 * Phase 1: Detect - What are the symptoms?
 *
 * Alert received at 14:00:
 * "Order creation success rate: 60% (threshold: 95%)"
 *
 * Questions to answer:
 * 1. When exactly did it start?
 * 2. Is it all orders or specific types?
 * 3. What errors are users seeing?
 * 4. What changed recently?
 */

// Check recent error rates from metrics
final class IncidentDetector
{
    public function getErrorTimeline(\PDO $metricsDb): array
    {
        // Query metrics database for error rate over last 2 hours
        $stmt = $metricsDb->prepare("
            SELECT
                date_trunc('minute', timestamp) as minute,
                count(*) as total_requests,
                count(*) FILTER (WHERE status_code >= 500) as errors,
                round(
                    count(*) FILTER (WHERE status_code >= 500)::numeric /
                    count(*)::numeric * 100, 2
                ) as error_rate_pct
            FROM http_requests
            WHERE
                path = '/api/orders'
                AND method = 'POST'
                AND timestamp > NOW() - INTERVAL '2 hours'
            GROUP BY 1
            ORDER BY 1 DESC
            LIMIT 120
        ");
        $stmt->execute();

        return $stmt->fetchAll(\PDO::FETCH_ASSOC);
    }
}

// Timeline analysis results:
// 13:45 - error rate: 0.3% (normal)
// 13:50 - error rate: 0.5% (normal)
// 13:55 - error rate: 15% (SPIKE)
// 14:00 - error rate: 40% (CRITICAL)
// 14:05 - error rate: 38% (STABLE at high error rate)

// Observation: Problem started at ~13:55
// Question: What happened at 13:55?

Проверка недавних изменений

<?php

declare(strict_types=1);

/**
 * Check what changed around 13:55
 *
 * Findings:
 * - No deployments since 11:00
 * - No config changes
 * - No infrastructure changes
 * - Traffic is normal (not a spike)
 *
 * Conclusion: Not deployment-related. Something else changed.
 */

Анализ ошибок

<?php

declare(strict_types=1);

/**
 * Check error logs for the failing requests
 *
 * Log entries from Order Service:
 *
 * [14:02:15] ERROR: Failed to create order
 *   exception: PDOException
 *   message: "SQLSTATE[53300] too many connections for role 'order_service'"
 *   file: /app/src/Repository/OrderRepository.php:45
 *   request_id: req_abc123
 *
 * [14:02:16] ERROR: Failed to create order
 *   exception: PDOException
 *   message: "SQLSTATE[53300] too many connections for role 'order_service'"
 *
 * [14:02:17] ERROR: Failed to create order
 *   exception: PDOException
 *   message: "SQLSTATE[53300] too many connections for role 'order_service'"
 *
 * Pattern: ALL errors are "too many connections"
 */

Важно: Мы уже знаем симптом -- connection pool исчерпан. Но это не root cause. Почему connections заканчиваются?

Фаза 2: Isolate (Изоляция)

Проверяем базу данных

<?php

declare(strict_types=1);

/**
 * Phase 2: Isolate - Where exactly is the problem?
 *
 * Check PostgreSQL connection status
 */

// Connect directly to PostgreSQL admin to check connections
final class DatabaseDiagnostics
{
    public function checkConnections(\PDO $adminDb): array
    {
        // Check current connections by state
        $stmt = $adminDb->query("
            SELECT
                state,
                count(*) as count,
                max(EXTRACT(EPOCH FROM now() - query_start))::int as max_duration_sec,
                avg(EXTRACT(EPOCH FROM now() - query_start))::int as avg_duration_sec
            FROM pg_stat_activity
            WHERE datname = 'orders_db'
            GROUP BY state
            ORDER BY count DESC
        ");

        return $stmt->fetchAll(\PDO::FETCH_ASSOC);
    }

    public function checkLongRunningQueries(\PDO $adminDb): array
    {
        $stmt = $adminDb->query("
            SELECT
                pid,
                state,
                EXTRACT(EPOCH FROM now() - query_start)::int as duration_sec,
                left(query, 200) as query_preview,
                wait_event_type,
                wait_event
            FROM pg_stat_activity
            WHERE
                datname = 'orders_db'
                AND state != 'idle'
                AND query_start < NOW() - INTERVAL '10 seconds'
            ORDER BY query_start ASC
            LIMIT 20
        ");

        return $stmt->fetchAll(\PDO::FETCH_ASSOC);
    }

    public function checkLocks(\PDO $adminDb): array
    {
        $stmt = $adminDb->query("
            SELECT
                blocked.pid AS blocked_pid,
                blocked_activity.query AS blocked_query,
                blocking.pid AS blocking_pid,
                blocking_activity.query AS blocking_query,
                EXTRACT(EPOCH FROM now() - blocked_activity.query_start)::int AS blocked_duration
            FROM pg_catalog.pg_locks blocked
            JOIN pg_catalog.pg_stat_activity blocked_activity
                ON blocked.pid = blocked_activity.pid
            JOIN pg_catalog.pg_locks blocking
                ON blocked.transactionid = blocking.transactionid
                AND blocked.pid != blocking.pid
            JOIN pg_catalog.pg_stat_activity blocking_activity
                ON blocking.pid = blocking_activity.pid
            WHERE NOT blocked.granted
            ORDER BY blocked_duration DESC
        ");

        return $stmt->fetchAll(\PDO::FETCH_ASSOC);
    }
}

/**
 * FINDINGS:
 *
 * checkConnections() result:
 * | state               | count | max_duration_sec |
 * |---------------------|-------|------------------|
 * | idle in transaction | 87    | 1523             |
 * | active              | 8     | 2                |
 * | idle                | 5     | 0                |
 *
 * 87 connections stuck in "idle in transaction"!
 * max_connections = 100, so we're at 100% capacity.
 *
 * checkLongRunningQueries() result:
 * All 87 idle-in-transaction connections have the same query:
 * "SELECT * FROM inventory WHERE product_id = $1 FOR UPDATE"
 *
 * checkLocks() result:
 * Massive lock contention on inventory table.
 * One blocking PID holds a lock for 1523 seconds (25 minutes!)
 */

Root cause найден

Проблема в коде, который открывает транзакцию, берет lock на inventory, но не закрывает транзакцию, если вызов к Payment Service зависает.

<?php

declare(strict_types=1);

/**
 * THE BUGGY CODE (found in OrderService):
 */
final class BuggyOrderService
{
    public function createOrder(CreateOrderRequest $request): Order
    {
        $this->db->beginTransaction(); // Transaction started

        try {
            // Step 1: Lock inventory (acquires row lock)
            $stmt = $this->db->prepare(
                'SELECT * FROM inventory WHERE product_id = :id FOR UPDATE'
            );
            $stmt->execute(['id' => $request->productId]);

            // Step 2: Call payment service
            // BUG: If Stripe is slow (timeout 30s default),
            // we hold the DB lock for 30 seconds!
            $payment = $this->paymentService->charge(
                $request->userId,
                $request->amount,
            );

            // Step 3: Create order
            $order = $this->orderRepository->create($request, $payment);

            // Step 4: Update inventory
            $this->inventoryRepository->decrement($request->productId);

            $this->db->commit();

            return $order;
        } catch (\Throwable $e) {
            $this->db->rollBack();
            throw $e;
        }
    }
}

/**
 * WHAT HAPPENED:
 *
 * 1. At 13:50, Stripe started experiencing degradation
 *    (confirmed on status.stripe.com)
 * 2. Payment API calls that normally take 200ms started taking 25-30s
 * 3. Each slow payment call held a FOR UPDATE lock on inventory
 * 4. Connections accumulated: each request = 1 locked connection
 * 5. At 13:55, connection pool (100) was exhausted
 * 6. New requests couldn't get a connection -> 500 errors
 * 7. Some requests eventually timed out and released connections
 *    but new slow requests immediately took them -> 60% error rate
 */

Фаза 3: Mitigate (Митигация)

Немедленные действия

<?php

declare(strict_types=1);

/**
 * Phase 3: Mitigate - Stop the bleeding
 *
 * Immediate actions taken (in order):
 *
 * 1. Kill long-running idle transactions
 * 2. Reduce payment timeout
 * 3. Consider enabling circuit breaker for payment service
 */

// Action 1: Kill stuck connections
// Executed directly on PostgreSQL:
//
// SELECT pg_terminate_backend(pid)
// FROM pg_stat_activity
// WHERE state = 'idle in transaction'
// AND query_start < NOW() - INTERVAL '60 seconds';
//
// Result: 83 connections terminated

// Action 2: Reduce payment timeout (config change)
// Changed from default 30s to 5s
// This limits how long a connection can be held

// Action 3: Monitor
// After killing connections and reducing timeout:
// 14:15 - error rate dropped to 5%
// 14:20 - error rate dropped to 1%
// 14:25 - error rate back to 0.3% (normal)

Фаза 4: Eliminate (Устранение)

Исправление кода

<?php

declare(strict_types=1);

/**
 * Phase 4: Eliminate - Fix the root cause
 *
 * Problem: External API call inside a database transaction with row lock
 * Solution: Restructure to minimize lock duration
 */
final class FixedOrderService
{
    public function __construct(
        private readonly \PDO $db,
        private readonly PaymentService $paymentService,
        private readonly OrderRepository $orderRepository,
        private readonly InventoryRepository $inventoryRepository,
    ) {}

    public function createOrder(CreateOrderRequest $request): Order
    {
        // Step 1: Validate inventory OUTSIDE transaction (no lock)
        $available = $this->inventoryRepository->checkAvailability(
            $request->productId,
            $request->quantity,
        );

        if (!$available) {
            throw new InsufficientInventoryException($request->productId);
        }

        // Step 2: Process payment OUTSIDE transaction (no lock)
        // With explicit timeout and circuit breaker
        $payment = $this->paymentService->charge(
            userId: $request->userId,
            amount: $request->amount,
            idempotencyKey: $request->idempotencyKey, // Prevent double charge
            timeoutMs: 5000, // 5 second timeout
        );

        // Step 3: ONLY NOW start transaction for DB operations
        // Lock duration is minimal (milliseconds, not seconds)
        $this->db->beginTransaction();

        try {
            // Re-check and lock inventory (very fast operation)
            $locked = $this->inventoryRepository->reserveWithLock(
                $request->productId,
                $request->quantity,
            );

            if (!$locked) {
                // Inventory was taken between check and lock
                // Refund the payment
                $this->paymentService->refund($payment->id);
                throw new InsufficientInventoryException($request->productId);
            }

            $order = $this->orderRepository->create($request, $payment);

            $this->db->commit();

            // Async: send notifications, update analytics
            $this->dispatchEvents($order);

            return $order;
        } catch (\Throwable $e) {
            $this->db->rollBack();

            // If order creation failed but payment succeeded, refund
            if (isset($payment)) {
                $this->paymentService->refund($payment->id);
            }

            throw $e;
        }
    }

    private function dispatchEvents(Order $order): void
    {
        // Fire-and-forget via message queue
        // Not inside transaction
    }
}

Дополнительные защитные меры

<?php

declare(strict_types=1);

/**
 * Additional safeguards implemented after the incident
 */

// 1. Statement timeout at database level
// ALTER ROLE order_service SET statement_timeout = '10s';
// ALTER ROLE order_service SET idle_in_transaction_session_timeout = '30s';

// 2. Circuit breaker for payment service
final class PaymentCircuitBreaker
{
    private int $failureCount = 0;
    private int $successCount = 0;
    private ?float $openedAt = null;

    public function __construct(
        private readonly PaymentService $inner,
        private readonly int $failureThreshold = 5,
        private readonly int $resetTimeoutSeconds = 30,
    ) {}

    public function charge(string $userId, int $amount, string $idempotencyKey, int $timeoutMs): PaymentResult
    {
        if ($this->isOpen()) {
            throw new CircuitOpenException('Payment service circuit breaker is open');
        }

        try {
            $result = $this->inner->charge($userId, $amount, $idempotencyKey, $timeoutMs);
            $this->recordSuccess();
            return $result;
        } catch (\Throwable $e) {
            $this->recordFailure();
            throw $e;
        }
    }

    private function isOpen(): bool
    {
        if ($this->failureCount < $this->failureThreshold) {
            return false;
        }

        // Check if enough time has passed to try again (half-open)
        if ($this->openedAt !== null) {
            $elapsed = microtime(true) - $this->openedAt;
            if ($elapsed > $this->resetTimeoutSeconds) {
                return false; // Allow one request through (half-open)
            }
        }

        return true;
    }

    private function recordFailure(): void
    {
        $this->failureCount++;
        $this->successCount = 0;
        if ($this->failureCount >= $this->failureThreshold) {
            $this->openedAt = microtime(true);
        }
    }

    private function recordSuccess(): void
    {
        $this->failureCount = 0;
        $this->successCount++;
        $this->openedAt = null;
    }
}

// 3. Connection pool monitoring with alerting
// Alert when connection utilization > 70% (early warning)
// Alert when idle-in-transaction count > 10

Post-Mortem

Хронология инцидента

Impact

• Длительность: ~30 минут
• ~800 заказов не были созданы
• ~$45,000 потенциально потерянных продаж
• Большинство пользователей успешно повторили заказ после восстановления

Action Items

Выводы

Этот кейс иллюстрирует несколько важных принципов:

1. Никогда не делайте внешние вызовы внутри транзакции с блокировками -- это бомба замедленного действия
2. Connection pool -- общий ресурс -- одна медленная операция может заблокировать всю систему
3. Мониторинг на каждом уровне -- без метрик connections мы бы искали проблему гораздо дольше
4. Быстрая митигация важнее идеального исправления -- сначала остановите кровотечение, потом лечите

На troubleshooting интервью покажите, что вы следуете системному подходу, задаете правильные вопросы и расставляете приоритеты: сначала impact mitigation, потом root cause analysis.