Представьте, endpoint на Fiber (Go framework) иногда отвечает за секунды вместо миллисекунд. Как вы будете искать причину?

Шаг 1: Воспроизведение и измерение

Прежде чем что-то менять, нужно воспроизвести проблему и получить конкретные цифры.

// Нагрузочный тест с помощью vegeta
// echo 'GET http://localhost:8080/api/endpoint' | \
//   vegeta attack -rate=100 -duration=60s | \
//   vegeta report -type=text

// Или через hey:
// hey -n 10000 -c 100 http://localhost:8080/api/endpoint

Смотрим latency distribution: p50, p95, p99, max. Если max >> p99 — редкие outliers. Если p99 стабильно высокий — системная проблема.

Шаг 2: Логирование с контекстом времени

// Middleware для детального логирования медленных запросов
app.Use(func(c *fiber.Ctx) error {
	start := time.Now()
	err := c.Next()
	duration := time.Since(start)

	if duration > 500*time.Millisecond {
		log.Printf("SLOW REQUEST path=%s method=%s status=%d duration=%v",
			c.Path(),
			c.Method(),
			c.Response().StatusCode(),
			duration,
		)
	}
	return err
})

Шаг 3: CPU и memory профилирование

// Подключаем pprof (только в dev/staging!)
import "github.com/gofiber/contrib/pprof"
pprof.Register(app)

// Снимаем CPU профиль во время нагрузки:
// go tool pprof -http=:6061 \
//   'http://localhost:8080/debug/pprof/profile?seconds=30'

// Смотрим goroutines при spike:
// curl http://localhost:8080/debug/pprof/goroutine?debug=1 | head -100

// Trace для детального анализа scheduler:
// curl http://localhost:8080/debug/pprof/trace?seconds=5 > trace.out
// go tool trace trace.out

Шаг 4: Проверка БД как источника

// Добавляем spans вокруг каждого DB-запроса
func (r *UserRepo) FindByID(ctx context.Context, id int) (*User, error) {
	_, span := tracer.Start(ctx, "db.users.findByID")
	defer span.End()

	var user User
	err := r.db.QueryRowContext(ctx,
		"SELECT id, email, name FROM users WHERE id = $1", id,
	).Scan(&user.ID, &user.Email, &user.Name)

	if err != nil {
		span.RecordError(err)
		return nil, err
	}
	return &user, nil
}

// Мониторинг pool в runtime
go func() {
	ticker := time.NewTicker(5 * time.Second)
	for range ticker.C {
		stats := db.Stats()
		if stats.WaitCount > 0 {
			log.Printf("DB POOL WAIT: count=%d duration=%v",
				stats.WaitCount, stats.WaitDuration)
		}
	}
}()

Шаг 5: GC как источник spike

// Запуск с GC трейсингом:
// GODEBUG=gctrace=1 ./myservice 2>&1 | grep ^gc

// Пример вывода при проблемном GC:
// gc 14 @23.attempt=1 12%: 0.1+450+0.3 ms clock
//                              ^-- 450ms STW pause!

// Уменьшение частоты GC (за счёт memory):
// GOGC=200 ./myservice  // GC при 200% от baseline heap

// Использование sync.Pool для hot-path структур:
var bufPool = sync.Pool{
	New: func() interface{} { return new(bytes.Buffer) },
}

Шаг 6: Fiber-специфичные проблемы

// Проверяем: нет ли утечки горутин в handler
func BadHandler(c *fiber.Ctx) error {
	// ОШИБКА: ctx переиспользуется, нельзя передавать в горутину
	go func() {
		time.Sleep(time.Second)
		log.Println(c.Path()) // c уже освобождён!
	}()
	return c.SendString("ok")
}

func GoodHandler(c *fiber.Ctx) error {
	path := c.Path() // копируем данные до запуска горутины
	go func() {
		time.Sleep(time.Second)
		log.Println(path) // безопасно
	}()
	return c.SendString("ok")
}

Подводные камни

• GC pause часто принимают за проблему Fiber — при heap >500 МБ паузы STW могут составлять сотни миллисекунд; диагностируется через GODEBUG=gctrace=1.
• Connection pool — самая частая причина — по умолчанию sql.DB имеет MaxOpenConns=0 (unlimited), что приводит к исчерпанию соединений PostgreSQL при нагрузке.
• Slowlog PostgreSQL выключен по умолчанию — нужно установить log_min_duration_statement = 100 в postgresql.conf для логирования медленных запросов.
• pprof профиль не отражает I/O wait — CPU pprof показывает только CPU time, а не время ожидания I/O; для этого нужен execution tracer (/debug/pprof/trace).
• Fiber Prefork усложняет профилирование — с Prefork: true запускаются дочерние процессы, pprof нужно подключать к каждому отдельно.
• Контекст с таймаутом не отменяет TCP соединение — при отмене context.Context DB-запрос отменяется на уровне Go, но не всегда на стороне PostgreSQL; нужен statement_timeout в самой БД.
• N+1 запросы видны только при реалистичных данных — в тестах с 10 записями N+1 незаметен, при 10 000 записях даёт 10 000 запросов к БД.
• Middleware порядок влияет на время измерения — если logger стоит после тяжёлого middleware, он не учитывает его время в метриках.

• Сразу обвинять Fiber (Go framework), не проверив соседние слои системы
• Чинить симптом без минимального воспроизведения и evidence
• Не учитывать версии, конфигурацию, окружение и recent changes

• Умеет локализовать проблему вокруг Fiber (Go framework)
• Двигается от симптома к гипотезам и проверкам
• Отличает баг инструмента от ошибки использования или окружения