"go test -cpuprofile" не создает полную трассировку

Question

Проблема

У меня есть пакет go с набором тестов.

Когда я запускаю набор тестов для этого пакета, общее время выполнения составляет ~ 7 секунд:

$ go test ./mydbpackage/ -count 1
ok      mymodule/mydbpackage    7.253s

Однако, когда я добавляю опцию -cpuprofile=cpu.out, выборка не охватывает весь цикл:

$ go test ./mydbpackage/ -count 1 -cpuprofile=cpu.out
ok      mymodule/mydbpackage    7.029s

$ go tool pprof -text -cum cpu.out
File: mydbpackage.test
Type: cpu
Time: Aug 6, 2020 at 9:42am (CEST)
Duration: 5.22s, Total samples = 780ms (14.95%)     # <--- depending on the runs, I get 400ms to 1s
Showing nodes accounting for 780ms, 100% of 780ms total
      flat  flat%   sum%        cum   cum%
         0     0%     0%      440ms 56.41%  testing.tRunner
      10ms  1.28%  1.28%      220ms 28.21%  database/sql.withLock
      10ms  1.28%  2.56%      180ms 23.08%  runtime.findrunnable
         0     0%  2.56%      180ms 23.08%  runtime.mcall
      ...

Просмотр собранных образцов:

# sample from another run :
$ go tool pprof -traces cpu.out | grep "ms "  # get the first line of each sample
      10ms   runtime.nanotime
      10ms   fmt.(*readRune).ReadRune
      30ms   syscall.Syscall
      10ms   runtime.scanobject
      10ms   runtime.gentraceback
      ...
# 98 samples collected, for a total sum of 1.12s

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

Контекст

go версия - 1.14.6, платформа - linux / amd64

$ go version
go version go1.14.6 linux/amd64

Этот пакет содержит код, который взаимодействует с базой данных, а тесты запускаются на реальном сервере postgresql.

Одна вещь, которую я пробовал: t.Skip() вызывает внутренний вызов runtime.Goexit(), поэтому я заменил вызовы t.Skip и варианты на простой return; но это не повлияло на результат.

Вопрос

Почему не собираются другие образцы? Есть ли какой-то известный шаблон, который блокирует / замедляет сэмплер или завершает сэмплер раньше, чем нужно?

Answer 1

@ Волкер привел меня к ответу в своих комментариях: -cpuprofile создает профиль, в котором отбираются только горутины, активно использующие ЦП.

В моем случае использования: мой код go тратит много времени в ожидании ответов сервера postgresql.

Создание трассировки с использованием go test -trace=trace.out, а затем извлечение профиля блокировки сети с использованием go tool trace -pprof=net trace.out > network.out дало гораздо более релевантную информацию.

Для справки, помимо открытия полной трассировки с помощью go tool trace trace.out , вот значения, которые вы можете передать в -pprof=:

из go tool trace docs :

• net: профиль блокировки сети
• syn c: профиль блокировки синхронизации
• syscall: профиль блокировки системных вызовов
• sched: профиль задержки планировщика