Многие разработчики редко используют отладчик при возникновении проблем в коде. Если вы пишете модульные тесты и используете линтинг и рефакторинг, то этот быстрый и грязный подход будет работать в большинстве случаев.

Однако порой намного проще открыть интерактивный отладчик, чем постоянно добавлять утверждения и операторы print.

Graph of a memory leak slowly building up, then the fix leveling out.
Пример графика, отображающего утечку памяти

Запись и визуализация профилирования

Возьмем базовый веб-сервер Golang и отправим искусственный трафик. Затем воспользуемся инструментом pprof, чтобы собрать как можно больше информации.

// main.go
package main

import (
    "fmt"
    "log"
    "net/http"
    "time"
)
func handler(w http.ResponseWriter, r *http.Request) {
    fmt.Fprintf(w, "Hello World!\n")
}

func main() {
    srv := http.Server{
        Addr:         ":8080",
        ReadTimeout:  time.Minute,
        WriteTimeout: time.Minute,
    }
    http.HandleFunc("/", handler)
    done := make(chan os.Signal, 1)
    signal.Notify(done, os.Interrupt, syscall.SIGINT, syscall.SIGTERM)
    
    go func() {
        srv.ListenAndServe()
    }()
    <-done
    err := srv.Shutdown(context.Background())
    if err != nil {
        log.Fatal(err)
    }
}

Чтобы убедиться в работоспособности кода, воспользуемся:

$ go run main.go &
$ curl localhost:8080
Hello World!

Теперь профилируем процессор с помощью следующего фрагмента:

...
f, err := os.Create("cpu.prof")
if err != nil {
    log.Fatal(err)
}
err = pprof.StartCPUProfile(f)
if err != nil {
    log.Fatal(err)
}
defer pprof.StopCPUProfile()
...

Мы используем инструмент нагрузочного тестирования vegeta для моделирования интенсивного трафика.

$ echo "GET http://localhost:8080" | vegeta attack -duration=5s
Hello world!
...

После отключения веб-сервера появится файл cpu.prof, который содержит профиль процессора. Его можно визуализировать с помощью pprof:

$ go tool pprof cpu.prof
Type: cpu
Time: Jan 16, 2020 at 4:51pm (EST)
Duration: 9.43s, Total samples = 50ms ( 0.53%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top 10
Showing nodes accounting for 50ms, 100% of 50ms total
Showing top 10 nodes out of 24
      flat  flat%   sum%        cum   cum%
      20ms 40.00% 40.00%       20ms 40.00%  syscall.syscall
...

Хорошее начало, но Go может и лучше. Чтобы профилировать приложение по мере получения трафика, не нужно полагаться на имитированный трафик или добавлять дополнительный код для записи профилей в файл. Импорт net/http/pprof автоматически добавляет дополнительные обработчики на веб-сервер:

import _ "net/http/pprof"

После этого можно перейти по маршруту /debug/pprof/ через веб-браузер и увидеть страницу pprof, переполненную информацией.

Example of the Golang profiler pprof’s web interface
Пример полученной информации при переходе на /debug/pprof/

Получить ту же информацию можно также с помощью команды:

$ go tool pprof -top http://localhost:8080/debug/pprof/heap

Вы также можете:

  • Генерировать изображения на основе типа профиля.
  • Создавать Flame Graphs для визуализации времени, потраченного приложением.
  • Отслеживать горутины для обнаружения утечек до ухудшения работы сервиса.

Интерактивный отладчик Delve

Delve — это простой в использовании полнофункциональный инструмент отладки для Go. Он значительно упрощает добавление точек останова, проверку утверждений и погружение в пакеты.

Начать работу с инструментом довольно просто: следуйте инструкциям по установке. Добавьте оператор runtime.Breakpoint() и запустите код с помощью dlv:

$ dlv debug main.go
Type 'help' for list of commands.
(dlv) continue

При достижении точки останова появится блок кода. Например, на веб-сервере выше я добавил it в обработчик:

> main.handler() ./main.go:20 (PC: 0x1495476)
    15:         _ "net/http/pprof"
    16: )
    17:
    18: func handler(w http.ResponseWriter, r *http.Request) {
    19:         runtime.Breakpoint()
=>  20:         fmt.Fprintf(w, "Hello World!\n")
    21: }
    22:
    23: func main() {
    24:         srv := http.Server{
    25:                 Addr:         ":8080",
(dlv)

Теперь можно пройтись по каждой строке с помощью команды next или n или углубиться в функцию, используя step или s.

Screenshot of interacting with VS Code test and debug buttons
Пример VS Code с расширением Golang

В VS Code есть отличная поддержка delve. При написании модульных тестов с использованием встроенной библиотеки тестирования вы увидите кнопку debug test, которая инициализирует delve и позволяет пройтись по коду через VS Code в интерактивном сеансе.

Дополнительную информацию об отладке кода Go с помощью кода VS можно найти на Microsoft wiki.

Детекторы утечки и Race-детекторы

В 2017 году Uber представил пакет goleak — простой инструмент для проверки элементов, отмеченных с помощью TestingT как ошибки, при наличии дополнительных горутин, найденных с помощью Find.

Он выглядит следующим образом:

func TestA(t *testing.T) {
   defer goleak.VerifyNone(t)
   // Тестируем логику здесь.
}

При выполнении сложной асинхронной работы вы можете быть уверены, что не столкнетесь с регрессией и будете следовать пятому принципу Дзена Go:

Прежде чем запускать горутину, определите момент ее остановки.

Убедившись в отсутствии утечек Go, необходимо установить защиту от состояния гонки. К счастью, для этого есть встроенный race-детектор. Рассмотрим пример из его документации:

func main() {
	c := make(chan bool)
	m := make(map[string]string)
	go func() {
		m["1"] = "a" // First conflicting access.
		c <- true
	}()
	m["2"] = "b" // Second conflicting access.
	<-c
	for k, v := range m {
		fmt.Println(k, v)
	}
}

Это гонка данных, которая может привести к сбоям и повреждению памяти. Запуск этого фрагмента с флагом -race приводит к появлению сообщения об ошибке:

go run -race main.go 
==================
WARNING: DATA RACE
Write at 0x00c0000e2210 by goroutine 8:
  runtime.mapassign_faststr()
      /usr/local/Cellar/go/1.13.6/libexec/src/runtime/map_faststr.go:202 +0x0
  main.main.func1()
      /PATH/main.go:19 +0x5d

Previous write at 0x00c0000e2210 by main goroutine:
  runtime.mapassign_faststr()
      /usr/local/Cellar/go/1.13.6/libexec/src/runtime/map_faststr.go:202 +0x0
  main.main()
      /PATH/main.go:22 +0xc6

Goroutine 8 (running) created at:
  main.main()
      /PATH/main.go:18 +0x97
==================
2 b
1 a
Found 1 data race(s)

Несмотря на то, что этот флаг можно использовать во время выполнения кода, наиболее полезной практикой будет добавление его в команду go test, чтобы обнаруживать гонки во время написания тестов.

Читайте также:


Перевод статьи Tyler Finethy: Debug Go Like a Pro

Предыдущая статья5 мудрых цитат известнейших программистов
Следующая статьяИсследование операций: что, когда и как