Deep Engineering

MEASUREMENT

bench/goprof/exposure.go

The script that produced the numbers in the article, and the record of the run. The file is read from the repository at build time — this is the code that was run, not a copy of it.

Cited in
/en/interview/golang/profiling
How to run it
go run bench/goprof/internals.go
go run bench/goprof/cores.go
go run bench/goprof/interfere.go
go run bench/goprof/exposure.go
go run bench/goprof/practice.go

The run below is recorded in Russian. It is a lab record, kept in the language it was written in; the numbers, the tables and the code read the same either way.

Record of the run

Замеры для урока «Профилирование»

Файл Что делает
internals.go одна нагрузка и шесть профилей: CPU и его частота, flat против cum, куча (alloc_space против inuse_space), выключенные по умолчанию профили блокировок и мьютексов, профиль горутин на утечке, цена профиля CPU
cores.go профиль CPU на одной и на двух занятых горутинах: почему «Total samples» бывает больше 100 %
interfere.go цена режимов «записывать всё» у профилей блокировок, мьютексов и памяти и то, как профиль памяти искажает профиль CPU
exposure.go что отдаёт /debug/pprof на DefaultServeMux без проверки доступа
practice.go источник ответов двух практических задач урока
go run bench/goprof/internals.go
go run bench/goprof/cores.go
go run bench/goprof/interfere.go
go run bench/goprof/exposure.go
go run bench/goprof/practice.go

Программы сами вызывают go tool pprof, поэтому нужен установленный Go. Записи прогонов — в runs/, go1.24.7 linux/amd64, GOMAXPROCS=2.

Что здесь важно прочитать правильно

Таблицы — вывод go tool pprof -top. Строки File:, Build ID:, Time: и Type: из них убраны: они меняются от запуска к запуску.

Наносекунды и миллисекунды не переносятся. Переносится форма: у какой функции flat почти ноль, а cum — почти всё; какая функция есть в alloc_space и отсутствует в inuse_space.

Надбавка профиля CPU — в пределах шума. Три серии: −4,0 %, +0,1 %, −0,5 %. Знак не устойчив, устойчиво, что она мала.

Что получилось

Частота профиля CPU — 100 сэмплов в секунду. Она зашита в исходнике runtime/pprof (const hz = 100). Замер: 203 сэмпла за 2,11 с работы одной горутины, 96 в секунду.

flat и cum. У main.handle flat 0, cum 1800 мс — 86,96 %: сам он ничего не делает, под ним hashAll.

Куча. main.churn выделил 596,83 МБ и в inuse_space отсутствует вовсе; main.retain выделил 16,19 МБ и держит их все.

Блокировки и мьютексы. Без настройки — 0 записей в обоих профилях при настоящей конкуренции; после SetBlockProfileRate(1) и SetMutexProfileFraction(1) — 3 и 2.

Утечка горутин. Сто горутин, ждущих канала, в который никто не пишет: горутин до: 1, после: 101, все сто — под одним стеком.

Процент в «Total samples» — доля процессорного времени от стенного. Одна занятая горутина: 93,39 %; две на двух ядрах: 181,35 % (cores.go). Одна горутина занимает не больше одного ядра; несколько — могут набрать больше процессорного времени, чем прошло по часам.

«Записывать всё» не бесплатно. На крайних нагрузках (interfere.go, три серии): SetBlockProfileRate(1) — ×1,64–1,90, SetMutexProfileFraction(1) — ×1,35–1,61, MemProfileRate = 1 — ×50–62. При MemProfileRate = 1 runtime.mProf_Malloc занимает 76,64 % профиля CPU той же нагрузки: один профиль искажает другой. Нагрузки намеренно крайние; переносится направление, а не кратность.

/debug/pprof на рабочем порту отдаёт всё без проверки доступа. exposure.go: сервис, зарегистрировавший только /hello на DefaultServeMux, отдал аргументы запуска (с выдуманным паролем), стеки горутин с путями к исходникам и профиль кучи — все со статусом 200.

Script

77 lines
//go:build ignore

// Что отдаёт /debug/pprof тому, кто до него достучался.
//
// ЗАЧЕМ. Урок советует снимать профиль CPU в продакшене через net/http/pprof.
// У этого совета есть обязательная вторая половина: импорт пакета
// регистрирует обработчики на http.DefaultServeMux, и если сервис отдаёт
// DefaultServeMux на внешний порт, профили уходят туда же. Здесь поднимается
// такой сервис на локальном порту и печатается, что он отдаёт без какой-либо
// проверки доступа. Секрет в аргументах — выдуманный, ради демонстрации.
//
// ЗАПУСК:
//
//	go run bench/goprof/exposure.go
package main

import (
	"fmt"
	"io"
	"net"
	"net/http"
	_ "net/http/pprof"
	"os"
	"runtime"
	"strings"
)

func get(base, path string) (int, string) {
	resp, err := http.Get(base + path)
	if err != nil {
		panic(err)
	}
	defer resp.Body.Close()
	b, _ := io.ReadAll(resp.Body)
	return resp.StatusCode, string(b)
}

func main() {
	// Как запускают сервис, которому пароль от базы передали флагом.
	os.Args = append(os.Args[:1], "-db-password=demo-secret")

	http.HandleFunc("/hello", func(w http.ResponseWriter, _ *http.Request) { io.WriteString(w, "hi") })
	ln, err := net.Listen("tcp", "127.0.0.1:0")
	if err != nil {
		panic(err)
	}
	go http.Serve(ln, nil) // nil — это DefaultServeMux, как у большинства сервисов
	base := "http://" + ln.Addr().String()

	fmt.Printf("%s %s/%s | что отдаёт /debug/pprof без проверки доступа\n\n",
		runtime.Version(), runtime.GOOS, runtime.GOARCH)
	fmt.Println("  сервис зарегистрировал только /hello и отдаёт DefaultServeMux")
	fmt.Println()

	code, body := get(base, "/debug/pprof/cmdline")
	args := strings.Split(body, "\x00")
	fmt.Printf("  GET /debug/pprof/cmdline           -> %d, аргументы: %q\n", code, args[1:])

	code, body = get(base, "/debug/pprof/goroutine?debug=2")
	frames := 0
	for _, l := range strings.Split(body, "\n") {
		if strings.HasPrefix(l, "\t/") || strings.HasPrefix(l, "\t") && strings.Contains(l, ".go:") {
			frames++
		}
	}
	fmt.Printf("  GET /debug/pprof/goroutine?debug=2 -> %d, строк «файл:строка»: %d\n", code, frames)

	code, _ = get(base, "/debug/pprof/heap")
	fmt.Printf("  GET /debug/pprof/heap              -> %d\n", code)

	fmt.Println()
	fmt.Println("  Ни одной проверки доступа: всё, что слушает порт сервиса, видит")
	fmt.Println("  аргументы запуска, стеки с путями к исходникам и профили памяти.")
	fmt.Println("  Пример из документации пакета слушает localhost:6060 — отдельный")
	fmt.Println("  порт, закрытый снаружи; так его и держат.")
}