предисловие
Эта серия статей выглядит следующим образом
В первой части я уделил время тому, чтобы описать поведение сборщика мусора golang и проиллюстрировать задержки, с которыми сталкивается сборщик во время работы программы. Я поделился тем, как генерировать и интерпретировать трассировки сборщика мусора. В нем также показано, как изменяется память в куче, и объясняется влияние различных этапов сборки мусора на стоимость задержки.
Суть в том, что если вы уменьшите нагрузку на кучу, вы уменьшите штрафы за задержку и улучшите производительность программы. Я также указал, что снижение скорости сбора, отсрочка сбора и попытка увеличить время между сборами — не лучшая стратегия. Даже при высокой скорости сбора, работа в постоянном темпе позволяет программе работать с максимальной производительностью.
В этой части я проведу вас через реальное веб-приложение и покажу, как генерировать трассировки сборщика мусора и состояние программы. Затем я объясню вывод этих инструментов, чтобы вы могли найти способы улучшить производительность своего приложения.
запустить приложение
Взгляните на веб-приложение для обучения go
Рисунок 1.1
GitHub.com/AR но лаборатории/…
На рис. 1 показано, как выглядит приложение. Эта программа загружает три набора rss-подписок из разных мест и позволяет пользователям осуществлять поиск. После сборки запустите программу
L1
$ go build
$ GOGC=off ./project > /dev/null
В L1 мы устанавливаем переменную GOGC в значение off, что означает отключение сборки мусора. Лог перенаправления на /dev/null. Когда программа запущена, мы можем отправлять запросы на сервер.
L2
$ hey -m POST -c 100 -n 10000 "http://localhost:5000/search?term=topic&cnn=on&bbc=on&nyt=on"
L2 показывает 10 000 запросов, отправленных через hey с использованием 100 соединений. Все запросы отправляются на сервер, и результат этого процесса выглядит следующим образом:
Рисунок 1.2
Включите сборщик мусора
Что произойдет, если GC включен
L3
$ GODEBUG=gctrace=1 ./project > /dev/null
GOGC убран в L3, с помощью переменной GODEBUG мы можем видеть следы GC.GODEBUGПосле настройки среда выполнения будет генерировать трассировку GC каждый раз при ее сборе. Теперь мы снова запускаем те же 10 000 запросов. Все запросы отправляются на сервер, мы можем видеть трассировки GC иheyпредоставленная информация.
L4
$ GODEBUG=gctrace=1 ./project > /dev/null
gc 3 @3.182s 0%: 0.015+0.59+0.096 ms clock, 0.19+0.10/1.3/3.0+1.1 ms cpu, 4->4->2 MB, 5 MB goal, 12 P
.
.
.
gc 2553 @8.452s 14%: 0.004+0.33+0.051 ms clock, 0.056+0.12/0.56/0.94+0.61 ms cpu, 4->4->2 MB, 5 MB goal, 12 P
Третья и последняя трассировка GC с начала выполнения программы показана в L4. Я не показывал первые две коллекции, потому что информация о загрузке не отправляется через службу до тех пор, пока эти коллекции не будут выполнены. Последняя коллекция показывает, что всего для обработки запроса была сгенерирована 2551 коллекция (не считая первых двух)
Ниже мой раскол для каждой трассы
L5
gc 2553 @8.452s 14%: 0.004+0.33+0.051 ms clock, 0.056+0.12/0.56/0.94+0.61 ms cpu, 4->4->2 MB, 5 MB goal, 12 P
gc 2553 : The 2553 GC runs since the program started
@8.452s : Eight seconds since the program started
14% : Fourteen percent of the available CPU so far has been spent in GC
// wall-clock
0.004ms : STW : Write-Barrier - Wait for all Ps to reach a GC safe-point.
0.33ms : Concurrent : Marking
0.051ms : STW : Mark Term - Write Barrier off and clean up.
// CPU time
0.056ms : STW : Write-Barrier
0.12ms : Concurrent : Mark - Assist Time (GC performed in line with allocation)
0.56ms : Concurrent : Mark - Background GC time
0.94ms : Concurrent : Mark - Idle GC time
0.61ms : STW : Mark Term
4MB : Heap memory in-use before the Marking started
4MB : Heap memory in-use after the Marking finished
2MB : Heap memory marked as live after the Marking finished
5MB : Collection goal for heap memory in-use after Marking finished
// Threads
12P : Number of logical processors or threads used to run Goroutines.
L5 показывает фактический номер последней коллекции. благодаряhey, а ниже приведены результаты производительности во время выполнения, которые мы видим.
L6
Requests : 10,000
------------------------------------------------------
Requests/sec : 1,882 r/s - Hey
Total Duration : 5,311ms - Hey
Percent Time in GC : 14% - GC Trace
Total Collections : 2,551 - GC Trace
------------------------------------------------------
Total GC Duration : 744.54ms - (5,311ms * .14)
Average Pace of GC : ~2.08ms - (5,311ms / 2,551)
Requests/Collection : ~3.98 r/gc - (10,000 / 2,511)
L6 дает результат. Визуализация процесса приведена ниже, чтобы увидеть, что происходит.
Рисунок 1.3
На рис. 1.3 показано, как происходит визуализация. После включения коллектора для тех же 10к запросов ему приходится обрабатывать около ~2,5к коллекций. Средняя скорость обработки каждой коллекции составляет около 2 мс, а обработка этих коллекций добавляет дополнительную задержку около 1,1 секунды.
Рисунок 1.4
уменьшить распределение
Нам лучше посмотреть на выделение памяти в куче, чтобы увидеть, есть ли непродуктивные выделения, которые можно удалить.
L7
go tool pprof http://localhost:5000/debug/pprof/allocs
L7 использует pprof для вызова/debug/pprof/allocsинтерфейса, а затем получить информацию о выделении памяти из запущенной программы. Этот интерфейс существует, потому что используется следующий код.
L8
import _ "net/http/pprof"
go func() {
http.ListenAndServe("localhost:5000", http.DefaultServeMux)
}()
импортnet/http/pprofДля привязки службы по умолчанию системы. затем используйтеhttp.ListenAndServerнестиhttp.DefaultServerMuxдля запуска службы.
L9
(pprof) top 6 -cum
Showing nodes accounting for 0.56GB, 5.84% of 9.56GB total
Dropped 80 nodes (cum <= 0.05GB)
Showing top 6 nodes out of 51
flat flat% sum% cum cum%
0 0% 0% 4.96GB 51.90% net/http.(*conn).serve
0.49GB 5.11% 5.11% 4.93GB 51.55% project/service.handler
0 0% 5.11% 4.93GB 51.55% net/http.(*ServeMux).ServeHTTP
0 0% 5.11% 4.93GB 51.55% net/http.HandlerFunc.ServeHTTP
0 0% 5.11% 4.93GB 51.55% net/http.serverHandler.ServeHTTP
0.07GB 0.73% 5.84% 4.55GB 47.63% project/search.rssSearch
Появился под L9rssSearchМетоды. Этот метод выделяет 4,55 ГБ памяти. Следующее использованиеlistДавайте посмотрим на внутренние детали этого метода.
L10
(pprof) list rssSearch
Total: 9.56GB
ROUTINE ======================== project/search.rssSearch in project/search/rss.go
71.53MB 4.55GB (flat, cum) 47.63% of Total
. . 117: // Capture the data we need for our results if we find ...
. . 118: for _, item := range d.Channel.Items {
. 4.48GB 119: if strings.Contains(strings.ToLower(item.Description), strings.ToLower(term)) {
48.53MB 48.53MB 120: results = append(results, Result{
. . 121: Engine: engine,
. . 122: Title: item.Title,
. . 123: Link: item.Link,
. . 124: Content: item.Description,
. . 125: })
L10 перечисляет код, строка 119 показывает большое выделение памяти
L11
. 4.48GB 119: if strings.Contains(strings.ToLower(item.Description), strings.ToLower(term)) {
L11 дает код, в котором возникает проблема. Вся функция выделяет 4,55 ГБ данных, но эта строка выделяет 4,48 ГБ. Давайте посмотрим, что делает эта строка кода, и посмотрим, где мы можем ее оптимизировать.
L12
117 // Capture the data we need for our results if we find the search term.
118 for _, item := range d.Channel.Items {
119 if strings.Contains(strings.ToLower(item.Description), strings.ToLower(term)) {
120 results = append(results, Result{
121 Engine: engine,
122 Title: item.Title,
123 Link: item.Link,
124 Content: item.Description,
125 })
126 }
127 }
L12 перечисляет код в узком цикле. передачаstrings.ToLowerВыделение памяти происходит потому, что необходимо создать новые строки и выделить их в куче. вызов в циклеstrings.ToLowerВ этом нет необходимости, так как обработка может быть выполнена полностью вне цикла.
119 строк кода можно подправить, чтобы избавиться от ненужного выделения памяти.
L13
// Before the code change.
if strings.Contains(strings.ToLower(item.Description), strings.ToLower(term)) {
// After the code change.
if strings.Contains(item.Description, term) {
Примечание: перед закладкой предмета в кешitem.DescriptionПосле нижней обработки эта часть кода не отображается. Новые вставленные элементы кэшируются каждые 15 минут. ПучокtermНижняя обработка может выполняться непосредственно вне цикла
L13 показывает, как мы ставимstrings.ToLowerВзято из узкой петли. Перекомпилируйте проект и запустите его, затем снова возьмите 10 000 запросов.
L14
$ go build
$ GODEBUG=gctrace=1 ./project > /dev/null
gc 3 @6.156s 0%: 0.011+0.72+0.068 ms clock, 0.13+0.21/1.5/3.2+0.82 ms cpu, 4->4->2 MB, 5 MB goal, 12 P
.
.
.
gc 1404 @8.808s 7%: 0.005+0.54+0.059 ms clock, 0.060+0.47/0.79/0.25+0.71 ms cpu, 4->5->2 MB, 5 MB goal, 12 P
В L14 после корректировки кода теперь всего 1402 коллекции под один и тот же 10К запрос.
L15
With Extra Allocations Without Extra Allocations
======================================================================
Requests : 10,000 Requests : 10,000
----------------------------------------------------------------------
Requests/sec : 1,882 r/s Requests/sec : 3,631 r/s
Total Duration : 5,311ms Total Duration : 2,753 ms
Percent Time in GC : 14% Percent Time in GC : 7%
Total Collections : 2,551 Total Collections : 1,402
----------------------------------------------------------------------
Total GC Duration : 744.54ms Total GC Duration : 192.71 ms
Average Pace of GC : ~2.08ms Average Pace of GC : ~1.96ms
Requests/Collection : ~3.98 r/gc Requests/Collection : 7.13 r/gc
L15 показывает сравнение с предыдущими результатами. Ниже представлена более четкая визуализация того, что происходит.
Рисунок 1.5
Рисунок 1.6
что ты изучал
Как упоминалось в предыдущей статье, повышение эффективности сборщика заключается в снижении нагрузки на динамическую память. Помните, что нагрузку можно определить как скорость, с которой приложение выделяет доступную память кучи в заданное время. Когда давление снижается, задержка, создаваемая коллектором, уменьшается. Эти задержки могут замедлить работу вашего приложения.
L16
With Extra Allocations Without Extra Allocations
======================================================================
Requests : 10,000 Requests : 10,000
----------------------------------------------------------------------
Requests/sec : 1,882 r/s Requests/sec : 3,631 r/s
Total Duration : 5,311ms Total Duration : 2,753 ms
Percent Time in GC : 14% Percent Time in GC : 7%
Total Collections : 2,551 Total Collections : 1,402
----------------------------------------------------------------------
Total GC Duration : 744.54ms Total GC Duration : 192.71 ms
Average Pace of GC : ~2.08ms Average Pace of GC : ~1.96ms
Requests/Collection : ~3.98 r/gc Requests/Collection : 7.13 r/gc
L16 — это текущее сравнение двух вышеуказанных программ с версией GC. Очевидно, удаление ненужного выделения 4,48 ГБ ускоряет работу программы. Интересно, что средняя скорость сборки мусора в обеих версиях почти одинакова, около 2 мс. Что мы изменили, так это то, что мы стали больше работать между каждой коллекцией. Заявка увеличена с 3,98р/гк до 7,13р/гк (запросы/гк). Объем работы увеличился на 79,1%.
Обработка большей работы между коллекциями поможет уменьшить количество коллекций. Вы можете увидеть, что количество GCS уменьшилось с 2551 до 1402, что составляет около 45%. Время GC Application было сокращено на 74%, от 745 до 193 мс или на 14% до 7% от общего времени. Если вы запустите оптимизированную версию кода с помощью GC, разница производительности составляет всего 13%, а время обработки приложений падает с 275 мс до 2398 м.
В заключение
Если вы потратите время, чтобы сосредоточиться на сокращении выделений, вы, как разработчик go, повысите эффективность сборщика мусора. Вы не можете написать программу с нулевым распределением памяти, поэтому важно различать продуктивные распределения памяти (которые помогают программе работать) и непродуктивные распределения памяти (которые снижают производительность). Тогда вы можете полностью довериться gc, который позаботится об управлении памятью за вас.
gc - хороший компромисс. Я потратил немного времени на обработку gc, и в результате мне больше не нужно было беспокоиться об управлении памятью. Go сделает разработчиков более продуктивными, а приложения по-прежнему будут работать достаточно быстро, и все благодаря сборщику мусора golang.