Профилирование веб-приложений в Голанге
Я смотрел видеоролики Gophercon 2017 года здесь. Есть много хороших разговоров, которые я бы рекомендовал посмотреть из этого списка.
То, что я действительно хотел попробовать самостоятельно, было профилирующим выступлением, которое сделал Питер Бургон. Я предполагаю, что для простоты он оставил некоторые подробности .Я пытался выяснить их самостоятельно.
Я был вдохновлен попытаться профилировать свои собственные веб-приложения Golang, используя метод, который он представил в своем разговоре.Поэтому в этом сообщении я покажу вам упрощенный пример того, как более подробно описывать собственные веб-приложения.
Веб-приложение
Чтобы увидеть практический пример профилирования и упростить его, нам нужно создать веб-приложение, которое при вызове по определенному маршруту выполняет какой-то расчет и возвращает результат в его полезную нагрузку.
Если бы мы подражали реальным сценариям жизни, мы были бы здесь весь день.Поэтому просто чтобы это было просто, мы создадим один маршрут, который вычисляет 25-й номер Фибоначчи, когда он вызывается, и возвращает его в тело ответа.
Я написал две версии функции Фибоначчи перед операцией, которая выполняет рекурсию (экспоненциальное время- очень интенсивный процессор) и тот, который вычисляет число с использованием вектора (линейное время- не очень интенсивное ЦП).
Чтобы использовать инструмент профилирования, вам необходимо импортировать пакетnet/http/pprofи зарегистрировать некоторые маршруты.В упомянутой выше презентации докладчик отметил, что мы можем оставить это импортированное даже в производственных средах, поскольку оно не влияет на производительность.
package main
import (
"fmt"
"log"
"net/http"
"net/http/pprof"
)
// O(n) Fibonacci
func linearFibonacci(n int) int {
// Create an int array of size n + 1
v := make([]int, n+1)
// F(0) = 0
v[0] = 0
// F(1) = 1
v[1] = 1
// F(i) = F(i-1) + F(i-2)
for i := 2; i <= n; i++ {
v[i] = v[i-1] + v[i-2]
}
// F(n) - return the n-th Fibonacci number
return v[n]
}
// O(2^n) Fibonacci
func exponentialFibonacci(n int) int {
// F(0) = 0
if n == 0 {
return 0
}
// F(1) = 1
if n == 1 {
return 1
}
// F(n) = F(n-1) + F(n-2) - return the n-th Fibonacci number
return exponentialFibonacci(n-1) + exponentialFibonacci(n-2)
}
// HTTP request handler
func handler(w http.ResponseWriter, r *http.Request) {
// return the 25th Fibonacci number in the response payload
fmt.Fprintf(w, "%d", exponentialFibonacci(25))
}
func main() {
// Create a new HTTP multiplexer
mux := http.NewServeMux()
// Register our handler for the / route
mux.HandleFunc("/", handler)
// Add the pprof routes
mux.HandleFunc("/debug/pprof/", pprof.Index)
mux.HandleFunc("/debug/pprof/cmdline", pprof.Cmdline)
mux.HandleFunc("/debug/pprof/profile", pprof.Profile)
mux.HandleFunc("/debug/pprof/symbol", pprof.Symbol)
mux.HandleFunc("/debug/pprof/trace", pprof.Trace)
mux.Handle("/debug/pprof/block", pprof.Handler("block"))
mux.Handle("/debug/pprof/goroutine", pprof.Handler("goroutine"))
mux.Handle("/debug/pprof/heap", pprof.Handler("heap"))
mux.Handle("/debug/pprof/threadcreate", pprof.Handler("threadcreate"))
// Start listening on port 8080
if err := http.ListenAndServe(":8080", mux); err != nil {
log.Fatal(fmt.Sprintf("Error when starting or running http server: %v", err))
}
}
Как вы можете видеть, это действительно простое приложение, сохраните его в файле main.пойдите и постройте его следующим образом: gobuild-omyservermain.перейдите .
Теперь вы можете запустить исполняемый файл: ./myserver и проверить, будет ли он работать, мы отправим ему запрос:
$ curl http://localhost:8080
75025
Профиль процессора
Теперь, пока сервер работает, вам нужно будет запустить две команды параллельно.Сначала вам нужно запустить инструмент профилирования, который будет записывать данные в течение 30 секунд после его запуска. И когда он запускается, запустите инструмент Apache Benchmark, чтобы отправить несколько запросов.
Поэтому вам нужно запустить инструмент профилирования следующим образом:
gotoolpprof-секунды30 myserver http:// localhost: 8080 / debug / pprof / profile
Пока это работает, запустите тест:
ab-k-c8-n100000 "http://127.0.0.1:8080/"
Это создаст в общей сложности 100 000 запросов keep-alive на ваш сервер, используя 8 ядер.Чтобы лучше понять, что делает эта эталонная команда, она поясняется в приведенной ссылке.
Через 30 секунд инструмент профилирования отобразит приглашение для команд, которые будут выглядеть примерно так:
$ go tool pprof -seconds 30 myserver http://localhost:8080/debug/pprof/profile
Fetching profile from http://localhost:8080/debug/pprof/profile?seconds=30
Please wait... (30s)
Saved profile in /Users/username/pprof/pprof.myserver.localhost:8080.samples.cpu.013.pb.gz
Entering interactive mode (type "help" for commands)
(pprof)
Здесь вы можете запускать команды, чтобы показать вам, сколько времени процессорной функции каждой из них и другая полезная информация.
Например, если я запустил
top5,
он перечислит 5 верхних функций, которые забивают процессор:
(pprof) top5
84.57s of 85.18s total (99.28%)
Dropped 87 nodes (cum <= 0.43s)
Showing top 5 nodes out of 30 (cum >= 1.09s)
flat flat% sum% cum cum%
51.93s 60.97% 60.97% 51.93s 60.97% main.exponentialFibonacci
20.57s 24.15% 85.11% 20.59s 24.17% fmt.(*pp).doPrintf
12.06s 14.16% 99.27% 12.06s 14.16% syscall.Syscall
0.01s 0.012% 99.28% 11.22s 13.17% net.(*netFD).Write
0 0% 99.28% 1.09s 1.28% bufio.(*Reader).ReadLine
ак вы можете видеть,экспоненциальная функция Fibonacci действительно запускает CPU.
Обратите внимание: эти значения могут отличаться на вашем компьютере.Для справки я использую MacBook Pro (Retina, 13-дюймовый, ранний 2015), 2,7 ГГц процессор Intel Core i5 и 8 ГБ 1867 МГц DDR3 памяти.
Если бы мы хотели увидеть график этого профиля, нам нужно запустить веб-команду следующим образом:
(pprof) web
(pprof)
Это откроет браузер по умолчанию и отобразит изображение профиля.Вот кадр изображения, который касается нашей функции Фибоначчи:
Таким образом, во время этого профиля, 60,97% времени,экспоненциальныйFibonacci работал на процессоре.
Оптимизации
Теперь из теории известно, что O (n) <O (2 ^ n).Давайте посмотрим, будет ли это выполняться на практике, мы должны заменитьэкспоненциальный вызовФибоначчи линейным фибоначчи внутри функцииобработчика.
Теперь мы снова запустим профиль.Вы можете сразу увидеть, что это заняло меньше времени, потому что на этот раз эталонный тест действительно очень быстро заканчивается.
Если теперьзапустить top5, функцияlinearFibonacciдаже не сделает разрезание.Даже если вы попытаетесь сделать top100, вы не найдете его, потому что компилятор ввел этот конкретный код.
Таким образом, нам нужно перестроить приложение с помощью флагов компилятора, которые запрещают вложение следующим образом:
go build -gcflags -l -o myserver main.go
Теперь даже с включенным флагом мне было трудно найти функцию в верхней части.Я пошел вперед и увеличил жестко запрограммированное значение для n-го числа Фибоначчи до 10 000.Поэтому я ищу 10 000-ое число Фибоначчи, это число даже не вписывается в целочисленный тип данных в Голанге.Он будет переполняться несколько раз, прежде чем остановиться.Я также увеличил контрольный показатель до 1 000 000 запросов.
Теперь, если я запускаюtop5, я получаю:
Или в графическом формате:
Как вы можете видеть, он даже не делает вмятины.
Таким образом, для этого теста,вычисление 25-го числа Фибоначчи рекурсивно занимает 60% от ЦП, в то время как вычисление 10 000-го числа Фибоначчи линейно занимает 4% от ЦП (без инкрустации).
Еще одна полезная команда для pprof, чтобы увидеть, сколько процессорного времени занимает функция, - это командасписка.Или, если вы похожи на меня, выясните, действительно ли функция вызвана.
Для нашей линейной функции Фибоначчи это выглядит так:
(pprof) list linearFibonacci
Total: 46.49s
ROUTINE ======================== main.linearFibonacci in /Users/username/workspace/go/src/github.com/username/test_profiling/main.go
2.32s 4.26s (flat, cum) 9.16% of Total
. . 8:)
. . 9:
. . 10:// O(n) Fibonacci
. . 11:func linearFibonacci(n int) int {
. . 12: // Create an int array of size n + 1
10ms 1.95s 13: v := make([]int, n+1)
. . 14:
. . 15: // F(0) = 0
. . 16: v[0] = 0
. . 17: // F(1) = 1
. . 18: v[1] = 1
. . 19:
. . 20: // F(i) = F(i-1) + F(i-2)
260ms 260ms 21: for i := 2; i <= n; i++ {
2.05s 2.05s 22: v[i] = v[i-1] + v[i-2]
. . 23: }
. . 24:
. . 25: // F(n) - return the n-th Fibonacci number
. . 26: return v[n]
. . 27:}
Лучшее сравнение
Лучший способ сравнить два метода и теорию с практикой заключается в следующем:
- Зная, что экспоненциальный метод Фибоначчи равен O (2 ^ n), для вычисления 25-го числа Фибоначчи потребуется приблизительно 2 ^ 25 = 33554432 инструкций.
- Линейно вычисление 33554432-го числа Фибоначчи должно занимать примерно то же время, что и вычисление 25-го числа по экспоненте.
Итак, следуя методологии выше, мы делаем следующее:
- Создайте приложение, используя вызов exponentialFibonacci (25).
- Запустите приложение.
- Запустите тест Apache для 1 000 000 запросов.
- Запустите профиль процессора в течение 30 секунд.
Мы получаем следующее:
(pprof) top5
98.27s of 99.02s total (99.24%)
Dropped 64 nodes (cum <= 0.50s)
Showing top 5 nodes out of 30 (cum >= 1.30s)
flat flat% sum% cum cum%
60.78s 61.38% 61.38% 60.78s 61.38% main.exponentialFibonacci
24.54s 24.78% 86.16% 24.54s 24.78% fmt.(*pp).doPrintf
12.95s 13.08% 99.24% 12.95s 13.08% syscall.Syscall
0 0% 99.24% 1.30s 1.31% bufio.(*Reader).ReadLine
0 0% 99.24% 1.30s 1.31% bufio.(*Reader).ReadSlice
Теперь для второй части:
- Создайте приложение, используя вызов linearFibonacci (33554432).
- Запустите приложение.
- Запустите тест Apache для 1 000 000 запросов.
- Запустите профиль процессора в течение 30 секунд.
Мы получаем следующее:(pprof) top5
49280ms of 49870ms total (98.82%)
Dropped 92 nodes (cum <= 249.35ms)
Showing top 5 nodes out of 29 (cum >= 470ms)
flat flat% sum% cum cum%
28650ms 57.45% 57.45% 44400ms 89.03% main.linearFibonacci
15660ms 31.40% 88.85% 15660ms 31.40% runtime.memclr
3910ms 7.84% 96.69% 3910ms 7.84% runtime.usleep
590ms 1.18% 97.87% 590ms 1.18% runtime.duffcopy
470ms 0.94% 98.82% 470ms 0.94% runtime.mach_semaphore_timedwait
Как вы можете видеть, плоские проценты, сколько времени потрачено на рутину, примерно одинаковы.61.38% против 57.45%, разница между ними составляет 4%.
Профилирующая память
Используя тот же процесс, вы можете запустить следующую команду в память профиля:
go tool pprof -alloc_objects myserver http://localhost:8080/debug/pprof/heap
Если вы запустите верхнюю команду, вы увидите что-то вроде этого:
(pprof) top10
9741685 of 9927382 total (98.13%)
Dropped 7 nodes (cum <= 49636)
Showing top 10 nodes out of 33 (cum >= 99079)
flat flat% sum% cum cum%
3182489 32.06% 32.06% 3182489 32.06% net/textproto.(*Reader).ReadMIMEHeader
2050835 20.66% 52.72% 2050835 20.66% context.WithCancel
1068043 10.76% 63.47% 8447075 85.09% net/http.(*conn).readRequest
675175 6.80% 70.28% 5155947 51.94% net/http.readRequest
667729 6.73% 77.00% 667729 6.73% net/url.parse
655370 6.60% 83.60% 1414760 14.25% main.handler
618866 6.23% 89.84% 618866 6.23% main.linearFibonacci
589833 5.94% 95.78% 589833 5.94% net/textproto.(*Reader).ReadLine
134266 1.35% 97.13% 172250 1.74% net/http.newBufioWriterSize
99079 1% 98.13% 99079 1% sync.(*Pool).pinSlow
Вывод
Теперь, когда вы узнали о том, как профилировать свои веб-приложения Golang, вы можете начать погружение в более тяжелые вещи, подобные этому. Потратьте некоторое время и запустите профиль на своих собственных веб-приложениях Golang.
Кроме того, вы должны увидеть разговор Gophercon, который я упомянул в начале этого сообщения, это неплохо.